php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login

go to bug id or search bugs for

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
View Developer Edit
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: anton at cpp dot in
New email:
PHP Version: OS:

 

 [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

Pull Requests

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
 [2021-11-08 15:18 UTC] nikic@php.net 
Related To: Bug #81600
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved. 		Last updated: Sat Nov 23 08:01:28 2024 UTC