FAQ: rotatelogs and piped loggers

General questions about rotatelogs

Can rotatelogs write to log files over 2GB?

Yes, in 7.0 and later.

Shouldn't I see a new logfile exactly when my interval ends?

Does rotatelogs rotate log files if no requests are received?

No, the rotate operation will not occur until IHS logs another request. If your configuration specifies that rotatelogs performs the rotation operation after 86400 seconds, and if IHS receives no requests after 86400 seconds have elapsed, the new log file will not yet be created. Then, when rotatelogs receives its next request to log, it will create the new log file and close the old one.

Does rotatelogs buffer data before writing to the log file?

No. However, data may be buffered in the operating system kernel after the web server writes the data but before rotatelogs can read it. This time is usually very brief.

Other programs can be used to filter data seen by rotatelogs, and those programs may introduce buffering. Example:

CustomLog "|grep -v \b200\b | /opt/IHS/bin/rotatelogs /opt/IHS/logs/grepped 86400" common

In this case, grep will buffer data internally until it has a full buffer, then rotatelogs will see many log records at the same time. (4096 bytes is a typical size for the buffer used by grep.)

Note: IBM HTTP Server 6.0 prior to 6.0.2.1, or IBM HTTP Server 2.0 prior to PK07831, does not support the type of CustomLog directive in the example above.

How can I rotate log files every night at midnight?

Specify a time interval of 86400 seconds. Use the -l option to rotate at midnight local time instead of midnight UTC. IBM HTTP Server 1.3 doesn't support the -l option; specify the UTC offset parameter instead.

Example:

CustomLog "|/usr/HTTPServer/bin/rotatelogs -l /www/logs/access_%Y-%m-%d 86400" custom

This example includes the year, month, and day in the log file name. An example generated filename is /www/logs/access_2007-11-26.

Why is the date in a new log file not todays date?

If you rotate every N seconds, rotatelogs picks an initial date and time based on whole intervals of N seconds starting from the beginning of the Unix epoch (January 1 1970).

For example, if you configure rotatelogs to rotate every 7 days (604800 seconds), a new logfile created January 1-6 1970 would have a timestamp of January 1 1970.

This algorithm can easily be investigated on a shell command line:

date -u --date=@$(($((`date +%s` / 604800)) * 604800))

Why are hour, minute, and second fields in generated filenames all zero when I rotate every 24 hours?

When rotating log files based on time intervals, the timestamp in generated filenames represents the beginning of the current interval, regardless of when the web server is started. The beginning of a 24-hour interval is always midnight, so hour, minute, and second fields are always zero. The beginning of a 1-hour interval is always the beginning of the hour, so minute and second fields are always zero.

Why is the timestamp always in UTC when I rotate based on file size?

The -l option and UTC offset parameters are not respected when rotating based on file size.
This is addressed by APAR PK56939.

Why are many timestamped files created at startup?

Apache, especially on Windows, launches rotatelogs a number of times for each time it's used in the configuration, as the configuration is first checked, re-ran, then possibly run again in the child proces (Windows only).

When you rotate based on size, and include seconds in your filename format, you will see multiple files with the second field incrementing.

We suggest not using seconds in general, but especially when rotating based on size.

Error Message: error writing to logfile xxx messages lost

This message can occur when the log has grown to 2 gigabytes on platforms that don't support large files with rotatelogs. In this case, shorten the rotation interval or use size-based rotation.

This message can also occur when there is insufficient free space on the filesystem used for logging.

If this error message occurs, the log file being written to by rotatelogs will be truncated and then new entries will continue to be written to the log.

Why am I unable to delete the original error log on my Windows server even after the logs are rotated?

You will not be able to remove logs to which the rotatelogs processes have active references. There are two references to each error log, one owned by the parent and one owned by a child process. As long as either process still has a reference to the error log, you will not be able to delete it. Once a new log file is created by the piped logger, the parent and child will not 'move' to the new log until something causes them to need to write to the log, or when the server restarts.

This behavior is the same in versions 6.x, 7.0, and the newer 8.x versions of IBM HTTP Server and is a limitation of using piped loggers such as rotatelogs.

If you attempt to remove a log that still has active references, the delete will not take place and if you are using a process monitor type tool, you may see an indication such as "DELETE PENDING". The behavior may vary depending upon whether you attempt the delete from the command-line versus doing it from Windows Explorer, with the latter apparently less likely to have issues.

