php / php-src

The PHP Interpreter
https://www.php.net
Other
37.96k stars 7.73k forks source link

Significant reduction in performance when running phpunit after upgrade from 8.1.9 to 8.1.10 #9993

Open piszczek opened 1 year ago

piszczek commented 1 year ago

Description

Last time we did update from PHP 8.1.7 to 8.1.12 and we noticed that phpunit tests slowed down.

I did a research where is the problem and it looks that some changes between version 8.1.9 and 8.1.10 are causing performance issues.

The phpunit timing between PHP version Tests: 2981, Assertions: 19876, Incomplete: 1

PHP 8.1.7: Time: 05:13.226, Memory: 829.00 MB
PHP 8.1.9: Time: 05:23.756, Memory: 831.00 MB
PHP 8.1.10: Time: 12:25.195, Memory: 773.00 MB
PHP 8.1.12: Time: 11:59.423, Memory: 773.00 MB

I couldn't find any specific code which is raising issue; but there is analogy more tests then the differences in time are bigger (longer duration on 8.1.10)

PHP configuration: ```ini Configure Command => './configure' '--build=x86_64-linux-gnu' '--with-config-file-path=/usr/local/etc/php' '--with-config-file-scan-dir=/usr/local/etc/php/conf.d' '--enable-option-checking=fatal' '--with-mhash' '--with-pic' '--enable-ftp' '--enable-mbstring' '--enable-mysqlnd' '--with-password-argon2' '--with-sodium=shared' '--with-pdo-sqlite=/usr' '--with-sqlite3=/usr' '--with-curl' '--with-iconv' '--with-openssl' '--with-readline' '--with-zlib' '--disable-phpdbg' '--with-pear' '--with-libdir=lib/x86_64-linux-gnu' '--disable-cgi' '--enable-fpm' '--with-fpm-user=www-data' '--with-fpm-group=www-data' 'build_alias=x86_64-linux-gnu' Server API => Command Line Interface Virtual Directory Support => disabled Configuration File (php.ini) Path => /usr/local/etc/php Loaded Configuration File => /usr/local/etc/php/php-cli.ini Scan this dir for additional .ini files => /usr/local/etc/php/conf.d Additional .ini files parsed => /usr/local/etc/php/conf.d/docker-php-ext-amqp.ini, /usr/local/etc/php/conf.d/docker-php-ext-bcmath.ini, /usr/local/etc/php/conf.d/docker-php-ext-calendar.ini, /usr/local/etc/php/conf.d/docker-php-ext-dba.ini, /usr/local/etc/php/conf.d/docker-php-ext-exif.ini, /usr/local/etc/php/conf.d/docker-php-ext-gd.ini, /usr/local/etc/php/conf.d/docker-php-ext-gettext.ini, /usr/local/etc/php/conf.d/docker-php-ext-intl.ini, /usr/local/etc/php/conf.d/docker-php-ext-opcache.ini, /usr/local/etc/php/conf.d/docker-php-ext-pcntl.ini, /usr/local/etc/php/conf.d/docker-php-ext-pdo_mysql.ini, /usr/local/etc/php/conf.d/docker-php-ext-pdo_pgsql.ini, /usr/local/etc/php/conf.d/docker-php-ext-soap.ini, /usr/local/etc/php/conf.d/docker-php-ext-sockets.ini, /usr/local/etc/php/conf.d/docker-php-ext-sodium.ini, /usr/local/etc/php/conf.d/docker-php-ext-xsl.ini, /usr/local/etc/php/conf.d/docker-php-ext-zip.ini PHP API => 20210902 PHP Extension => 20210902 Zend Extension => 420210902 Zend Extension Build => API420210902,NTS PHP Extension Build => API20210902,NTS Debug Build => no Thread Safety => disabled Zend Signal Handling => enabled Zend Memory Manager => enabled Zend Multibyte Support => provided by mbstring IPv6 Support => enabled DTrace Support => disabled Registered PHP Streams => https, ftps, compress.zlib, php, file, glob, data, http, ftp, phar, zip Registered Stream Socket Transports => tcp, udp, unix, udg, ssl, tls, tlsv1.0, tlsv1.1, tlsv1.2, tlsv1.3 Registered Stream Filters => zlib.*, convert.iconv.*, string.rot13, string.toupper, string.tolower, convert.*, consumed, dechunk This program makes use of the Zend Scripting Language Engine: Zend Engine v4.1.12, Copyright (c) Zend Technologies with Zend OPcache v8.1.12, Copyright (c), by Zend Technologies _______________________________________________________________________ Configuration amqp Version => 1.11.0 Revision => release Compiled => Nov 17 2022 @ 14:16:42 AMQP protocol version => 0-9-1 librabbitmq version => 0.10.0 Default max channels per connection => 256 Default max frame size => 131072 Default heartbeats interval => 0 Directive => Local Value => Master Value amqp.auto_ack => 0 => 0 amqp.cacert => no value => no value amqp.cert => no value => no value amqp.channel_max => 256 => 256 amqp.connect_timeout => 0 => 0 amqp.frame_max => 131072 => 131072 amqp.global_prefetch_count => 0 => 0 amqp.global_prefetch_size => 0 => 0 amqp.heartbeat => 0 => 0 amqp.host => localhost => localhost amqp.key => no value => no value amqp.login => guest => guest amqp.password => guest => guest amqp.port => 5672 => 5672 amqp.prefetch_count => 3 => 3 amqp.prefetch_size => 0 => 0 amqp.read_timeout => 0 => 0 amqp.rpc_timeout => 0 => 0 amqp.sasl_method => 0 => 0 amqp.timeout => no value => no value amqp.verify => 1 => 1 amqp.vhost => / => / amqp.write_timeout => 0 => 0 bcmath BCMath support => enabled Directive => Local Value => Master Value bcmath.scale => 0 => 0 calendar Calendar support => enabled Core PHP Version => 8.1.12 Directive => Local Value => Master Value allow_url_fopen => On => On allow_url_include => Off => Off arg_separator.input => & => & arg_separator.output => & => & auto_append_file => no value => no value auto_globals_jit => On => On auto_prepend_file => no value => no value browscap => no value => no value default_charset => UTF-8 => UTF-8 default_mimetype => text/html => text/html disable_classes => no value => no value disable_functions => no value => no value display_errors => Off => Off display_startup_errors => Off => Off doc_root => no value => no value docref_ext => no value => no value docref_root => no value => no value enable_dl => Off => Off enable_post_data_reading => On => On error_append_string => no value => no value error_log => no value => no value error_prepend_string => no value => no value error_reporting => 22527 => 22527 expose_php => On => On extension_dir => /usr/local/lib/php/extensions/no-debug-non-zts-20210902 => /usr/local/lib/php/extensions/no-debug-non-zts-20210902 fiber.stack_size => no value => no value file_uploads => On => On hard_timeout => 2 => 2 highlight.comment => #FF8000 => #FF8000 highlight.default => #0000BB => #0000BB highlight.html => #000000 => #000000 highlight.keyword => #007700 => #007700 highlight.string => #DD0000 => #DD0000 html_errors => Off => Off ignore_repeated_errors => Off => Off ignore_repeated_source => Off => Off ignore_user_abort => Off => Off implicit_flush => On => On include_path => .:/usr/local/lib/php => .:/usr/local/lib/php input_encoding => no value => no value internal_encoding => no value => no value log_errors => On => On mail.add_x_header => Off => Off mail.force_extra_parameters => no value => no value mail.log => no value => no value max_execution_time => 0 => 0 max_file_uploads => 20 => 20 max_input_nesting_level => 64 => 64 max_input_time => -1 => -1 max_input_vars => 1000 => 1000 memory_limit => 8192M => 8192M open_basedir => no value => no value output_buffering => 0 => 0 output_encoding => no value => no value output_handler => no value => no value post_max_size => 48M => 48M precision => 14 => 14 realpath_cache_size => 4096K => 4096K realpath_cache_ttl => 120 => 120 register_argc_argv => On => On report_memleaks => On => On report_zend_debug => Off => Off request_order => GP => GP sendmail_from => no value => no value sendmail_path => /usr/sbin/sendmail -t -i => /usr/sbin/sendmail -t -i serialize_precision => -1 => -1 short_open_tag => Off => Off SMTP => localhost => localhost smtp_port => 25 => 25 sys_temp_dir => no value => no value syslog.facility => LOG_USER => LOG_USER syslog.filter => no-ctrl => no-ctrl syslog.ident => php => php unserialize_callback_func => no value => no value upload_max_filesize => 32M => 32M upload_tmp_dir => no value => no value user_dir => no value => no value user_ini.cache_ttl => 300 => 300 user_ini.filename => .user.ini => .user.ini variables_order => GPCS => GPCS xmlrpc_error_number => 0 => 0 xmlrpc_errors => Off => Off zend.assertions => -1 => -1 zend.detect_unicode => On => On zend.enable_gc => On => On zend.exception_ignore_args => On => On zend.exception_string_param_max_len => 0 => 0 zend.multibyte => Off => Off zend.script_encoding => no value => no value zend.signal_check => Off => Off ctype ctype functions => enabled curl cURL support => enabled cURL Information => 7.74.0 Age => 7 Features AsynchDNS => Yes CharConv => No Debug => No GSS-Negotiate => No IDN => Yes IPv6 => Yes krb4 => No Largefile => Yes libz => Yes NTLM => Yes NTLMWB => Yes SPNEGO => Yes SSL => Yes SSPI => No TLS-SRP => Yes HTTP2 => Yes GSSAPI => Yes KERBEROS5 => Yes UNIX_SOCKETS => Yes PSL => Yes HTTPS_PROXY => Yes MULTI_SSL => No BROTLI => Yes Protocols => dict, file, ftp, ftps, gopher, http, https, imap, imaps, ldap, ldaps, mqtt, pop3, pop3s, rtmp, rtsp, scp, sftp, smb, smbs, smtp, smtps, telnet, tftp Host => x86_64-pc-linux-gnu SSL Version => OpenSSL/1.1.1n ZLib Version => 1.2.11 libSSH Version => libssh2/1.9.0 Directive => Local Value => Master Value curl.cainfo => no value => no value date date/time support => enabled timelib version => 2021.17 "Olson" Timezone Database Version => 2022.4 Timezone Database => internal Default timezone => UTC Directive => Local Value => Master Value date.default_latitude => 31.7667 => 31.7667 date.default_longitude => 35.2333 => 35.2333 date.sunrise_zenith => 90.833333 => 90.833333 date.sunset_zenith => 90.833333 => 90.833333 date.timezone => UTC => UTC dba DBA support => enabled Supported handlers => cdb cdb_make db4 inifile flatfile Directive => Local Value => Master Value dba.default_handler => flatfile => flatfile dom DOM/XML => enabled DOM/XML API Version => 20031129 libxml Version => 2.9.10 HTML Support => enabled XPath Support => enabled XPointer Support => enabled Schema Support => enabled RelaxNG Support => enabled exif EXIF Support => enabled Supported EXIF Version => 0220 Supported filetypes => JPEG, TIFF Multibyte decoding support using mbstring => enabled Extended EXIF tag formats => Canon, Casio, Fujifilm, Nikon, Olympus, Samsung, Panasonic, DJI, Sony, Pentax, Minolta, Sigma, Foveon, Kyocera, Ricoh, AGFA, Epson Directive => Local Value => Master Value exif.decode_jis_intel => JIS => JIS exif.decode_jis_motorola => JIS => JIS exif.decode_unicode_intel => UCS-2LE => UCS-2LE exif.decode_unicode_motorola => UCS-2BE => UCS-2BE exif.encode_jis => no value => no value exif.encode_unicode => ISO-8859-15 => ISO-8859-15 fileinfo fileinfo support => enabled libmagic => 540 filter Input Validation and Filtering => enabled Directive => Local Value => Master Value filter.default => unsafe_raw => unsafe_raw filter.default_flags => no value => no value ftp FTP support => enabled FTPS support => enabled gd GD Support => enabled GD Version => bundled (2.1.0 compatible) FreeType Support => enabled FreeType Linkage => with freetype FreeType Version => 2.10.4 GIF Read Support => enabled GIF Create Support => enabled JPEG Support => enabled libJPEG Version => 6b PNG Support => enabled libPNG Version => 1.6.37 WBMP Support => enabled XPM Support => enabled libXpm Version => 30411 XBM Support => enabled WebP Support => enabled BMP Support => enabled AVIF Support => enabled TGA Read Support => enabled Directive => Local Value => Master Value gd.jpeg_ignore_warning => 1 => 1 gettext GetText Support => enabled hash hash support => enabled Hashing Engines => md2 md4 md5 sha1 sha224 sha256 sha384 sha512/224 sha512/256 sha512 sha3-224 sha3-256 sha3-384 sha3-512 ripemd128 ripemd160 ripemd256 ripemd320 whirlpool tiger128,3 tiger160,3 tiger192,3 tiger128,4 tiger160,4 tiger192,4 snefru snefru256 gost gost-crypto adler32 crc32 crc32b crc32c fnv132 fnv1a32 fnv164 fnv1a64 joaat murmur3a murmur3c murmur3f xxh32 xxh64 xxh3 xxh128 haval128,3 haval160,3 haval192,3 haval224,3 haval256,3 haval128,4 haval160,4 haval192,4 haval224,4 haval256,4 haval128,5 haval160,5 haval192,5 haval224,5 haval256,5 MHASH support => Enabled MHASH API Version => Emulated Support iconv iconv support => enabled iconv implementation => glibc iconv library version => 2.31 Directive => Local Value => Master Value iconv.input_encoding => no value => no value iconv.internal_encoding => no value => no value iconv.output_encoding => no value => no value intl Internationalization support => enabled ICU version => 67.1 ICU Data version => 67.1 ICU Unicode version => 13.0 Directive => Local Value => Master Value intl.default_locale => no value => no value intl.error_level => 0 => 0 intl.use_exceptions => Off => Off json json support => enabled libxml libXML support => active libXML Compiled Version => 2.9.10 libXML Loaded Version => 20910 libXML streams => enabled mbstring Multibyte Support => enabled Multibyte string engine => libmbfl HTTP input encoding translation => disabled libmbfl version => 1.3.2 mbstring extension makes use of "streamable kanji code filter and converter", which is distributed under the GNU Lesser General Public License version 2.1. Multibyte (japanese) regex support => enabled Multibyte regex (oniguruma) version => 6.9.6 Directive => Local Value => Master Value mbstring.detect_order => no value => no value mbstring.encoding_translation => Off => Off mbstring.http_input => no value => no value mbstring.http_output => no value => no value mbstring.http_output_conv_mimetypes => ^(text/|application/xhtml\+xml) => ^(text/|application/xhtml\+xml) mbstring.internal_encoding => no value => no value mbstring.language => neutral => neutral mbstring.regex_retry_limit => 1000000 => 1000000 mbstring.regex_stack_limit => 100000 => 100000 mbstring.strict_detection => Off => Off mbstring.substitute_character => no value => no value mysqlnd mysqlnd => enabled Version => mysqlnd 8.1.12 Compression => supported core SSL => supported extended SSL => supported Command buffer size => 4096 Read buffer size => 32768 Read timeout => 86400 Collecting statistics => Yes Collecting memory statistics => No Tracing => n/a Loaded plugins => mysqlnd,debug_trace,auth_plugin_mysql_native_password,auth_plugin_mysql_clear_password,auth_plugin_caching_sha2_password,auth_plugin_sha256_password API Extensions => pdo_mysql openssl OpenSSL support => enabled OpenSSL Library Version => OpenSSL 1.1.1n 15 Mar 2022 OpenSSL Header Version => OpenSSL 1.1.1n 15 Mar 2022 Openssl default config => /usr/lib/ssl/openssl.cnf Directive => Local Value => Master Value openssl.cafile => no value => no value openssl.capath => no value => no value pcntl pcntl support => enabled pcre PCRE (Perl Compatible Regular Expressions) Support => enabled PCRE Library Version => 10.39 2021-10-29 PCRE Unicode Version => 14.0.0 PCRE JIT Support => enabled PCRE JIT Target => x86 64bit (little endian + unaligned) Directive => Local Value => Master Value pcre.backtrack_limit => 1000000 => 1000000 pcre.jit => 1 => 1 pcre.recursion_limit => 100000 => 100000 PDO PDO support => enabled PDO drivers => sqlite, mysql, pgsql pdo_mysql PDO Driver for MySQL => enabled Client API version => mysqlnd 8.1.12 Directive => Local Value => Master Value pdo_mysql.default_socket => no value => no value pdo_pgsql PDO Driver for PostgreSQL => enabled PostgreSQL(libpq) Version => 13.8 pdo_sqlite PDO Driver for SQLite 3.x => enabled SQLite Library => 3.34.1 Phar Phar: PHP Archive support => enabled Phar API version => 1.1.1 Phar-based phar archives => enabled Tar-based phar archives => enabled ZIP-based phar archives => enabled gzip compression => enabled bzip2 compression => disabled (install ext/bz2) Native OpenSSL support => enabled Phar based on pear/PHP_Archive, original concept by Davey Shafik. Phar fully realized by Gregory Beaver and Marcus Boerger. Portions of tar implementation Copyright (c) 2003-2009 Tim Kientzle. Directive => Local Value => Master Value phar.cache_list => no value => no value phar.readonly => On => On phar.require_hash => On => On posix POSIX support => enabled readline Readline Support => enabled Readline library => 8.1 Directive => Local Value => Master Value cli.pager => no value => no value cli.prompt => \b \> => \b \> Reflection Reflection => enabled session Session Support => enabled Registered save handlers => files user Registered serializer handlers => php_serialize php php_binary Directive => Local Value => Master Value session.auto_start => Off => Off session.cache_expire => 180 => 180 session.cache_limiter => nocache => nocache session.cookie_domain => no value => no value session.cookie_httponly => no value => no value session.cookie_lifetime => 0 => 0 session.cookie_path => / => / session.cookie_samesite => no value => no value session.cookie_secure => 0 => 0 session.gc_divisor => 1000 => 1000 session.gc_maxlifetime => 1440 => 1440 session.gc_probability => 1 => 1 session.lazy_write => On => On session.name => PHPSESSID => PHPSESSID session.referer_check => no value => no value session.save_handler => files => files session.save_path => no value => no value session.serialize_handler => php => php session.sid_bits_per_character => 5 => 5 session.sid_length => 26 => 26 session.upload_progress.cleanup => On => On session.upload_progress.enabled => On => On session.upload_progress.freq => 1% => 1% session.upload_progress.min_freq => 1 => 1 session.upload_progress.name => PHP_SESSION_UPLOAD_PROGRESS => PHP_SESSION_UPLOAD_PROGRESS session.upload_progress.prefix => upload_progress_ => upload_progress_ session.use_cookies => 1 => 1 session.use_only_cookies => 1 => 1 session.use_strict_mode => 0 => 0 session.use_trans_sid => 0 => 0 SimpleXML SimpleXML support => enabled Schema support => enabled soap Soap Client => enabled Soap Server => enabled Directive => Local Value => Master Value soap.wsdl_cache => 1 => 1 soap.wsdl_cache_dir => /tmp => /tmp soap.wsdl_cache_enabled => On => On soap.wsdl_cache_limit => 5 => 5 soap.wsdl_cache_ttl => 86400 => 86400 sockets Sockets Support => enabled sodium sodium support => enabled libsodium headers version => 1.0.18 libsodium library version => 1.0.18 SPL SPL support => enabled Interfaces => OuterIterator, RecursiveIterator, SeekableIterator, SplObserver, SplSubject Classes => AppendIterator, ArrayIterator, ArrayObject, BadFunctionCallException, BadMethodCallException, CachingIterator, CallbackFilterIterator, DirectoryIterator, DomainException, EmptyIterator, FilesystemIterator, FilterIterator, GlobIterator, InfiniteIterator, InvalidArgumentException, IteratorIterator, LengthException, LimitIterator, LogicException, MultipleIterator, NoRewindIterator, OutOfBoundsException, OutOfRangeException, OverflowException, ParentIterator, RangeException, RecursiveArrayIterator, RecursiveCachingIterator, RecursiveCallbackFilterIterator, RecursiveDirectoryIterator, RecursiveFilterIterator, RecursiveIteratorIterator, RecursiveRegexIterator, RecursiveTreeIterator, RegexIterator, RuntimeException, SplDoublyLinkedList, SplFileInfo, SplFileObject, SplFixedArray, SplHeap, SplMinHeap, SplMaxHeap, SplObjectStorage, SplPriorityQueue, SplQueue, SplStack, SplTempFileObject, UnderflowException, UnexpectedValueException sqlite3 SQLite3 support => enabled SQLite Library => 3.34.1 Directive => Local Value => Master Value sqlite3.defensive => On => On sqlite3.extension_dir => no value => no value standard Dynamic Library Support => enabled Path to sendmail => /usr/sbin/sendmail -t -i Directive => Local Value => Master Value assert.active => On => On assert.bail => Off => Off assert.callback => no value => no value assert.exception => On => On assert.warning => On => On auto_detect_line_endings => Off => Off default_socket_timeout => 60 => 60 from => no value => no value session.trans_sid_hosts => no value => no value session.trans_sid_tags => a=href,area=href,frame=src,form= => a=href,area=href,frame=src,form= unserialize_max_depth => 4096 => 4096 url_rewriter.hosts => no value => no value url_rewriter.tags => form= => form= user_agent => no value => no value tokenizer Tokenizer Support => enabled xml XML Support => active XML Namespace Support => active libxml2 Version => 2.9.10 xmlreader XMLReader => enabled xmlwriter XMLWriter => enabled xsl XSL => enabled libxslt Version => 1.1.34 libxslt compiled against libxml Version => 2.9.10 EXSLT => enabled libexslt Version => 1.1.34 Zend OPcache Opcode Caching => Disabled Optimization => Disabled SHM Cache => Enabled File Cache => Disabled JIT => On Startup Failed => Opcode Caching is disabled for CLI Directive => Local Value => Master Value opcache.blacklist_filename => no value => no value opcache.consistency_checks => 0 => 0 opcache.dups_fix => Off => Off opcache.enable => On => On opcache.enable_cli => Off => Off opcache.enable_file_override => Off => Off opcache.error_log => no value => no value opcache.file_cache => no value => no value opcache.file_cache_consistency_checks => On => On opcache.file_cache_only => Off => Off opcache.file_update_protection => 2 => 2 opcache.force_restart_timeout => 180 => 180 opcache.huge_code_pages => Off => Off opcache.interned_strings_buffer => 8 => 8 opcache.jit => tracing => tracing opcache.jit_bisect_limit => 0 => 0 opcache.jit_blacklist_root_trace => 16 => 16 opcache.jit_blacklist_side_trace => 8 => 8 opcache.jit_buffer_size => 0 => 0 opcache.jit_debug => 0 => 0 opcache.jit_hot_func => 127 => 127 opcache.jit_hot_loop => 64 => 64 opcache.jit_hot_return => 8 => 8 opcache.jit_hot_side_exit => 8 => 8 opcache.jit_max_exit_counters => 8192 => 8192 opcache.jit_max_loop_unrolls => 8 => 8 opcache.jit_max_polymorphic_calls => 2 => 2 opcache.jit_max_recursive_calls => 2 => 2 opcache.jit_max_recursive_returns => 2 => 2 opcache.jit_max_root_traces => 1024 => 1024 opcache.jit_max_side_traces => 128 => 128 opcache.jit_prof_threshold => 0.005 => 0.005 opcache.lockfile_path => /tmp => /tmp opcache.log_verbosity_level => 1 => 1 opcache.max_accelerated_files => 10000 => 10000 opcache.max_file_size => 0 => 0 opcache.max_wasted_percentage => 5 => 5 opcache.memory_consumption => 128 => 128 opcache.opt_debug_level => 0 => 0 opcache.optimization_level => 0x7FFEBFFF => 0x7FFEBFFF opcache.preferred_memory_model => no value => no value opcache.preload => no value => no value opcache.preload_user => no value => no value opcache.protect_memory => Off => Off opcache.record_warnings => Off => Off opcache.restrict_api => no value => no value opcache.revalidate_freq => 2 => 2 opcache.revalidate_path => Off => Off opcache.save_comments => On => On opcache.use_cwd => On => On opcache.validate_permission => Off => Off opcache.validate_root => Off => Off opcache.validate_timestamps => On => On zip Zip => enabled Zip version => 1.19.5 Libzip version => 1.7.3 BZIP2 compression => Yes XZ compression => No ZSTD compression => No AES-128 encryption => Yes AES-192 encryption => Yes AES-256 encryption => Yes zlib ZLib Support => enabled Stream Wrapper => compress.zlib:// Stream Filter => zlib.inflate, zlib.deflate Compiled Version => 1.2.11 Linked Version => 1.2.11 Directive => Local Value => Master Value zlib.output_compression => Off => Off zlib.output_compression_level => -1 => -1 zlib.output_handler => no value => no value Additional Modules Module Name ```

