Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-547

Exception stack trace printing starting from root cause

    Details

    • Type: New Feature
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 0.9.22
    • Fix Version/s: 0.9.30
    • Component/s: None
    • Labels:
      None

      Description

      A typical exception in multi-tier application looks similar to this:

      com.acme.BusinessException: Can't process request
      at ...
      at ...
      Caused by: com.acme.dao.PersistenceException: Can't access database
      at ...
      at ...
      ... 49 common frames omitted
      Caused by: org.springframework.jdbc.datasource.lookup.DataSourceLookupFailureException: Unable to locate datasource
      at ...
      at ...
      ... 65 common frames omitted
      Caused by: java.net.UnknownHostException: Unknown host localhostt
      at ...
      at ...
      ... 84 common frames omitted

      The deeper exception, the more specific information it gives. Typically the last "Caused by" is the most interesting one. So it seems like reversing the order in which the exceptions are thrown (from most specific to consecutive, less specific wrappers) might be more intuitive:

      java.net.UnknownHostException: Unknown host localhostt
      at ...
      at ...
      Wrapped by: org.springframework.jdbc.datasource.lookup.DataSourceLookupFailureException: Unable to connect to the database
      at ...
      at ...
      Wrapped by: com.acme.dao.PersistenceException: Can't access database
      at ...
      at ...
      Wrapped by: com.acme.BusinessException: Can't process request
      at ...
      at ...

      It is not only easier to read and follow (business exception is interesting for the end user while the most precise, technical information is for developers and system administrators - so it should be easily accessible in the logs), but also the stack trace isn't mixed. You can read stack frames in exactly the same order as they were executed, no need to jump from one stack trace line to another (see attachment from the real application). This also means that the beginning of the thread is always at the bottom and the line that caused the very first exception - at the top. (look at the attached real exception)

      I already implemented this feature by adding RootCauseFirstThrowableProxyConverter extending ch.qos.logback.classic.pattern.ExtendedThrowableProxyConverter. It is turned on by appending "%rEx" to the encoder pattern. If you like this feature, I will push the changes (just few classes have changed) into my GitHub fork.

        Activity

        Show
        nurkiewicz Tomasz Nurkiewicz added a comment - I pushed rough implementation of this feature, including some smoke unit tests: http://github.com/nurkiewicz/logback/commit/679fcda1a4a3e67fcb2604e47c7fa0de2beaf6bd http://github.com/nurkiewicz/logback/commit/869b85c1362ba5e60d53e92d1480609d906f0c20
        Hide
        nurkiewicz Tomasz Nurkiewicz added a comment -

        Any news on this issue?

        Show
        nurkiewicz Tomasz Nurkiewicz added a comment - Any news on this issue?
        Hide
        noreply.ceki@qos.ch Ceki Gulcu added a comment -

        Looks good.

        Show
        noreply.ceki@qos.ch Ceki Gulcu added a comment - Looks good.
        Hide
        noreply.ceki@qos.ch Ceki Gulcu added a comment - - edited

        I get 404 on both github links listed above.

        Anyway, I am currently looking into https://github.com/nurkiewicz/logback/commit/a21ed3cc6fc72da5b3c2f54e6b61752ff1d0100f which seems to be the relevant commit. However, it lacks documentation for rEx/rootException under [1]. Care to add it? The source is under logback-site/src/site/pages/manual/layouts.html. As I plan to make a release soon, please let me know if you want to take a shot at the docs. Otherwise, I'll handle it.

        [1] http://logback.qos.ch/manual/layouts.html#conversionWord

        Show
        noreply.ceki@qos.ch Ceki Gulcu added a comment - - edited I get 404 on both github links listed above. Anyway, I am currently looking into https://github.com/nurkiewicz/logback/commit/a21ed3cc6fc72da5b3c2f54e6b61752ff1d0100f which seems to be the relevant commit. However, it lacks documentation for rEx/rootException under [1] . Care to add it? The source is under logback-site/src/site/pages/manual/layouts.html. As I plan to make a release soon, please let me know if you want to take a shot at the docs. Otherwise, I'll handle it. [1] http://logback.qos.ch/manual/layouts.html#conversionWord
        Hide
        noreply.ceki@qos.ch Ceki Gulcu added a comment - - edited

        Just applied https://github.com/nurkiewicz/logback/commit/a21ed as [1] on my repo. I also wrote the relevant documentation [2]. Please review if you can.

        [1] https://github.com/ceki/logback/commit/f0b1a778e9
        [2] https://github.com/ceki/logback/commit/b1e595bcf4

        Show
        noreply.ceki@qos.ch Ceki Gulcu added a comment - - edited Just applied https://github.com/nurkiewicz/logback/commit/a21ed as [1] on my repo. I also wrote the relevant documentation [2] . Please review if you can. [1] https://github.com/ceki/logback/commit/f0b1a778e9 [2] https://github.com/ceki/logback/commit/b1e595bcf4
        Hide
        nurkiewicz Tomasz Nurkiewicz added a comment -

        Thank you for applying this feature! Sorry for broken links, don't know how this happened. I opened a trivial pull request (Correct 0.9.30 version in @since tag: https://github.com/ceki/logback/pull/28). If you care, I also blogged about this feature: http://nurkiewicz.blogspot.com/2011/09/logging-exceptions-root-cause-first.html

        Show
        nurkiewicz Tomasz Nurkiewicz added a comment - Thank you for applying this feature! Sorry for broken links, don't know how this happened. I opened a trivial pull request (Correct 0.9.30 version in @since tag: https://github.com/ceki/logback/pull/28 ). If you care, I also blogged about this feature: http://nurkiewicz.blogspot.com/2011/09/logging-exceptions-root-cause-first.html

          People

          • Assignee:
            logback-dev@qos.ch Logback dev list
            Reporter:
            nurkiewicz Tomasz Nurkiewicz
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: