Re: log4net mysteriously stops logging
am 07.04.2008 07:30:00 von RobinS"RobinS"
news:MqednVV_C__Go3ranZ2dnUVZ_sednZ2d@comcast.com...
>
> "Jeroen Mostert"
> news:47e6956f$0$14355$e4fe514c@news.xs4all.nl...
>> RobinS wrote:
>>> More comments inline...
>>>
>>> "Jeroen Mostert"
>>> news:47e56bef$0$14342$e4fe514c@news.xs4all.nl...
>>>> RobinS wrote:
>>>>> Comments inline...
>>>>>
>>>>> "Jeroen Mostert"
>>>>> news:47e40559$0$14350$e4fe514c@news.xs4all.nl...
>>>
>
>>
>>> Here's some of the debugging stuff from log4net at startup:
>>>
>>> log4net: XmlConfigurator: configuring repository
>>> [log4net-default-repository] using file
>>> [C:\Users\Jeanne\Documents\GoldMail\Log4netConfig.xml]
>>
>> ^ Note this. ^
>>
>>>>> Okay, more info. I had our QA person run the application repeatedly.
>>>>> Sometimes the logging stops right away, sometimes it stops after she's
>>>>> run through the app a couple of times. It's not 100% reproducible.
>>>>> With the debugging in log4net enabled, I found the following:
>>>>>
>>>>>
>>>>> log4net: Hierarchy: Shutdown called on Hierarchy
>>>>> [log4net-default-repository]
>>>>> log4net: XmlConfigurator: configuring repository
>>>>> [log4net-default-repository] using file
>>>>> [C:\Users\Jeanne\Documents\GoldMail\GoldMailLog.txt]
>>
>> ^ Now note this! ^
>>
>> It's using the *file that you're logging to* as the configuration file,
>> which quite obviously fails. Interesting, eh?
>>
>> Now, why does it reconfigure itself, and why is it using the wrong file
>> for that? I have no idea, honestly. I pulled apart the source but found
>> no obvious wrongdoing.
>>
>> At this point I would pull out a debugger and set a breakpoint on
>> log4net.Config.XmlConfigurator.Configure(ILoggerRepository, FileInfo),
>> but that demands a reproducible environment.
>>
>>> I have no idea what those last 6 lines are from or what they mean. Our
>>> GMSound project has a lot of DirectX stuff in it, and a lot of objects
>>> created and disposed; I'm not sure that's relevant, but thought I'd
>>> mention it just in case.
>>>
>> It might be, though it's unlikely. If there's some kind of error invoking
>> native DirectX stuff it could cause memory corruption, though corruption
>> of the kind where log4net spontaneously reconfigures itself with a wrong
>> file is hard to imagine (that said, stranger things have happened).
>>
>>> I'm not using ConfigureAndWatch, I'm just using Configure. And none of
>>> the AssemblyInfo.cs files access or reference log4net.
>>>
>> Curiouser and curiouser.
>>
>>> Any idea how I can figure out where in the code it's messing up my
>>> logging? Is it probably in the GMSound project, since that's the last
>>> one that does the whole "does not have a RespositoryAttribute..." stuff
>>> before the logging gets shut down?
>>>
>> It's certainly a possibility.
>>
>> OK, at this point things are so weird that I can't offer any more help
>> unless you paid for a flight and put me behind a computer with a
>> debugger.
>>
>> Set a breakpoint on the method I mentioned. The first call will be the
>> regular startup call; the second one should be the culprit and the stack
>> trace should be interesting. That's assuming that the debug version still
>> exhibits the problem. If it doesn't, then you may very well have memory
>> corruption on your hands, or a CLR bug, neither of which are fun.
>>
>> To investigate *that*, you might try running your application with
>> Managed Debugging Assistants (MDAs) enabled. It will run much, much
>> slower, but it will also include lots of checks. There's a good article
>> on them here: http://msdn2.microsoft.com/en-us/magazine/cc163606.aspx
>>
>> If you can't install VS on the target computer, you can simply use the
>> native debuggers (ntsd.exe is installed with every copy of Windows).
>> These have very limited support for managed code, but they will allow you
>> to see the MDA output.
>>
>
>
> Thanks very much, I will check it out and see what I can do. The other
> thing that occurred to me is I can put in some trace statements, and they
> will write to the debug log for log4net (because the trace statements are
> redirected to a file), and using that I may be able to figure out *where*
> it's happening.
>
> That, and stepping through the code and using the breakpoint you
> recommended.
>
> I assume I can get the code for log4net from their website?
>
> Thanks again for the advice and help. I'll report back when I solve the
> problem.
>
> RobinS.
> GoldMail.lcom
>
Just a follow-up. I attached the code for log4net, and found that we were,
indeed shutting down log4net, and starting it back up and passing it the
wrong file. The filename was pulled out of a config file we have, and it was
retrieving the wrong item. So as I suspected, it was our own darn fault.
Thanks for your help, Jeroen.
RobinS.
GoldMail.com