php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #81591 Fatal Error not properly logged in particular cases
Submitted: 2021-11-04 14:15 UTC Modified: 2021-11-04 15:15 UTC
From: anton at cpp dot in Assigned:
Status: Closed Package: *General Issues
PHP Version: 8.0.12 OS: FreeBSD 12.3
Private report: No CVE-ID: None
 [2021-11-04 14:15 UTC] anton at cpp dot in
Description:
------------
We had a few 500 pages without any traces in php.log after updating from 7.4 to 8.0.

The reason was a parameter type mismatch of in_array and array_key_exists functions, but TypeError was not logged if a warning previously occurred at the same line.

We had these warnings silenced with @$_REQUEST['whatever'], so no log messages were produced as a result of the crash.

While this pattern is ugly and should be refactored with proper checking and casting (and it was), I believe TypeError should be generated and properly logged in this case nonetheless.


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

error_reporting(E_ALL);

$not_array = false;

// Case #1, incorrect: only 'PHP Warning:  Undefined array key "nonexistant"' is logged
echo (array_key_exists($_REQUEST['nonexistant'], $not_array) ? "yes" : "no");

// Case #2, correct: 'PHP Fatal error:  Uncaught TypeError: array_key_exists(): Argument #2 ($array) must be of type array, bool given' is logged
$nonexistant = NULL;
echo (array_key_exists($nonexistant, $not_array) ? "yes" : "no");

// Case #3, correct: both Warning and Fatal error are logged
function my_ake(string|int $key, array $array): bool {return array_key_exists($key, $array);}
echo (my_ake($_REQUEST['nonexistant'], $not_array) ? "yes" : "no");



Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2021-11-04 14:27 UTC] nikic@php.net
-Status: Open +Status: Feedback
 [2021-11-04 14:27 UTC] nikic@php.net
I can't reproduce this. https://3v4l.org/iAGg4 shows that this works with error display, and trying with "-d display_errors=0 -d log_errors=1" instead I get the same result, with both errors logged.

Which ini settings are necessary to reproduce this?
 [2021-11-04 14:40 UTC] anton at cpp dot in
-Status: Feedback +Status: Open
 [2021-11-04 14:40 UTC] anton at cpp dot in
Thanks for the instant reply. Indeed it depends on the config.
I think it only happens with "ignore_repeated_errors=On".

The complete php.ini follows:
[PHP]
expose_php        = Off
cgi.fix_pathinfo  = 0
disable_functions = dl
enable_dl         = Off

date.timezone    = "UTC"
default_mimetype = "text/html"
default_charset  = "windows-1251"
default_socket_timeout = 10

max_execution_time = 3600 ; Maximum execution time of each script, in seconds
max_input_time     = 1200 ; Maximum amount of time each script may spend parsing request data
memory_limit       = 1024M ; Maximum amount of memory a script may consume (8MB)
post_max_size      = 200M
max_input_vars     = 500

upload_tmp_dir      = /tmp
upload_max_filesize = 200M

error_reporting  = E_ALL & ~E_NOTICE
display_errors   = Off
log_errors       = On
error_log        = /var/log/php.log
ignore_repeated_errors = On

;zend_extension = /usr/local/lib/php/20160303/opcache.so
;zend_extension = /usr/local/lib/php/20170718/opcache.so
;zend_extension = /usr/local/lib/php/20180731/opcache.so
;zend_extension = /usr/local/lib/php/20190902/opcache.so
zend_extension = /usr/local/lib/php/20200930/opcache.so
extension = apcu.so
extension = apc.so

apc.enabled      = On
apc.shm_segments = 1
apc.shm_size     = 32M

opcache.memory_consumption      = 128
opcache.interned_strings_buffer = 8
opcache.max_accelerated_files   = 2000
opcache.max_wasted_percentage   = 5
opcache.validate_timestamps     = 1
opcache.fast_shutdown           = 1

openssl.cafile = /usr/local/share/certs/ca-root-nss.crt
curl.cainfo = /usr/local/share/certs/ca-root-nss.crt
 [2021-11-04 15:10 UTC] nikic@php.net
-Status: Open +Status: Verified
 [2021-11-04 15:10 UTC] nikic@php.net
Thanks! I can reproduce the issue with ignore_repeated_errors=On.
 [2021-11-04 15:15 UTC] nikic@php.net
-Status: Verified +Status: Analyzed
 [2021-11-04 15:15 UTC] nikic@php.net
Eeek. As part of https://github.com/php/php-src/commit/975acfe71ebed352d86753a6deba3475acad3238 I accidentally inverted the condition in https://github.com/php/php-src/blob/52ccb4d16b9b6ead80bd12d98143e1bf68140e36/main/main.c#L1215, which means we now hide "repeated" errors if they're different, rather than if they're the same.
 [2021-11-04 15:25 UTC] git@php.net
Automatic comment on behalf of nikic
Revision: https://github.com/php/php-src/commit/4c171ed5eb0e379ebf4b1d5ab3af60e6c5327e23
Log: Fix bug #81591: ignore_repeated_errors broken
 [2021-11-04 15:25 UTC] git@php.net
-Status: Analyzed +Status: Closed
 
PHP Copyright © 2001-2022 The PHP Group
All rights reserved.
Last updated: Mon Oct 03 21:03:57 2022 UTC