Bug 429807
| Summary: | Apache fails to re-open logfiles after SIGHUP from logrotate | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 5 | Reporter: | Jon Jensen <jon> |
| Component: | httpd | Assignee: | Joe Orton <jorton> |
| Status: | CLOSED NOTABUG | QA Contact: | |
| Severity: | medium | Docs Contact: | |
| Priority: | low | ||
| Version: | 5.1 | ||
| Target Milestone: | rc | ||
| Target Release: | --- | ||
| Hardware: | x86_64 | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2008-01-28 11:15:25 UTC | Type: | --- |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
Sunday at 4am is special in the above configuration because on that day, the parent will get SIGHUP-ed *twice* by logrotate in a very short period of time - once for each section specified above. (The "sharedscripts" does not apply across the two sections.) Can you clarify what you mean by "fails to re-open the files"? Are the access_log/error_log files simply not created; or are they created, but stay empty? Is the httpd logging configuration otherwise as default? Oh, of course; I was forgetting that the default is weekly, so that plus the
daily config above = Sunday specialness. Thanks for pointing that out.
IIRC, access_log/error_log are created but remain empty. My guess is that the
files are being created by logrotate, though, and Apache doesn't touch them at
all.
The logging setup is pretty standard. In each virtual host:
ErrorLog logs/sites/$domain/error_log
CustomLog logs/sites/$domain/access_log combined
With $domain varying, of course. And an additional log for SSL:
CustomLog
logs/sites/$domain/ssl_request_log "%t %h %{SSL_PROTOCOL}x %{SSL_CIPHER}x
\"%r\" %b"
Perhaps a simple kludge such as a "sleep 10" command in the custom logrotate
stanza's script would help?
There's a period of time during the restart process in which httpd has opened the log files but is ignoring SIGHUP. I can see that this results in a race condition with the double-logrotate; in the above config, when the weekly logrotate comes along, it may rename the files but fail to restart the server. This would leave the server logging to the old log files (those renamed during rotation) until the subsequent daily logrotate run; with no default access_log/error_log files in existence (logrotate does not create them, AFAIK). Putting a "sleep 10" or similar before the reload in *both* the stanzas would be necessary to avoid that race. I can't see how it would be possible for the server to end up in a state where the new empty access_log/error_log are created but not being logged to, however. I'm going to mark this as NOTABUG on the assumption that the race being hit is as described in comment 3 (which is essentially by design); the "sleep" hack should be able to work around the particular logrotate configurations. Another workaround would be to disable the logrotate configuration for httpd completely, create a separate logrotate config (outside the default directory), which does *not* run the httpd reload internally, and cron a daily job which does simply: logrotate /etc/special-httpd-logrotate.conf service httpd reload Ok, thanks for your help, Joe. It really seems like something Apache should be able to handle, but I imagine it'd be complicated. In any case, I've consolidated stanzas and expect that to solve my immediate problem. I appreciate your input. |
Description of problem: About 1 in 2 or 1 in 3 times, every 4:00 am Sunday morning, Apache starts sending its logs into nowhereland, because if fails to re-open the files after logrotate sends a HUP signal. This results in lost logs till Monday, Tuesday, or even later, when it happens to work again. Version-Release number of selected component (if applicable): RHEL 5.0 and 5.1 on x86_64. Seen with current httpd-2.2.3-11.el5 and all earlier RHEL 5 versions. How reproducible: It's been happening for months. Can't make it happen intentionally, but happens Sunday mornings quite often. We can't see what Sunday has to do with it -- no relevant cron jobs, etc. -- but that's what's happening. Additional info: We're running SELinux with the default targeted policy in enforcing mode. SELinux booleans that may be relevant: httpd_builtin_scripting --> on httpd_can_network_connect --> off httpd_can_network_connect_db --> off httpd_can_network_relay --> off httpd_disable_trans --> on httpd_enable_cgi --> on httpd_enable_ftp_server --> off httpd_enable_homedirs --> on httpd_rotatelogs_disable_trans --> off httpd_ssi_exec --> off httpd_suexec_disable_trans --> off httpd_tty_comm --> on httpd_unified --> on What ships in /etc/logrotate.d/httpd is unchanged, but we have added an additional stanza, so the whole file looks like this: /var/log/httpd/*log { missingok notifempty sharedscripts postrotate /sbin/service httpd reload > /dev/null 2>/dev/null || true endscript } /var/log/httpd/sites/*/*log { daily rotate 120 missingok notifempty sharedscripts postrotate /sbin/service httpd reload > /dev/null 2>/dev/null || true endscript } Thanks for any help.