Unintended consequence of dialing down tracing using Ent-Lib, no error logging
I've run into an unexpected problem using enterprise library tracing and exception logging. What I've noticed is that when I dial down the trace logging using the category filters in 'App.Config' I'm inadvertently turning off error logging for errors that occur below the trace logging level that I'm filtering to.
For Example:
Private Sub ProcA()
Using (New Tracer("Trace High Level")
Try
<Do some logic here>
ProcB()
Catch ex AS Exception
Dim rethrow As Boolean = ExceptionPolicy.HandleException(ex, "Log Only Policy")
If rethrow Then
Throw ex
End If
End Try
End Using
End Sub
Private Sub ProcB()
Using (New Tracer("Trace Mid Level")
Try
<Do some logic here>
ProcC()
Catch ex AS Exception
Dim rethrow As Boolean = ExceptionPolicy.HandleException(ex, "Log Only Policy")
If rethrow Then
Throw ex
End If
End Try
End Using
End Sub
Private Sub ProcC()
Using (New Tracer("Trace Low Level")
Try
Throw New Exception("Test error logging")
Catch ex AS Exception
Dim rethrow As Boolean = ExceptionPolicy.HandleException(ex, "Log Only Policy")
If rethrow Then
Throw ex
End If
End Try
End Using
End Sub
Now if I've set up my category filter in App.Config to allow full tracing I'm getting all of my trace messages and the error message thrown in ProcC written to my log. However, if I dial down the tracing to only log only "Trace High Level", for instance, then I get my high level trace message but the error thrown in ProcC is not logged.
I've stepped through the code and noted that the accumulated categories for the LogEntry at the time of the error in ProcC include "Trace High Level", "Trace Mid Level", "Trace Low Level" and "Error". As a result, the call to ShouldLog() in LogWriterImpl.cs returns false anytime I'm not trace logging all of my levels and the consequence is that my error is not logged.
My Question:
In this scenario, is there a way to configure the enterprise library logging to still allow the error to be logged even when I'm not doing detailed trace logging at all levels?In response to @Tuzo's comment:
<exceptionHandling>
<exceptionPolicies>
<add name="Exception Policy">
<exceptionTypes>
<add name="Exception" type="System.Exception, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
postHandlingAction="NotifyRethrow">
<exceptionHandlers>
<add name="Exception Logging" type="Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.Logging.LoggingExceptionHandler, Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.Logging"
logCategory="Error" eventId="666" severity="Error" title="REPSS .Net Exception Handler"
formatterType="Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.TextExceptionFormatter, Microsoft.Practices.EnterpriseLibrary.ExceptionHandling"
priority="1" />
</exceptionHandlers>
</add>
</exceptionTypes>
</add>
<add name="Log Only Policy">
<exceptionTypes>
<add name="Exception" type="System.Exception, mscorlib" postHandlingAction="None">
<exceptionHandlers>
<add name="Exception Logging" type="Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.Logging.LoggingExceptionHandler, Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.Logging"
logCategory="Error" eventId="666" severity="Error" title="REPSS .Net Exception Handler"
formatterType="Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.TextExceptionFormatter, Microsoft.Practices.EnterpriseLibrary.ExceptionHandling"
priority="2" />
</exceptionHandlers>
</add>
</exceptionTypes>
</add>
</exceptionPolicies>
<loggingConfiguration name="Logging Application Block" tracingEnabled="true"
defaultCategory="General" logWarningsWhenNoCategoriesMatch="true">
<listeners>
<add name="Database Trace Listener" type="Microsoft.Practices.EnterpriseLibrary.Logging.Database.FormattedDatabaseTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging.Database"
listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Database.Configuration.FormattedDatabaseTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging.Database"
databaseInstanceName="ReiApplicationLogging" writeLogStoredProcName="WriteLog"
addCategoryStoredProcName="AddCategory" formatter="Database Rei Applications Logging Formatter"
traceOutputOptions="None" />
<add name="Formatted EventLog TraceListener" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.FormattedEventLogTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging"
listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.FormattedEventLogTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging"
source="REPSS .Net" formatter="Text Formatter" log="REI Applications"
machineName="" traceOutputOptions="LogicalOperationStack" />
<add name="SDSCellPhone" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.EmailTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging"
listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.EmailTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging"
toAddress="sstudy@flexifloat.com" fromAddress="sstudy@flexifloat.com"
subjectLineStarter="REPSS .Net: " subjectLineEnder="(sms forward)"
smtpServer="REISRV05" smtpPort="25" formatter="Cell Phone Formatter"
authenticationMode="WindowsCredentials" traceOutputOptions="LogicalOperationStack, DateTime, Timestamp, ProcessId, ThreadId, Callstack"
filter="Off" />
<add name="Rolling Flat File Trace Listener" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.RollingFlatFileTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.414.0, Culture=neutral, PublicKeyToken=null"
listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.RollingFlatFileTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.414.0, Cul开发者_如何学Goture=neutral, PublicKeyToken=null"
fileName="C:\Users\sstudy\Documents\Visual Studio Projects\_Production\Win Forms\REPSS\REPSS .Net Solution\RepssDN\repps net rolling error.log"
footer="^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^"
formatter="Text Formatter" header="vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv"
rollInterval="Week" traceOutputOptions="LogicalOperationStack, Callstack" />
</listeners>
<formatters>
<add type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging"
template="Timestamp: {timestamp(local:F)}
Title:{title}
Machine: {machine}"
name="Cell Phone Formatter" />
<add type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging"
template="{newline}{newline}________________________

Timestamp: {timestamp(local:F)}

Title:{title}
Process: {processName}

Extended Properties: 

{dictionary({key} - {value}

)}{newline}

Category: {category}

Priority: {priority}

EventId: {eventid}

Severity: {severity}

Machine: {machine}

Application Domain: {processName}

{newline}

Message: {message}

{newline}"
name="Database Rei Applications Logging Formatter" />
<add type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging"
template="Timestamp: {timestamp(local:F)}
Title:{title}
Message: {message}
{newline}
Category: {category}
Priority: {priority}
EventId: {eventid}
Severity: {severity}
Machine: {machine}
Application Domain: {processName}
Process Id: {processId}
Process Name: {processName}
Win32 Thread Id: {win32ThreadId}
Thread Name: {threadName}
{newline}
Extended Properties: 
{dictionary({key} - {value}
)}"
name="Text Formatter" />
</formatters>
<logFilters>
<add type="Microsoft.Practices.EnterpriseLibrary.Logging.Filters.LogEnabledFilter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.414.0, Culture=neutral, PublicKeyToken=null"
enabled="true" name="Enable All Logging" />
<add type="Microsoft.Practices.EnterpriseLibrary.Logging.Filters.CategoryFilter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.414.0, Culture=neutral, PublicKeyToken=null"
categoryFilterMode="AllowAllExceptDenied" name="Trace Filter">
<categoryFilters>
<add name="Trace Insane Detail" />
<add name="Trace Low Level" />
</categoryFilters>
</add>
</logFilters>
<categorySources>
<add switchValue="Error" name="Development Error">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
<add name="SDSCellPhone" />
</listeners>
</add>
<add switchValue="Error" name="Error">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
<add name="SDSCellPhone" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Feature Usage">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="All" name="General">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="All" name="Security">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Start Up">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Shut Down">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Menu Item Selected">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace High Level">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Mid Level">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Low Level">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Detail">
<listeners>
<add name="Database Trace Listener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Insane Detail">
<listeners>
<add name="Database Trace Listener" />
</listeners>
</add>
<add switchValue="All" name="Trace">
<listeners>
<add name="Rolling Flat File Trace Listener" />
</listeners>
</add>
<add switchValue="Verbose" name="Useful Info">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
</categorySources>
<specialSources>
<allEvents switchValue="All" name="All Events">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</allEvents>
<notProcessed switchValue="All" name="Unprocessed Category">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</notProcessed>
<errors switchValue="All" name="Logging Errors & Warnings">
<listeners>
<add name="Database Trace Listener" />
<add name="SDSCellPhone" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</errors>
</specialSources>
</loggingConfiguration>
Attempt to use the "SourceLevel" recommended by @Tuzo:
@Tuzo, I gave the "SourceLevel" switch a try and modified the app.config to turn "off" the lower level trace categories. Interestingly, this creates the opposite problem. Since the traces are chained together, EntLib sees that there is at least one trace category in the chain that isn't "Off" (In my test case, "Trace High Level") and goes ahead and logs the turned off trace at the lower level(s). This EntLib logic is coded in ProcessLog() in LogWriterImpl class. The end result is that all of the lower level tracings are now logged even though they are turned off. On the bright side, I do get my error logged now. ;) I guess I'll take a look at the custom filter you recommended and see if I can make that work for this scenario.The behavior you are seeing seems to be by design.
If filters exist then a LogEntry must pass successfully through all filters. Similarly for the category filter if you specify to AllowAllExceptDenied and one of the categories appears in the log entry then it will not pass the category filter and the message will not be logged.
"Tell me something I don't already know", you are saying. :)
I can think of 2 approaches to work around this:
- Switch from using a filter to
SourceLevel - Create a custom filter that does exactly what you need
Switch from using a filter to a SourceLevel
Instead of enabling and disabling activity traces via a filter you could probably do it just as well using the SourceLevel (switchvalue). E.g Remove your filter but for the listeners "Trace Insane Detail" and "Trace Low Level" (as in your filter) set the switchValue to Off; you can still leave "Trace Mid Level" enabled.
<add switchValue="Off" name="Trace Insane Detail">
<listeners>
<add name="Database Trace Listener" />
</listeners>
</add>
<add switchValue="ActivityTracing" name="Trace Mid Level">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
<add switchValue="Off" name="Trace Low Level">
<listeners>
<add name="Database Trace Listener" />
<add name="Formatted EventLog TraceListener" />
</listeners>
</add>
Create a Custom Filter that does exactly what you need
A custom filter will let you do almost anything your want. It's more complicated so should probably only be done if absolutely necessary. See Using Custom Filters in the Enterprise Library Logging Block for a good example.
加载中,请稍侯......
精彩评论