Log4net
  1. Log4net
  2. LOG4NET-154

Add a StackTracePatternConverter to display method calls leading up to log message

    Details

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

      Description

      Modify LocationInfo to save StackTrace information and make it available as StackTracePatternConverter to display call stack leading up to the log message:

      log.Debug("Item Saved");

      [%stackTrace

      {3}

      ] %message%newline

      [default_aspx.btnSubmit_Click > productController.Save > productService.Save] Item Saved

      This will probably be a slow pattern converter on par with other LocationInfo derived pattern converters.

      1. StackTracePatternConverter.zip
        4 kB
        Michael Cromwell
      2. log4net - StackTrace and StackTraceDetail.zip
        2 kB
        Adam Davies
      3. StackTracePatternConverter.cs
        8 kB
        Adam Davies

        Issue Links

          Activity

          Hide
          Stefan Bodewig added a comment -

          The parts discussed here that have not been implemented yet have been postponed to LOG4NET-314

          Show
          Stefan Bodewig added a comment - The parts discussed here that have not been implemented yet have been postponed to LOG4NET-314
          Hide
          Stefan Bodewig added a comment -

          I've had a look at Adam's (MAX|MIN) contribution and would suggest some improvements (in particular in the light of Lars' comments further up). Therefore I've opened LOG4NET-314 - which will not be part of the 1.2.11 release - and intend to close this issue as soon as the docs are in.

          Show
          Stefan Bodewig added a comment - I've had a look at Adam's (MAX|MIN) contribution and would suggest some improvements (in particular in the light of Lars' comments further up). Therefore I've opened LOG4NET-314 - which will not be part of the 1.2.11 release - and intend to close this issue as soon as the docs are in.
          Hide
          Stefan Bodewig added a comment -

          Documentation on stacktracedetail pattern is missing completely and stacktrace isn't documented in all places where it should be.

          I'll look into Adam's latest attachment to see what is still missing from his patch.

          Show
          Stefan Bodewig added a comment - Documentation on stacktracedetail pattern is missing completely and stacktrace isn't documented in all places where it should be. I'll look into Adam's latest attachment to see what is still missing from his patch.
          Hide
          Dominik Psenner added a comment -

          Is this issue fixed?

          Show
          Dominik Psenner added a comment - Is this issue fixed?
          Hide
          Adam Davies added a comment -

          There appears to be a large portion of functionality missing from StackTracePatternConverter, I have included the actual file (no patch file). Currently the MAX/MIN functionality is missing from the build. This file will fix this issue.

          Show
          Adam Davies added a comment - There appears to be a large portion of functionality missing from StackTracePatternConverter, I have included the actual file (no patch file). Currently the MAX/MIN functionality is missing from the build. This file will fix this issue.
          Hide
          Adam Davies added a comment -

          I have further extended the functionality of the StackTracePatternConverter to allow the selection of min / max frames.

          Given: %message%exception%stacktrace

          {MAX|MIN}

          Explantion: {MAX|MIN}

          The MAX controls how deep to display the stacktrace. MAX displays the first n of the stacktrace from the top item
          (stacktrace[0] to stacktrace[n])
          Any int >= 0 will only allow the first x
          The MIN is optional. MIN sets the number of stacktrace items to skip from stacktrace[0]
          If MIN is greater than the number of stacktrace items, then no stacktrace will be displayed.

          Example: %stacktrace

          {3}, displays stacktrace[2] > stacktrace[1] > stacktrace[0]
          Example: %stacktrace{5}, displays stacktrace[4] > stacktrace[3] > stacktrace[2] > stacktrace[1] > stacktrace[0]
          Example: %stacktrace{3|1}, displays stacktrace[2] > stacktrace[1]
          Example: %stacktrace{-1}, displays stacktrace[n] > stacktrace[n-1] > ... > stacktrace[1] > stacktrace[0]
          Example: %stacktrace{-1|3}, displays stacktrace[n] > stacktrace[n-1] > ... > stacktrace[4] > stacktrace[3]


          In addition I have created a new pattern StackTraceDetailPatternConverter. This pattern inherits from StackTracePatternConverter, and provides parameter information for each method.

          Given: %message%exception%stacktracedetail{MAX|MIN}

          Example: %stacktrace{3}

          , displays stacktrace[2](type param, ...) > stacktrace[1](type param, ...) > stacktrace[0](type param, ...)
          Example: %stacktrace

          {3|1}

          , displays stacktrace[2](type param, ...) > stacktrace[1](type param, ...)

          Show
          Adam Davies added a comment - I have further extended the functionality of the StackTracePatternConverter to allow the selection of min / max frames. Given: %message%exception%stacktrace {MAX|MIN} Explantion: {MAX|MIN} The MAX controls how deep to display the stacktrace. MAX displays the first n of the stacktrace from the top item (stacktrace [0] to stacktrace [n] ) Any int >= 0 will only allow the first x The MIN is optional. MIN sets the number of stacktrace items to skip from stacktrace [0] If MIN is greater than the number of stacktrace items, then no stacktrace will be displayed. Example: %stacktrace {3}, displays stacktrace [2] > stacktrace [1] > stacktrace [0] Example: %stacktrace{5}, displays stacktrace [4] > stacktrace [3] > stacktrace [2] > stacktrace [1] > stacktrace [0] Example: %stacktrace{3|1}, displays stacktrace [2] > stacktrace [1] Example: %stacktrace{-1}, displays stacktrace [n] > stacktrace [n-1] > ... > stacktrace [1] > stacktrace [0] Example: %stacktrace{-1|3}, displays stacktrace [n] > stacktrace [n-1] > ... > stacktrace [4] > stacktrace [3] In addition I have created a new pattern StackTraceDetailPatternConverter. This pattern inherits from StackTracePatternConverter, and provides parameter information for each method. Given: %message%exception%stacktracedetail{MAX|MIN} Example: %stacktrace{3} , displays stacktrace [2] (type param, ...) > stacktrace [1] (type param, ...) > stacktrace [0] (type param, ...) Example: %stacktrace {3|1} , displays stacktrace [2] (type param, ...) > stacktrace [1] (type param, ...)
          Hide
          Lars Corneliussen added a comment -

          Hi,

          I'm writing a similar piece of code right now, and I got some comments:

          1) stackFrame.GetMethod().DeclaringType fails for dynamic methods.
          2) I think the stacktrace ist mostly only interesting when no exceptionobject including stacktrace is logged. The default behaviour could be, to not log the stacktrace in that case.
          3) Since stacktrace is expensive and often interesting for certain levels, a option to set a level-threshold would be great.
          4) The level of detail is to little.

          Example: %message%exception%stacktrace

          {threshold:WARN}

          As %exception does, %stacktrace could write one line per frame and end with a line break.

          My current stacktrace format is:
          7 ERROR - c3ad8e6f-3c70-4e7d-840c-2f92854445bc - [DLR.CoMet.Test.Api.Utils.LoggingTest (null) 2009-05-18 19:31:43,155]
          at When_logging_error_messages.Error_ShouldLogToDefaultAndDevException() : Void in C:\Workbench\DLR\trunk\Diensteverwaltung\src\Test.Components\Api\Utils\LoggingTests\When_logging_error_messages.cs:29:13

          It includes generic type- and method-parameters.

          Show
          Lars Corneliussen added a comment - Hi, I'm writing a similar piece of code right now, and I got some comments: 1) stackFrame.GetMethod().DeclaringType fails for dynamic methods. 2) I think the stacktrace ist mostly only interesting when no exceptionobject including stacktrace is logged. The default behaviour could be, to not log the stacktrace in that case. 3) Since stacktrace is expensive and often interesting for certain levels, a option to set a level-threshold would be great. 4) The level of detail is to little. Example: %message%exception%stacktrace {threshold:WARN} As %exception does, %stacktrace could write one line per frame and end with a line break. My current stacktrace format is: 7 ERROR - c3ad8e6f-3c70-4e7d-840c-2f92854445bc - [DLR.CoMet.Test.Api.Utils.LoggingTest (null) 2009-05-18 19:31:43,155] at When_logging_error_messages.Error_ShouldLogToDefaultAndDevException() : Void in C:\Workbench\DLR\trunk\Diensteverwaltung\src\Test.Components\Api\Utils\LoggingTests\When_logging_error_messages.cs:29:13 It includes generic type- and method-parameters.
          Hide
          Michael Cromwell added a comment -

          I may be wrong as I haven't spent much time in the code but it looks like the LocationInfo is loaded on demand at the moment, through the LocationInformation property on LoggingEvent:

          public LocationInfo LocationInformation
          {
          get
          {
          if (m_data.LocationInfo == null && this.m_cacheUpdatable)

          { m_data.LocationInfo = new LocationInfo(m_callerStackBoundaryDeclaringType); }

          return m_data.LocationInfo;
          }
          }

          And only the pattern converters that need the stacktrace details access this property such as FileLocationPatternConverter, FullLocationPatternConverter, LineLocationPatternConverter etc... so if only the simple pattern converters are used it should not be loading the stack trace and therefore not affecting performance.

          Thanks,
          Mike

          Show
          Michael Cromwell added a comment - I may be wrong as I haven't spent much time in the code but it looks like the LocationInfo is loaded on demand at the moment, through the LocationInformation property on LoggingEvent: public LocationInfo LocationInformation { get { if (m_data.LocationInfo == null && this.m_cacheUpdatable) { m_data.LocationInfo = new LocationInfo(m_callerStackBoundaryDeclaringType); } return m_data.LocationInfo; } } And only the pattern converters that need the stacktrace details access this property such as FileLocationPatternConverter, FullLocationPatternConverter, LineLocationPatternConverter etc... so if only the simple pattern converters are used it should not be loading the stack trace and therefore not affecting performance. Thanks, Mike
          Hide
          Ron Grabowski added a comment -

          Thanks! That was easier than I thought..

          I wonder if there would be any speed benefits to communicating to LocationInfo that no one needs stack information so don't bother collecting any...i.e. all the layouts are just simple %message%newline. Plus in Release mode the stack info may be unreliable. The simple solution would be to add a special value to the repository's properties. A more complicated solution would track each pattern layout and only activate stack gathering if at least one appender requested it.

          Show
          Ron Grabowski added a comment - Thanks! That was easier than I thought.. I wonder if there would be any speed benefits to communicating to LocationInfo that no one needs stack information so don't bother collecting any...i.e. all the layouts are just simple %message%newline. Plus in Release mode the stack info may be unreliable. The simple solution would be to add a special value to the repository's properties. A more complicated solution would track each pattern layout and only activate stack gathering if at least one appender requested it.
          Hide
          Michael Cromwell added a comment -

          I have enclosed a patch and new StackTracePatternConverter object let me know if it fits what your after.

          Thanks,
          Mike

          Show
          Michael Cromwell added a comment - I have enclosed a patch and new StackTracePatternConverter object let me know if it fits what your after. Thanks, Mike

            People

            • Assignee:
              Ron Grabowski
              Reporter:
              Ron Grabowski
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development