I’m trying to log to a file and move it about every 30 seconds. I’m using the os.rename function (which I do from a supervisord process) in python to move the current log to a timestamped log (which will then be processed by another python script) and then I continue to log to the old stream from my uwsgi server.
I’ve also tried the RotatingFileHandler and the timed version, but they don’t seem to work properly. I wasn’t sure if that was a function of using it with the uwsgi server or not.
My question is, what is the simplest and most efficient way to continue logging to the same file name after the file it was “pointing to” has been moved?
5
Once Python opens a filehandle, it will continue to point to that file even if the file is renamed. (This is OS specific behavior, but that is the POSIX defined behavior for Unix.)
Therefore you either need to do the log rotation from inside of the Python process, or else make the file that you write to be a named pipe that itself handles log rotation. The latter is probably easier to set up. http://www.linuxjournal.com/article/2156 is an old, but still relevant, article on how to do this under Unix.
I appreciate the help, but in the end the simplest method was just opening and closing the file in python for each write. It may not be the most efficient, but its working.
At a very low level, it is necessary to open and close the files to change the file a logger is writing to. This isn’t an option, it is a necessity with how files really work.
The open()
call takes a pathname and returns back a file descriptor. This points to the file itself. Modifications to the directory entry for the file are outside of this and the file descriptor really doesn’t care.
A demonstration of this can be seen on a unix system –
- Fire up three shell windows and cd to
/tmp
in each of them - In the first shell,
cat > file.tmp
-
In the second shell,
tail -f file.tmp
At this point, anything you type in the cat window will appear on the tail window (hitting return may be required)
-
In the third shell,
mv file.tmp file.foo
You’ve moved the file, but if you keep typing in the cat window, it will still appear in the tail window.
- In the third shell,
rm file.foo
And still, what you type in the cat window shows up in the tail window, even though there’s no file in /tmp anymore.
In #2, a file was opened, created on the disk, and a file descriptor was used by the shell. In #3, the file on the disk was opened for read, and it got back a file descriptor too. The two processes are reading and writing to a file that they each access with their own file descriptor. Moving the file on the disk doesn’t affect these processes – they are still accessing the same file. Whats more, even though the file is deleted from the directory entry, the file exists as a common place for those two processes (until they each close the file).
The only way to break the connection between a file descriptor and the file is to close the file and open a new file to get back a new file descriptor.
Many logging frameworks have a way of doing this open and close for you. In Python (I admit I’m just reading the docs on this), the TimedRotatingFileHandler
will rotate the log (and this is probably the important bit) on the next log after the time it is set to rotate.
Lets say you have a logger that spits out about one message every 10 minutes on the 5 (so 5, 15, 25, 35, 45, and 55). You also have a log rotator that rotates on the hour. The log file will not appear to be rotated until the 05 log message is written, then the logger realizes that it is after the time it needs to rotate and then rotates the log file, writing the new 05 message to a new file.
A not uncommon way to solve this (and get logs rotating when you want them to) is to log a message of high enough priority to cause the logs to rotate just after the time to rotate them.
The other thing to do is wait awhile. Do you really need to move that log file now? Or can it sit for awhile?
1