Delay in Database and Event Viewer Logging

Topics: Logging Application Block
Aug 28, 2013 at 7:45 AM
Hello.

I am using Enterprise Library 6.0.

I am experiencing significant delays in Database and Event Viewer Logging.
Sometimes, new log records appear immediately, but in most cases I have to wait significant periods of time (the periods vary all the time) to get new log records appear in a database and in the Event Viewer.
I suppose, it happens because of caching mechanism.
If it depends on cache, how can I define 'no-cache' or flushing a cache instantly?

Thanks,
Alex.
Aug 29, 2013 at 4:43 AM
There is an autoFlush property which can be set on the category (but the default is true). Also, setting a trace listener as asynchronous might explain the behavior you are seeing. Can you post the configuration?

~~
Randy Levy
entlib.support@live.com
Enterprise Library support engineer
Support How-to
Aug 29, 2013 at 6:53 AM
My configuration is:
<configSections>
    <section name="loggingConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.LoggingSettings, Microsoft.Practices.EnterpriseLibrary.Logging, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" requirePermission="true" />
    <section name="dataConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Data.Configuration.DatabaseSettings, Microsoft.Practices.EnterpriseLibrary.Data, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" requirePermission="true" />
</configSections>
<loggingConfiguration name="" tracingEnabled="true" defaultCategory="General">
    <listeners>
        <add name="Doc Database Listener" type="Microsoft.Practices.EnterpriseLibrary.Logging.Database.FormattedDatabaseTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging.Database, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
            listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Database.Configuration.FormattedDatabaseTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging.Database, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
            databaseInstanceName="Logging" writeLogStoredProcName="WriteLog"
            addCategoryStoredProcName="AddCategory" formatter="Text Formatter"
            traceOutputOptions="LogicalOperationStack, DateTime, Timestamp, ProcessId, ThreadId, Callstack"
            filter="All" asynchronous="true" />
        <add name="Doc EventLog Listener" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.FormattedEventLogTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
            listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.FormattedEventLogTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
            source="Doc Logging" formatter="Text Formatter" log="Doc"
            traceOutputOptions="LogicalOperationStack, DateTime, Timestamp, ProcessId, ThreadId, Callstack"
            filter="All" asynchronous="true" />
    </listeners>
    <formatters>
        <add type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=6.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
            template="Severity: {severity}{newline}&#xA;Category: {category}{newline}&#xA;Message: {message}{newline}"
            name="Text Formatter" />
    </formatters>
    <categorySources>
        <add switchValue="All" name="General">
            <listeners>
                <add name="Doc Database Listener" />
                <add name="Doc EventLog Listener" />
            </listeners>
        </add>
    </categorySources>
    <specialSources>
        <allEvents switchValue="All" name="All Events">
            <listeners>
                <add name="Doc Database Listener" />
                <add name="Doc EventLog Listener" />
            </listeners>
        </allEvents>
        <notProcessed switchValue="All" name="Unprocessed Category">
            <listeners>
                <add name="Doc Database Listener" />
                <add name="Doc EventLog Listener" />
            </listeners>
        </notProcessed>
        <errors switchValue="All" name="Logging Errors &amp; Warnings">
            <listeners>
                <add name="Doc Database Listener" />
                <add name="Doc EventLog Listener" />
            </listeners>
        </errors>
    </specialSources>
</loggingConfiguration>

I operate Log writing by the following method:
    public static void WriteToLog(TraceEventType severity, string category, string message)
    {
        try
        {
            DatabaseFactory.ClearDatabaseProviderFactory();
            DatabaseFactory.SetDatabaseProviderFactory(new DatabaseProviderFactory());

            Logger.SetLogWriter((new LogWriterFactory()).Create());
            Logger.Write(new LogEntry() { Severity = severity, Categories = new List<string>(new string[] { category }), Message = message });
        }
        catch {}
    }
Additionally to the delay problem, I have two other problems:
  1. Value in the 'Message' field appears truncated
  2. 'Timestamp' field displays not correct time: differs in 3 hours from my local (GMT+2) time.
Thanks,
Alex.
Aug 30, 2013 at 6:53 PM
The trace listeners are configured to log asynchronously which is why logging does not happen immediately. If you want to log immediately, then you can use synchronous logging.
Value in the 'Message' field appears truncated
Message field is limited to 1500 characters. The FormattedMessage column supports an arbitrarily long string so you could always use that column to contain the Message data (the posted template is doing this along with Severity and Category).
'Timestamp' field displays not correct time: differs in 3 hours from my local (GMT+2) time.
When running asynchronously thread specific properties are initialized (TimeStamp, ActivityId, ThreadName, and ThreadId) which sets the TimeStamp to be DateTime.UtcNow. You could use the local timestamp in the template to set the local time value in the FormattedMessage (e.g. "Local Time: {timestamp(local)}").

~~
Randy Levy
entlib.support@live.com
Enterprise Library support engineer
Support How-to