Possible techniques for working around this limitation:

  • A graceful restart of the service after the logs rotate should allow the rotated logs to be removed. The restart of the web server will relinquish the reference to the original error log, and the rotatelogs associated with the parent will then have a reference to the current error log.

  • Another option would be to not rotate the main error log, and to define error logs in virtual hosts that are rotated. Those are not written to by the parent process, so only the child process would ever have a reference to them. Once the child has rotated to the new log, there should be no active references to prevent a delete.

  • Getting the parent process to give up its reference to the original error log:

    If mod_mpmstats is not regularly writing messages from within the parent process, the parent will retain a reference to the one original error log that is opened when the web server starts. In this scenario without mod_mpmstats, the global error log opened at startup will not be deletable.

    For IHS 7.0 and later, mod_mpmstats is included in the product and enabled by default. For earlier releases, you can obtain the mod_mpmstats module by downloading the ihsdiag package at this url:
    Debugging IBM HTTP Server crashes, hangs, high CPU, startup failures

  • Getting the child process to give up its reference to the original error log:

    Rotation is usually configured because logs are growing at a rate proportional to the number of requests, which implies the child is actively writing to the erorr log. But in a synthetic test, you might find that no entries are written and the childs lock remains even after the parent has rolled over.

    If the original error log still can't be deleted, then it is probable that the child process is retaining a reference to the file. This should happen only if there has been nothing to cause the child to write to the error log, and hence to cause it to move to the new error log. In such a case, the following techniques might help:

    • Cause any condition that would result in the child process writing to the error log file, such as accessing the server and requesting a non-existent file (resulting in a 404). This would cause the child process to need to write to the error log, and it would move to the new log file in the process of doing so.

    • Cause the child process to occasionally expire by setting 'MaxRequestsPerChild' to a non-zero value. When a new child process gets created, it should not have a reference to the original error log. This technique still allows windows of time during which the original log cannot be deleted, but if there is sufficient delay between the rotate and the attempted deletion, this may work in some scenarios.

Is it safe to have two logging directives that use piped loggers point to the same file?

No, it's not safe to have two piped loggers writing to a logfile. The writes are not coordinated.

It is possible that a more sophisticated, non "rotatelogs" piped logger could coordinate its writes across processes.

When does rotatelogs close the file it's logging to?

Rotatelogs closes its output under the following scenarios:

  • At shutdown, restart, or graceful restart the piped loggers input is closed which triggers a close of the output file.

  • When a new log entry is sent to rotatelogs, and the time or size interval is found to have been exceeded, the output file is closed when the new one is opened.

It is possible that a more sophisticated, non "rotatelogs" piped logger could arrange to close the file earlier.

Questions that apply to any piped logger

Why am I getting errors or rotatelogs crashes when starting large numbers of rotatelogs instances

If you are using Windows and are trying to use large numbers of rotatelogs instances (for example, within a large number of Virtual Hosts), then you may experience errors or rotatelogs processes frequently crashing and being restarted. This is caused by exhaustion of a resource called the "Desktop Heap". For more information on the desktop heap, refer to this article.

Possible techniques for working around this limitation:

  • Start IHS from the command-line rather than as an IHS service. The number of rotatelogs instances that you can start goes up greatly when IHS is not started as a Windows service.

  • Use only 1 log file with all the requests logged in it, and then split it based on the virtualhost name as explained here.
    The split-logfile is not provided by IHS, but you should be able to use one from the stock Apache release (requires Perl to work).

  • Increase the desktop heap size for services, as explained below.

Increasing the desktop heap size involves changing registry values. Back up the Windows Registry before making any changes and be very careful when changing any values.

To increase the desktop heap, use the following procedure:

  • Run regedit.exe as administrator.

  • Find the registry key "HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control\SessionManager\SubSystems\Windows".

  • Within the value of the key, find the section "SharedSection=xxxx,yyyy,zzzz".

  • Edit the third value in that section, increasing the value.

Note that increasing the last value increases the desktop heap size for all services. Do not make the value larger than necessary; each service in the system will consume more resources. While experimenting, we found that a value of 2048 was enough to run 200+ instances of rotatelogs.

Are there alternatives to rotatelogs?

rotatelogs is a piped logger which is responsible for switching to a new log file when certain criteria are met. You can choose to use piped logger software from a third party.

Refer to How can I rotate (switch) log files? for additional information on other possible alternatives.

Errors after enabling piped loggers 'piped log program 'bin/rotatelogs... failed unexpectedly'

You must use the full filesystem path to the piped logger. The piped logger cannot be specified relative to the ServerRoot. The operative part of the error message in this FAQ is that the path is not absolute. For rotatelogs, the logfile path must also be absolute (although other piped loggers might allow you to use a relative path).

Why do I see zombie rotatelogs processes?

  • This should not happen unless the IHS parent process is hung, but not crashed, which is exceptionally rare.

  • One cause of zombie rotatelogs processes is running the server with the options -DDEBUG or -DONE_PROCESS. Both are obscure debugging arguments which should never be used.