Newsgroups: php.internals
Path: news.php.net
Xref: news.php.net php.internals:80258
Mailing-List: contact internals-help@lists.php.net; run by ezmlm
Received-SPF: pass (pb1.pair.com: domain catseye.org designates 66.111.4.26 as permitted sender)
Message-ID: <54ADACAF.3050609@catseye.org>
Date: Wed, 07 Jan 2015 17:01:19 -0500
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:31.0) Gecko/20100101 Thunderbird/31.3.0
MIME-Version: 1.0
To: internals@lists.php.net
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit
Subject: journald support for Linux systems that use systemd
From: mark@catseye.org (Mark Montague)


I'd like to start an RFC (see the draft proposal at the end of this 
message) for adding
journald support to PHP on Linux systems that use systemd.  This message 
is to
measure reaction to the intended proposal prior to requesting RFC karma.

Proof of concept implementation against PHP master branch:
https://github.com/markmont/php-src/commit/051775f01d9d1414b7cf45d35983abd958195a0c

Proof of concept implementation against PHP-5.6.5 branch:
https://github.com/markmont/php-src/commit/7572e35fa0ae1066e4dba2797a28f9dfbb548c1a

Thanks for any feedback!

-- 
   Mark Montague
   mark@catseye.org



====== PHP RFC: journald support ======
   * Version: 1.0
   * Date: 2015-01-07
   * Author: Mark Montague, mark@catseye.org
   * Status: Draft
   * First Published at: http://wiki.php.net/rfc/journald_support

