logging-log4net-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Robin Shahan" <Robin.Sha...@goldmail.com>
Subject RE: Log4Net stopping
Date Wed, 26 Mar 2008 18:10:58 GMT
I have searched our source code, and can't find any other calls to
Configure. 


I guess the next step is to get the log4net code and put a breakpoint in
at the call to Configure and figure out where my code is calling it, or
where it's being called. 

 

Do I have to have Subversion to get the log4net source code? I don't
want to check it out and make changes to it, I just want to be able to
run against it. And does anyone have any tips how I can add it to my
project and debug with it? 

 

Thanks,

RobinS.

 

From: Dean Fiala [mailto:dfiala@celadonlabs.com] 
Sent: Monday, March 24, 2008 1:23 PM
To: 'Log4NET User'
Subject: RE: Log4Net stopping

 

I'd just confirm that this is the case, because all the behavior you
have described points to something being called either unexpectedly or
out of order.

 

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com] 
Sent: Monday, March 24, 2008 2:43 PM
To: Log4NET User
Subject: RE: Log4Net stopping

There are actually two places where we shut down the logging and start
it back up again. One is when the user changes the logging level, the
other is when the user views the log file. In this case, neither of
those is happening. The only other place where we are configuring the
logging is in Program.cs at the top of our application.

 

Thanks much. I'll do more searching.

 

RobinS.

 

From: Dean Fiala [mailto:dfiala@celadonlabs.com] 
Sent: Monday, March 24, 2008 11:37 AM
To: 'Log4NET User'
Subject: RE: Log4Net stopping

 

Logging will shut down I believe when you call
XmlConfigurator.Configure, so I'd double check that you are not calling
this method more than once in your code.  

 

I'll see I can confirm this later.

 

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com] 
Sent: Monday, March 24, 2008 1:13 PM
To: Log4NET User
Subject: RE: Log4Net stopping

You are exactly right. What's weird is that we only load the
configuration file when the application starts up, but it does appear to
be shutting down the logging and then trying to start it back up using
the log file as its configuration file. 

 

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]

log4net: XmlConfigurator: configuring repository
[log4net-default-repository] using stream

log4net:ERROR XmlConfigurator: Error while loading XML configuration

 

I have no idea why it would be shutting down the logging. In fact, I
don't even know HOW to shut down the logging. In all of the classes
where we use it, we define it:

 

private static readonly ILog log =
LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().Dec
laringType);

 

and then we use it like this:

 

    log.Debug("this is my message");

 

I am going to put in some trace.writeline statements and see if I can
figure out where it's shutting down the logging, and then maybe I/we can
figure out why? The only other idea someone in the usenet newsgroup
suggested was to get the source code for log4net and put a breakpoint at
the call to Configure and see where else it is being called and why. 

 

When you say "check your autoload code", where would that be? The only
thing I have is where it loads the config file the first time. Is there
something in the XML configuration file that has that information?

 

Thanks for your ongoing help. I'm not sure how else to proceed other
than what I'm going. I'd welcome any ideas.

 

Robin

 

From: Dean Fiala [mailto:dfiala@celadonlabs.com] 
Sent: Monday, March 24, 2008 9:56 AM
To: 'Log4NET User'
Subject: RE: Log4Net stopping

 

It seems you are sending a bad config file to XmlConfigurator. This one
works...

>>log4net: XmlConfigurator: configuring repository
[log4net-default-repository] using file
[C:\Users\Jeanne\Documents\GoldMail\Log4netConfig.xml]

 

But in your error statement, you seem to sending the configurator the
log file itself...

>>log4net: XmlConfigurator: configuring repository
[log4net-default-repository] using file
[C:\Users\Jeanne\Documents\GoldMail\GoldMailLog.txt]

 

this is obviously not going to be valid XML. I'd check your autoload
code to make sure are always sending the proper file path,

 

 

 

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com] 
Sent: Friday, March 21, 2008 7:03 PM
To: Log4NET User
Subject: RE: Log4Net stopping

This is what I see in the log4net debugger log when the app starts up:

 

log4net: DefaultRepositorySelector: Creating repository
[log4net-default-repository] using type
[log4net.Repository.Hierarchy.Hierarchy]
log4net: XmlConfigurator: configuring repository
[log4net-default-repository] using file
[C:\Users\Jeanne\Documents\GoldMail\Log4netConfig.xml]
log4net: XmlConfigurator: configuring repository
[log4net-default-repository] using stream
log4net: XmlConfigurator: loading XML configuration
log4net: XmlConfigurator: Configuring Repository
[log4net-default-repository]

