2

I have a PHP application that can generate quite a lot of log information. I'd like to use logrotate to make sure these logs don't get out of hand over time.

However, I'm concerned about race conditions. Could there be a loss of log messages if PHP is in the middle of writing to a log when logrotate determines it needs to rotate that log, as in the sequence of events below? If not, why?

  1. PHP opens log file for writing.
  2. PHP writes a line.
  3. logrotate decides the log file should be rotated.
  4. PHP writes another line.
  5. PHP closes file resource.

Would using PHP's file_put_contents, for example, make any difference? What about, more generally, output that is piped to a log file?

Environment Specifics:

I'm using php5-fpm (Version: 5.5.9+dfsg-1ubuntu4.6) behind an nginx server on a different machine.

My proposed logrotate config (I haven't set anything up yet) would be something like this (in /etc/logrotate.d/my-app):

/var/my-app-data/logs/*.log {
    missingok
    notifempty
    weekly
    size 20M
    rotate 4
}

A couple of examples of my PHP logging code:

$res = file_put_contents('/var/my-app-data/logs/general.log', date('[d/m/Y H:i:s]') . ' Something noteworthy has happened!' . "\n", FILE_APPEND);

It's possible we may want to use something like the code below in the future:

$fp = fopen('/var/my-app-data/logs/general.log', 'a');
fwrite($fp, date('[d/m/Y H:i:s]') . ' Starting process...' . "\n");
// ...
fwrite($fp, date('[d/m/Y H:i:s]') . ' Something happened!' . "\n");
// ...
fwrite($fp, date('[d/m/Y H:i:s]') . ' Something happened!' . "\n");
// ...
fwrite($fp, date('[d/m/Y H:i:s]') . ' End of process.' . "\n");
fclose($fp);
sotirov
  • 3,169
Alex
  • 329
  • 1
  • 4
  • 15
  • logrotate can be configured in different ways, but to be sure not to miss any logs, it is necessary an interaction between logrotate and php application. Could you post your logrotate configuration related to php log file? Could you update your question with apache version? – Lety Mar 18 '15 at 20:50

1 Answers1

1

When an application opens a file, continue to write in it even if it is moved. Therefore, if you want to be sure not to lose information, you should send a signal to the application, so it releases resources.

You can try this configuration:

 /var/my-app-data/logs/general.log {
           missingok
           notifempty
           size 20M
           rotate 4
           create mode owner group
           sharedscripts
           postrotate
               nginx command to do graceful restart 
           endscript
       }

This general.log file is rotated whenever it grows over 20M in size, after going through 4 rotations, file are removed.

The sharedscripts means that the postrotate script will only be run once, not once for each log which is rotated.

According to logrotate manual:

          create mode owner group
          Immediately after rotation (before the postrotate script is run)
          the log file is created (with the same name as the log file just
          rotated).   mode  specifies  the  mode for the log file in octal
          (the same as chmod(2)), owner specifies the user name  who  will
          own  the  log  file,  and group specifies the group the log file
          will belong to.

So in your case:

  1. rotate file
  2. remove general.log.5 if exists
  3. create general.log with proper attribute and owneship
  4. runs postrotate script

Your application will continue to write general.log.1 until either closes the file or postscript is executed and nginx perform a graceful restart.

If your application always close log file via fclose($fp) or uses file_put_contents you should omit nginx graceful restart.

Lety
  • 6,039
  • 2
  • 29
  • 37
  • So, just to clarify, log entries would only be lost/incorrectly end up in the wrong file if a file descriptor remained open pointing to a log file that's since been rotated, or maybe even deleted? – Alex Mar 19 '15 at 13:59
  • In this case I guess that your application continues to write file even if it was rotated until file close. file_put_contents implements fopen, fwrite and fclose. This happens because logrotate move file and this doesn't change file inode. Subsequently, a new fopen will write in general.log created by logrotate. This is why I supposed that graceful restart is not necessary. – Lety Mar 19 '15 at 17:30
  • If you are sure that your php application will call fclose before file is removed (after 4 rotation) I guess that in your case you don't lose information. – Lety Mar 19 '15 at 17:33
  • Yeah. If we assume that file_put_contents is close enough to being an atomic operation for logging purposes, then I just need to be careful not to leave log files hanging open for long running processes if I decide to use the approach of holding files open for multiple messages. I may well just avoid that approach though. Thanks a lot @Letizia! – Alex Mar 19 '15 at 17:53
  • Hmm, but what will happen if the compression is on? Maybe an application would write clear text to a compressed log-rotated file(because inode hasn't changed) and would screw it up?... – mathway Jan 26 '23 at 16:47
  • postrotate runs before logs are compressed. Compression could take a long time, and your software should switch to the new log file immediately. – Lety Jan 26 '23 at 17:25