Why do only some of my logs get rotated?

Question

I'm using Ubuntu 14.04. I have the following in my /etc/logrotate.conf file ...

/home/rails/myproject/log {
        daily
        rotate 3
        compress
        delaycompress
        missingok
        notifempty
        create 644 rails rails
}

/var/log/postgresql {
        daily
        rotate 3
        compress
        delaycompress
        missingok
        notifempty
        create 644 root root
}

Every night, I would look at my rails logs and it would always be bigger -- i.e. it didn't seem like the logs were getting rotated ...

myuser@myproject:~$ ls -al /home/rails/myproject/log
total 4574368
drwxr-xr-x  2 rails rails       4096 May 30 12:04 .
drwxr-xr-x 15 rails rails       4096 May 30 12:03 ..
-rw-rw-r--  1 rails rails      14960 Jun  1 22:39 development.log
-rw-rw-r--  1 rails rails          0 Oct 22  2016 .keep
-rw-r--r--  1 rails rails 4523480004 Jun 22 10:19 production.log
-rw-rw-r--  1 rails rails  156358087 Jun 22 10:19 sidekiq.log
-rw-rw-r--  1 rails rails      54246 Apr 10 14:34 test.log

When I run the command manually, I see that some of the logs seem to get rotated ...

myuser@myproject:~$ sudo logrotate /etc/logrotate.conf
myuser@myproject:~$ ls -al /home/rails/myproject/log
total 4570288
drwxr-xr-x  2 rails rails       4096 Jun 22 10:22 .
drwxr-xr-x 15 rails rails       4096 May 30 12:03 ..
-rw-rw-r--  1 rails rails          0 Jun 22 10:22 development.log
-rw-rw-r--  1 rails rails      14960 Jun  1 22:39 development.log.1
-rw-rw-r--  1 rails rails          0 Oct 22  2016 .keep
-rw-r--r--  1 rails rails          0 Jun 22 10:22 production.log
-rw-r--r--  1 rails rails 4523505906 Jun 22 10:23 production.log.1
-rw-rw-r--  1 rails rails  156369048 Jun 22 10:23 sidekiq.log
-rw-rw-r--  1 rails rails      54246 Apr 10 14:34 test.log

How do I figure out why my rails logs are not rotated nightly? Note that other logs in the system seem to be. Above, I included my postgres configuration, and when I look at the logs there, seem to be rotating normally ...

myuser@myproject:~$ ls -al /var/log/postgresql
total 1832
drwxrwxr-t  2 root     postgres    4096 May  2 20:42 .
drwxr-xr-x 13 root     root        4096 Jun 22 10:22 ..
-rw-r-----  1 postgres adm      1861361 Jun 22 10:14 postgresql-9.6-main.log

Thanks, - Dave

Edit: Putting the configuration in a separate file didn't seem to do anything. Below is my configuration and also the logs that didn't appear to get rotated ...

