Re: log4net mysteriously stops logging

Tech Tip: Click here to run a free scan for Windows Errors and optimize PC performance

RobinS wrote:
More comments inline...

"Jeroen Mostert" <jmostert@xxxxxxxxx> wrote in message news:47e56bef$0$14342$e4fe514c@xxxxxxxxxxxxxxxxx
RobinS wrote:
Comments inline...

"Jeroen Mostert" <jmostert@xxxxxxxxx> wrote in message news:47e40559$0$14350$e4fe514c@xxxxxxxxxxxxxxxxx

<snip>
I don't understand this: "my call only retrieves a logger *once*". We have the definition of [log] defined at the top of the class, not in each method that uses it.

Oh, my bad. I assumed it was done in each method individually, what with the ..GetCurrentMethod() call. But of course this even works as part of a field initializer -- the "current method" will be the constructor. My assumptions made an ass out of me.

Ignore this, then.

We have a separate .config file just for log4net. It gets deployed with the project. The first time the user runs it, it opens it and saves it under a folder under their MyDocuments, and reads it from there. We call XmlConfigurator.Configure and pass it the FileInfo object that represents the config file.

This sounds important. Can you repro the code, in particular the .Configure call?

Here is the startup for our log4net; this is in Program.cs.

<snip>
OK, nothing special here either.

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.

<snip>
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.

--
J.
.

Relevant Pages

  • Re: log4net mysteriously stops logging
    ... Since the guy who put the logging in did this, the rest of us just carried it through. ... We call XmlConfigurator.Configure and pass it the FileInfo object that represents the config file. ... With the debugging in log4net enabled, ...
    (microsoft.public.dotnet.general)
  • Re: log4net mysteriously stops logging
    ... Sometimes the logging stops right away, sometimes it stops after she's run through the app a couple of times. ... With the debugging in log4net enabled, ... you might try running your application with Managed Debugging Assistants enabled. ...
    (microsoft.public.dotnet.general)
  • Re: log4net mysteriously stops logging
    ... Sometimes the logging stops right away, sometimes it stops after she's run through the app a couple of times. ... With the debugging in log4net enabled, ... you might try running your application with Managed Debugging Assistants enabled. ...
    (microsoft.public.dotnet.general)
  • Re: How do I open a console from a Winform App?
    ... It can log debug messages to almost anything, ... change the config file for the level of logging you want while your ... This also works as a source for Log4Net. ... problem with this is that debug logging only occurs for debug builds. ...
    (microsoft.public.dotnet.languages.csharp)
  • Re: log4net mysteriously stops logging
    ... I posted it to both because I'm desperate, I've seen log4net q's here, and the people here are exceptionally smart. ... You have to close the app and restart it and the logging will restart. ... log4net: DefaultRepositorySelector: Creating repository for assembly ... some dolt misconfigured it; ...
    (microsoft.public.dotnet.general)