PHP Version

PHP 8.1.10

Operating System

Docker Image PHP-FPM 8.1.10

Girgias commented 1 year ago

The diff between the two versions is: https://github.com/php/php-src/compare/php-8.1.10...php-8.1.9 which doesn't seem to indicate much. Are you sure opcache is in the same configuration between both versions?

piszczek commented 1 year ago

@Girgias thanks for the reply! I think this comparison is more accurate: https://github.com/php/php-src/compare/php-8.1.9...php-8.1.10?diff=unified and it shows a lot of more changes (or am I wrong to comparing those tags?)

Are you sure opcache is in the same configuration between both versions?

Yes I do, I ran tests with exact the same configuration. I also changed opcache.enable_cli to On but without any differences. Result was almost the same.

cmb69 commented 1 year ago

PHP 8.1.7: Time: 05:13.226, Memory: 829.00 MB PHP 8.1.9: Time: 05:23.756, Memory: 831.00 MB PHP 8.1.10: Time: 12:25.195, Memory: 773.00 MB PHP 8.1.12: Time: 11:59.423, Memory: 773.00 MB

If that is a general issue with phpunit performance, I wonder why that has not already been reported. Maybe @sebastianbergmann has heard about it?

sebastianbergmann commented 1 year ago

This is the first time I hear about a PHPUnit performance degredation related to PHP 8.1.9->PHP 8.1.10.

