[ZODB-Dev] restart log weirdness

[Chris McDonough]

Oh this is pretty hysterical...

If you start up Zope with STUPID_LOG_FILE="duh" (not an absolute path, a
relative path), *two* "duh" logfiles will be written.  One in the
current working directory.  The other in the "var" directory of your
instance.

The current working directory "duh" is messages from zdaemon.  The var
directory "duh" is messages from Zope.

Eeek!

- C


On Thu, 2002-10-10 at 23:48, Chris McDonough wrote:
> On Thu, 2002-10-10 at 22:38, Guido van Rossum wrote:
> > I'm experimenting with SIGUSR2 in ZEO/start.py.  This signal (now) is
> > supposed to reopen the log file.
> > 
> > The weirdness is that after sending the signal, the storage server
> > process indeed reopens the log file, but the zdaemon appears to stop
> > logging!
> 
> Do messages from the child process still make it to the logfile after
> the signal is sent?
> 
> It doesn't appear that the zLOG messages that are emitted by zdaemon
> *ever* make it to a zLOG-backed disk-file logfile, independent of
> signals, at least that I could tell by setting the STUPID_LOG_FILE
> envvar before starting Zope.
> 
> OTOH, if you start up in 'debug mode' (Z_DEBUG_MODE=1) with the
> STUPID_LOG_FILE envar set to '' (telling zLOG to log to stderr),
> zdaemon's messages are printed to the console along with the server's
> messages.
> 
> > I can't find anything to explain this.
> 
> > Could it be that the subprocess and the parent process share a file
> > descriptor and that when the child closes it (as part of the reopening
> > procedure) the parent's file descriptor is somehow also closed?
> 
> I'm not sure if we're describing the same phenomenon, but I think *my*
> phenomenon is caused by the fact that the zdaemon process inherits a
> zLOG set up in such a way (by virtue of forking before some other later
> zLOG setup) that it's backed by MinimalLogger.  Because MinimalLogger is
> not initialized, it returns instead of actually logging.  Meanwhile,
> under Zope at least, the child server's zLOG is backed by
> ZLogger.stupidFileLogger, which gets initialized on every write, so the
> child's messages do go to a logfile.  I still dont understand why I do
> see log messages from zdaemon under debug mode when the log goes to the
> console, but the machinations of this code are making my head spin so
> I'm giving up. ;-)
> 
> The logging system in Zope is such a mess that I'm not sure it's worth
> disentangling.  We should try hard to replace zLOG/ZLogger and the
> medusa logger with Vinay Sajip's PEP 282 logger (or something) soon.
> 
> I'm not sure that what you're seeing is at all related to any of this,
> but if the only problem really is that messages sent by zdaemon dont
> make it to a logfile while the child's messages do, I think the answer
> is to call it a feature until we can replace the logging system. ;-)
> 
> - C
> 
> 
> 
> _______________________________________________
> For more information about ZODB, see the ZODB Wiki:
> http://www.zope.org/Wikis/ZODB/
> 
> ZODB-Dev mailing list  -  ZODB-Dev@zope.org
> http://lists.zope.org/mailman/listinfo/zodb-dev