This is what is in the C# code. If the user doesn't have a Config file
set up, it copies the config file over and saves it in the right place.

 

File.Copy(logPath, configFile.FullName);
XmlDocument document = new XmlDocument();
document.Load(configFile.FullName);

foreach (XmlNode node in document.GetElementsByTagName("file"))
{
    node.Attributes.GetNamedItem("value").Value =
Path.Combine(appDataFolder, "GoldMailLog.txt");
    break;
}
document.Save(configFile.FullName);

Then it does this to start it up: XmlConfigurator.Configure(configFile);
You can see the successful entries in the debug log for this. 

 

Here's something else I'm seeing that might apply; is this shutting down
log4net? 

 

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]
log4net: XmlConfigurator: configuring repository
[log4net-default-repository] using stream
log4net:ERROR XmlConfigurator: Error while loading XML configuration
System.Xml.XmlException: Data at the root level is invalid. Line 1,
position 1.
   at System.Xml.XmlTextReaderImpl.Throw(Exception e)
   at System.Xml.XmlTextReaderImpl.Throw(String res, String arg)
   at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
   at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
   at System.Xml.XmlTextReaderImpl.Read()
   at System.Xml.XmlLoader.Load(XmlDocument doc, XmlReader reader,
Boolean preserveWhitespace)
   at System.Xml.XmlDocument.Load(XmlReader reader)
   at log4net.Config.XmlConfigurator.Configure(ILoggerRepository
repository, Stream configStream)
log4net: Logger: No appenders could be found for logger
[GMStudio.gmPreviewForm] repository [log4net-default-repository]
log4net: Logger: Please initialize the log4net system properly.
log4net: Logger:    Current AppDomain context information: 
log4net: Logger:       BaseDirectory   :
C:\Users\Jeanne\AppData\Local\Apps\2.0\EM6ZCA9H.ZH3\2YEVW4GX.TD1\gmst..t
ion_e84b302e57430172_0003.0002_8d1f3aa9ab6946c1\
log4net: Logger:       FriendlyName    : DefaultDomain
log4net: Logger:       DynamicDirectory: 
log4net: Hierarchy: Shutdown called on Hierarchy
[log4net-default-repository]

This happens for 2 forms and one class. We have tons of forms and
classes, but only 3 of them cause this error. 

 

The really odd thing is, when I run this on *my* machine, I don't get
this XML exception in my debug log. So for some reason, it happens for
some people, but not others, and not consistently even for those who can
reproduce it. I am running the same build, installed the same way, not
running it through the IDE.

 

I'm not sure what else to try or how exactly to track down the problem.
Any ideas would be greatly appreciated.

 

Thanks,

RobinS.

GoldMail.com

________________________________

From: Ron Grabowski [mailto:rongrabowski@yahoo.com]
Sent: Wed 3/19/2008 4:38 PM
To: Log4NET User
Subject: Re: Log4Net stopping

How is log4net being initialized? It looks like something is causing it
to shutdown... I'm pretty sure this message:

 log4net: Logger: No appenders could be found for logger

is being caused by attempts to log without first configuring log4net.

----- Original Message ----
From: Robin Shahan <Robin.Shahan@goldmail.com>
To: Log4NET User <log4net-user@logging.apache.org>
Sent: Wednesday, March 19, 2008 5:47:27 PM
Subject: RE: Log4Net stopping

Yes, it stops logging to both places. I'm looking at the debugging info
that was output, and there's a lot of this kind of stuff:

 

log4net: Logger: No appenders could be found for logger
[GMStudio.gmPreviewForm] repository [log4net-default-repository]
log4net: Logger: Please initialize the log4net system properly.
log4net: Logger:    Current AppDomain context information: 
log4net: Logger:       BaseDirectory   : <snip>

log4net: Logger:       FriendlyName    : DefaultDomain
log4net: Logger:       DynamicDirectory: <snip>

 

and this


log4net: Hierarchy: Shutdown called on Hierarchy
[log4net-default-repository]
log4net: Logger: No appenders could be found for logger
[GMSound.SoundUtils] repository [log4net-default-repository]
log4net: Logger: Please initialize the log4net system properly.
log4net: Logger:    Current AppDomain context information: 
log4net: Logger:       BaseDirectory   : <snip>