===== Introduction =====
Add optional support to PHP for
[[http://www.freedesktop.org/software/systemd/man/systemd-journald.service.html|journald]]
as a standard extension.  On web servers which use journald, this would permit
   * structured system log messages via the Journal API
   * journald to be used as an alternative to syslog for non-structured logging, if desired

This proposal was motivated by the desire to retain structure when logging
Content Security Policy reports; see the example in the documentation for
the proposed sd_journal_send() function below.  Other functionality such as
error_log support is included in the proposal in order to provide complete
support for journald logging in PHP.

===== Proposal =====
This proposal is to add support for journald (a part of systemd) to PHP in
in order to allow both PHP as well as PHP scripts to log directly to journald
rather than logging via syslog.  The primary advantage of this is to permit
structured logging; a secondary advantage is that non-structured logs
(including messages logged via the error_log() function) can contain
additional information, including script file, script line number, and
PHP function or class name.

==== Base PHP support ====

=== error_log() ===
When the php.ini resource error_log is set to the special value "journald",
error_log() output will be sent directly to journald via the Journal API.

A priority, syslog facility, and a syslog tag will automatically be added
based on the values of the php.ini resources journald.priority,
journald.syslog_facility, and journald.syslog_identifier unless
journald.suppress_syslog_fields is set to a non-zero value in which case
journald defaults will be used.

The PHP script file name, line number, and function or class name will
automatically be added unless the php.ini resource journald.suppress_location
is set to a non-zero value.

Example:

<code>
$ php -d error_log=journald -r 'error_log("Hello, world!");'
</code>

Result:

<code>
# journalctl -a -l -n 1 -o verbose
-- Logs begin at Wed 2014-09-17 02:51:22 UTC, end at Thu 2014-12-04 14:58:14 UTC
Thu 2014-12-04 14:58:14.280324 UTC [s=7a262009cac947bd85e44417c1fd5059;i=31870;b
     _UID=1000
     _GID=1000
     _CAP_EFFECTIVE=0
     _AUDIT_LOGINUID=1000
     _SYSTEMD_OWNER_UID=1000
     _SYSTEMD_SLICE=user-1000.slice
     _SELINUX_CONTEXT=staff_u:staff_r:staff_t:s0
     _BOOT_ID=36f1fee4683d460fba350a50136f1f32
     _MACHINE_ID=e66253b193b3405d9e82008bd6e05c5c
     _HOSTNAME=www.example.com
     PRIORITY=5
     SYSLOG_IDENTIFIER=php
     _TRANSPORT=journal
     _COMM=php
     _AUDIT_SESSION=24849
     _SYSTEMD_CGROUP=/user.slice/user-1000.slice/session-24849.scope
     _SYSTEMD_SESSION=24849
     _SYSTEMD_UNIT=session-24849.scope
     MESSAGE=Hello, world!
     SYSLOG_FACILITY=19
     CODE_FILE=Command line code
     CODE_LINE=1
     CODE_FUNC=error_log
     _PID=5761
     _EXE=/usr/bin/php
     _CMDLINE=php -d error_log=journald -r error_log("Hello, world!");
     _SOURCE_REALTIME_TIMESTAMP=1417705094280324
#
</code>

Note that the function name reported above is error_log() because
error_log() was called directly by the main script.  If error_log() had
been called from within a function or class method, the name of the
calling function or method would be reported instead.

=== mail() ===
When the php.ini resource error_log is set to the special value "journald",
log messages generated by the mail() function will be sent directly to
journald via the Journal API.

A priority, syslog facility, and a syslog tag will automatically be added
based on the values of the php.ini resources journald.priority,
journald.syslog_facility, and journald.syslog_identifier unless
journald.suppress_syslog_fields is set to a non-zero value in which case
journald defaults will be used.

The PHP script file name, line number, and function or class name will
automatically be added unless the php.ini resource journald.suppress_location
is set to a non-zero value.

=== PHP-FPM SAPI ===
When the php-fpm.conf resource error_log is set to the special value
"journald", all log messages generated by the php-fpm daemon will be
logged directly to journald via the Journal API.

The php-fpm.conf resources syslog.facility and syslog.ident control
the facility and tag of the the logged messages.  The C function name
and line number of the code generating the log message are automatically
added.

Note that log messages generated by the php-fpm daemon are controlled
and handled separately from log messages generated by PHP scripts.

==== Journal API support ====

Currently, this proposal only includes adding support for PHP to log to the
Journal API, and only for the functions for which this makes sense.  For
example, sd_journal_sendv() is not included as a function to support from
PHP since due to the nature of the PHP language this function would not add
any feature or benefit that is not already covered by sd_journal_send().

Support for generating and manipulating 128-bit systemd IDs or support
for querying journal entries could be added if use cases in PHP for such
functions are identified.

=== sd_journal_print() ===
sd_journal_print - Submit log entry to the journal
== Description ==
<code php>
bool sd_journal_print( int $priority, string $format [, mixed $args [, mixed $... ]] )
</code>
sd_journal_print() generates a log message via journald (part of systemd,
which is only available on certain Linux systems).
== Parameters ==
* priority - indicates the severity or importance of the log message.  Uses the
same constants defined by the [[syslog]] function.
* format - a format string in the style used by the [[sprintf]] function.
* args - arguments corresponding to parameters, if any, in the format string.
== Return Values ==
Returns TRUE on success or FALSE on failure.
== Examples ==
Example #1 - Using sd_journal_print()
<code php>
<?php
     // some code
     if (authorized_client()) {
         // do something
     } else {
         // unauthorized client!
         // log the attempt
         sd_journal_print(LOG_WARNING, "Unauthorized client: %s (%s)", $_SERVER['REMOTE_ADDR'], $_SERVER['HTTP_USER_AGENT']);
     }
?>
</code>
Result:
<code>
# journalctl -a -l -n 1 -o verbose
-- Logs begin at Wed 2014-09-17 02:51:22 UTC, end at Tue 2015-01-06 19:54:43 UTC
Tue 2015-01-06 19:54:43.291860 UTC [s=7a262009cac947bd85e44417c1fd5059;i=46419;b
     _UID=1000
     _GID=1000
     _CAP_EFFECTIVE=0
     _AUDIT_LOGINUID=1000
     _SYSTEMD_OWNER_UID=1000
     _SYSTEMD_SLICE=user-1000.slice
     _SELINUX_CONTEXT=staff_u:staff_r:staff_t:s0
     _BOOT_ID=36f1fed4689d460fba350a50136f1f32
     _MACHINE_ID=e66253b193b3405d9e82008bd6e05c5c
     _HOSTNAME=www.example.com
     _AUDIT_SESSION=38610
     _SYSTEMD_CGROUP=/user.slice/user-1000.slice/session-38610.scope
     _SYSTEMD_SESSION=38610
     _SYSTEMD_UNIT=session-38610.scope
     MESSAGE=Unauthorized client: 10.0.0.7 (Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:34.0) Gecko/20100101 Firefox/34.0)
     PRIORITY=5
     SYSLOG_FACILITY=19
     CODE_FILE=/var/www/html/sd_journal_print-example1.php
     CODE_LINE=17
     CODE_FUNC=do_stuff
     SYSLOG_IDENTIFIER=php
     _TRANSPORT=journal
     _PID=2450
     _COMM=php
     _EXE=/usr/bin/php
     _CMDLINE=php-fpm
     _SOURCE_REALTIME_TIMESTAMP=1420574083291860
#
</code>
== Notes ==
PHP will add a configurable syslog tag and facility unless overridden by
journald.suppress_syslog_fields.

PHP will add the file, line number, and name/class of the calling function
unless overridden journald.suppress_location.

The format parameter should not contain any untrusted data, as sd_journal_print
will interpret any format string metacharacters that are present.  Instead,
print any untrusted data via a %s format string parameter.  For example:

Wrong, insecure:
<code php>
<?php
     // % characters in $data_from_client will affect the running code:
     sd_journal_print(LOG_NOTICE, "the request is: $data_from_client");  // insecure
?>
</code>

Correct:
<code php>
<?php
     // % characters in $data_from_client will print literally:
     sd_journal_print(LOG_NOTICE, "the request is: %s", $data_from_client);
?>
</code>
== See Also ==
[[syslog]]
[[sprintf]]

=== sd_journal_printv() ===
sd_journal_printv - Submit log entry to the journal
== Description ==
<code php>
bool sd_journal_printv( int $priority, string $format [, array $args] )
</code>
sd_journal_printv() generates a log message via journald (part of systemd,
which is only available on certain Linux systems).  sd_journal_printv()
is the same as sd_journal_print() except that sd_journal_printv() takes
its format string arguments as an array instead of as a variable length
argument list.
== Parameters ==
* priority - indicates the severity or importance of the log message.
Uses the same constants defined by the [[syslog]] function.
* format - a format string in the style used by the [[sprintf]] function.
* args - arguments corresponding to parameters, if any, in the format string.
== Return Values ==
Returns TRUE on success or FALSE on failure.
== Examples ==
Example #1 - Using sd_journal_print()
<code php>
<?php
     // some code
     if (authorized_client()) {
         // do something
     } else {
         // unauthorized client!
         // log the attempt
         sd_journal_printv(LOG_WARNING, "Unauthorized client: %s (%s)", array($_SERVER['REMOTE_ADDR'], $_SERVER['HTTP_USER_AGENT']));
     }
?>
</code>
See the [[sd_journal_print]] documentation for the result.
== Notes ==
PHP will add a configurable syslog tag and facility unless overridden by
journald.suppress_syslog_fields.

PHP will add the file, line number, and name/class of the calling function
unless overridden journald.suppress_location.

The format parameter should not contain any untrusted data, as sd_journal_print
will interpret any format string metacharacters that are present.  Instead,
print any untrusted data via a %s format string parameter.  For example:

Wrong, insecure:
<code php>
<?php
     // % characters in $data_from_client will affect the running code:
     sd_journal_printv(LOG_NOTICE, "the request is: $data_from_client");  // insecure
?>
</code>

Correct:
<code php>
<?php
     // % characters in $data_from_client will print literally:
     sd_journal_print(LOG_NOTICE, "the request is: %s", array($data_from_client));
?>
</code>
== See Also ==
[[syslog]]
[[sprintf]]
[[sd_journal_print]]

=== sd_journal_send() ===
sd_journal_send - Submit log entry to the journal
== Description ==
<code php>
bool sd_journal_send( string $format [, mixed $args [, mixed $... ]]
     [string $format [, mixed $args [, mixed $... ]]], ... )
HERE
</code>
sd_journal_send() generates a log message via journald (part of systemd,
which is only available on certain Linux systems).
== Parameters ==
* format - a format string in the style used by the [[sprintf]] function.
* args - arguments corresponding to parameters, if any, in the format string.
As many format strings and sets of arguments as desired can be used in
a single call to sd_journal_send().
== Return Values ==
Returns TRUE on success or FALSE on failure.
== Examples ==
Example #1 - logging a structured Content Security Policy report
<code php>
<?php
//
// Accept and log CSP violation reports from web browsers.  See
// http://www.html5rocks.com/en/tutorials/security/content-security-policy/
//

// Get information about the CSP report submission (note that this is NOT
// the same as the information about the request that resulted in the report).
$vars = array(
     'CONTENT_LENGTH', 'CONTENT_TYPE', 'QUERY_STRING', 'REMOTE_ADDR',
     'REMOTE_PORT', 'REMOTE_USER', 'REQUEST_METHOD', 'REQUEST_URI'
);
$info = array();
foreach ( $vars as $v ) {
     if ( ! empty( $_SERVER[$v] ) ) { $report_info[$v] = $_SERVER[$v]; }
}
$info['REQUEST_TIME'] = empty( $_SERVER['REQUEST_TIME'] ) ?
     time() : $_SERVER['REQUEST_TIME'];
$info['TIMESTAMP'] = date( 'c', $info['REQUEST_TIME'] );
$csp_report_info = json_encode( $info,
     JSON_PRETTY_PRINT | JSON_UNESCAPED_SLASHES );
if ( ! $csp_report_info ) { return 'failed to encode report information'; }

// Get and check the CSP report being submitted by the web browser:
$json = file_get_contents( 'php://input' );
if ( ! $json ) { return 'failed to get POST data'; }
if ( strlen( $json ) > 16384 ) { return 'report too large'; }
$data = json_decode( $json, TRUE );
if ( ! $data ) { return 'failed to decode report'; }
if ( ! isset( $data['csp-report'] ) ) {
     return 'report does not contain required key "csp-report"';
}
// re-encode the report, omitting any unexptected keys:
$csp_report = json_encode( $data['csp-report'],
     JSON_PRETTY_PRINT | JSON_UNESCAPED_SLASHES );
if ( ! $csp_report ) { return 'failed to re-encode report'; }

// Log the report.  $csp_report and $csp_report_info both contain untrusted
// data, so print them via format strings instead of directly
sd_journal_send( 'MESSAGE=Content Security Policy Violation',
     'CSP_REPORT=%s', $csp_report,
     'CSP_REPORT_INFO=%s', $csp_report_info,
     "SYSLOG_FACILITY=LOG_LOCAL4" );

return 'ok';

?>
</code>
Result:
<code>
# journalctl -a -l -n 1 -o verbose "MESSAGE=Content Security Policy Violation" | cat
-- Logs begin at Wed 2014-09-17 02:51:22 UTC, end at Tue 2015-01-06 21:20:01 UTC. --
Thu 2014-12-11 01:28:00.720105 UTC [s=8f85b448a56a4e0c9dd8e279dea9a0c0;i=353ca;b=36f1fee4683d460fba350a50136f1f32;m=53472b7037e;t=509e6afd60c26;x=feadb0f51c2f47b1]
     _TRANSPORT=journal
     _BOOT_ID=36f1fee4683d460fba350a50136f1f32
     _MACHINE_ID=e66253b79393405d9e82008bd6e05c5c
     _HOSTNAME=www.example.com
     _CAP_EFFECTIVE=0
     _SYSTEMD_SLICE=system.slice
     PRIORITY=5
     MESSAGE=Content Security Policy Violation
     SYSLOG_FACILITY=160
     SYSLOG_IDENTIFIER=php-fpm-pool-1
     CODE_FILE=/var/www/html/csp-report.php
     CODE_LINE=40
     CODE_FUNC=sd_journal_send
     _UID=2000
     _GID=2000
     _COMM=php-fpm
     _EXE=/usr/sbin/php-fpm
     _CMDLINE=php-fpm: pool pool1
     _SYSTEMD_CGROUP=/system.slice/php-fpm.service
     _SYSTEMD_UNIT=php-fpm.service
     _SELINUX_CONTEXT=system_u:system_r:phpfcgi_t:s0
     CSP_REPORT={
                    "blocked-uri": "https://secure.gravatar.com/avatar/48bca497c6fa74c466d25a598ae846c1?s=26&d=https%3A%2F%2Fsecure.gravatar.com%2Favatar%2Fad516503a11cd5ca435acc9bb6523536%3Fs%3D26&r=G",
                    "document-uri": "https://www.example.com/wp-admin/nav-menus.php?action=edit&menu=0",
                    "original-policy": "default-src https://www.example.com; script-src https://www.example.com 'unsafe-inline' 'unsafe-eval'; style-src https://www.example.com 'unsafe-inline'; img-src https://www.example.com data:; font-src https://www.example.com data:; frame-ancestors https://www.example.com; report-uri https://www.example.com/csp-report.php",
                    "referrer": "https://www.example.com/wp-admin/themes.php",
                    "violated-directive": "img-src https://www.example.com data:"
                }
     CSP_REPORT_INFO={
                         "CONTENT_LENGTH": "753",
                         "CONTENT_TYPE": "application/json",
                         "REMOTE_ADDR": "35.2.217.249",
                         "REMOTE_PORT": "63593",
                         "REQUEST_METHOD": "POST",
                         "REQUEST_URI": "/csp-report.php",
                         "REQUEST_TIME": 1418261280,
                         "TIMESTAMP": "2014-12-11T01:28:00+00:00"
                     }
     _PID=16282
     _SOURCE_REALTIME_TIMESTAMP=1418261280720105
</code>
== Notes ==
PHP will add a configurable syslog tag and facility unless overridden by
journald.suppress_syslog_fields.

PHP will add the file, line number, and name/class of the calling function
unless overridden journald.suppress_location.

The format parameters should not contain any untrusted data, as sd_journal_print
will intrepret any format string metacharacters that are present.  Instead,
print any untrusted data via a %s format string parameter.  For example:

Wrong, insecure:
<code php>
<?php
     // % characters in $data_from_client will affect the running code:
     sd_journal_send("MESSAGE={$data_from_client}");  // insecure
?>
</code>

Correct:
<code php>
<?php
     // % characters in $data_from_client will print literally:
     sd_journal_send("MESSAGE=%s", $data_from_client);
?>
</code>
== See Also ==
[[sprintf]]


===== Backward Incompatible Changes =====
Adding support for journald to PHP would not break any existing code or
configuration.

===== Proposed PHP Version(s) =====
PHP 7 and next PHP 5.x.

===== RFC Impact =====
==== To SAPIs ====
There is no particular impact to CLI, Development web server, embedded PHP etc.

The FPM SAPI would be modified to support logging directly to journald as
an alternative to logging via syslog.

==== To Existing Extensions ====
No existing extensions will be affected.

==== To Opcache ====
There should be no compatibility issues with opcache.

==== New Constants ====
No new constants would be added, but journald would rely on the constants
already defined for use by the openlog() and syslog() functions.  Therefore,
journald support can only be enabled if syslog support is also enabled.

==== php.ini Defaults ====

=== error_log ===
A new special value, "journald", is defined.  This is analogous to the special
value "syslog" that already exists. Specifying "journald" as a value causes
the error_log() function to send its output directly to journald.
   
=== mail_log ===
A new special value, "journald", is defined.  This is analogous to the special
value "syslog" that already exists. Specifying "journald" as a value causes
the mail() function to send its logs directly to journald.
   
=== journald.syslog_identifier ===
Controls the value of the journald field SYSLOG_IDENTIFIER for log entries
that are sent to journald.  If this value is not set, journald will supply
its own default per the systemd.journal-fields(7) man page (typically, the
short name of the program that is running the PHP script).

sd_journal_send() can optionally override this value.

This setting has no effect if journald.suppress_syslog_fields is set.

NOTE: the PHP-FPM SAPI logs message pertaining to the FPM daemons using its
own identifier specified via syslog.ident resource in php-fpm.conf.
However, scripts run under the PHP-FPM SAPI use the value of
journald.syslog_identifier.

Default values:
   * hardcoded: not set
   * php.ini-development: not set
   * php.ini-production: not set

=== journald.syslog_facility ===
Controls the value of the journald field SYSLOG_FACILITY for log entries
that are sent to journald.

The value can be any of the values defined for use by the openlog() function:
LOG_AUTH, LOG_AUTHPRIV, LOG_CRON, LOG_DAEMON, LOG_KERN, LOG_LOCAL0 ...
LOG_LOCAL7, LOG_LPR, LOG_MAIL, LOG_NEWS, LOG_SYSLOG, LOG_USER, LOG_UUCP

sd_journal_send() can optionally override this value.

This setting has no effect if journald.suppress_syslog_fields is set.

NOTE: the PHP-FPM SAPI logs message pertaining to the FPM daemons using its
own facility specified via syslog.facility resource in php-fpm.conf.
However, scripts run under the PHP-FPM SAPI use the value of
journald.syslog_facility.

Default values:
   * hardcoded: LOG_USER
   * php.ini-development: LOG_USER
   * php.ini-production: LOG_USER

=== journald.priority ===
Controls the value of the journald field PRIORITY for log entries
that are sent to journald.

The value can be any of the values defined for use by the syslog() function:
LOG_EMERG, LOG_ALERT, LOG_CRIT, LOG_ERR, LOG_WARNING, LOG_NOTICE, LOG_INFO,
LOG_DEBUG.

sd_journal_send() can optionally override this value.

This setting has no effect if journald.suppress_syslog_fields is set.

NOTE: the PHP-FPM SAPI logs message pertaining to the FPM daemons using its
own priorities which depend on the specific messages being logged.  However,
scripts run under the PHP-FPM SAPI use the value of journald.syslog_facility.

Default values:
   * hardcoded: LOG_NOTICE
   * php.ini-development: LOG_NOTICE
   * php.ini-production: LOG_NOTICE

=== journald.suppress_location ===
When set to a non-zero value, PHP will not supply values for the journald
fields SYSLOG_IDENTIFIER, SYSLOG_FACILITY, and PRIORITY; journald's
default values will be used instead.

Default values:
   * hardcoded: 0
   * php.ini-development: 0
   * php.ini-production: 0

=== journald.suppress_syslog_fields ===
When set to a non-zero value, PHP will not supply values for the journald
fields CODE_FILE, CODE_LINE, and CODE_FUNC and these fields will not
be included in the journald log entry.

Default values:
   * hardcoded: 0
   * php.ini-development: 0
   * php.ini-production: 0

===== Open Issues =====
   * Documentation needs to be created.
   * Tests need to be created, if it makes sense to have tests for
journald support (see "Patches and Tests" section, below).

===== Unaffected PHP Functionality =====
No functionality will be affected unless one of the following occurs:
   * the php.ini value for error_log is set to journald
   * the php.ini value for mail_log is set to journald
   * the php-fpm.conf value for error_log is set to journald
   * the script calls one of the new journald functions: sd_journal_print(),
     sd_journal_printv(), sd_journal_send()

===== Future Scope =====
If journald logging functionality is enhanced by systemd maintainers in the
future, similar changes should be made to PHP's support for systemd to the
extent that makes sense.

If a use arises, functions for generating and manipulating systemd 128 bit IDs
could be added (see the sd-128 manual page).

If a use arises, functions could be added for querying journal log entries.

===== Proposed Voting Choices =====
Adding journald support to PHP does not change the language itself or its
syntax, therefore a 50%+1 majority vote is proposed.

===== Patches and Tests =====
Prototype patches are available against:
   * PHP 5.6.x (currently 5.6.4) for hopeful inclusion in 5.7
   * PHP master for hopeful inclusion in PHP 7.0

Tests are not yet available and need to be written, if it makes sense to
have tests.  There are currently no tests for syslog support, so
if we add tests for journald support it might make sense to also add
syslog tests.

===== Implementation =====
After the project is implemented, this section should contain
   - the version(s) it was merged to
   - a link to the git commit(s)
   - a link to the PHP manual entry for the feature

===== References =====
   * [[http://www.freedesktop.org/software/systemd/man/systemd-journald.service.html|systemd-journald.service]] - a high-level description of the systemd journald service
   * [[http://www.freedesktop.org/software/systemd/man/sd_journal_send.html|sd_journal_send()]] - documentation for relevant Journal API functions.
   * [[http://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html|systemd.journal-fields]] - description of fields in journald log entries

===== Rejected Features =====
Keep this updated with features that were discussed on the mail lists.