1

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?

  • You need a way to buffer incoming log entries in memory until you can re-create the new file. I smell all sorts of race conditions. – Robert Harvey Aug 12 '13 at 20:52
  • Just to make sure I understand what you are seeing, you are starting to write to a file (lets call it log.file), and then you move it to log.file.201308081315 or something of that nature and are still seeing data being written to the timestamped file rather than the newly created log file? – user40980 Aug 12 '13 at 20:52
  • Wouldn't you be better off changing your code to have it send a message via syslog? Then you have the choice of a whole pile of daemons which can handle the tricky file operations and save you from reinventing the wheel and reduce complexity in your code. – James Snell Aug 12 '13 at 21:34
  • @JamesSnell I would not these days use syslog. These days rsyslog and syslog-ng are the main contenders, and I personally prefer syslog-ng if you're going to set up something serious. – btilly Aug 12 '13 at 21:39
  • @MichaelT, I'd want to do the opposite. Start writing to a file (log.file) then move it (log.file.2013..) and then without opening and closing my file in python (using open(), and close()), write to a new log file (log.file) – tonyl7126 Aug 13 '13 at 2:11
1

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.

0

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.

0

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 -

  1. Fire up three shell windows and cd to /tmp in each of them
  2. In the first shell, cat > file.tmp
  3. 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)

  4. 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.

  5. 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?

  • They can wait awhile, but I wasn't getting normal behavior wihth the TimedRotatingFileHandler and i wasn't sure if it was because I had multiple uwsgi workers.processes accessing it. I will try this again, but for now I just run a cron that moves the file every 60 seconds. – tonyl7126 Aug 15 '13 at 17:21

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.