logging-log4net-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dean Fiala" <dfi...@celadonlabs.com>
Subject RE: Log4Net stopping
Date Mon, 24 Mar 2008 20:22:52 GMT
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().Declari
ngType);

 

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