(Moved to list, such that google can pick this up for the benefit of others) Thanks a bunch! I am using (or rather, the people configuring the log is using) AsyncAppender. I had totally missed that you need to set includeCallerData to true, mea culpa. Thanks & Kind regards Mads Torsdag 13 juni 2013 17:59:05 skrev Ceki Gülcü:

Are the logging evetns sent over the network? Are you using AsyncAppender? You need to set includeCallerData to true.

http://logback.qos.ch/manual/appenders.html#asyncIncludeCallerData

On 6/13/2013 5:29 PM, Mads Bondo Dydensborg wrote:

...

Hi Ceki

Thanks!

We are using slf4j - the language is java, configuration through logback.xml and binding using Maven. We are using Rhino to run som JavaScript, but the problems are "everywhere", not related to JavaScript.

There are no AOP.

Here is a stacktrace before a log statement (In one of the first constructors. I have no statements where the class, method or line information is shown, so any log statement will do, I reckon.). The stacktrace looks "correct", ie, have methodnames, linenumbers, etc. that makes sense to me ;-)

java.lang.Exception: testing at dk.dbc.openformat.EnvironmentFactory.<init>(EnvironmentFactory.java:107) at dk.dbc.openformat.OpenFormatServletContextListener.contextInitialized(OpenFormatServletContextListener.java:124) at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:579) at org.mortbay.jetty.servlet.Context.startContext(Context.java:156) at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1215) at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:548) at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:348) at org.mortbay.jetty.plugin.Jetty6PluginWebAppContext.doStart(Jetty6PluginWebAppContext.java:107) at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:151) at org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:156) at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:151) at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130) at org.mortbay.jetty.Server.doStart(Server.java:222) at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) at org.mortbay.jetty.plugin.Jetty6PluginServer.start(Jetty6PluginServer.java:132) at org.mortbay.jetty.plugin.AbstractJettyMojo.startJetty(AbstractJettyMojo.java:384) at org.mortbay.jetty.plugin.AbstractJettyMojo.execute(AbstractJettyMojo.java:320) at org.mortbay.jetty.plugin.Jetty6RunWar.execute(Jetty6RunWar.java:67) at org.apache.maven.plugin.DefaultPluginManager.executeMojo(DefaultPluginManager.java:490) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoals(DefaultLifecycleExecutor.java:694) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeStandaloneGoal(DefaultLifecycleExecutor.java:569) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoal(DefaultLifecycleExecutor.java:539) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoalAndHandleFailures(DefaultLifecycleExecutor.java:387) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeTaskSegments(DefaultLifecycleExecutor.java:348) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.execute(DefaultLifecycleExecutor.java:180) at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:328) at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:138) at org.apache.maven.cli.MavenCli.main(MavenCli.java:362) at org.apache.maven.cli.compat.CompatibleMain.main(CompatibleMain.java:60) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.codehaus.classworlds.Launcher.launchEnhanced(Launcher.java:315) at org.codehaus.classworlds.Launcher.launch(Launcher.java:255) at org.codehaus.classworlds.Launcher.mainWithExitCode(Launcher.java:430) at org.codehaus.classworlds.Launcher.main(Launcher.java:375)

Any help greatly appreciated!

Kind regards

Mads

Torsdag 13 juni 2013 15:23:04 skrev Ceki Gülcü:

...

Hi Mads,

The character is output '?' by %class (or %C), %method (or %M), %line (or %L) if caller information could not be computed. Incorrect caller information is usually due to logging via wrappers or interceptors in dynamic languages. In other words, computation of caller information is sensitive to the method invocation stack.

Are you using a dynamic language, AOP or a logger wrapper?

In any case, an actual stack trace would help understanding the problem. For example, if the following logger call results in incorrect caller info:

logger.debug("Hello world");

print a stack trace just before (or after) that logger invocation, e.g.

new Exception("testing").printStackTrace(); logger.debug("Hello world");

I'd appreciate if you could post the stack trace here.

Best regards,

Can you post a stack trace

On 6/13/2013 2:43 PM, Mads Bondo Dydensborg wrote:

...

Hi there.

Using <slf4j.version>1.7.5</slf4j.version> <logback.version>1.0.13</logback.version>

And, with the following in logback.xml:

<!-- Copy encoder from console --> <encoder> <!-- <pattern>%d{ISO8601} [%thread] rid:%X{trackingId} %-5level %logger{5} - %msg%n</pattern> --> <!-- <pattern>%d{ISO8601} [%thread] rid:%X{trackingId} %-5level %logger{5}.%M:%L - %msg%n</pattern> --> <pattern>%d{ISO8601} [%thread] rid:%X{trackingId} %-5level %class{5}.%M:%L - %msg%n</pattern> <immediateFlush>true</immediateFlush> <outputPatternAsHeader>true</outputPatternAsHeader> </encoder>

This outputs #logback.classic pattern: %d{ISO8601} [%thread] rid:%X{trackingId} %-5level %class{5}.%M:%L - %msg%n 2013-06-13 12:55:49,486 [main] rid: TRACE ?.?:? - entry

Changing to the first commented pattern, gets me:

#logback.classic pattern: %d{ISO8601} [%thread] rid:%X{trackingId} %-5level %logger{5} - %msg%n 2013-06-13 14:35:20,450 [main] rid: TRACE d.d.o.EnvironmentFactory - entry

Second commented pattern: #logback.classic pattern: %d{ISO8601} [%thread] rid:%X{trackingId} %-5level %logger{5}.%M:%L - %msg%n 2013-06-13 14:36:37,689 [main] rid: TRACE d.d.o.EnvironmentFactory.?:? - entry

Any idea what I am doing wrong here? The point was to get method name and line numbers, as per this: http://logback.qos.ch/manual/layouts.html#conversionWord

Any clues?

Thanks in advance.

Mads

_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user

-- Med venlig hilsen/Regards Chefarkitekt/Chief Architect cand.scient.dat, Ph.d., Mads Bondo Dydensborg Dansk BiblioteksCenter A/S, Tempovej 7-11, 2750 Ballerup, Tlf. +45 29 84 00 42