[CherryPy] #646: logging breaks when running as daemon

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:
Component: CherryPy code | Keywords:
------------------------------------------+---------------------------------
I'm trying to run my CherryPy server as a daemon process (using ll.daemon
available from http://www.livinglogic.de/Python/daemon/). With CherryPy
2.2.1 this worked flawlessly. 3.0 however is giving me problems. Here is a
small test script that demonstrates the bug:

{{{
import os

import cherrypy

from ll import daemon

cherrypy.config.update(
{
"server.environment": "production",
"server.socket_port": 9999,
"server.thread_pool": 10,
"server.log_to_screen": 0,
"server.log_file": "/home/walter/cherrylogs/wiki.error",
"server.log_access_file":
"/home/walter/cherrylogs/wiki.access",
}
)


if __name__ == "__main__":
d = daemon.Daemon(
pidfile="/var/run/walter/wiki.pid",
user="walter",
group="users",
)
if d.service():
cherrypy.quickstart(lambda n: "foo", "/")
}}}

Here is the stacktrace I'm getting:

{{{
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
File "/usr/local/lib/python2.5/atexit.py", line 24, in _run_exitfuncs
func(*targs, **kargs)
File "/usr/local/lib/python2.5/logging/__init__.py", line 1351, in
shutdown
h.flush()
File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush
self.stream.flush()
ValueError: I/O operation on closed file
Error in sys.exitfunc:
Traceback (most recent call last):
File "/usr/local/lib/python2.5/atexit.py", line 24, in _run_exitfuncs
func(*targs, **kargs)
File "/usr/local/lib/python2.5/logging/__init__.py", line 1351, in
shutdown
h.flush()
File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush
self.stream.flush()
ValueError: I/O operation on closed file
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
File "/usr/local/lib/python2.5/atexit.py", line 24, in _run_exitfuncs
func(*targs, **kargs)
File "/usr/local/lib/python2.5/logging/__init__.py", line 1351, in
shutdown
h.flush()
File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush
self.stream.flush()
ValueError: I/O operation on closed file
Error in sys.exitfunc:
Traceback (most recent call last):
File "/usr/local/lib/python2.5/atexit.py", line 24, in _run_exitfuncs
func(*targs, **kargs)
File "/usr/local/lib/python2.5/logging/__init__.py", line 1351, in
shutdown
h.flush()
File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush
self.stream.flush()
ValueError: I/O operation on closed file
}}}

--
Ticket URL: <http://www.cherrypy.org/ticket/646>
CherryPy <http://www.cherrypy.org>
CherryPy - a pythonic, object-oriented HTTP framework

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:

Component: CherryPy code | Resolution:
Keywords: |
------------------------------------------+---------------------------------
Comment (by fumanchu):

Hm. To start, the config keys for logging have changed. Your example
should read:

{{{
#!python
cherrypy.config.update(
{

"environment": "production",
"server.socket_port": 9999,
"server.thread_pool": 10,

"log.screen": False,
"log.error_file": "/home/walter/cherrylogs/wiki.error",
"log.access_file": "/home/walter/cherrylogs/wiki.access",
}
)
}}}

Second, I don't understand why you're passing a function to
cherrypy.quickstart(lambda n: "foo", "/"). You should pass a Root instance
(that has page handlers as methods) or an instance of cherrypy.Application
if you want more control.

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:

Component: CherryPy code | Resolution:
Keywords: |
------------------------------------------+---------------------------------

Comment (by walter AT livinglogic DOT de):

OK, I've changed the logging configuration according to your example.
However this doesn't change the traceback.

I've used a lambda in the quickstart() call simply for demonstration
purposes. The real code of course uses a root instance with handler
methods.

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:

Component: CherryPy code | Resolution:
Keywords: |
------------------------------------------+---------------------------------

Comment (by fumanchu):

Hm. Looks like you're seeing a similar problem to this recently patched
[http://sourceforge.net/tracker/index.php?func=detail&aid=1566280&group_id=5470&atid=105470
bug] on Python SF. Since the fix for that delves into main.c, asking you
to patch that is a bit much. Python 2.5 has a new global
logging.raiseExceptions attribute that you can set to False to just
silence these errors, but that will silence more than just shutdown
errors. :/ Maybe you can set it to False in an engine stop callback?

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:

Component: CherryPy code | Resolution:
Keywords: |
------------------------------------------+---------------------------------

Comment (by walter AT livinglogic DOT de):

I've applied Python SVN revision r53250 to my local version of Python 2.5
and recompiled. However this does not fix the problem (still the same
stack trace). I now added logging.raiseExceptions = False to the start of
the script and with this the server runs fine. How would the engine stop
callback version look?

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:

Component: CherryPy code | Resolution:
Keywords: |
------------------------------------------+---------------------------------

Comment (by fumanchu):

To use an engine stop callback, instead of:

{{{
#!python
logging.raiseExceptions = False
}}}

...write something like this:

{{{
#!python
def silence_logging_errors():
logging.raiseExceptions = False
cherrypy.engine.on_stop_engine_list.append(silence_logging_errors)

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon
Type: defect | Status: new
Priority: normal | Milestone:

Component: CherryPy code | Resolution:
Keywords: |
------------------------------------------+---------------------------------

Comment (by walter AT livinglogic DOT de):

I tried that, but this results in the same stack trace as before. An
unconditional logging.raiseExceptions = False works.

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon

Type: defect | Status: closed
Priority: normal | Milestone: 3.0
Component: CherryPy code | Resolution: toolfix
Keywords: |
------------------------------------------+---------------------------------
Changes (by fumanchu):

* milestone: => 3.0
* resolution: => toolfix
* status: new => closed

[CherryPy]

#646: logging breaks when running as daemon
------------------------------------------+---------------------------------
Reporter: walter AT livinglogic DOT de | Owner: rdelon

Type: defect | Status: closed
Priority: normal | Milestone: 3.0
Component: CherryPy code | Resolution: toolfix
Keywords: |
------------------------------------------+---------------------------------

Comment (by fumanchu):

Python bug report moved to http://bugs.python.org/issue1566280.