classification
Title: RotatingFileHandler rollover doesn't work on QNX shmem filesystems
Type: enhancement Stage:
Components: Library (Lib) Versions: Python 3.3, Python 2.7
process
Status: closed Resolution: wont fix
Dependencies: Superseder:
Assigned To: Nosy List: pconnell, pitrou, r.david.murray, serhiy.storchaka, vinay.sajip
Priority: normal Keywords: patch

Created on 2012-11-10 14:36 by pconnell, last changed 2012-11-11 16:41 by vinay.sajip. This issue is now closed.

Files
File name Uploaded Description Edit
rfh_rename_fix.patch pconnell, 2012-11-10 14:36 Proposed patch review
Messages (12)
msg175277 - (view) Author: Phil Connell (pconnell) * Date: 2012-11-10 14:36
logging.handlers.RotatingFileHandler.doRollover fails on QNX /dev/shmem filesystems (seen on a 6.4.0-based system).

QNX RAM filesystems don't support rename() (see http://www.qnx.com/developers/docs/6.4.0/neutrino/sys_arch/fsys.html#DEVSHMEM - it's a 'big filesystem' feature).

So for example, rename("/dev/shmem/foo", "/dev/shmem/bar") fails with EXDEV.


This is easily fixed by using shutils.move rather than os.rename where appropriate, falling back to copying if a rename() fails. It's not sufficient to set the rotator attribute, since there are other os.rename calls in in doRollover.
msg175282 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2012-11-10 15:21
I'm not sure why you would setup logging on a RAM filesystem (I assume we're talking about normal volatile RAM)?
But besides, the big point of using rename() is that it's fast, atomic and won't disrupt existing file handlers pointing to that file. If RotatingFileHandler may resort to copying by mistake, it may cause other issues down the line.
msg175284 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2012-11-10 15:47
I agree with Antoine.  It seems to me that it is very important to the semantics of rollover that the rename be atomic, even if we ignore the issue of existing other readers.  If it were not atomic, you might end up with lost log messages.  So I don't think there is anything to do here: you just can't use rollover on a filesystem that doesn't support atomic rename.

I'll leave it Vinay to close the issue if he agrees with us.
msg175350 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2012-11-11 11:45
Thanks for the patch, but I'm closing this as 'wontfix', as per the points made by Antoine and David. If you need logging from an embedded system, please consider using one of the socket-based logging handlers, if that's feasible in the specific situation.
msg175352 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2012-11-11 12:10
What about the "rotator" attribute.
msg175359 - (view) Author: Phil Connell (pconnell) * Date: 2012-11-11 12:38
I'm not convinced that it matters whether the rename or move is atomic. Can anyone come up with a quick concrete example?


I see two scenarios:

1. The process crashes during a copy in shutils.move(). In this case, some logs will be duplicated across the files involved in the copy.

2. Other threads emit logs during the rollover. Given that the IO lock is acquired in Handler.handle() before calling emit(), this is fine.


While the first case isn't ideal, I don't think there can be any loss of logs.
msg175360 - (view) Author: Phil Connell (pconnell) * Date: 2012-11-11 12:39
Serhiy, there are also calls to os.rename in RotatingFileHandler.doRollover
msg175362 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2012-11-11 13:17
The current implementation was written with an expectation of working rename functionality in the stdlib. As such, while this issue might be categorised as being of type "enhancement", I don't see how you can categorise it as being of type "behaviour".

What's the problem with subclassing the relevant handlers to implement your own doRollover() method? You only need to do that once for all the projects in your QNX environment. Given that it's not a mainstream environment, that's not IMO an unreasonable suggestion.

If you publish such a handler, I'll mention it on

http://plumberjack.blogspot.co.uk/p/handlers-for-logging.html

which has a whole bunch of handlers written by people for specific requirements which don't warrant adding functionality directly in the stdlib.
msg175365 - (view) Author: Phil Connell (pconnell) * Date: 2012-11-11 13:46
I've updated the type to enhancement (it seems like a grey area to me - it's a behavioural fix for a niche use case).

I suggested a patch rather than simply subclassing RotatingFileHandler since:
  - The subclass would just have a copy of RotatingFileHandler's doRollover method with a one-line change.
  - The proposed fix is functionally equivalent to the current code for all currently working uses.


Thanks for the offer of having an extension linked from your blog. I don't think it's appropriate for this case (since it's just a slightly modified copy of the stdlib code - I'll probably just keep the patch along with a few other compatibility hacks we have) although I may have something for you in future (we do have a subclass that compresses old logs).
msg175366 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2012-11-11 13:57
> I've updated the type to enhancement (it seems like a grey area to me
> - it's a behavioural fix for a niche use case).
> 
> I suggested a patch rather than simply subclassing RotatingFileHandler
> since:
>   - The subclass would just have a copy of RotatingFileHandler's
> doRollover method with a one-line change.
>   - The proposed fix is functionally equivalent to the current code
> for all currently working uses.

You may just as well monkeypatch os.rename() to fallback on
shutil.move() if the filenames are on a /dev/shm filesystem (or you
could bug QNX to fix their broken filesystem...).

From a code quality and readability standpoint, os.rename() conveys the
intended semantics clearly, while shutil.move() doesn't, so switching to
shutil.move() in the stdlib would be a regression. Also, doing this in
logging would open the door to doing the same thing in other modules.
Even a critical piece of infrastructure such as importlib relies on
os.rename() working properly.
msg175368 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2012-11-11 14:49
Doesn't the "rotator" attribute break atomicity?  A careful rotator should first rename the source to the temporary file, process the data and save it to other temporary file, and then rename the result to the destination and remove the first temporary file.
msg175371 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2012-11-11 16:41
> Doesn't the "rotator" attribute break atomicity?

Which rotator do you mean? The default rotator is None, which leads to os.rename being called. If you're referring to the example in the documentation (cookbook) - it was intended purely as an example, and the paragraph under the snippet does say it's only intended for illustrative purposes.
History
Date User Action Args
2012-11-11 16:41:24vinay.sajipsetmessages: + msg175371
2012-11-11 14:49:45serhiy.storchakasetmessages: + msg175368
2012-11-11 13:57:52pitrousetmessages: + msg175366
2012-11-11 13:46:53pconnellsettype: behavior -> enhancement
messages: + msg175365
2012-11-11 13:17:52vinay.sajipsetmessages: + msg175362
2012-11-11 12:39:10pconnellsetmessages: + msg175360
2012-11-11 12:38:21pconnellsetmessages: + msg175359
2012-11-11 12:10:16serhiy.storchakasetnosy: + serhiy.storchaka
messages: + msg175352
2012-11-11 11:45:46vinay.sajipsetstatus: open -> closed
resolution: wont fix
messages: + msg175350
2012-11-10 15:47:43r.david.murraysetnosy: + r.david.murray
messages: + msg175284
2012-11-10 15:21:59pitrousetnosy: + pitrou
messages: + msg175282
2012-11-10 14:36:23pconnellsettype: behavior
2012-11-10 14:36:10pconnellcreate