php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #75897 error_log() results in inappropriate/inconsistent Apache severity
Submitted: 2018-01-31 22:22 UTC Modified: 2018-02-02 21:05 UTC
Votes:1
Avg. Score:3.0 ± 0.0
Reproduced:0 of 1 (0.0%)
From: bjohnson at paylease dot com Assigned:
Status: Open Package: Apache2 related
PHP Version: 7.1.13 OS: any
Private report: No CVE-ID: None
 [2018-01-31 22:22 UTC] bjohnson at paylease dot com
Description:
------------
PHP 7.1 changed the behavior of PHP messages delivered to Apache2: specifically now PHP messages will have an Apache severity corresponding to the PHP severity. Previous to 7.1 the Apache severity was always 'warn'.

This change brought with it two undesired side effects for calls to the built-in error_log() function when the error_log INI directive is un-set.

1. A simple call of error_log('some message') will have an Apache severity of 'notice', which may be lower than a user's Apache error LogLevel is set
2. When the error_log INI directive is unset, and using the Apache2 SAPI, the following three calls should be equivalent:
error_log('message');
error_log('message', 0);
error_log('message', 4);
However the first two will result is a 'notice' level message, while the third will result in an 'error' level message.

More discussion regarding the how/why of this behavior can be found in this pull request: https://github.com/php/php-src/pull/1981

Test script:
---------------
<?php

error_log('message');
error_log('message', 0);
error_log('message', 4);

Expected result:
----------------
The following three commands should have consistent behavior when the error_log INI directive is unset. If using the Apache2 SAPI, the message severity should be 'error'

error_log('message');
error_log('message', 0);
error_log('message', 4);

Actual result:
--------------
The first two commands will have a 'notice' severity. The third will have 'error'.

Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2018-01-31 22:33 UTC] requinix@php.net
The first point is a documented change:
http://php.net/migration71.incompatible#migration71.incompatible.error_log-syslog
> If the error_log ini setting is set to syslog [0], the PHP error levels are mapped to the syslog error levels.

The second point ("Was this difference in behavior between message type 0 and 4 intended?") is still questionable.
 [2018-02-01 14:00 UTC] bjohnson at paylease dot com
Thank you for your response, requinx. However, I do not believe your link/quote addresses the first issue I've raised. I'm specifically discussing the scenario when the error_log INI directive is unset, not when it is set to syslog. Further, my complaint is not that PHP error levels are mapped to Apache error levels. I acknowledged that as a documented, desired change in the opening of my bug description. My complaint is that when error_log INI is unset, and using the Apache SAPI, simple calls to the error_log() function such as error_log('message') are now Apache 'notice' level. Previous to 7.1 they were 'warn' level. In the linked PR it was suggested they should be 'error' level: https://github.com/php/php-src/pull/1981#issuecomment-361684885

Regarding the inconsistency in severity when explicitly sending the message to SAPI logger as opposed to letting it fall there by default because error_log INI directive is unset, that inconsistency would be... odd, if intended. But, if that were the case it should at least be documented. The author of the PR seems to suggest it was unintended: https://github.com/php/php-src/pull/1981#issuecomment-360932281
 [2018-02-01 20:05 UTC] requinix@php.net
I think with the syslog/SAPI juggling between error_log() and error_log I managed to get the two of them mixed up. So ignore what I said.


tl;dr: IMO errors becoming notices is intentional and should remain but needs to be documented, while the 0/4 behavior should be fixed so that either error_log() with 4 explicitly logs as a notice or all messages are errors.


Here's an unnecessarily in-depth analysis of everything.

As of that PR 1981, error_log() with default/0 explicitly classifies as a notice (unchanged) and with 4 classifies using the logging's default which is as an error for Apache (unchanged). Additionally the SAPI error logger is capable of differentiating between PHP's error levels when that information gets passed through (new). That "gets passed through" happens when error logging goes through the error_log setting, and not through error_log() since that doesn't receive any severity information.

The result is the two differences you pointed out:
1. Previously, error_log() with default/0 had tried to log as a notice, however if the error went through the SAPI (meaning error_log is unset or empty) then Apache's behavior of forcing an error took over. Now, error_log() still tries to use a notice as before but this time Apache will respect that.
2. Now that SAPIs can respect the error level, to keep backwards compatibility the Apache logger uses error as the default level and error_log() with 4 will indicate the default level.

In other words,
- error_log() with default/0 and error_log *set* will log as a notice (unchanged)
- error_log() with default/0 and error_log *unset* will log as a notice (unchanged) but Apache will honor that (new)
- error_log() with 4 will log as the default level which to Apache means an error (unchanged)

The docs I linked before talk about syslog and come from the unrelated PR 1702:
  https://github.com/php/php-src/pull/1702

1981 is not mentioned in the migration guide, but both are stated in the 7.1.0 changelog as
  Implemented logging to syslog with dynamic error levels.
  Added PHP to SAPI error severity mapping for logs.

So,

The first point (messages are now notices instead of errors) is an undocumented but clearly intentional change. Really, I would say that trigger_error() is more appropriate for error situations than error_log() is to begin with - especially if you want to consider attaching a significance to the message's severity. This is a slight break to BC but it's now been more than a year since 7.1.0 was released so I think this should be left in place and documented in the migration log alongside the other comment.

The second point (default/0 and 4 are different) is still questionable. I think I agree that the only apparent difference between the two - where the message gets sent, or rather the decision making process that results in the message going to the SAPI in both cases - should not affect the severity of the message. Given the first point, I think error_log() with 4 should explicitly state an error level of notice. Alternatively *all* error_log() messages could go as errors. Both are easy changes. Preserving full BC by having messages go back to being errors *just for the SAPI* is more awkward to fix since execution goes through the general-purpose PHP logging facility and that would mean automagically changing severity from notice to error partway through.

I think that choice of notice or error boils down to whether error_log() is considered to mean "log an error message" and messages indicate problems, or more "log a message to the place errors get logged" and messages are informational.
 [2018-02-02 21:05 UTC] bjohnson at paylease dot com
requinx, thanks for your followup and extended analysis.
 [2022-04-11 02:01 UTC] bkfake-php at yahoo dot com
uncaught exceptions handled via `set_exception_handler` are not logged... unlike `set_error_handler`which is logged depending on the return value of the callback,

So I'd like to log the uncaught exception with `error_log()`...  which logs it as a "notice"..

There should be param (such as the `$additional_headers` param) to specify the severity/level)
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Thu Nov 21 14:01:29 2024 UTC