Omer Mor | 6 Aug 09:02 2009
Picon

Debugging log4net source

Hi,
to research a (rare) bug we have with log4net (log file is not being created) we wanted to debug its source.
However, the release build of 1.2.10 is supplied without a pdb file.
And since it is a signed assembly we can't compile it ourself and replace it.
Also - the debug build of 1.2.10 is supplied with a pdb, but is not signed, so it is not substitutable.
What I'd like to ask is that one of the developers compile a release build of 1.2.10 and enable pdb creation, so that we could debug the source.
 
Using a non-signed copy of log4net is not an option for us, because some of our 3rd-party assemblies are compiled against the signed 1.2.10 log4net assembly.
 
The files could be sent irectly to me at omer.mor <at> gmail.com .
 
Thanks in advance,
  Omer Mor.
Diego Jancic | 6 Aug 17:50 2009

FW: Mixed Logs

Hi,

Can you help with this? I don’t know if log4net is using thread inside or something that can produce such behavior when locking in an appender.

What happens if an appender takes much time to complete or throws an exception, are the other ones going to success?

 

Thanks,

Diego

 

From: Diego Jancic [mailto:diegoj <at> engineerica.com]
Sent: Wednesday, August 05, 2009 13:12
To: 'Log4NET User'
Subject: RE: Mixed Logs

 

Hi again,

I’ve removed that appender and looks to be working fine now.

Now, the question is how should I do that lock?

 

Thanks,
Diego

 

From: Diego Jancic [mailto:diegoj <at> engineerica.com]
Sent: Tuesday, August 04, 2009 11:38
To: 'Log4NET User'
Subject: RE: Mixed Logs

 

No, the configurations are pretty simple, although I have a custom appender.

I guess it should not affect the file appender, but here it is:

 

Appender code:

 

public class FormAppender : AppenderSkeleton

      {

            public static Dictionary<string, ListBox> outputLists = new Dictionary<string, ListBox>();

            public static InvokeDelegate Invoke;

 

            protected override void Append(LoggingEvent loggingEvent)

            {

                  if (MyOutputList != null)

                  {

                        AddItemThreadSafeDelegate del = AddItemThreadSafe;

                        Invoke(del, new object[] { loggingEvent });

                  }

            }

 

            protected override bool RequiresLayout

            {

                  get { return true; }

            }

 

            private delegate void AddItemThreadSafeDelegate(LoggingEvent loggingEvent);

 

            private void AddItemThreadSafe(LoggingEvent loggingEvent)

            {

                  string text = RenderLoggingEvent(loggingEvent);

                  text = text.Trim('\n', '\r', ' ');

 

                  MyOutputList.Items.Insert(0, text);

 

                  // Purge old message

                  lock (MyOutputList)

                  {

                        if (MyOutputList.Items.Count > 1500)

                        {

                              while (MyOutputList.Items.Count > 1400)

                                    MyOutputList.Items.RemoveAt(MyOutputList.Items.Count - 1);

                        }

                  }

            }

 

            private ListBox MyOutputList

            {

                  get { return outputLists[Name]; }

            }

      }

 

 

To Setup the appender by code:

 

FormAppender.outputLists.Add("WinAppender-MainLog", lbLog);

FormAppender.outputLists.Add("WinAppender-DeviceLog", lbDeviceOutput);

 

FormAppender.Invoke = Invoke;

 

XmlConfigurator.ConfigureAndWatch(new FileInfo("log4net.config"));

log = LogManager.GetLogger(GetType());

 

 

The config file:

 

