Hi guys,
I was looking at bugs #51118 and #52052. Both are related to syslog
(one from a user PHP script and the other within FPM).
I think syslog is not handled correctely by PHP. Let me explain:
There is basically 3 functions provided by the syslog library:
void openlog(const char *ident, int option, int facility);
void syslog(int priority, const char *format, ...);
void closelog(void);
If syslog(...) is only used, messages are logged with default
facility, ident and option.
If openlog(...) is called before syslog(...), default facility, ident
and option are replaced.
closelog() restores default facility, ident and option.
These 3 options (facility, ident and option) visibility is global to a process.
So if independent parts of a program are calling openlog(), syslog()
and closelog() on their sides, it will affect others. This typically
happens in PHP.
here is an example running with php-cli (in order not to think with
forks and threads):
<?php
trigger_error("PHP error #1 (logged by PHP core) ".getmypid());
openlog("custom ident", LOG_PID, LOG_LOCAL0);
syslog(LOG_ALERT, "message from PHP script ".getmypid());
trigger_error("PHP error #2 (logged by PHP core) ".getmypid());
?>
I've added the 2 following lines to my /etc/syslog.conf in order to
send LOG_USER and LOG_LOCAL0 to different files:
local0.* /var/log/local0.log
user.* /var/log/loguser.log
I ran ./sapi/cli/php -d error_reporting=E_ALL -d log_errors=On -d
error_log=syslog test.php
and the results:
==> /var/log/loguser.log <==
Jan 29 16:56:16 wild php: PHP Notice: PHP error #1 (logged by PHP
core) 28503 in /LIBRE/dev/php-src/trunk/test.php on line 2
==> /var/log/local0.log <==
Jan 29 16:56:16 wild custom ident[28503]: message from PHP script 28503
Jan 29 16:56:16 wild custom ident[28503]: PHP Notice: PHP error #2
(logged by PHP core) 28503 in /LIBRE/dev/php-src/trunk/test.php on
line 5
The first trigger_error is sent correctely with facility LOG_USER (the
default one, as php core does not call openlog) and the name of the
process for the ident.
The syslog() calls from my php script, is sent correctely to
LOG_LOCAL0 (as set with the previous openlog() call)
But the last trigger_error is also sent to LOG_LOCAL0 which is wrong
as it should have been sent to LOCAL_USER
Now, we can imagine the switching errors it can cause on a multiple
vhost shared prefork apache .
I've been working the following patch (attached in bug #51118)
http://bugs.php.net/patch-display.php?bug_id=51118&patch=php-syslog.patch&revision=1296394262&download=1
What's been done :
- add error_log_facility and error_log_ident variables to php.ini
- add main/php_syslog.c file with :
- php_openlog: save ident, facility and option in its global context
before calling openlog
- php_closelog: clear global context before calling closelog
- php_syslog_get_ident: returns the ident global context
- php_syslog_get_facility: returns the facility global context
- php_syslog_get_option: returns the option global context
- php_syslog2() is quite the same as php_syslog with
ident/facility/option arguments added. Thoses are compared to the
syslog global context, and openlog is called if they don't match.
- php_syslog remains #defined to syslog
- in main/main.c:
- if error_log is set to "syslog", call php_syslog2() with
error_log_ident/facility instead of php_syslog()
- in ext/standard/syslog.c
- now openlog() returns a ressource which contains ident/option/facility
- now syslog() and closelog() takes an optional ressource parameter
(returned from openlog)
- use php_syslog2,php_openlog and php_closelog
- in sapi/milter/php_milter.c
- use php_syslog2 in place of previous openlog/syslog
what guys do you think ?
++ Jerome
--
PHP Internals - PHP Runtime Development Mailing List
To unsubscribe, visit: http://www.php.net/unsub.php
