[jira] Created: (LOG4NET-154) Add a StackTracePatternConverter to display method calls leading up to log message

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

                 Key: LOG4NET-154
                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
             Project: Log4net
          Issue Type: New Feature
            Reporter: Ron Grabowski


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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

     [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Ron Grabowski updated LOG4NET-154:
----------------------------------

    Fix Version/s: 1.2.11

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

     [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Michael Cromwell updated LOG4NET-154:
-------------------------------------

    Attachment: StackTracePatternConverter.zip

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

Thanks,
Mike

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

    [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12708306#action_12708306 ]

Ron Grabowski commented on LOG4NET-154:
---------------------------------------

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.

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

    [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12708664#action_12708664 ]

Michael Cromwell commented on LOG4NET-154:
------------------------------------------

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

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

    [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12710413#action_12710413 ]

Lars Corneliussen commented on LOG4NET-154:
-------------------------------------------

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.

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

    [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12774694#action_12774694 ]

Adam Davies commented on LOG4NET-154:
-------------------------------------

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, ...)

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

     [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Adam Davies updated LOG4NET-154:
--------------------------------

    Attachment: log4net - StackTrace and StackTraceDetail.zip

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: log4net - StackTrace and StackTraceDetail.zip, StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

     [ https://issues.apache.org/jira/browse/LOG4NET-154?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Ron Grabowski reassigned LOG4NET-154:
-------------------------------------

    Assignee: Ron Grabowski

> Add a StackTracePatternConverter to display method calls leading up to log message
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4NET-154
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-154
>             Project: Log4net
>          Issue Type: New Feature
>            Reporter: Ron Grabowski
>            Assignee: Ron Grabowski
>             Fix For: 1.2.11
>
>         Attachments: log4net - StackTrace and StackTraceDetail.zip, StackTracePatternConverter.zip
>
>
> 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.

--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.