<!-- WINDOW APPENDER -->

      <appender name="WinAppender-MainLog" type="RollCaller.UI.Admin.Win.FormAppender">

            <layout type="log4net.Layout.PatternLayout">

                  <conversionPattern value="%date %-5level %logger - %message%newline" />

            </layout>

      </appender>

     

      <appender name="WinAppender-DeviceLog" type="RollCaller.UI.Admin.Win.FormAppender">

            <layout type="log4net.Layout.PatternLayout">

                  <conversionPattern value="%date - %message%newline" />

            </layout>

      </appender>

 

 

      <!-- FILE APPENDER -->

      <appender name="FileAppender" type="log4net.Appender.RollingFileAppender">

            <file value="Logs\Log.txt" />

            <appendToFile value="true" />

            <rollingStyle value="Size" />

            <maxSizeRollBackups value="10" />

            <maximumFileSize value="2MB" />

            <staticLogFileName value="true" />

            <layout type="log4net.Layout.PatternLayout">

                  <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />

            </layout>

      </appender>

 

      <root>

            <level value="DEBUG" />

            <appender-ref ref="WinAppender-MainLog" />

            <appender-ref ref="FileAppender" />

      </root>

 

      ... other loggers ...

 

 

Now I’m wondering if the lock may cause a delay in all appenders and produce such weird behavior. I’ll disable it, but it’ll take me all the day to figure out if it keeps failing.

 

Thanks,

Diego

 

 

From: Ross Hinkley [mailto:rosshinkley <at> gmail.com]
Sent: Tuesday, August 04, 2009 11:28
To: Log4NET User
Subject: Re: Mixed Logs

 

Karim,

I believe that's the [1], which is interesting to point out.  I didn't look that far.  My gut reaction to seeing something like that was multiple processes.  I leapt before I looked.

Hm.  That is an interesting anomaly.

Diego, do you have buffer values set up in your configuration?  I guess my next gut feeling is something odd happening with message buffering.

-Ross

On Tue, Aug 4, 2009 at 9:21 AM, Karim Bourouba <karym6 <at> hotmail.com> wrote:

I may be mis-reading this, but isnt the value after the timestamp the thread ID? 


 

 

Date: Tue, 4 Aug 2009 09:05:09 -0500
Subject: Re: Mixed Logs
From: rosshinkley <at> gmail.com
To: log4net-user <at> logging.apache.org



Do these processes run on different computers?

Correct me if I'm wrong, doesn't log4net use local system time for timestamps (the time from the logging machine, not necessarily where the log is located)?

-Ross

On Tue, Aug 4, 2009 at 8:51 AM, Diego Jancic <diegoj <at> engineerica.com> wrote:

Hi Guys,
 
I’ve got an application that uses log4net everywhere and logs a lot of things. Yesterday I leave running some hardware stress tests all the night, and today I found something weird in the logs.
The app ran near 1000 test, and 2 of them failed, but just before the failed test it logged something like this:
 
2009-08-04 04:42:41,846 [1] DEBUG XXX.Communications.Messages.ReadMemoryMessage - Downloading memory. Start: 5120 -- Length: 1024
2009-08-04 04:42:54,046 [1] DEBUG XXX.Communications.Messages.ReadMemoryMessage - Downloading memory. Start: 6144 -- Length: 412
2009-08-04 04:42:42,073 [1] INFO  XXX.UI.Admin.Win.MainForm - Test completed OK!
2009-08-04 04:42:54,049 [1] INFO  XXX.UI.Admin.Win.MainForm - -----------------------------------------------------
2009-08-04 04:42:54,050 [1] INFO  XXX.UI.Admin.Win.MainForm - Cleaning scans before start.
 
Look at the 3rd log, it’s second part (42) is between 2 logs that happened after it (second 54)
 
Well, it’s hard to reproduce the problem in the application. Do you know why it could happen?
 
Thanks,
Diego
 

 

Windows Live Messenger: Thanks for 10 great years—enjoy free winks and emoticons. Get Them Now

 

Ron Grabowski | 7 Aug 05:12 2009
Picon

Re: Debugging log4net source

Have you tried specifying a custom error handler on the appender to track down when it enters a failed state?

<appender name=".." >
  ...
  <errorHandler type="Your.ErrorHandler, YourAssembly" />
</appender>

You would write one that sends an email when the file can't be created.

From: Omer Mor <omer.mor <at> gm ail.com>
To: log4net-dev <at> logging.apache.org
Sent: Thursday, August 6, 2009 3:02:17 AM
Subject: Debugging log4net source