myuser@myapp:~$ sudo cat /etc/logrotate.d/myapp
[sudo] password for myuser:
/home/rails/myapp/log/*.log {
   daily
   missingok
   compress
   notifempty
   rotate 12
   create
   delaycompress
   missingok
   su rails rails
}

Here are the logs. Doesn't appear anything happened ...

myuser@myapp:~$ ls -al /home/rails/myapp/log
total 4635956
drwxr-xr-x  2 rails rails       4096 Jun 22 10:22 .
drwxr-xr-x 15 rails rails       4096 May 30 12:03 ..
-rw-rw-r--  1 rails rails          0 Jun 22 10:22 development.log
-rw-rw-r--  1 rails rails      14960 Jun  1 22:39 development.log.1
-rw-rw-r--  1 rails rails          0 Oct 22  2016 .keep
-rw-r--r--  1 rails rails          0 Jun 22 10:22 production.log
-rw-r--r--  1 rails rails 4546785231 Jun 24 12:12 production.log.1
-rw-rw-r--  1 rails rails  200336693 Jun 24 12:51 sidekiq.log
-rw-rw-r--  1 rails rails      54246 Apr 10 14:34 test.log

Answer 1

Logrotate's job is to move (rename), and compress, files. You've configured it in this case to rename and compress the Rails log files, then create new ones with the original names.

File names are a way of finding a file, but the actual file is just some space on disk. A file can have multiple names (hard links) or no names (you can rm a file that's open, but it still takes up space on disk as long as the file is open in some process).

The problem you seem to be having here is that the Rails app has already got the file open when it gets renamed. The Rails logger doesn't notice the name change, because it's used the name once to open the file, and then completely stopped caring about its name. The logger just has a handle on the open file.

You have to persuade it to close and re-open the log files, using their names again, meaning it starts writing to the new empty ones which now have the name the old ones used to have.

If you have a look in /etc/logrotate.d you'll see a lot of examples of this, depending what you've got installed.

For example, rsyslog has:

postrotate
    invoke-rc.d rsyslog rotate > /dev/null
endscript

stunnel has:

postrotate
    /etc/init.d/stunnel4 reopen-logs > /dev/null
endscript

These are scripts to tell the relevant process that the file needs re-opening. The specific mechanism depends on the program, but what this tends to be doing is sending a HUP (or sometimes USR1) (see man 7 signal), which long-running processes take as an instruction to close and re-open logfiles.

In the case of Rails the way of doing it varies depending on what logger you're using. I've just seen some advice suggesting you should use copytruncate which is basically a "cheat option" in logrotate telling it to manually copy the contents out and empty the file rather than moving it and making a new one. (see man logrotate.conf). This is used instead of create like so:

/home/rails/myapp/log/*.log {
    daily
    missingok
    compress
    notifempty
    rotate 12
    copytruncate
    delaycompress
    missingok
    su rails rails
}

This is not a great solution as it is literally copying the whole file (to create a snapshot of it as it is) before deleting its contents, which is quite inefficient.

However, if you're using Unicorn to run your app (which multiplexes requests across a bunch of identical Rails worker processes) it supports the USR1 signal as normal (killing and replacing all the workers, effectively causing them to re-open the files) and you can just send it in a postrotate using pkill or similar, perhaps like this:

/home/rails/myapp/log/*.log {
    daily
    missingok
    compress
    notifempty
    rotate 12
    create
    delaycompress
    missingok
    su rails rails
    postrotate
        pkill -USR1 -u rails unicorn
    endscript
}

pkill is a tool to search running processes and send them signals, so this would find everything with the name unicorn running as the rails user and send it the USR1 signal that tells it to re-open the log files. (The examples I gave from Ubuntu packages' /etc/logrotate.d files are actually doing the same thing but those services have the searching hidden in functions in their /etc/init.d scripts.)

I'm sure there'll be some way to configure a sensible postrotate for whatever Rails setup you've got (in the worst and easiest case, just restart it), but hopefully that explains the Ubuntu side of things anyway...

Answer 2

It looks like the problem comes down to you specifying a directory for file rotation, instead of actual file names. The configuration files for logrotate accept wildcards for globbing (pattern matching).

To rotate all files with a .log extension in your /home/rails/myproject/log directory you could use the following line in place of the first line of your configuration:

/home/rails/myproject/log/*.log {

and similarly in the postgres directory configuration

/var/log/postgresql/*.log {

It's possible to use the * wildcard without the .log extension, to rotate all files (except hidden ones starting with a .) in your postgresql directory, but I prefer the added control of specifying .log files only:

/var/log/postgresql/* {

As a side note, be aware of how you create new versions of the log file with logrotate, if you create the new postgresql log with 644 octal permissions, owned by the root user, then the postgres user will not be able to write into the new log file.

Answer 3

Check the status in /var/lib/logrotate/status if showing any issues

Please check the permissions and ownership of files in /etc/logrotate.d root owner and permission mode 644. code snippet for logrotate:

/home/rails/myapp/log/*.log {
   rotate 12
   daily
   missingok
   compress
   notifempty
   create 640 rails rails
   delaycompress
   missingok
}

do check the logrotate output by manual execution with --verbose If you require logrotation for more than a spefici size you can experiment with maxsize and size options in logrotate config file