Brainspiritus

Funkenflug aus flammenden Synapsen.

I dent, you dent, we all dent for syslog.

This was a "fun" one to figure out… we run a (actually several) shared PHP-FPM setups at work for our customers. While they're not big or sensitive enough to warrant per-user process segregation, we'd still like them to get their own php error logs, so we can tell them they need to fix their own messes.

This is possible, but a bit… batteries not included, let's say. I have about six points in the following where either the semantics are unclear but currently work the way I want them to, or the features I use are so obscure that PHP might drop them.

Step 1: use syslog.

Starting from PHP 7.3, you can set syslog.ident, the prefix of syslog messages. It's configurable at PHP_INI_SYSTEM level, i.e. basically in php.ini. I won't go into detail on how to point the syslog to a remote logging server or something like that, partially because I don't understand rsyslog enough, it can't possibly be as bad as it feels to me.

Step 2: but that doesn't work, does it?

We have several users connecting into the same php-fpm processes, which share a common php.ini. Are we out of luck? As it turns out, no. Well-hidden in the docs, we find that you can have php.ini sections that only apply to certain directories or hostnames:

[PATH=/home/user1/public_html]
syslog.ident = "user1php"

[PATH=/home/user2/public_html]
syslog.ident = "user2php"

Step 3: but you'll have a monolithic, often-changing php.ini now!

Turns out, no. There is an environment variable PHP_INI_SCAN_DIR, again so documented you only find it if you know it exists, that points at a directory full of .ini files and applies all of them. You will have to augment your systemd service file to use it:

Environment=PHP_INI_SCAN_DIR=:/etc/php/7.4/fpm/accounts.d/

Step 4: but that doesn't work, does it?

You're right. phpinfo() will tell you all the settings get there, but you won't see the prefixes you want in the syslog. This is because even though you can set syslog.ident on a per-directory basis, it's only used once, when openlog is called. (This might be implicitly when syslog() is called for the first time.)

So, we need more help, by way of auto_prepend_file. Prepending something to every file at parse time is exactly what we need to make sure the proper syslog.ident is applied:

@closelog();
@openlog(ini_get('syslog.ident'),
         LOG_NDELAY,
         constant("LOG_" . strtoupper(ini_get('syslog.facility'))));

Yes, that constant(…) construct looks ugly and is probably not the best way to do it. In practice, you could probably hardcode the value you want there anyway. You probably don't strictly need the closelog() either.

And yes, this is semantically very odd: as per docs,

[t]he [autoprepended] file is included as if it was called with the require function

and it doesn't itself need to be within the scope given by the [PATH=] section, it just needs to be covered by open_basedir and include_path. This is something I'm pretty worried about, because it looks like the intended behaviour is under-defined, so if it breaks it's just "why did you use such a border case anyway".

Step 5: Is this going anywhere useful?

We're almost there. It'll look good when you test it. It'll fall over in production and direct all logs to a small number of files. The problem will mysteriously go away as you try to debug it, and come back when you're not looking.

The problem is: opcache. PHP keeps some files parsed and precompiled to bytecode for performance reasons. Since our autoprepended file is getting hit for literally every request, it will never leave the cache unless you change the source file. Unfortunately, though, bytecompiling it will apparently resolve the ini_gets since it thinks they're constants. I can't blame opcache here, after all, it's the literally same file, just included from different paths.

Fortunately, there is the (at time of writing still named thusly) opcache.blacklist_filename, with which you can tell PHP to never cache bytecode for the autoprepended file.

Step 6: Profit??

Now you should get your nice stream of syslog messages with the right prefixes. Splitting that off into different files is left as an exercise for the reader. ;-)