Bug 67861 - Logging issue for piped logs vs file
Summary: Logging issue for piped logs vs file
Status: NEW
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: Core (show other bugs)
Version: 2.4.56
Hardware: Other FreeBSD
: P2 minor (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-10-21 17:42 UTC by coelhop24
Modified: 2023-10-21 17:42 UTC (History)
0 users


Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description coelhop24 2023-10-21 17:42:46 UTC 
Hello

I think I have discovered a bug, where using a log file vs using a pipe
command will not log the exact same messages.

System:
Server version: Apache/2.4.56 (Unix)
Server built: Jul 10 2023 10:58:41
root@ns-pedros# uname -a
FreeBSD ns-pedros 11.4-NETSCALER-13.1 FreeBSD 11.4-NETSCALER-13.1 #0
a7c4dc80d(rs_131_49_4_RTM): Mon Jul 10 12:01:16 PDT 2023
root@sjc-bld-bsd114-232:/usr/obj/usr/home/build/adc/usr.src/sys/NS64 amd64

I configure the following ErrorLog Directive as follows:
-A:ErrorLog "/var/log/httperror.log"
-B:ErrorLog "|/usr/bin/logger -t httperror -p local3.error"

I have also tried option B with |$, yielding the same result.

I have to use logger and not the "syslog:facility:tag" because I need to
control the level of the log, and this doesn't provide me with that option.

I have syslog writing to a different file, /var/log/httperror_syslog.log

If I use option A, I see the following messages after /bin/httpd -k restart
-f /etc/httpd.conf several times, in order to ensure before and after
loading the config I get the same set of messages:
[Wed Oct 11 07:54:34.505202 2023] [mpm_prefork:notice] [pid 215] AH00173:
SIGHUP received. Attempting to restart
[Wed Oct 11 07:54:34.624822 2023] [mpm_prefork:notice] [pid 215] AH00163:
Apache/2.4.56 (Unix) mod_perl/2.0.10 Perl/v5.30.2 configured -- resuming
normal operations
[Wed Oct 11 07:54:34.625678 2023] [core:notice] [pid 215] AH00094: Command
line: '/bin/httpd -f /etc/httpd.conf'

If I use option B, after several restarts I have the following set of
messages:
Oct 11 07:55:56 <local3.err> ns-pedros httperror: [Wed Oct 11
07:55:56.486944 2023] [mpm_prefork:notice] [pid 215] AH00163: Apache/2.4.56
(Unix) mod_perl/2.0.10 Perl/v5.30.2 configured -- resuming normal operations
Oct 11 07:55:56 <local3.err> ns-pedros httperror: [Wed Oct 11
07:55:56.488838 2023] [core:notice] [pid 215] AH00094: Command line:
'/bin/httpd -f /etc/httpd.conf'


Besides the obvious new prefix from syslog, we can see that the SIGHUP
message is not sent to the piped log. I will theorize that the pipe is
closed before the SIGHUP message is sent.

I believe that this message should be sent before closing the pipe.