[JIRA] Created: (LBCLASSIC-305) Logger does not implement LocationAwareLogger correctly with Wrapper class
Logger does not implement LocationAwareLogger correctly with Wrapper class --------------------------------------------------------------------------- Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug.zip As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
[ http://jira.qos.ch/browse/LBCLASSIC-305?page=com.atlassian.jira.plugin.syste... ] Steve Cohen updated LBCLASSIC-305: ---------------------------------- Attachment: logback-bug.zip
Logger does not implement LocationAwareLogger correctly with Wrapper class ---------------------------------------------------------------------------
Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug.zip
As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
[ http://jira.qos.ch/browse/LBCLASSIC-305?page=com.atlassian.jira.plugin.syste... ] Steve Cohen commented on LBCLASSIC-305: --------------------------------------- After stepping through code it seems that the problem is that when filtered through LocationAwareLogger.log(), the new Throwable() call does not fill in a correct stack trace, but when going through a method such as Logger.debug(), the call to new Throwable() DOES produce a correct stack trace (albeit non-location-aware). This is why my original bandaid in see http://jira.qos.ch/browse/LBCORE-233) works, but this does not. Hard to tell what's going on here because Throwable.fillInStackTrace() is native code. However, I don't suspect platform implementation because this issue was originally noticed (see http://jira.qos.ch/browse/LBCORE-233) on a Windows XP platform using Sun Java 1.6, whereas this test was on Ubuntu Linux using Sun Java 1.6.
Logger does not implement LocationAwareLogger correctly with Wrapper class ---------------------------------------------------------------------------
Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug.zip
As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
[ http://jira.qos.ch/browse/LBCLASSIC-305?page=com.atlassian.jira.plugin.syste... ] Steve Cohen updated LBCLASSIC-305: ---------------------------------- Attachment: logback-bug-2.zip In this version of the project (logback-bug-2.zip) it's a bit easier to see what's going on. This version rewrites LogHelper so that trace(...) delegates to Logger.trace() whereas all the other levels delegate, as before, to LocationAwareLogger.log(). It shows that the former does find correct (but, of course, non-location-aware) stack traces to work with but the latter does not find correct stack traces. Output: 2011-11-07 08:28:23,230 DEBUG [main] ?#?:? - Constructor of A 2011-11-07 08:29:30,554 TRACE [main] Caller+0 at org.javactivity.LogHelper.trace(LogHelper.java:51) - A() 2011-11-07 08:34:42,981 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:10) - Constructor of B 2011-11-07 08:35:16,844 TRACE [main] Caller+0 at org.javactivity.LogHelper.trace(LogHelper.java:51) - B()
Logger does not implement LocationAwareLogger correctly with Wrapper class ---------------------------------------------------------------------------
Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug-2.zip, logback-bug.zip
As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
[ http://jira.qos.ch/browse/LBCLASSIC-305?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-305: -------------------------------------- It seems that you have missed the point of the fcqn parameter in LocationAwareLogger#log method. The fcqn should be always equal to the fully qualified class name of the wrapper class, in your case LogHelper. The fcqn should not be a parameter passed to LogHelper. Here is the modified code: public class LogHelper { private static final String fqcn = LogHelper.class.getName(); private LocationAwareLogger logger; public LogHelper(Class<?> klazz) { this.logger = (LocationAwareLogger) LoggerFactory.getLogger(klazz); } ... rest of the code unchanged } With this modification it all works nicely. Please check and confirm.
Logger does not implement LocationAwareLogger correctly with Wrapper class ---------------------------------------------------------------------------
Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug-2.zip, logback-bug.zip
As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
[ http://jira.qos.ch/browse/LBCLASSIC-305?page=com.atlassian.jira.plugin.syste... ] Steve Cohen commented on LBCLASSIC-305: --------------------------------------- Yes, indeed, it was confusion on my part, thank you. With your suggestion, it works. In my original implementations I was using the LogHelper class name as the FQCN, but that wasn't working because I didn't understand the need for LocationAwareLogger. So somewhere along there, I started passing in the name of the caller of the logHelper, but this fell afoul of the +1 logic. If I may make a suggestion: The explanations in the slf4j javadoc should be improved: http://slf4j.org/api/index.html?org/slf4j/spi/LocationAwareLogger.html Currently it says the following og void log(Marker marker, String fqcn, int level, String message, Object[] argArray, Throwable t) Printing method with support for location information. Parameters: marker - fqcn - The fully qualified class name of the caller level - message - t - A couple of points could be clearer as we discussed on the other thread: 1) marker - it may and in this case should be null. 2) fqcn - the comment is confusing. What is the caller? Is it the caller in the user code who invokes the wrapper (i.e, the one whose location info you want to see) or it is the wrapper class who invokes LocationAwareLogger.log()? I now know it's the latter, but it's not hard to see why I became confused. Anyway, thanks again for a great utility.
Logger does not implement LocationAwareLogger correctly with Wrapper class ---------------------------------------------------------------------------
Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug-2.zip, logback-bug.zip
As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
[ http://jira.qos.ch/browse/LBCLASSIC-305?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu resolved LBCLASSIC-305. ---------------------------------- Resolution: Duplicate
Logger does not implement LocationAwareLogger correctly with Wrapper class ---------------------------------------------------------------------------
Key: LBCLASSIC-305 URL: http://jira.qos.ch/browse/LBCLASSIC-305 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Steve Cohen Assignee: Logback dev list Attachments: logback-bug-2.zip, logback-bug.zip
As shown in the attached project, we are logging using Logback classic through a wrapper class (LogHelper), with formatting specified by the %caller format specifier. Instead of showing the desired actual caller of the LogHelper.debug() method, the output shows as the caller, the caller of the caller of the logHelper. I'm expecting: 2011-11-06 18:49:59,650 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:8) - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.B.<init>(B.java:7) - Constructor of B Instead I get: 2011-11-06 18:49:59,650 DEBUG [main] ?#?:? - Constructor of A 2011-11-06 18:49:59,654 DEBUG [main] Caller+0 at org.javactivity.A.<init>(A.java:9) - Constructor of B
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
participants (2)
-
Ceki Gulcu (JIRA) -
Steve Cohen (JIRA)