[logback-user] Configuring for detailed information on trace level, for entry and exit extensions
Mads Bondo Dydensborg
mbd at dbc.dk
Thu Jun 13 17:29:54 CEST 2013
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 at 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
More information about the Logback-user
mailing list