Uploaded image for project: 'Log4j 2'
  1. Log4j 2
  2. LOG4J2-2092

Extended Throwable produces unnecessary long stack traces compared to standard stack trace

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Open
    • Minor
    • Resolution: Unresolved
    • 2.9.1
    • None
    • Pattern Converters
    • None

    Description

      Let's consider the following exception stack trace, printed using the standard %throwable converter (43 lines):

      java.lang.RuntimeException: Failed to parse JavaBean
	at com.example.test.Main$JavaBean.parse(Main.java:16)
	at com.example.test.Main.main(Main.java:23)
Caused by: Cannot create property=test for JavaBean=com.example.test.Main$JavaBean@2957fcb0
 in 'string', line 1, column 1:
    test: !test Hello World!
    ^
Can't construct a java object for !test; exception=Invalid tag: !test
 in 'string', line 1, column 7:
    test: !test Hello World!
          ^

 in 'string', line 1, column 7:
    test: !test Hello World!
          ^

	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.constructJavaBean2ndStep(Constructor.java:268)
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.construct(Constructor.java:149)
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:308)
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207)
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196)
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructDocument(BaseConstructor.java:161)
	at org.yaml.snakeyaml.constructor.BaseConstructor.getSingleData(BaseConstructor.java:147)
	at org.yaml.snakeyaml.Yaml.loadFromReader(Yaml.java:524)
	at org.yaml.snakeyaml.Yaml.loadAs(Yaml.java:501)
	at com.example.test.Main$JavaBean.parse(Main.java:14)
	... 1 more
Caused by: Can't construct a java object for !test; exception=Invalid tag: !test
 in 'string', line 1, column 7:
    test: !test Hello World!
          ^

	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:313)
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207)
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196)
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.constructJavaBean2ndStep(Constructor.java:247)
	... 10 more
Caused by: org.yaml.snakeyaml.error.YAMLException: Invalid tag: !test
	at org.yaml.snakeyaml.nodes.Tag.getClassName(Tag.java:112)
	at org.yaml.snakeyaml.constructor.Constructor.getClassForNode(Constructor.java:637)
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.getConstructor(Constructor.java:298)
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:308)
	... 13 more

      The same exception, printed using the extended throwable (%xThrowable) converter, takes 64 lines:

      java.lang.RuntimeException: Failed to parse JavaBean
	at com.example.test.Main$JavaBean.parse(Main.java:16) ~[test/:?]
	at com.example.test.Main.main(Main.java:23) [test/:?]
Caused by: org.yaml.snakeyaml.constructor.ConstructorException: Cannot create property=test for JavaBean=com.example.test.Main$JavaBean@2957fcb0
 in 'string', line 1, column 1:
    test: !test Hello World!
    ^
Can't construct a java object for !test; exception=Invalid tag: !test
 in 'string', line 1, column 7:
    test: !test Hello World!
          ^

 in 'string', line 1, column 7:
    test: !test Hello World!
          ^

	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.constructJavaBean2ndStep(Constructor.java:268) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.construct(Constructor.java:149) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:308) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructDocument(BaseConstructor.java:161) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.getSingleData(BaseConstructor.java:147) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.Yaml.loadFromReader(Yaml.java:524) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.Yaml.loadAs(Yaml.java:501) ~[snakeyaml-1.19.jar:?]
	at com.example.test.Main$JavaBean.parse(Main.java:14) ~[test/:?]
	... 1 more
Caused by: org.yaml.snakeyaml.constructor.ConstructorException: Can't construct a java object for !test; exception=Invalid tag: !test
 in 'string', line 1, column 7:
    test: !test Hello World!
          ^

	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:313) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.constructJavaBean2ndStep(Constructor.java:247) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.construct(Constructor.java:149) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:308) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructDocument(BaseConstructor.java:161) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.getSingleData(BaseConstructor.java:147) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.Yaml.loadFromReader(Yaml.java:524) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.Yaml.loadAs(Yaml.java:501) ~[snakeyaml-1.19.jar:?]
	at com.example.test.Main$JavaBean.parse(Main.java:14) ~[test/:?]
	... 1 more
Caused by: org.yaml.snakeyaml.error.YAMLException: Invalid tag: !test
	at org.yaml.snakeyaml.nodes.Tag.getClassName(Tag.java:112) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor.getClassForNode(Constructor.java:637) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.getConstructor(Constructor.java:298) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:308) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.constructJavaBean2ndStep(Constructor.java:247) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructMapping.construct(Constructor.java:149) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.Constructor$ConstructYamlObject.construct(Constructor.java:308) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:207) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:196) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructDocument(BaseConstructor.java:161) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.constructor.BaseConstructor.getSingleData(BaseConstructor.java:147) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.Yaml.loadFromReader(Yaml.java:524) ~[snakeyaml-1.19.jar:?]
	at org.yaml.snakeyaml.Yaml.loadAs(Yaml.java:501) ~[snakeyaml-1.19.jar:?]
	at com.example.test.Main$JavaBean.parse(Main.java:14) ~[test/:?]
	... 1 more

      While the standard stack trace always excludes all stack trace elements that have been mentioned before, the extended stack trace includes the full stack trace except for elements that are present in the root throwable. This makes long throwable cause chains hard to read since several elements are included more than once.

      The extended throwable converter should produce stack traces consistent with the standard stack trace converter (plus the location information), or at least provide an option to exclude the unnecessary elements.

      It seems like ThrowableProxy initializes all causes with the root Throwable as parent, instead of passing the actual (direct) parent of the cause:

      https://github.com/apache/logging-log4j2/blob/ee71628868326caad9dd974028058b4efcac7afd/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ThrowableProxy.java#L166

      Changing new ThrowableProxy(parent, ... to new ThrowableProxy(cause, ... on the line above fixes the issue.

      Attachments

        1. Example.java
          2 kB
          Thomas Rebele

        Activity

          People

            Unassigned Unassigned
            applefreak AppleFreak
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

              Created:
              Updated: