Bug 61926

Summary: [PATCH] Race Condition with Piped Logging and multiple Graceful restarts
Product: Apache httpd-2 Reporter: Gary S <gary>
Component: CoreAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: NEW ---    
Severity: major CC: cbarbara
Priority: P2    
Version: 2.4.29   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: Patch to remove SIGTERM from server/log.c

Description Gary S 2017-12-24 21:31:38 UTC
Created attachment 35627 [details]
Patch to remove SIGTERM from server/log.c

If you configure piped logging to pipe to a program, and you perform a lot of graceful restarts within a short amount of time, the pipe will emit EPIPE because of this section of code in server/log.c

static apr_status_t piped_log_cleanup(void *data)
    piped_log *pl = data;
    if (pl->pid != NULL) {
        apr_proc_kill(pl->pid, SIGTERM);
    return piped_log_cleanup_for_exec(data);

The above will simply SIGTERM the pipe'd program no matter what it is doing, such as in the middle of a write to the pipe which throws this:

[Sat Mar 04 14:02:09.728865 2017] [log_config:warn] [pid 21677] (32)Broken pipe: [client] AH00646: Error writing to |/usr/local/cpanel/bin/splitlogs --main=whm-11-62-c7.vm.local --suffix=-bytes_log
[Sat Mar 04 14:02:09.728947 2017] [log_config:warn] [pid 21677] (32)Broken pipe: [client] AH00646: Error writing to |/usr/local/cpanel/bin/splitlogs --main=whm-11-62-c7.vm.local --mainout=/etc/apache2/logs/access_log

When a graceful is performed, the pipe'd program will receive EOF and it will die anyways. SIGTERM seems too drastic and will likely result in data loss (logging loss) 

To reproduce this issue, simply grab a 100MB file somewhere and configure Piped Logging, then do this:

ab -t 120 -c 50 http://local.server.ip/100MB.testfile.zip 

While that is running, then do something like this, ie:

while true ; do apachectl graceful ; sleep 1 ; done 

Check Apache's error log for EPIPE (Broken Pipe) 

The patch removes SIGTERM from the piped logging maintenance, since it will go away anyway. This corrects the issue.

Another possible option is a flag to either kill piped programs or not kill them, but I did not research that too much.
Comment 1 Eric Covener 2017-12-25 13:06:17 UTC
I wonder what the ramifications of possible overlapped piped loggers are? I'd be hesitant to just flip everyone over without a way to go back. At least with the signal present it can be handled or ignored.
Comment 2 Gary S 2017-12-25 20:17:21 UTC
I was unable to reproduce multiple piped loggers being spawned with my patch, however there's still the possibility that behavior could happen.

Another option is I suppose the piped loggers could be patched to ignore SIGTERM which would still allow them to die during a EOF, but I did not research that too much.