Bug 57742

Summary: "reliable piped logging" doesn't work for ErrorLog anymore
Product: Apache httpd-2 Reporter: Reinhard Nißl <reinhard.nissl>
Component: CoreAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: NEW ---    
Severity: normal Keywords: PatchAvailable
Priority: P2    
Version: 2.4.10   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: Enable reliable piped logging for virtualhost error logs
Enable reliable piped logging for error logs

Description Reinhard Nißl 2015-03-23 12:47:13 UTC
After upgrading from openSUSE 12.1 (apache2-2.2.21) to openSUSE 13.2 (apache2-2.4.10), piped logging for ErrorLog is no longer reliable. I. e., killing the program for log rotation doesn't start a new instance.

Piped logging is still reliable for CustomLog though. From looking at the source, CustomLog uses a totally different code than ErrorLog, but only CustomLog implements "reliability".

I've verified this behavior for 2.4.12 too.

Steps to reproduce this issue:
- replace in httpd.conf
ErrorLog /var/log/apache2/error_log
by
ErrorLog "|$cat >>/var/log/apache2/error_log"
- restart apache2
- kill the cat process
- no new instance of cat will be created
Comment 1 Eric Covener 2015-03-23 12:58:21 UTC
Does seem to be broken in 2.4.x HEAD as well
Comment 2 Eric Covener 2015-03-23 16:44:26 UTC
AFAICT it didn't work in 2.2.21 either. Perhaps SUSE was patching 2.2.x and thought it was no longer needed when they moved to 2.4.  Does opensuse make the patches obvious in some kind of srpm?
Comment 3 Reinhard Nißl 2015-03-23 17:15:09 UTC
This is the source rpm of the version which was running on the old machine:

http://ftp.uni-paderborn.de/pub/linux/opensuse/update/12.1/src/apache2-2.2.21-3.13.1.src.rpm

At first glance, I didn't see anything obvious in it.

I just had a look for /var/log/apache2/error_log* on the old machine and it seems it didn't work there either. I only find some files for days, when apache2 was restarted.

Anyway, this is not what "reliable" is expected for.
Comment 4 Edward Lu 2015-03-24 15:24:39 UTC
Created attachment 32604 [details]
Enable reliable piped logging for virtualhost error logs

It looks like there was never reliable piped logging for ErrorLog. A quick grep through the patches in the RPM shows no changes to the logging, so it's likely that it never worked.

It looks pretty easy to add reliable logging for virtualhost error logs, but there's an issue with the main error log that makes it harder. The issue requires some understanding of PR40651; the code change made there requires the main error log to be opened using log_child(), which is the function made for unreliable logging.

A few options we have:
 - Ignore PR40651 and use ap_open_piped_log() for the main error log. Probably low impact, since we don't use /bin/sh by default to fork anymore.
 - Make reliable logging available for virtualhost error logs, but not for the main error log, and doc this fact.
 - Copy/paste log_child() and add the one function call (apr_proc_other_child_register()) to restart the process when it goes down.

I had some trouble when trying the first option - the main error log seemed not to want to restart, and I'm still not sure why. The attached patch takes the second route, which isn't ideal, but it should hopefully get some discussion going.
Comment 5 Edward Lu 2015-04-01 17:44:24 UTC
Created attachment 32627 [details]
Enable reliable piped logging for error logs

Here's a patch that enables reliable piped logging on both the main and virtualhost error logs. It seems to work fine on some simple tests.

The patch is a little more complicated than anticipated; it wasn't enough to simply attach the maintenance function to the main error logging program. Here's a description of the problem I was running into, for any reviewers: for the main error log, we close the fd originally intended to be used as the writing end of the pipe to rotatelogs, and use stderr instead. However, when rotatelogs goes down, we try to re-use the original fd as the descriptor for the pipe to the new rotatelogs process, which fails since the descriptor's been closed. I got around this by stashing away the stderr descriptor instead of the original fd, and then making sure that it doesn't get cleaned up.

I also introduced an ap_open_piped_log_helper() function to pass dummy_stderr down, so we can still avoid the problem described in PR40651.