Hi,
to research a (rare) bug we have with log4net (log file is not being created) we wanted to debug its source.
However, the release build of 1.2.10 is supplied without a pdb file.
And since it is a signed assembly we can't compile it ourself and replace it.
Also - the debug build of 1.2.10 is supplied with a pdb, but is not signed, so it is not substitutable.
What I'd like to ask is that one of the developers compile a release build of 1.2.10 and enable pdb creation, so that we could debug the source.
 
Using a non-signed copy of log4net is not an option for us, because some of our 3rd-party assemblies are compiled against the signed 1.2.10 log4net assembly.
 
The files could be sent irectly to me at omer.mor <at> gmail.com .
 
Thanks in advance,
  Omer Mor.
Omer Mor | 7 Aug 11:44 2009
Picon

Re: Debugging log4net source

I prefer debugging the situation live.
Is it so hard to re-compile 1.2.10 with pdb? It's just a matter of a slight tweak in the project settings.

On Fri, Aug 7, 2009 at 6:12 AM, Ron Grabowski <rongrabowski <at> yahoo.com> wrote:
Have you tried specifying a custom error handler on the appender to track down when it enters a failed state?

<appender name=".." >
  ...
  <errorHandler type="Your.ErrorHandler, YourAssembly" />
</appender>

You would write one that sends an email when the file can't be created.

Sent: Thursday, August 6, 2009 3:02:17 AM
Subject: Debugging log4net source

Hi,
to research a (rare) bug we have with log4net (log file is not being created) we wanted to debug its source.
However, the release build of 1.2.10 is supplied without a pdb file.
And since it is a signed assembly we can't compile it ourself and replace it.
Also - the debug build of 1.2.10 is supplied with a pdb, but is not signed, so it is not substitutable.
What I'd like to ask is that one of the developers compile a release build of 1.2.10 and enable pdb creation, so that we could debug the source.
 
Using a non-signed copy of log4net is not an option for us, because some of our 3rd-party assemblies are compiled against the signed 1.2.10 log4net assembly.
 
The files could be sent irectly to me at omer.mor <at> gmail.com .
 
Thanks in advance,
  Omer Mor.

Ingeniouz | 7 Aug 16:04 2009
Picon

Log4net stopped logging from some assemblies.

Hi,
In my project which involves a lot of assemblies, I have been using Log4net for more than two years without any problems. The assemblies were compiled in VS2005. Recently some assemblies stopped logging and the only change that these projects went through was, they were opened in a machine which has VS2008 installed on them. Does anyone know what settings I have to change to resume logging from these assemblies again. I tried compiling the projects with older version of csproj files still no luck. I tried enabling internal debugging on log4net but I couldnot get that working, here is my config file. Using log4net version 1.2.10.0.

<log4net debug="true">
    <appender name="FileAppender" type="log4net.Appender. FileAppender">

        <file value="log-file.txt"/>
        <appendToFile value="true"/>
        <lockingModel type="log4net.Appender.FileAppender+MinimalLock"/>
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level - %logger{1}.%method - [%message]%newline"/>
        </layout>
    </appender>
 .
.
.
.
.
  <logger name="MyAssembly1">
    <additivity value="false" />
    <level value="ERROR"/>
    <appender-ref ref="EventLogAppender"/>
  </logger>
  <root>
    <level value="ALL" />
    <appender-ref ref="FileAppender" />
  </root>
</log4net>


Thanks,
AK.
 
