views:

409

answers:

5

I'm looking at the output from spring being loaded up by tomcat and there's something very strange...Everything is duplicated. What would cause this? Whatever it is, it's causing my application to run in odd ways.

Additional Info:

The application is a web app. All the spring information is loaded using the context loader(?) defined in the web.xml file. My configuration files are split amoung 6 (or so) files.

Example debug output:

[DEBUG,DefaultFilterInvocationDefinitionSource,main] Added URL pattern: /**; attributes: [REQUIRES_SECURE_CHANNEL]

[DEBUG,DefaultFilterInvocationDefinitionSource,main] Added URL pattern: /**; attributes: [REQUIRES_SECURE_CHANNEL]

[DEBUG,DefaultFilterInvocationDefinitionSource,main] Added URL pattern: /**; attributes: [ROLE_READ, ROLE_UPDATE]

[DEBUG,DefaultFilterInvocationDefinitionSource,main] Added URL pattern: /**; attributes: [ROLE_READ, ROLE_UPDATE]

[DEBUG,AbstractFallbackMethodDefinitionSource,main] Adding security method [CacheKey[com.service.impl.FooServiceImpl; public abstract java.lang.Boolean com.service.IFooService.saveOrUpdateFoo(com.model.Foo2,java.lang.String) throws org.springframework.dao.DataAccessException]] with attribute [[ROLE_UPDATE]]

[DEBUG,AbstractFallbackMethodDefinitionSource,main] Adding security method [CacheKey[com.service.impl.FooServiceImpl; public abstract java.lang.Boolean com.service.IFooService.saveOrUpdateFoo(com.model.Foo2,java.lang.String) throws org.springframework.dao.DataAccessException]] with attribute [[ROLE_UPDATE]]

[INFO,AbstractSecurityInterceptor,main] Validated configuration attributes

[INFO,AbstractSecurityInterceptor,main] Validated configuration attributes

+1  A: 

Are you sure that something in the logging configuration isn't adding each category/logger to the appender more than once?

That's something that's possible with log4j, not sure about JCL or whatever the latest version of Tomcat uses under the cover.

matt b
I'd say i'm about 95% sure. Given that each http request is being processed twice leads me to believe spring is "loaded twice"
oneBelizean
Are you sure that you aren't actually receiving two http requests? What does Tomcat's access log show?
matt b
That definitely looks like duplicate logging output. Have you checked the timestamps? If they're exactly the same, presumably your app does stuff that is expensive, and so the timestamps should not match up.
MetroidFan2002
You might get diagnostic help by adding the internal application timestamp to the log format. In log4j I think this is %r, which is the # of microseconds since the application launched. If these differ at all between log statements, the actions are repeated, if not the logging is.
Dov Wasserman
A: 

Are you loading the spring config info programatically ? How are you loading SpringConfig ? That might give us some inputs.

anjanb
A: 

In Tomcat, if your application is configured to be the default application it must be deployed under the /root directory. If not, then Tomcat will launch 2 copies of your application, one where you put it, and one where it expects the default to be.

That could explain what is happening here, assuming that I recall all of that correctly.

Gary Rowe
A: 

The answer and comments here are very likely to be correct.

Post your log4j configuration as an update/edit to your question, then I'll post the fix as an update/edit to my answer.

opyate
A: 

I face the same problem with you, and it was just a log4j configuration problem, here is my original configuration

<category name="org.springframework">
    <level value="INFO"></level>
    <appender-ref ref="basicAppender" />
</category>

In this configuration, all the class in package org.springframework will log once and because of I didn't set the additivity property to false, the logger "org.springframework" will log again, and that results all the logs are duplicated. So I just set the additivity property to false, and it works. Well, it's just my situation, may it will be helpful to you.

khotyn