cmb69 commented 1 year ago

@piszczek, is the test suite you are referring to publicly available, so someone could check it?

sebastianbergmann commented 1 year ago

Furthermore (and just to rule out obvious mistakes): Are you using the same PHPUnit version? Does one PHP version have Xdebug enabled and the other does not?

piszczek commented 1 year ago

@cmb69 unfortunately code isn't public. I noticed this issue on commercial project in my work.

@sebastianbergmann XDEBUG is turned off we are using same version of between tests; PHPUnit 9.5.26, symfony/phpunit-bridge: 6.1.6

here is a configuration of phpunit.xml

<?xml version="1.0" encoding="UTF-8"?>
<!-- https://phpunit.de/manual/current/en/appendixes.configuration.html -->
<phpunit backupGlobals="false" colors="true"
         bootstrap="config/bootstrap.php"
>
    <php>
        <ini name="error_reporting" value="-1"/>
        <env name="APP_ENV" value="test"/>
        <env name="KERNEL_CLASS" value="App\Kernel"/>
        <env name="SHELL_VERBOSITY" value="-1"/>
        <env name="SYMFONY_DEPRECATIONS_HELPER" value="weak"/>
        <env name="SYMFONY_PHPUNIT_VERSION" value="9.5"/>
        <!-- ###+ symfony/mailer ### -->
        <!-- MAILER_DSN=smtp://localhost -->
        <!-- ###- symfony/mailer ### -->
    </php>

    <testsuites>
        <testsuite name="Project Test Suite">
            <directory>tests</directory>
        </testsuite>
    </testsuites>

    <listeners>
        <listener class="Symfony\Bridge\PhpUnit\SymfonyTestsListener"/>
    </listeners>

    <extensions>
        <extension class="DAMA\DoctrineTestBundle\PHPUnit\PHPUnitExtension"/>
    </extensions>
