Fix GH-24308: Request shutdown closes a syslog handle PHP did not open

[lazerg]

The syslog RSHUTDOWN handler called php_closelog() after every request, even when nothing in the request had opened syslog. In an embedded SAPI, a host that called openlog() before running PHP lost its connection when each request ended. PHP already tracks this in PG(have_called_openlog), so the handler now checks it first. Requests that open syslog through openlog(), syslog() or error_log = syslog still close it at the end.

I checked it with an embed host on Debian (glibc). The host opens syslog with LOG_NDELAY and runs three requests that do not touch syslog. Before the fix, strace shows four connects to /dev/log. After the fix, it shows one. There is no test, because run-tests has no way to drive the embed SAPI with a host-owned handle.

Fixes GH-24308

[LamentXU123]

I am curious how this will work

#include <sapi/embed/php_embed.h>

int main(int argc, char **argv)
{
    php_embed_module.php_ini_ignore = 1;
    php_embed_init(argc, argv);
    zend_eval_string("syslog(LOG_INFO, 'test');", NULL, "test");
    php_embed_shutdown();
    return 0;
}

[lazerg]

Good catch, I fixed it in 8cd9f6f. Your example left the socket open: syslog() without openlog() lets libc connect on its own, PHP never set have_called_openlog, so request shutdown skipped closelog(). strace showed the socket open until the process exited. Now syslog() marks the request, and shutdown closes the log if either flag is set. Your example closes the socket at request end again. A host that calls openlog() and runs requests that don't touch syslog still keeps its one connection.

[LamentXU123]

Thank you. can you write a regression test?

[lazerg]

I added a test in f0ed6aa (ext/standard/tests/network/gh24308.phpt). It sends two requests to the CLI server. The first request calls syslog() without openlog(). The second request checks that the socket from syslog() is closed. The test fails without 8cd9f6f and passes with it. It needs Linux and /dev/log, so it skips on other systems.

The test does not cover the original case, where the embed host opens syslog itself. run-tests cannot run an embed host.

[andypost]

Thank you adding a test!
Sleeping with it, I bet we can skip changing fpm which has own workaround for this bug

[lazerg]

Agreed. This PR does not change FPM, it only changes ext/standard/syslog.c. The FPM child calls php_closelog() in fpm_stdio_init_child(), which also clears have_called_openlog, so the new check sees the same state in FPM as before.

I ran php-fpm with error_log = syslog on Debian, with requests that log nothing, call error_log(), and call syslog(). Base and this branch give the same result: one /dev/log connect for the master, and one in the child for each request that logs. sapi/fpm/tests also gives the same result on both.

[phpclub]

Real BUG - approve please!

[ndossche]

We shouldn't need this extra variable.
I also think the check is simply incorrect: if a host embed already opens the syslog, and the script calls syslog through the host, then syslog_called is set which will close the host syslog, exactly what we tried to prevent; i.e. it reintroduces the issue.

A better fix is to drop syslog_called, and make sure that if syslog is called without PG(have_called_openlog), that it calls php_openlog. However, that's a behaviour change and can't go into a stable branch.

[lazerg]

I dropped syslog_called in 44d80f5. Now syslog() calls php_openlog() with syslog.ident and syslog.facility if the log is not open, so request shutdown only checks have_called_openlog. You are right about the old check. I ran an embed host that calls openlog("host", ...), and a script syslog() closed the host log at request end, same as on base.

A script syslog() still replaces the host log, because libc has one log per process. With this change the message uses the php ident, like error_log = syslog. A host whose requests do not call syslog() keeps its one connection. gh24308.phpt still fails without the change and passes with it.

This changes the ident for syslog() without openlog(). Do you want me to rebase onto master and add an UPGRADING note? The other option is to keep only the have_called_openlog check for PHP-8.4, but then a plain syslog() leaves its socket open until the process exits.

[andypost]

Thank you! Nice idea, it saves for FreeUnit 1 syscall at least and even more in upcoming "worker mode" on musl

PS: musl closelog() doing close(log_fd); log_fd = -1; without checking (https://github.com/kraj/musl/blob/dd1e63c3638d5f9afb857fccf6ce1415ca5f1b8b/src/misc/syslog.c#L41-L50) so when log_fd == -1 it leads to close(-1) = EBADF, so extra syscall on request

[lazerg]

The FREEBSD_NTS failure is not caused by this change. The job stopped before the build because the FreeBSD package mirror returned "Not Found".