Configuring for detailed information on trace level, for entry and exit extensions
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 -- 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
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
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
participants (2)
-
Ceki Gülcü -
Mads Bondo Dydensborg