</phpunit>

(Extension: DAMA\DoctrineTestBundle\PHPUnit\PHPUnitExtension)

Project is Symfony based 6.1

cmb69 commented 1 year ago

unfortunately code isn't public. I noticed this issue on commercial project in my work.

I'm afraid this ticket is not actionable, if there is no reproducer.

piszczek commented 1 year ago

@cmb69 I raised issue with hope that someone had similar problem and maybe solution...

I will try to spend some time in December to reproduce that again and do more tests then I will back to you with code samples (that I can share)

gitnik commented 1 year ago

We are experiencing the exact same issue. Related to the same version upgrade. @piszczek have you been able to make any progress on this or find a workaround?

Girgias commented 1 year ago

@gitnik do you have a reproducible?

gitnik commented 1 year ago

No. But I will try to bisecting the diff from 8.1.9 to 8.1.10 to see which commit is the culprit

piszczek commented 1 year ago

@gitnik unfortunately I didn't find any workaround to this.

I did more tests in December - but unfortunately, I didn't have time to create a version for reproduction this issue.


What I observe, and this might be a hint ;

When I ran one PHPUnit test with one controller test (SymfonyTestClient in the same process) then the timing was the same in 8.1.9 and 8.1.10

but

When I ran one test with multiple controllers tests then the performance was significantly worse on PHP 8.1.10.

