search

cjbhaines / Log4Net.Async

Asynchronous Log4Net appenders and forwarder
http://www.nuget.org/packages/Log4Net.Async/
MIT License
121 stars 37 forks source link

ParallelForwardingAppender not logging #26

Closed KamranShahid closed 8 years ago

KamranShahid commented 8 years ago

I have configured ParallelForwardingAppender but logging to file is not hapening Details are as below I have a web application on which reference log4net.asyc library and added the section 

<configSections>
      <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net" />
  </configSections>

My log4net config is as following.

<?xml version="1.0" encoding="utf-8" ?>
<log4net>
  <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender" >
    <file value="..\\Logs\\Logfile.txt" />
    <appendToFile value="true" />
    <datePattern value="yyyyMMdd" />
    <rollingStyle value="Date"/>    
    <filter type="log4net.Filter.LevelRangeFilter">
      <acceptOnMatch value="true" />
      <levelMin value="DEBUG" />
      <levelMax value="FATAL" />
    </filter>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%d{yyyy-MM-dd HH:mm:ss.fff} %10p %-5property{_App} %-5property{_Node} [%2t] %5c{1}.%M - %m%n" />
    </layout>
  </appender>
  <appender name="asyncForwarder" type="Log4Net.Async.ParallelForwardingAppender,Log4Net.Async">
    <appender-ref ref="RollingLogFileAppender" />
    <bufferSize value="200" />
  </appender>
  <appender name="AdoNetAppender" type="log4net.Appender.AdoNetAppender">
    <reconnectOnError value="true" />
    <connectionType value="MySql.Data.MySqlClient.MySqlConnection, MySql.Data" />
    <connectionString value="data source=localhost;Port=3306;initial catalog=logging_db;User ID=root;Password=;Max Pool Size=25;" />    
    <commandText value="AddLogEntry" />
    <commandType value="StoredProcedure" />
    <bufferSize value="25" />
    <useTransactions value="false" />
    <parameter>
      <parameterName value="_appname" />
      <dbType value="String" />
      <size value="32" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="My Web Service" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_action" />
      <dbType value="String" />
      <size value="45" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%c{1}" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_level" />
      <dbType value="String" />
      <size value="10" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%p" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_thread_id" />
      <dbType value="String" />
      <size value="10" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%t" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_context" />
      <dbType value="String" />
      <size value="45" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%M" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_context_id" />
      <dbType value="String" />
      <size value="128" />
      <layout type="log4net.Layout.RawPropertyLayout">
        <key value="context_id" />
      </layout>
    </parameter>   
    <filter type="log4net.Filter.LevelRangeFilter">
      <acceptOnMatch value="true" />
      <levelMin value="DEBUG" />
      <levelMax value="FATAL" />
    </filter>
  </appender>
  <root>
    <level value="ALL" />
    <appender-ref ref="asyncForwarder" /> 
    <!--<appender-ref ref="AdoNetAppender" />-->
  </root>
  <logger name="Boloro.Business.RuleEngine.ConditionComparer" additivity="false">
    <level value="ALL" />
    <appender-ref ref="RollingLogFileAppender" />
  </logger>
</log4net>

Please let me know what wrong i am doing

cjbhaines commented 8 years ago

Have you tried your appender configuration outside of the async forwarder?

KamranShahid commented 8 years ago

Do you mean other then async forwarder? Yes.following do work when i were not using async forwarder

<root>
    <level value="ALL" />
    <appender-ref ref="RollingLogFileAppender" /> 
    <!--<appender-ref ref="AdoNetAppender" />-->
  </root>
KamranShahid commented 8 years ago

Chris can you help me in it

vivek-meka commented 8 years ago

Can you enable internal debug to see the actual error that you are getting ?

KamranShahid commented 8 years ago

Ok i will try enabling intrnal debug to see the actual error

vivek-meka commented 8 years ago

If you need the code for it here is it

<system.diagnostics>
    <trace autoflush="true">
      <listeners>
        <add
            name="textWriterTraceListener"
         type="System.Diagnostics.TextWriterTraceListener"
         initializeData="C:\Path\log4net.txt" />
      </listeners>
    </trace>
  </system.diagnostics>
<appSettings>
      <add key="log4net.Internal.Debug" value="true"/>
   </appSettings>
KamranShahid commented 8 years ago

Thanks PoorDesigner, Yes I know how to enable that tracing and have done it prior

vivek-meka commented 8 years ago

Ok. Did you find out the issue?

KamranShahid commented 8 years ago

I think it's due to log4net version difference. I have log4net 1.2.15