Thomas Haller (JIRA | 10 Aug 17:26 2009
Picon

[jira] Created: (LOG4NET-225) Multithreading and Deadlocks

Multithreading and Deadlocks
----------------------------

                 Key: LOG4NET-225
                 URL: https://issues.apache.org/jira/browse/LOG4NET-225
             Project: Log4net
          Issue Type: Bug
          Components: Appenders
    Affects Versions: 1.2.10
            Reporter: Thomas Haller
            Priority: Blocker

If an Appender has to execute some logic on another thread, 
witch uses also log4net, this leads to a deadlock.

The sample project i created demonstrates that problem.

--

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

Thomas Haller (JIRA | 10 Aug 17:28 2009
Picon

[jira] Updated: (LOG4NET-225) Multithreading and Deadlocks


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

Thomas Haller updated LOG4NET-225:
----------------------------------

    Attachment: Log4NetDeadlock.zip

project to reproduce that Problem

> Multithreading and Deadlocks
> ----------------------------
>
>                 Key: LOG4NET-225
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-225
>             Project: Log4net
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 1.2.10
>            Reporter: Thomas Haller
>            Priority: Blocker
>         Attachments: Log4NetDeadlock.zip
>
>
> If an Appender has to execute some logic on another thread, 
> witch uses also log4net, this leads to a deadlock.
> The sample project i created demonstrates that problem.

--

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

Dag Trygve Christensen | 10 Aug 19:59 2009
Picon

RE: [jira] Updated: (LOG4NET-225) Multithreading and Deadlocks

Can you provide a better example? If it didn't deadlock, it would run out of stack since you're calling your
own appender recursively?

Regards,

Dag

-----Opprinnelig melding-----
Fra: Thomas Haller (JIRA) [mailto:jira <at> apache.org] 
Sendt: 10. august 2009 17:28
Til: log4net-dev <at> logging.apache.org
Emne: [jira] Updated: (LOG4NET-225) Multithreading and Deadlocks

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

Thomas Haller updated LOG4NET-225:
----------------------------------

    Attachment: Log4NetDeadlock.zip

project to reproduce that Problem

> Multithreading and Deadlocks
> ----------------------------
>
>                 Key: LOG4NET-225
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-225
>             Project: Log4net
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 1.2.10
>            Reporter: Thomas Haller
>            Priority: Blocker
>         Attachments: Log4NetDeadlock.zip
>
>
> If an Appender has to execute some logic on another thread, 
> witch uses also log4net, this leads to a deadlock.
> The sample project i created demonstrates that problem.

--

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

###########################################

This message has been scanned by F-Secure Anti-Virus for Microsoft Exchange.
For more information, connect to http://www.f-secure.com/

Maxim Fateev (JIRA | 11 Aug 00:44 2009
Picon

[jira] Created: (LOG4NET-226) Allow to specify file name as wildcard pattern

Allow to specify file name as wildcard pattern
----------------------------------------------

                 Key: LOG4NET-226
                 URL: https://issues.apache.org/jira/browse/LOG4NET-226
             Project: Log4net
          Issue Type: Improvement
          Components: Appenders
    Affects Versions: 1.2.10, 1.2.9, 1.2.11, v.Next
         Environment: Windows
            Reporter: Maxim Fateev

Change 707809 fixes issue with windows file name extension. 
From filename.txt.1, filename.txt.2 it changes it to filename.1.txt, filename.2.txt. 
But it is still limiting form some use cases. I need to integrate logs with existing logging infrastucture
that requires file names to be filename_0.log, filename_1.log.
I propose to add additional property to specify filename as a format pattern. I recommend using standard
.net string format. So in my case file name would be filename_{0}.log.

It would also support other cases like requirement for filename to be filename_00.log, filename_01.log.
Just specify format as filename_{00}.log

Also property to specify initial counter value is necessary to support my use case.

--

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

Dag Christensen (JIRA | 11 Aug 12:33 2009
Picon

[jira] Commented: (LOG4NET-225) Multithreading and Deadlocks


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

Dag Christensen commented on LOG4NET-225:
-----------------------------------------

Without the lock, your sample code would be calling its own Appender recursively with a stack overflow as
result. Should work if your appender logs to a different appender since the lock prevents appender reentry.

From AppenderSkeleton.cs:

// This lock is absolutely critical for correct formatting
// of the message in a multi-threaded environment.  Without
// this, the message may be broken up into elements from
// multiple thread contexts (like get the wrong thread ID).
lock(this)
{ 
(...)

> Multithreading and Deadlocks
> ----------------------------
>
>                 Key: LOG4NET-225
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-225
>             Project: Log4net
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 1.2.10
>            Reporter: Thomas Haller
>            Priority: Blocker
>         Attachments: Log4NetDeadlock.zip
>
>
> If an Appender has to execute some logic on another thread, 
> witch uses also log4net, this leads to a deadlock.
> The sample project i created demonstrates that problem.

--

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


Gmane