Sample PHP code


$start = microtome(true);
      $response = $this
            ->requestBuilder(
                $client,
                $method = 'GET',
                $url = sprintf(Endpoint::GET_PANEL, $panelId)
            )
            ->send()
        ;
$diff = microtome(true) - $start ; // one $response has the same time between version 8.1.9 and 8.1.10

// another test with multiple requests (request in the same process)
$start = microtome(true);
for ($i = 1; $i <= 100; $i++) {
      $response = $this
            ->requestBuilder(
                $client,
                $method = 'GET',
                $url = sprintf(Endpoint::GET_PANEL, $panelId)
            )
            ->send()
        ;
}
$diff = microtome(true) - $start ; // much worse timing on 8.1.10 (and also on 8.2  !)

and I saw some correlation when the session was created, without the creation of the session differences in timing were minimal. But this is theory, and maybe I did smth wrong - as I said I didn't have time to do better tests. (this is really time consuming)

sebastianbergmann commented 1 year ago

Can you elaborate on "much worse", in other words: what are the numbers you get?

piszczek commented 1 year ago

@sebastianbergmann I didn't save those results (because my December tests were not completed as I wanted it to be), but It was around 2x time slower on 8.1.10; and the dependence looks like - more executed tests than the time differences were bigger.... (first post)