Error I am getting is log4net:ERROR Could not create Appender [asyncForwarder] of type [Log4Net.Async.ParallelForwardingAppender,Log4Net.Async]. Reported error follows. System.IO.FileLoadException: Could not load file or assembly 'log4net, Version=1.2.13.0, Culture=neutral, PublicKeyToken=669e0ddf0bb1aa2a' or one of its dependencies. The located assembly's manifest definition does not match the assembly reference. (Exception from HRESULT: 0x80131040) File name: 'log4net, Version=1.2.13.0, Culture=neutral, PublicKeyToken=669e0ddf0bb1aa2a' at System.RuntimeTypeHandle.GetTypeByName(String name, Boolean throwOnError, Boolean ignoreCase, Boolean reflectionOnly, StackCrawlMarkHandle stackMark, IntPtr pPrivHostBinder, Boolean loadTypeFromPartialName, ObjectHandleOnStack type) at System.RuntimeTypeHandle.GetTypeByName(String name, Boolean throwOnError, Boolean ignoreCase, Boolean reflectionOnly, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean loadTypeFromPartialName) at System.RuntimeType.GetType(String typeName, Boolean throwOnError, Boolean ignoreCase, Boolean reflectionOnly, StackCrawlMark& stackMark) at System.Type.GetType(String typeName, Boolean throwOnError, Boolean ignoreCase) at log4net.Util.SystemInfo.GetTypeFromString(Assembly relativeAssembly, String typeName, Boolean throwOnError, Boolean ignoreCase) at log4net.Util.SystemInfo.GetTypeFromString(String typeName, Boolean throwOnError, Boolean ignoreCase) at log4net.Repository.Hierarchy.XmlHierarchyConfigurator.ParseAppender(XmlElement appenderElement)

WRN: Assembly binding logging is turned OFF. To enable assembly bind failure logging, set the registry value HKLM\Software\Microsoft\Fusion!EnableLog to 1. Note: There is some performance penalty associated with assembly bind failure logging. To turn this feature off, remove the registry value [HKLM\Software\Microsoft\Fusion!EnableLog].

KamranShahid commented 8 years ago

I have downloaded the repository and then reference the log4net new version. Now I am getting other error

log4net:ERROR [RollingFileAppender] ErrorCode: GenericFailure. Failed in DoAppend System.NullReferenceException: Object reference not set to an instance of an object. at log4net.Layout.Pattern.MethodLocationPatternConverter.Convert(TextWriter writer, LoggingEvent loggingEvent) at log4net.Layout.Pattern.PatternLayoutConverter.Convert(TextWriter writer, Object state) at log4net.Util.PatternConverter.Format(TextWriter writer, Object state) at log4net.Layout.PatternLayout.Format(TextWriter writer, LoggingEvent loggingEvent) at log4net.Appender.AppenderSkeleton.RenderLoggingEvent(TextWriter writer, LoggingEvent loggingEvent) at log4net.Appender.TextWriterAppender.Append(LoggingEvent loggingEvent) at log4net.Appender.FileAppender.Append(LoggingEvent loggingEvent) at log4net.Appender.RollingFileAppender.Append(LoggingEvent loggingEvent) at log4net.Appender.AppenderSkeleton.DoAppend(LoggingEvent loggingEvent)

KamranShahid commented 8 years ago

I have put in my RollingLogFileAppender and it's look like working now Please do comment on this 

<?xml version="1.0" encoding="utf-8" ?>
<log4net >
  <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender" >
    <file value="..\\Logs\\MyLog.txt" />
    <appendToFile value="true" />
    <datePattern value="yyyyMMdd" />
    <rollingStyle value="Date"/>
    <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
    <filter type="log4net.Filter.LevelRangeFilter">
      <acceptOnMatch value="true" />
      <levelMin value="DEBUG" />
      <levelMax value="FATAL" />
    </filter>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%d{yyyy-MM-dd HH:mm:ss.fff} %10p %-5property{_App} %-5property{_Node} [%2t] %5c{1}.%M - %m%n" />
    </layout>
  </appender>
  <appender name="asyncForwarder" type="Log4Net.Async.ParallelForwardingAppender,Log4Net.Async">
    <appender-ref ref="RollingLogFileAppender" />
    <bufferSize value="10" />
    <Fix value="268435455" />
  </appender>   
  <appender name="AdoNetAppender" type="log4net.Appender.AdoNetAppender">
    <reconnectOnError value="true" />
    <connectionType value="MySql.Data.MySqlClient.MySqlConnection, MySql.Data" />
    <connectionString value="data source=localhost;Port=3306;initial catalog=logging_db;User ID=root;Password=;Max Pool Size=25;" /><!--Max Pool Size=100;-->
    <commandText value="AddLogEntry" />
    <commandType value="StoredProcedure" />
    <bufferSize value="25" />
    <useTransactions value="false" />
    <parameter>
      <parameterName value="_appname" />
      <dbType value="String" />
      <size value="32" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="My Web Service" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_action" />
      <dbType value="String" />
      <size value="45" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%c{1}" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_level" />
      <dbType value="String" />
      <size value="10" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%p" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="_thread_id" />
      <dbType value="String" />
      <size value="10" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%t" />
      </layout>
    </parameter>   
    <filter type="log4net.Filter.LevelRangeFilter">
      <acceptOnMatch value="true" />
      <levelMin value="DEBUG" />
      <levelMax value="FATAL" />
    </filter>
  </appender>
  <root>
    <level value="ALL" />
    <appender-ref ref="asyncForwarder" />   
    <!-- <appender-ref ref="AdoNetAppender" />  -->
  </root>

