RotatingFileHandler and pserve --reload

[Marcus Mann]

Hello!

I am trying to setup logging. I have run into a bug. If I use RotatingFileHandler and try to start my pyramid setup with pserve --reload development.ini, it throws an error similar to this when it tries to rotate the file:

PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'C:\\var\\log\\testing.log' -> 'C:\\var\\log\\testing.log.1'

Here is the logging portion of my development.ini:

[loggers]

keys = root, companalysis

[handlers]

keys = console, filelog, debugfilelog

[formatters]

keys = generic

[logger_root]

level = DEBUG

handlers = console, debugfilelog

[logger_companalysis]

level = DEBUG

handlers = filelog

qualname = companalysis

[handler_console]

class = StreamHandler

args = (sys.stderr,)

level = INFO

formatter = generic

[handler_filelog]

class=handlers.RotatingFileHandler

level=DEBUG

args=('/var/log/testing.log','a',1000,100)

formatter=generic

[handler_debugfilelog]

class=handlers.RotatingFileHandler

level=NOTSET

args=('/var/log/toolbox_debugging.log','a',1000,100)

formatter=generic

[formatter_generic]

format = %(asctime)s %(levelname)-5.5s [%(name)s:%(lineno)s][%(threadName)s] %(message)s

I am on Windows 10.

If I start it without the --reload tag, it works as expected.

[Mikko Ohtamaa]

Hi Marcus,

Hello!

I am trying to setup logging. I have run into a bug. If I use RotatingFileHandler and try to start my pyramid setup with pserve --reload development.ini, it throws an error similar to this when it tries to rotate the file:

Maybe this https://docs.python.org/3/library/logging.handlers.html#watchedfilehandler

 

--
You received this message because you are subscribed to the Google Groups "pylons-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pylons-discus...@googlegroups.com.
To post to this group, send email to pylons-...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/pylons-discuss/098b16e7-1955-4d21-9f4c-6a32d82fe103%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Marcus Mann]

Thanks for the quick reply!

It says on the page:

This handler is not appropriate for use under Windows, because under Windows open log files cannot be moved or renamed - logging opens the files with exclusive locks - and so there is no need for such a handler. Furthermore, ST_INO is not supported under Windows; stat() always returns zero for this value.

[Michael Merickel]

The issue is that pserve configures logging *before* forking the children, while in the monitor process, and then configures logging again in the child subprocesses after forking. This is an issue and hasn't been pointed out by anyone before. This means you always have two processes opening those files.

I recommend logging to stderr instead and handling file rotation and such external to the processes themselves, however it doesn't mean this isn't a bug.

Possible solutions:

1) Do not configure logging in the parent process, or just do it using basicConfig. Only use your logging config in the child process. This is probably an acceptable solution but means that the logging coming from hupper in the parent process would not use the logging formatters/handlers that are in your config which is slightly surprising.

2) Keep doing what we're doing and say something about how it's not supported.

3) ???

- Michael

--

[Marcus Mann]

So what if I moved the logging stuff into the __init__.py and remove all the logging stuff from development.ini? Would that solve my issue?

[Mikko Ohtamaa]

On Fri, 25 Jan 2019 at 21:13, Marcus Mann <mitym...@gmail.com> wrote:

So what if I moved the logging stuff into the __init__.py and remove all the logging stuff from development.ini? Would that solve my issue?

Some ideas with lack of better information:

1) Not sure about pserve, but uWSGI had an event it fires after forking, so could quite deterministically initialise post-fork stuff

2) Lazily configure loggers when they are first time referred within HTTP request processing (not sure how either)

-Mikko

 

To view this discussion on the web visit https://groups.google.com/d/msgid/pylons-discuss/7aca6559-568d-4ff6-8aa1-5af39abe9bc2%40googlegroups.com.

[Michael Merickel]

I opened https://github.com/Pylons/pyramid/issues/3455 to track this.