Apache – rotating log filesThis article relates my experiences with rotatelogs, a utility provided with Apache, and how you can use it to rotate www logs without having to restart Apache.
But since I wrote this article, I’ve learned how to use newsyslog.conf to do the same thing. And I like using newsyslog better. And I’ve also learned not to compress apache log files.
What? Where’d you hear about this?I heard about it one day in Undernet’s IRC channel #FreeBSD. Someone happened to mention that such a program existed. Eventually someone found it.
Well, won’t /etc/newsyslog.conf do this for me anyway?
No, it won’t. You need to HUP apache so it starts to use the new log files. Otherwise it will continue to happily write to the end of the old log file.
But syslog will HUP Apache for you. See what I wrote later.
How does rotatelogs work?See man rotatelogs where you’ll find:
TransferLog "|rotatelogs /path/to/logs/access_log 86400"
So I went to /usr/local/etc/apache/httpd.conf, found the appropriate section of the file, and added the above. Here is what it looks like:
<VirtualHost 192.168.0.69> ServerAdmin firstname.lastname@example.org DocumentRoot /www/freebsddiary ServerName freebsddiary.unixathome.org ErrorLog /www/logs/freebsddiary-error.log # CustomLog /www/logs/freebsddiary-access_log common TransferLog "|rotatelogs /www/logs/freebsddiary-access_log 61" </VirtualHost>
You will note that I commented out the previous log and that I set the rotation time to 61 seconds for my testing.
Then I restarted apache:
Then I started looking at /www/logs/ to see what turned up. Nothing. So I looked in /var/log/httpd-error.log and found:
[Tue Jan 11 10:32:59 2000] [notice] Apache/1.3.9 (Unix) PHP/3.0.12 configured -- resuming normal operations rotatelogs: not found rotatelogs: not found rotatelogs: not found
Ahhh! It can’t find the executable! OK. Let’s try the full path. I modified the line as follows:
TransferLog "|/usr/local/sbin/rotatelogs /www/logs/freebsddiary-access_log 61"
Then I started watching the logs. Nothing happened. So I browsed to the site. And kept browsing. Here are the log file names which appeared:
-rw-r--r-- 1 root www 246 Jan 11 11:45 freebsddiary-access_log.0947544293 -rw-r--r-- 1 root www 984 Jan 11 11:17 freebsddiary-access_log.0947542646 -rw-r--r-- 1 root www 1722 Jan 11 11:16 freebsddiary-access_log.0947542524 -rw-r--r-- 1 root www 254 Jan 11 11:15 freebsddiary-access_log.0947542463 -rw-r----- 1 www www 99986 Jan 11 07:47 freebsddiary-access_log
The issuesThese are the things I have noticed about this utility.
- The new files are owned by root and world readable. I would like that to be user-configurable. I don’t know how to change it.
- A new log is created if it has been more than xxx seconds since the log was initially created.
- I’m not sure I like the file name format. I’m used to the format generated by /etc/newsyslog.conf.
Adrian Mugnolo wrote in regarding the world-readable problem.
These are my two cents regarding rotatelogs. I thought of two solutions to the world readable problem you mentioned.
1) Apache’s rotatelogs opens files with a 0666 mode. You could try setting your umask to 0077, for example, to filter the group and world access just *before* starting httpd.
2) You can always modify rotatelogs’ source and change the mode parameter to 0600, for example. Where it reads:nLogFD = open(buf2, O_WRONLY | O_CREAT | O_APPEND, 0666);
Thank you Adrian.
An untried alternativeUnless someone can point out to me other advantages, I think I’ll use newsyslog. I haven’t implemented this yet, but here’s my strategy for that approach:
- create an hourly cron job in /etc/crontab, similar to that for newsyslog.
- make this job a shell script
- the first function of this shell script is to check the apache log files by calling newsyslog with a configuration file which contains the specifications for the apache log files (syslog -f /etc/local/newsyslog-apache.conf).
- the second function of this shell script is to HUP apache (/usr/local/sbin/apachectl graceful).
I haven’t tried this strategy. But if you do, and find it works, please add your comments using the links at the top and bottom of this article.
Note: the above is now no longer necessary. See the next section.
The newsyslog solutionThis solution was given to me by David Kelly email@example.com and by Iain Patterson firstname.lastname@example.org. In fact, their answers arrived within hours of each other. Thanks guys. It is much appreciated.
If you look at the top of /etc/newsyslog.conf, you’ll find the following:
# configuration file for newsyslog # $FreeBSD: src/etc/newsyslog.conf,v 188.8.131.52 1999/08/29 14:18:51 peter Exp $ # # logfilename [owner.group] mode count size when [ZB] [/pid_file] [sig_num]
And looking at the man newsyslog page, you’ll find the following:
path_to_pid_file This optional field specifies the file name to read to find the daemon process id. If this field is present, a signal_number is sent the process id contained in this file. This field must start with "/" in order to be recognized properly. signal_number This optional field specifies the signal number will be sent to the daemon process. By default a SIGHUP will be sent.
This means that the following entries will rotate the log file and HUP apache (see note below):
/var/log/httpd-access_log 644 7 100 24 B /var/run/httpd.pid 30
Check that the file which contains your apache process id (PID) is indeed the file referenced above. Look in your /usr/local/etc/apache/httpd.conf file for PidFile. Here’s a quick way to find it:
# grep PidFile /usr/local/etc/apache/httpd.conf # PidFile: The file in which the server should record its process PidFile /var/run/httpd.pid
This is a great solution! I like it much better than the first one.
More on newsyslogRalph Meijer wrote some good stuff in the forum which provides additional information regarding rotating logs. Here are a few of his points.
Ralph makes the point that the newsyslog entry should include the signal to send to Apache. For more detail on this a simple HUP is not enough, see Apache – starting/stopping. He is the one that pointed out we should be sending a SIGUSR1, not a HUP to Apache. The reasons for doing so are outlined at http://httpd.apache.org/docs/stopping.html.
Ralph mentions that SIGUS1 corresponds to 30. I wanted to find out why. So I started with man kill. Which led me to man sigaction. In turn, I found signal.h. Using locate, I found signal.h. And here is what I found:
# grep SIGUSR1 /usr/src/sys/sys/signal.h #define SIGUSR1 30 /* user defined signal 1 */
There’s your connection between the signal name and the signal number.
Ralph also points out that newsyslog, by default, places a message within the log file to indicate it has been turned over. This can be avoided by using the B flag and man newsyslog indicates why:
The B flag means that the file is a binary file, and so the ASCII message which newsyslog inserts to indicate the fact that the logs have been turned over should not be included.
If you don’t add the B flag, you’ll get this within your apache logs:
$ head freebsddiary-access_log Jan 27 00:00:00 fred newsyslog: logfile turned over
This is a nice thing for most logs, but for apache logs which are going to be fed into analog or webalizer, it’s not something you want.
A reason not to compress those logsDavid Kelly writes in with some interesting points which made me realize that my example above was incorrect. I originally specified the Z flag for the apache logs. This is bad. That will compress the logs. This is Not A Good Thing (TM) especially when you may wish to use those logs for analog or webalizer. Thanks David.
Date sent: Fri, 28 Jan 2000 12:05:26 -0600 From: David Kelly Subject: more on http://www.freebsddiary.org/rotatelogs.html Didn't know about the SIGUSR1 stuff when I wrote last. Did some more looking at http://www.apache.org/docs/stopping.html and read: >At present there is no way for a log rotation script using USR1 to >know for certain that all children writing the pre-restart log have >finished. We suggest that you use a suitable delay after sending the >USR1 signal before you do anything with the old log. For example if >most of your hits take less than 10 minutes to complete for users on >low bandwidth links then you could wait 15 minutes before doing >anything with the old log. So going by this its dangerous (in that logging data will be lost) to let newsyslog compress the log it has rotated as there may still be processes with that file open. Then again somebody more fluent in Unix than I might report on when kill(2) returns. Does it return upon signaling the process(es). Or does it return only after the process(es) have completed the signal handling? I strongly suspect it returns immediately and we have a problem. Using fstat(1) its apparent Apache opens the log files and keeps the connection open. The Right Thing To Do would be to enhance newsyslog to wait until all processes have closed the logfile which is to be rotated. (How long should newsyslog wait?) Many utilities log by open-append, write, close, per incident. As newsyslog is implemented, that is fine. Apparently each child Apache spawns opens (or inherits) the log file and keeps it open at all times causing this problem. For now the quickest solution is not to use the compress option in newsyslog.
If the real reason you want to rotate logs is because you want to keep your /var size down, and you have a web stats package in your crontab, something like the script I use may be what you want.
I have the following shell script in my crontab; it runs daily, not long after Webalizer, which also runs daily. It renames the main Apache log, restarts Apache, sleeps for ten minutes, then copies the last 100 lines of the log back to the original logfile.
The 600 is probably much higher than necessary, but it doesn’t really matter. Also, my webserver is fairly low-traffic and I don’t often get 100 hits in between the time Webalizer and this script run, both in the middle of the night. 🙂 You have to have some sleep time in there, though, so Apache has time to restart and recreate the logfile.
Webalizer also doesn’t care if the logfile entries are out of order, as it reads their times from the entries themselves. It will also ignore duplicate records, which will often happen with this shell script (and in fact should happen; if you’re not getting duplicate records when you run Webalizer – or whatever you use – increase the number in the tail line; you’re losing hits in your stats.)
mv /var/log/apache/main-access.log /var/log/apache/main-access.foo
kill -USR1 `cat /var/run/httpd.pid`
tail -n 100 /var/log/apache/main-access.foo >> /var/log/apache/main-access.log
Why bother copying the 100 lines over?
In versions of Apache older than 1.3.x, using Apache’s homegrown log rotation was probably the only reliable way.
However, Apache 1.3.x supports logging via syslog(3), which means that newsyslog(8) can operate safely on the files without having to send signals to the parent httpd process at all.
Sorry, please ignore that. Don’t know what I was smoking, but you can only syslog errors.
I’ve got something at http://ioctl.org/unix/ which waits for files to be closed before rotating them. It’s really braindead (I wrote it with cat(1)) but it does the trick; called logrotate.
If sending rotated logs to Analog or Webalizer, it’s simple enough to uncompress them beforehand. Analog includes an UNCOMPRESS option.
UNCOMPRESS *.gz,*.Z "gzip -cd"
For those without gzip (or those who don’t want the extra arguments), use zcat instead.
I’ve never seen the piping problems as described.
Thanks for that.
BTW: what piping problem are you referring to?
No one has touched on cronolog. There are two versions of cronolog, one for use with pipe, and the apache module (still beta).
As with any logs rotate that gets fed via pipe, you’ll spawn extra child processes that eats up all kind of system resources. The apache module doesn’t do that.
Still yet another interesting solution is PgLOGd. It uses FIFO, backend Postgresql, backup file overflow, and it’s FAST.
Since apache httpd is capable of writing log files through pipes, redirecting messages through /usr/bin/logger is a convenient way to avoid losing data.
ErrorLog "|/usr/bin/logger -p local1.err"
CustomLog "|/usr/bin/logger -p local1.info" common
Well, because the format of logging messages is slightly changed, additional processing may needed before analyzing them.