</log4net>
KamranShahid commented 8 years ago

Only thing i am seeing is that logs entries were written instantly in log file even tough i have put buffersize to 200

vivek-meka commented 8 years ago 
<appender name="asyncForwarder" type="Log4Net.Async.ParallelForwardingAppender,Log4Net.Async">
    <appender-ref ref="RollingLogFileAppender" />
    _<bufferSize value="10" />_
    <Fix value="268435455" />
  </appender>

The buffer size for asyncforwarder serves a different purpose. I am not sure what it means exactly but here is what i think it is As the async appender writes the messages parallely it stores the messages into buffer and then writes them into the logs file/db. The buffer size here indicates how many messages that it can store in buffer before it reaxhes a state where it can't take more message but @cjbhaines can give more information on it

KamranShahid commented 8 years ago

Is there any chance of loss of messages. looks like at the moment chris is busy in some other work

rcollette commented 8 years ago

No. It will block when the buffer is full.

KamranShahid commented 8 years ago

Richard Collette Can you please let me know what's mean by block here? Will application stop doing any further thing or logging will stop?

cjbhaines commented 8 years ago

Hi Kamran, sorry I've not replied I have a lot of work commitments at the moment.

If you read the documentation in the readme you will see that the AsyncForwardingAppender is implemented using a ring buffer and loss of messages (the oldest ones) will occur when the buffer is full. This appender is slightly less efficient than the ParallelForwardingAppender because it has to poll the buffer on a background thread.

The ParallelForwardingAppender is implemented using a blocking collection so when the collection has reached it's limit then the threads trying to log will block which is not ideal in a low latency application.

So it's really up to you which one you want to use, it's all documented.

KamranShahid commented 8 years ago

I don't want's the messages to be loss and neither low latency. AsyncForwardingAppender looks better if some how i can make sure that limit will not reach Any suggestion how i can achieve both?Even a suggestion for alternative appender will be fine.

cjbhaines commented 8 years ago

I suggest you use the AsynxForwardingAppender and use a large buffer size.

KamranShahid commented 8 years ago

My application is doing about a 80 transaction per seconds where each transaction logs about 100 to 125 logs entries. Any suggestion for buffersize.

rcollette commented 8 years ago

@KamranShahid - If you don't want message loss then you definitely do not want to use a ring buffer. ParallelForwardingAppender will not introduce any "extra" latency. You just need to experiment and make sure that you use a buffer size that is sufficiently large to handle peak logging periods.

To better understand the behavior you should look at the documentation for BlockingCollection

https://msdn.microsoft.com/en-us/library/dd267312(v=vs.110).aspx

KamranShahid commented 8 years ago

Ok . I will experiment with both again with peak load. About ParallelForwardingAppender I were thinking that my application proessing(other then logging) might have a glitch when there is a condition of bolcking occurs as described https://github.com/cjbhaines/Log4Net.Async (I might be wrong in understanding that). My prior importance is my application don't slow for file i/o needed for logs entry in the file and neither logs will be loss. That's why i had put the hack on my application_end event of my web application as described in http://stackoverflow.com/questions/2045935/is-there-anyway-to-programmably-flush-the-buffer-in-log4net to avoid loss. Thanks

rcollette commented 8 years ago

You should be calling LogManager.shutdown() on application_end. That's not a hack, that's a known requirement of Log4Net.

https://logging.apache.org/log4net/log4net-1.2.11/release/sdk/log4net.LogManager.Shutdown.html

@cjbhaines - This issue should probably be closed at this point.

rcollette commented 8 years ago

Actually, I can do so I just realized.

mirkomaty commented 3 years ago

For all people, having the same problem: The cause of the trouble is, that Log4net.Async has a reference to log4net v. 1.2.13. If you work with a newer log4net version (currently 2.0.x), it won't work. You need an assembly binding:

<assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
    <dependentAssembly>
        <assemblyIdentity name="log4net" publicKeyToken="669e0ddf0bb1aa2a" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-2.0.12.0" newVersion="2.0.12.0" />
    </dependentAssembly>
</assemblyBinding>

Use your current log4net version instead of 2.0.12.0.