sebastianbergmann commented 1 year ago

There are only 77 commits between PHP 8.1.9 and PHP 8.1.10, with even fewer actually changing the code. It should be relatively easy to find the exact change that causes this using git-bisect.

As you are experiencing this in a complex setup (Symfony, PHPUnit), it is unlikely that you can provide a minimal, self-contained test case to debug this issue.

What you can do is bisect between PHP 8.1.9 ("good") and PHP 8.1.10 ("bad"), build PHP for each bisect step, and run your tests. Then report the commit between PHP 8.1.9 and PHP 8.1.10 that causes this performance regression for you.

gitnik commented 1 year ago

This is the commit that doubles PHPUnit's run times for us: https://github.com/php/php-src/commit/0709578517e4367f8b69d013f0f30c3a21624fd3

Any hint as to what behaviour we should be looking for in our code (or dependencies) that could potentially cause this increase in run time, given this commit?

gitnik commented 1 year ago

I'm not sure if that's expected but here's what gc_status returns after two test runs:

fast binary (pre https://github.com/php/php-src/commit/0709578517e4367f8b69d013f0f30c3a21624fd3):

array(4) {
  ["runs"]=>
  int(89)
  ["collected"]=>
  int(6020079)
  ["threshold"]=>
  int(230001)
  ["roots"]=>
  int(183697)
}

slow binary (at https://github.com/php/php-src/commit/0709578517e4367f8b69d013f0f30c3a21624fd3):

array(4) {
  ["runs"]=>
  int(1889)
  ["collected"]=>
  int(6307068)
  ["threshold"]=>
  int(10001)
  ["roots"]=>
  int(6231)
}
derickr commented 1 year ago

Yeah, running the GC n^2 times would definitely decrease performance... You can also see that before the "fix" the buffer has grown to 230001 instead of the default 10001 (which is what the bug attempted to fix).

As a workaround, you could try turning the GC off with zend.enable_gc=0 in php.ini (or on the command line with:

php -dzend.enable_gc=0 vendor/bin/phpunit ...
gitnik commented 1 year ago

Disabling GC adds one more gig of memory (2.6GB -> 3.6GB) but decreases time from 8-9 minutes to 4 minutes (even faster than pre fix obviously).

You're saying "workaround" but if I interpret your response and the code change correctly, the behaviour we're seeing is expected? Given the previously incorrectly calculated treshold we we're just "lucky"?

staabm commented 1 year ago

@gitnik I think you should check your code for circular dependencies

bwoebi commented 1 year ago

@staabm TBH, I think it's a relatively common pattern in complex tests to have closures which hold a reference to the test class object (the implcit $this binding) and from there it goes downhill.

sebastianbergmann commented 1 year ago

I assume that complex object graphs are stored in private properties of the test object without cleaning them up in tearDown(). This will no longer be a problem in a future version of PHPUnit. Until then: clean up in tearDown() or stop storing complex object graphs in test object properties.

derickr commented 1 year ago

@gitnik

You're saying "workaround" but if I interpret your response and the code change correctly, the behaviour we're seeing is expected? Given the previously incorrectly calculated treshold we we're just "lucky"?

Yes.

bwoebi commented 1 year ago

But ultimately it also means that the heuristics we are using for growing the GC root buffer are not well suited for his code.

staabm commented 1 year ago

TBH, I think it's a relatively common pattern in complex tests to have closures which hold a reference to the test class object (the implcit $this binding) and from there it goes downhill.

@bwoebi thats a great point. I did not consider this as we use php-cs fixer to clean this up automatically

@gitnik in case you have this problem, the cs fixer rule might help you

piszczek commented 1 year ago

In my case On PHP 8.1.9: Time: 05:33.321, Memory: 878.01 MB On PHP 8.2.1 with zend.enable_gc = 0 Time: 04:23.903, Memory: 5.46 GB

gitnik commented 1 year ago

@staabm

in case you have this problem, the cs fixer rule might help you

Unfortunately that didn't help. I also spend all day tracking down cyclical dependencies and looking for missing tearDown actions, but no luck so far.

piszczek commented 1 year ago

hi @bwoebi

You mentioned that PHP is not well suited for this kind of code, do you think PHP team will work on this?

@gitnik did you solve your problem?


We did a further investigation of our code - and we found that indirectly our OAS pre-validation is causing those performance issues.

Each request is validated against schema declared in our OpenAPI Schema. The OpenAPI object is large (because it contains every endpoint definition) and it contains around 60000 objects - objects are cached as valid php code and are loaded once when the first request in test suite is runned.

The problem only appears in tests when they are run in a single process. GC at some point hits the limit and we guess it causes problem.

Unfortunatelly we stuck at this and we have below options:

gitnik commented 1 year ago

No we did not. We were able to shave off a few seconds by setting null in some tearDown methods, but never came close to the "original" performance. We opted to simply disable GC and accept the increase in memory.

Once PHP 8.3 and the updated gc_status() are released (see this article) we plan to do another round of investigations.

sebastianbergmann commented 1 year ago

FYI: Starting with PHPUnit 10.1, the telemetry for events emitted by PHPUnit will include information from gc_status().

elnur commented 1 year ago

I'm experiencing a significant slowdown of our test suite with 8.2. Not sure if it's related.

Our tests finish in 19 minutes on PHP 8.1 and it took 3 hours to get to 52% on PHP 8.2. I just couldn't wait anymore and aborted the run. So I'm stuck with PHP 8.1 for now.

Also the memory usage went up crazily — like over 20G of RAM. While on 8.1 it was around 1-2G.

sebastianbergmann commented 1 year ago

Our tests finish in 19 minutes on PHP 8.1 and it took 3 hours to get to 52% on PHP 8.2. I just couldn't wait anymore and aborted the run. So I'm stuck with PHP 8.1 for now.

Same PHP configuration and PHPUnit version/configuration?

elnur commented 1 year ago

Same PHP configuration and PHPUnit version/configuration?

Yep. Everything else is the same. We use Vagrant with Ansible, so the VMs are destroyed and configured from scratch when upgrading PHP and other stuff. I just changed 8.1 to 8.2.

Using the ondrej/php PPA — if that's anyhow important.

elnur commented 1 year ago

Figured it out. The cause was a crazy number of deprecation warnings. I guess they all get accumulated during a test run to be printed out after the run is finished. There were so many of them that it consumed tens of GBs of RAM. And I guess the slowdown was caused by having to swap RAM because it exceeded my machine's capacity.

sebastianbergmann commented 1 year ago

@elnur You never mentioned which version of PHPUnit you are using experiencing this with.

elnur commented 1 year ago

@elnur You never mentioned which version of PHPUnit you are using experiencing this with.

9.6.6. Why? Are deprecation warnings handled differently in 10?

sebastianbergmann commented 1 year ago

9.6.6. Why? Are deprecation warnings handled differently in 10?

Yes, see the section titled "Test Outcome versus Test Issues" in the PHPUnit 10 release announcement.

elnur commented 1 year ago

Yes, see the section titled "Test Outcome versus Test Issues" in the PHPUnit 10 release announcement.

Good to know. Thanks. I tried upgrading to PHPUnit 10 while dealing with this PHP 8.2 problem, but couldn't because of the BC breaks. Will get to it later.

stepozer commented 1 year ago

Found same problem. We have big Symfony 5.2 project with unit tests on PHP Unit 9.6.3. After update from PHP 8.1.9 to PHP 8.1.10 our tests was slow down:

PHP 8.1.9:  Time: 02:34.485, Memory: 1.13 GB  
PHP 8.1.10: Time: 04:53.430, Memory: 1.12 GB

please let me know how we can fix this issue. Update to PHPUnit 10 can fix this issue?

sebastianbergmann commented 1 year ago

Update to PHPUnit 10 can fix this issue?

Unlikely.

stepozer commented 1 year ago

We found an a possible solution. If we run tests in parallel mode with paratest it give us more fast result on PHP 8.1.10 and 8.2 that we have before with paratest on PHP 8.1.9. So @piszczek and @elnur I suggest try to run tests in parallel mode. Provably it will give you a chance update PHP without significant reduction in performance

piszczek commented 1 year ago

hi @stepozer

unfortunately paratest won't work for us. We are using doctrine-test-bundle which works on the rollback/transactions - but with a combination with paratests it generates db errors (described on that link).

In a previous post, I suggested that our OAS Schema validator causes those performance issues. We spent some time refactoring this library. It helped us when we ran a group of tests (we tested this issue on the specific directory with tests) - and we were very happy that finally, we got it - but when we ran all the test - we stuck again 🐒 - our OAS library was unguilty. At the beginning of the tests, the timing was the same on 8.1.9 and 8.2.0, but later 8.1.9 was faster; after More tests = the differences were bigger.

We spent a lot of time investigating that, team are tired ("@piszczek, leave it we can work on 8.1.9 for now") . We decided to leave this topic, and we will back to this after 3 months.

We still have to check suggestions with deprecation messages.

stepozer commented 1 year ago

@piszczek interesting... We also using Symfony + doctrine-test-bundle with paratest and it is working well for us. Do you create DB for each paratest process? Because it is require setup separate DB for each execution thread. Also we split redis for each thread.

piszczek commented 1 year ago

@stepozer no, we ran that test on the same database (MariaDB). 🤔 Thanks, for the suggestion. So you are using, let say 8 test databases? eg. test_1, test_2 ... for each thread?

stepozer commented 1 year ago

@piszczek on one DB it will not work. Each thread should be run in separate environment (DB, redis, etc). And yes, we create 8 DB as I remember. I suggest try to use 8 threads. This is documentation:

https://github.com/paratestphp/paratest#test-token

so paratest generate special ENV variable that can be used for setting DB number. This give us speed up for our tests into 2 or 3 times. I don't remember

piszczek commented 1 year ago

@stepozer thank for this; We will test this approach, and I will back with answer .

elnur commented 1 year ago

I've solved my PHP 8.2 problem by updating dependencies that caused many deprecation notices and also refactoring our code to remove the remaining deprecation notices. So it's all good here. But I guess my problem was different from the one this issue is about.

drzraf commented 1 year ago

PHPUnit 9.5.28, 139 tests, 411 assertions, 100% pass (a Symfony project ~4400 LoC testsuite bootstraping many kernels & co)

Reference run, php 7.4

Time: 02:16, Memory: 267.00 MB

Run 2, php 8.2 (zend.enable_gc=0)

Time: 02:14, Memory: 772.50 MB Remaining self deprecation notices (209)

Run 3, php 8.2 (zend.enable_gc=0) after fixing some deprecations

Time: 02:17, Memory: 778.50 MB Remaining indirect deprecation notices (90)

Run 4, php 8.2 (with enable_gc)

Time > 20 minutes (^C since it's pure craziness)