log4net: Logger:       FriendlyName    : DefaultDomain
log4net: Logger:       DynamicDirectory: 

and this has error "does not have a RepositoryAttribute specified."

 

log4net: RollingFileAppender: Searched for existing files in
[C:\Users\Jeanne\Documents\GoldMail]
log4net: RollingFileAppender: curSizeRollBackups starts at [0]
log4net: FileAppender: Opening file for writing
[C:\Users\Jeanne\Documents\GoldMail\GoldMailLog.txt] append [True]
log4net: XmlHierarchyConfigurator: Created Appender
[RollingLogFileAppender]
log4net: XmlHierarchyConfigurator: Adding appender named
[RollingLogFileAppender] to logger [root].
log4net: XmlHierarchyConfigurator: Hierarchy Threshold []
log4net: DefaultRepositorySelector: Creating repository for assembly
[GMLibrary, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]
log4net: DefaultRepositorySelector: Assembly [GMLibrary,
Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] Loaded From
[C:\Users\Jeanne\AppData\Local\Apps\2.0\EM6ZCA9H.ZH3\2YEVW4GX.TD1\gmst..
tion_e84b302e57430172_0003.0002_8a24dc44b8cff001\GMLibrary.dll]
log4net: DefaultRepositorySelector: Assembly [GMLibrary,
Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] does not have a
RepositoryAttribute specified.
log4net: DefaultRepositorySelector: Assembly [GMLibrary,
Version=1.0.0.0, Culture=neutral, PublicKeyToken=null] using repository
[log4net-default-repository] and repository type
[log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: repository
[log4net-default-repository] already exists, using repository type
[log4net.Repository.Hierarchy.Hierarchy]
log4net: DefaultRepositorySelector: Creating repository for assembly
[GMBusinessLogicLayer, Version=3.1.0.0, Culture=neutral,
PublicKeyToken=null]

Does this mean anything? Note than when I run it with the log debugging
enabled, it works.

 

Thanks,

Robin

 

________________________________

From: Ron Grabowski [mailto:rongrabowski@yahoo.com]
Sent: Wed 3/19/2008 2:41 PM
To: Log4NET User
Subject: Re: Log4Net stopping

Does logging stop on both the ConsoleAppender and the
RollingLogFileAppender?

----- Original Message ----
From: Robin Shahan <Robin.Shahan@goldmail.com>
To: Log4NET User <log4net-user@logging.apache.org>
Sent: Wednesday, March 19, 2008 2:40:40 PM
Subject: RE: Log4Net stopping

When I turn on the internal debugging, the logging works every time.
When I turn it off, it doesn't. I'm enabled this feature following the
instructions in the link below.

 

Does anybody have any ideas at all? 

 

Thanks,

Robin 

 

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com]
Sent: Wed 3/19/2008 10:51 AM
To: Log4NET User; Log4NET User
Subject: RE: Log4Net stopping

The upload is spun off in a separate thread. We had another occurrence
this morning where it stopped logging as soon as the user authenticated.
This is not in a separate thread. 

 

I found this link, and it has some info about running internal debugging
while logging; has anyone tried this? 

 

http://logging.apache.org/log4net/release/faq.html

 

Thanks,

Robin

 

________________________________

From: Dean Fiala [mailto:dfiala@celadonlabs.com]
Sent: Wed 3/19/2008 9:13 AM
To: 'Log4NET User'
Subject: RE: Log4Net stopping

Hmmm, doesn't sound like you are bombarding the logger, but a few large
file tests would be my next step.

 

By large messages, I meant a couple of kilobytes, that's only really
variably sized bit of the log entry.

 

Another question.  Does this file upload happen on the application's
main thread, or is it spun off in a separate thread?

 

Finally, is the rolling file log being accessed by anything else in the
application?

 

Dean

 

 

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com] 
Sent: Wednesday, March 19, 2008 12:01 PM
To: Log4NET User
Subject: RE: Log4Net stopping

It uploads the file in chunks, so it prints out a log entry with each
chunk. So maybe it's not "a lot of logging" by other people's standards,
but it's probably where the most logging occurs in our app. It depends
on the size of the file. We're testing with pretty small ones (no
patience), so the last one I did was 156 lines of logging. It is just
statements like "hitting the refresh code", "posting chunk", "chunk #23
posted", "chunk 23 successful". It prints the date/time and routing that
logged the entry.

 

