Rsyslog stops sending data to remote server after log rotation

Question

In my configuration, I have rsyslog who is in charge of following changes of /home/user/my_app/shared/log/unicorn.stderr.log using imfile. The content is sent to another remote logging server using TCP.

When the log file rotates, rsyslog stops sending data to the remote server.

I tried reloading rsyslog, sending a HUP signal and restarting it altogether, but nothing worked.

The only ways I could find that actually worked were dirty:

• stop the service, delete the rsyslog stat files and start rsyslog again. All that in a postrotate hook in my logrotate file.
• kill -9 rsyslog and start it over.

Is there a proper way for me to do this without touching rsyslog internals?

Rsyslog file

$ModLoad immark
$ModLoad imudp
$ModLoad imtcp
$ModLoad imuxsock
$ModLoad imklog
$ModLoad imfile

$template WithoutTimeFormat,"[environment] [%syslogtag%] -- %msg%"

$WorkDirectory /var/spool/rsyslog

$InputFileName /home/user/my_app/shared/log/unicorn.stderr.log
$InputFileTag unicorn-stderr
$InputFileStateFile stat-unicorn-stderr
$InputFileSeverity info
$InputFileFacility local8
$InputFilePollInterval 1
$InputFilePersistStateInterval 1
$InputRunFileMonitor

# Forward to remote server
if $syslogtag contains 'apache-' then @@my_server:5000;WithoutTimeFormat
:syslogtag, contains, "apache-" ~

*.* @@my_server:5000;SyslFormat

Logrotate file

/home/user/my_app/shared/log/*.log {
  daily
  missingok
  dateext
  rotate 30
  compress
  notifempty
  extension gz
  copytruncate
  create 640 user user
  sharedscripts
  post-rotate
    (stop rsyslog && rm /var/spool/rsyslog/stat-* && start rsyslog 2>&1) || true
  endscript
}

FYI, the file is readable for the rsyslog user, my server is reachable and other log files which do not rotate on the same cycle continue to be tracked properly.

I'm running Ubuntu 12.04.

Solution 1

The problem was actually coming from logrotate.

Basically with my configuration, running unicorn, I don't need to use the copytruncate directive. (which is what causes problems here)

USR1 - Reopen all logs owned by the worker process. See Unicorn::Util.reopen_logs for what is considered a log. Log files are not reopened until it is done processing the current request, so multiple log lines for one request (as done by Rails) will not be split across multiple logs.

This started working properly after updating to this configuration:

/home/user/my_app/shared/log/*.log {
  daily
  missingok
  dateext
  rotate 30
  compress
  notifempty
  extension gz
  create 640 user user
  sharedscripts

  post-rotate
    # Telling Unicorn to reload files
    test -s /home/user/my_app/shared/pids/unicorn.pid && kill -USR1 "$(cat /home/user/my_app/shared/pids/unicorn.pid)"

    # Reloading rsyslog telling it that files have been rotated
    reload rsyslog 2>&1 || true
  endscript
}

Solution 2

Your logrotate file contains an entry for /home/user/shared/log/*.log, which doesn't match your logfile in /home/user/my_app/shared/log/unicorn.stderr.log. You need to add a logrotate entry for that directory and make sure it contains copytruncate - as it is, rsyslog is renaming the current file and creating a new one, and imfile keeps following the filehandle of the now renamed file.

Comments

[Vincent B.]

Sorry the filename is just a typo. However copytruncate might be a good point. Let me just look into that one :).

[mltsy]

If these are direct copies of your file, I think your problem was actually that you were using post-rotate (which is not a thing) instead of postrotate, because that original logrotate script you had should have worked fine with rsyslog (if the postrotate script had been running)... ?

[Vincent B.]

I don't remember when, but I did change post-rotate for lastaction. Your comment is still very sensible and it may have solved my problem at the time :). For the record though, I will avoid using copytruncate in the future anyway because it is slow and plays with file handles.