Bug 61926 - [PATCH] Race Condition with Piped Logging and multiple Graceful restarts
Summary: [PATCH] Race Condition with Piped Logging and multiple Graceful restarts
Status: NEW
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: Core (show other bugs)
Version: 2.4.29
Hardware: PC Linux
: P2 major (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-12-24 21:31 UTC by Gary Stanley
Modified: 2018-01-22 16:43 UTC (History)
1 user (show)



Attachments
Patch to remove SIGTERM from server/log.c (1.63 KB, patch)
2017-12-24 21:31 UTC, Gary Stanley
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Gary Stanley 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 192.168.130.63:38670] 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 192.168.130.63:38670] 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 Stanley 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.