Bug #79794 [Opn]: Speed degradation with many NOTICEs and set_error_handler

Edit report at https://bugs.php.net/bug.php?id=79794&edit=1 ID: 79794 User updated by: oleg at salionov dot ru Reported by: oleg at salionov dot ru Summary: Speed degradation with many NOTICEs and set_error_handler Status: Open Type: Bug Package: Performance problem Operating System: Debian GNU/Linux 9 PHP Version: 7.4.7 Block user comment: N Private report: N New Comment: On 7.4.6 I have results on test script <= 1s in output On 7.4.7 I have results on test script >= 20s Previous Comments: ------------------------------------------------------------------------ [2020-07-05 00:18:49] oleg at salionov dot ru Description: ------------ I have speed degradation when code have error_handler On 7.4.6 I have results <= 1s in output On 7.4.7 I have results >= 20s here is results of strace -c on 2 versions of PHP PHP 7.4.6 strace -c php test.php double(28.002721071243) % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 99.43 4.600459 46 100009 gettimeofday 0.11 0.004931 105 47 munmap 0.09 0.004235 21 202 mmap 0.06 0.003006 21 144 mprotect 0.06 0.002844 26 111 19 open 0.06 0.002577 32 80 rt_sigaction 0.05 0.002182 20 111 fstat 0.04 0.001781 19 96 close 0.04 0.001768 19 93 read 0.02 0.001028 19 55 54 access 0.01 0.000420 19 22 brk 0.01 0.000378 24 16 4 stat 0.01 0.000337 26 13 1 lstat 0.01 0.000236 11 22 futex 0.00 0.000176 15 12 12 ioctl 0.00 0.000144 48 3 getcwd 0.00 0.000080 80 1 write 0.00 0.000070 35 2 getrlimit 0.00 0.000061 61 1 execve 0.00 0.000049 49 1 clock_gettime 0.00 0.000048 24 2 rt_sigprocmask 0.00 0.000046 23 2 getdents 0.00 0.000035 35 1 lseek 0.00 0.000033 33 1 socket 0.00 0.000028 28 1 sysinfo 0.00 0.000023 23 1 clock_getres 0.00 0.000007 7 1 readlink 0.00 0.000005 5 1 arch_prctl 0.00 0.000005 5 1 set_tid_address 0.00 0.000005 5 1 getrandom 0.00 0.000004 4 1 set_robust_list ------ ----------- ----------- --------- --------- ---------------- 100.00 4.627001 101054 90 total PHP 7.4.7 strace -c php test.php double(67.658080101013) % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 43.95 1637.994611 16378 100009 gettimeofday 36.99 1378.316977 19977 68996 munmap 18.46 688.027506 19834 34689 mmap 0.11 4.025349 27954 144 mprotect 0.08 3.104728 27971 111 19 open 0.08 3.102637 27952 111 fstat 0.07 2.683311 27951 96 close 0.07 2.599923 27956 93 read 0.06 2.236857 27961 80 rt_sigaction 0.04 1.537768 27959 55 54 access 0.02 0.615141 27961 22 brk 0.02 0.614762 27944 22 futex 0.01 0.447294 27956 16 4 stat 0.01 0.363522 27963 13 1 lstat 0.01 0.335352 27946 12 12 ioctl 0.00 0.083917 27972 3 getcwd 0.00 0.055945 27973 2 rt_sigprocmask 0.00 0.055918 27959 2 getdents 0.00 0.055898 27949 2 getrlimit 0.00 0.027985 27985 1 clock_gettime 0.00 0.027973 27973 1 lseek 0.00 0.027967 27967 1 socket 0.00 0.027964 27964 1 sysinfo 0.00 0.027962 27962 1 write 0.00 0.027960 27960 1 clock_getres 0.00 0.027948 27948 1 execve 0.00 0.027945 27945 1 readlink 0.00 0.027943 27943 1 getrandom 0.00 0.027942 27942 1 arch_prctl 0.00 0.027937 27937 1 set_tid_address 0.00 0.027937 27937 1 set_robust_list 0.00 0.021011 10506 2 mremap ------ ----------- ----------- --------- --------- ---------------- 100.00 3726.613890 204492 90 total OPCodes are identical in both versions I think problem in that commit https://github.com/php/php-src/commit/ccd41e083359cf6dd264f88806dce4cc49d9358e Test script: --------------- <?php error_reporting(E_NOTICE); function my_error_handler($code, $msg, $file, $line) { } $old_error_handler = set_error_handler('my_error_handler'); $time = microtime(true); $a = []; $i = 50000; while ($i-- > 0) { if ( !is_array($a[$i]) || !in_array($i, $a[$i], true) ) { $a[$i][] = $i; } } var_dump(microtime(true) - $time); ------------------------------------------------------------------------ -- Edit this bug report at https://bugs.php.net/bug.php?id=79794&edit=1