As far as I know, we don't have any large individual messages (how do
you define large?), but I'll see. It's weird because as far as I know,
that code hasn't been mucked with, and it has been working just fine. Or
so we think. Luckily, we use TFS, so I can tell if someone's changed it,
and if so, how. 

 

Thanks, 

Robin

 

From: Dean Fiala [mailto:dfiala@celadonlabs.com] 
Sent: Wednesday, March 19, 2008 8:38 AM
To: 'Log4NET User'
Subject: RE: Log4Net stopping

 

OK,

Hard to tell how it is related without seeing what you are logging, but
since that is your best guess, might as well follow up in that
direction. Can you quantify "a lot of logging"?  Are you attempting to
log a large section of the file that is being uploaded?  Or some other
large individual message during the process?  That's where I'd look
since it seems to be appender indepenent.  

 


Dean

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com] 
Sent: Wednesday, March 19, 2008 11:12 AM
To: Log4NET User
Subject: RE: Log4Net stopping

The file is being uploaded to our servers via web services. I don't see
how it can be related (it's not a new feature), but that is the pattern
we're seeing -- logging stops for some people after they've uploaded.
One thing to note: There is a lot of logging done during the upload
process.

 

One other thing - I remembered last night that I've seen this in one
other case. I put some logging statements in this click event in a user
control once, and it wouldn't output the statements. I ended up putting
in messageboxes to get the information I was looking for.

 

And the other programmer who has seen this problem said the log messages
don't show up in the Output window in Visual Studio either.

 

Here is our configuration file. I didn't add the logging to our
application, another programmer did, who is long gone. So I don't know a
whole lot about log4net, except how it's set up in our app (it starts
first thing), where the logs go, and how to write to the log. That, and
it's worked great right up to this moment. 

 

<?xml version="1.0" encoding="utf-8"?>

<log4net>

  <appender name="ConsoleAppender"
type="log4net.Appender.ConsoleAppender">

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

      <conversionPattern value="%date %-5level %logger (%L) [%ndc] -
%message%newline" />

    </layout>

  </appender>

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

    <file value="D:\RobinShahan\GoldMail\GoldMailLog.txt" />

    <staticLogFileName value="true" />

    <appendToFile value="true" />

    <rollingStyle value="Size" />

    <maxSizeRollBackups value="5" />

    <maximumFileSize value="1MB" />

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

      <conversionPattern
value="GMLog#%date;%-5level;%logger(%L);%message#End%newline" />

    </layout>

  </appender>

  <root>

    <level value="DEBUG" />

    <appender-ref ref="ConsoleAppender" />

    <appender-ref ref="RollingLogFileAppender" />

  </root>

</log4net>

 

Thanks,

Robin Shahan

GoldMail.com

From: Dean Fiala [mailto:dfiala@celadonlabs.com] 
Sent: Wednesday, March 19, 2008 5:56 AM
To: 'Log4NET User'
Subject: RE: Log4Net stopping

 

Robin,

No answers, but some questions: Is the file being uploaded to the same
directory as the log?  Dose the size of the file being uploaded matter?
Which appenders are you using?

 

Regards,

 

Dean Fiala

 

 

________________________________

From: Robin Shahan [mailto:Robin.Shahan@goldmail.com] 
Sent: Tuesday, March 18, 2008 8:53 PM
To: log4net-user@logging.apache.org
Subject: Log4Net stopping

We are using log4net to do logging in a .Net 2.0 application. We have
used it successfully for about 6 months. Then today, we discovered that
sometimes it just stops working. It still goes through the statements to
write to the log, but it doesn't actually write anything anywhere. The
users have to close our application and re-open it to start the logging
off again. 

 

The action that happens right before it stops is uploading a file via
web services. The file succeeds, and shortly thereafter it stops
logging. I don't know if that's coincidence or what. We are not seeing
this on all the customers, just some, and for those, some are
intermittent and some are always happening.

 

We are running the most current version (1.2.10).

 

Any help would be greatly appreciated.

 

Robin Shahan

Sr. Software Engineer

GoldMail, Inc.

robin.shahan@goldmail.com 

 

 

 


Mime
View raw message