[JIRA] Created: (LBCLASSIC-303) LoggingEvent.getCallerData() fails when called from a sub class
LoggingEvent.getCallerData() fails when called from a sub class --------------------------------------------------------------- Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too. -- 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-303?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-303: -------------------------------------- I believe that writing "new LoggingEvent(this.getClass().getName()" biases the whole test.
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Greg Thomas commented on LBCLASSIC-303: --------------------------------------- OK - thanks; I found the original construct in some of the DBAppender tests which I'm in the middle of re-factoring - see the createLoggingEvent() method in https://github.com/ceki/logback/blob/master/logback-classic/src/test/java/ch... I spent some time trying to work out why my re-factored test wasn't working - until I realised it was caused by this problem. I'll see if I can modify the test in line with your suggestion ...
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-303: -------------------------------------- In DBAppenderH2Test.java, we only care that the event's callerData in persisted into the database. We don't care about the actual callerData values which are assumed to be correct.
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Greg Thomas commented on LBCLASSIC-303: --------------------------------------- Hmm, interestingly the tests appear to test something that isn't supported. Unless I've missed something, you can't log an exception with an array of arguments. i.e. there's no final public void debug(String format, Object[] argArray, Throwable t); set of methods. So, if you call, for example, logger.debug(msg, args, new Exception("test Ex") ); you end up in final public void debug(String format, Object arg1, Object arg2); which means that contents of args is lost. So, a) Should the (String format, Object[] argArray, Throwable t) set of signatures exists?, or b) Should I remove the argArray with Exception test from the DBAppender test suite?, or c) What have I missed? Thanks for your patience!
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-303: -------------------------------------- If the last argument is an exception it is treated as such. This change was introduced in SLF4J v 1.6.0. Here is the text: In the presence of multiple parameters and if the last argument in a logging statement is an exception, then SLF4J will now presume that the user wants the last argument to be treated as an exception and not a simple parameter. See the relevant FAQ entry for further details. This fixes bug 70 submitted by Joern Huxhorn who also provided the relevant patch. See also http://slf4j.org/faq.html#paramException Does the above help?
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Greg Thomas commented on LBCLASSIC-303: --------------------------------------- Sorry, I should have made myself clearer. I'm aware of the way that the last argument is treated as an exception, however logger.info("This message has two arguments, arg1={} and arg2={}, and an exception:", new Object[]{"1", "2"}, new Exception("Foobar")); Is not handled as I would expect.
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-303: -------------------------------------- The following will work as intended: logger.info("arg1={} and arg2={}, and an exception:", new Object[]{"1", "2", new Exception("Foobar")}); Regarding you initial question, a) the existing signatures have their inconveniences but for compatibility reasons the interface can't be changed b) no, see the "logger.info("arg1={} ..." example c) I hope it makes better sense now.
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Greg Thomas commented on LBCLASSIC-303: --------------------------------------- It does - many thanks. I can now get my re-factored DBAppender test for LBCORE-220 working, I just need to add an additional multi-threaded test. I think the report in the original description is still valid; but it's a pretty low priority issue, as there is the work around that you suggested. Unfortunately, I mistakenly left the priority at the default (Major) and now can't change it!
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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-303?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-303: -------------------------------------- Don't worry about the priority. As long as it gets fixed, whether LBCORE-220 is TRIVIAL, MINOR, MAJOR etc is not important.
LoggingEvent.getCallerData() fails when called from a sub class ---------------------------------------------------------------
Key: LBCLASSIC-303 URL: http://jira.qos.ch/browse/LBCLASSIC-303 Project: logback-classic Issue Type: Bug Affects Versions: 1.0.0 Reporter: Greg Thomas Assignee: Logback dev list
This is probably best demonstrated with a code example; package com.example; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.LoggingEvent; public class Test { Logger logger; public static void main(String[] args) { Test test = new Test(); test.go(); } private void go() { SuperClass anotherClass = new SuperClass(); anotherClass.go(); anotherClass = new SubClass(); anotherClass.go(); } private class SuperClass { public void go() { LoggerContext lc = new LoggerContext(); lc.setName("default"); // ... a logger logger = lc.getLogger("root"); LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "Test logging event", new Exception( "test Ex"), new String[] { "something" }); StackTraceElement[] callerData = le.getCallerData(); System.out.println("LoggingEvent in " + this.getClass().getName() + " has " + callerData.length + " stack trace elements:"); for (StackTraceElement stackTraceElement : callerData) { System.out.println("Element=" + stackTraceElement); } } } private class SubClass extends SuperClass { } } The output of this is as follows; LoggingEvent in com.example.Test$SuperClass has 2 stack trace elements: Element=com.example.Test.go(Test.java:20) Element=com.example.Test.main(Test.java:14) LoggingEvent in com.example.Test$SubClass has 0 stack trace elements: This is despite exactly the same go() method being called; it's not being modified in the subclass. Note that although the example uses inner classes, the same behaviour is exhibited in regular classes too.
-- 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) -
Greg Thomas (JIRA)