Skip to content

Instantly share code, notes, and snippets.

@norberttech

norberttech/01-intro.md

Last active September 14, 2019 18:56
Show Gist options
  • Save norberttech/f0264ae1f95435b48bc6b8a44e79b056 to your computer and use it in GitHub Desktop.
Save norberttech/f0264ae1f95435b48bc6b8a44e79b056 to your computer and use it in GitHub Desktop.
Download ZIP
Is it a bug in php 7.2.22?
Raw
01-intro.md

I think there might be something wrong with memory leaks detection in php 7.2.x, this gist describes how I ran into this problem.

Recently I migrated https://github.com/norzechowicz/php-uamqp extension into Github Actions CI/CD. This extension brings uamqp 1.0 protocol into php (probably useless for most people but I work on Azure that works only on amqp 1.0) On gitub I have 3 actions, each for different php version. Action flow is simple:

  • Checkout source code
  • Installing required software
  • Clonning PHP from github
  • Checkout to PHP-7.y.z branch
  • Compile PHP
  • Configure & phpize extension
  • Compile extension
  • Run extensions test

On PHP 7.4 and 7.3.9 branches tests are passing but on PHP 7.2.22 functional tests that are actually connceting to Azure Service Bus are failing with following error:

[Fri Sep 13 22:05:52 2019]  Script:  '/home/runner/work/php-uamqp/php-uamqp/ext/tests/test_consumer_receiving_messages_peak_and_lock.php'
Segmentation fault (core dumped)

Termsig=11int(1)
Raw
02-environment.md

OS: Ubuntu 18-04 PHP Version: 7.2.22

PHP 7.2.23-dev (cli) (built: Sep 14 2019 17:02:20) ( NTS DEBUG )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies

Compiled with:

./configure \
  --without-iconv \
  --enable-debug \
  --enable-phpdbg \
  --enable-sockets \
  --with-curl \
  --with-openssl \
  --prefix={{ uamqpphp_php_bin }} \ 
  --with-config-file-path={{ uamqpphp_php_ini }}

Ansible Playbook used to provision vagrant machine where php and extension was compiled.

Raw
03-investigation.md

I noticed that this issue affects only tests where callback passed to the consumer is executed more than once:

General test that is going to send couple of messages into the destination through \UAMQP\Producer and receive them using \UAMQP\Consumer [tests/test_consumer_receiving_messages_peak_and_lock.phpt]
General test that is going to send couple of messages into the destination through \UAMQP\Producer and receive them using \UAMQP\Consumer [tests/test_consumer_receiving_messages_receive_and_delete.phpt]

The same test that runs callback from userland only once is passing:

\UAQMP\Producer sending message to destination in debug mode tests/test_sending_message_in_debug_mode.phpt

I started digging and I noticed that this is the code responsbile for the segfault:

    // initialize value (zval) of Message object constructor argument from string
    ZVAL_STRING(&constructor_arg, msg);

    //Initialize UAMQP\Message object
    object_init_ex(&message_object, php_uamqp_message_ce());

    // execute UAMQP\Message object constructor
    zend_call_method_with_1_params(&message_object, php_uamqp_message_ce(), &php_uamqp_message_ce()->constructor, "__construct", &constructor_result, &constructor_arg);

    // Prepare callback
    listen_method_callback.param_count = 1;
    listen_method_callback.params = &message_object;
    listen_method_callback.no_separation = 0;
    listen_method_callback.retval = &callback_result;

    // call listener callback with message object passed as first argument
    callback_return = zend_call_function(&listen_method_callback, &listen_method_callback_cache);

php_uamqp_consumer.c

I think it might be related the fact that the callback funciton needs Message object so I'm initializing it and then calling constructor on it passing string argument. Why do I think so? Because when I change this code into passing simple string message directly into callback without creating Message object everything is fine, test is failing (it's expecting object in var dump) but there is no segfault.

Code that works:

    ZVAL_STRING(&constructor_arg, msg);

//    //Initialize UAMQP\Message object
//    object_init_ex(&message_object, php_uamqp_message_ce());
//
//    // execute UAMQP\Message object constructor
//    zend_call_method_with_1_params(&message_object, php_uamqp_message_ce(), &php_uamqp_message_ce()->constructor, "__construct", &constructor_result, &constructor_arg);

    // Prepare callback
    listen_method_callback.param_count = 1;
    listen_method_callback.params = &constructor_arg;
    listen_method_callback.no_separation = 0;
    listen_method_callback.retval = &callback_result;

    // call listener callback with message object passed as first argument
    callback_return = zend_call_function(&listen_method_callback, &listen_method_callback_cache);

Yeah I know, I could remove Message object from the extension and makes my life easier but I'm not that type of person 😜

Raw
04-core-dump.md

I looked into core dump and I notcied that it fails on php_message_handler_for_zend function with %s(%d) : Freeing string format. In php source code this string is used in one place main/main.c#L1509

#if ZEND_DEBUG
			if (EG(error_reporting) & E_WARNING) {
				char memory_leak_buf[1024];

				if (message==ZMSG_MEMORY_LEAK_DETECTED) {
					zend_leak_info *t = (zend_leak_info *) data;

					snprintf(memory_leak_buf, 512, "%s(%d) :  Freeing " ZEND_ADDR_FMT " (%zu bytes), script=%s\n", t->filename, t->lineno, (size_t)t->addr, t->size, SAFE_FILENAME(SG(request_info).path_translated));
					if (t->orig_filename) {
						char relay_buf[512];

						snprintf(relay_buf, 512, "%s(%d) : Actual location (location was relayed)\n", t->orig_filename, t->orig_lineno);
						strlcat(memory_leak_buf, relay_buf, sizeof(memory_leak_buf));
					}
				} else {
					unsigned long leak_count = (zend_uintptr_t) data;

					snprintf(memory_leak_buf, 512, "Last leak repeated %ld time%s\n", leak_count, (leak_count>1?"s":""));
				}
#	if defined(PHP_WIN32)
				OutputDebugString(memory_leak_buf);
#	else
				fprintf(stderr, "%s", memory_leak_buf);
#	endif
			}
#endif

It looks this code is responsible for printing messages about memory leaks, when php is complied without --enable-debug I'm not getting this error.

Core dump backtrace:

Program terminated with signal SIGSEGV, Segmentation fault.
#0  strlen () at ../sysdeps/x86_64/strlen.S:106
106     ../sysdeps/x86_64/strlen.S: No such file or directory.
(gdb) bt
#0  strlen () at ../sysdeps/x86_64/strlen.S:106
#1  0x00000000008d2c02 in format_converter (odp=0x7ffd232284f0, fmt=0x108c769 "s(%d) :  Freeing 0x%016zx (%zu bytes), script=%s\n", ap=0x7ffd23228550)
    at /home/vagrant/php-uamqp/php-build/src/main/snprintf.c:997
#2  0x00000000008d369c in strx_printv (ccp=0x7ffd2322854c, buf=0x7ffd232288c0 "[Sat Sep 14 17:57:09 2019]  Script:  '/home/vagrant/php-uamqp/examples/publish_and_receive_to_service_bus.php'\n", 
    len=512, format=0x108c768 "%s(%d) :  Freeing 0x%016zx (%zu bytes), script=%s\n", ap=0x7ffd23228550) at /home/vagrant/php-uamqp/php-build/src/main/snprintf.c:1252
#3  0x00000000008d3947 in ap_php_snprintf (buf=0x7ffd232288c0 "[Sat Sep 14 17:57:09 2019]  Script:  '/home/vagrant/php-uamqp/examples/publish_and_receive_to_service_bus.php'\n", len=512, 
    format=0x108c768 "%s(%d) :  Freeing 0x%016zx (%zu bytes), script=%s\n") at /home/vagrant/php-uamqp/php-build/src/main/snprintf.c:1297
#4  0x00000000008cde7c in php_message_handler_for_zend (message=4, data=0x7ffd23229970) at /home/vagrant/php-uamqp/php-build/src/main/main.c:1509
#5  0x000000000096b7ac in zend_message_dispatcher (message=4, data=0x7ffd23229970) at /home/vagrant/php-uamqp/php-build/src/Zend/zend.c:1063
#6  0x0000000000930b44 in zend_mm_check_leaks (heap=0x7f6460800040) at /home/vagrant/php-uamqp/php-build/src/Zend/zend_alloc.c:2112
#7  0x0000000000930ea1 in zend_mm_shutdown (heap=0x7f6460800040, full=0, silent=0) at /home/vagrant/php-uamqp/php-build/src/Zend/zend_alloc.c:2184
#8  0x0000000000931c77 in shutdown_memory_manager (silent=0, full_shutdown=0) at /home/vagrant/php-uamqp/php-build/src/Zend/zend_alloc.c:2600
#9  0x00000000008cee2f in php_request_shutdown (dummy=0x0) at /home/vagrant/php-uamqp/php-build/src/main/main.c:1927
#10 0x0000000000a60f6f in do_cli (argc=3, argv=0x2bf02e0) at /home/vagrant/php-uamqp/php-build/src/sapi/cli/php_cli.c:1178
#11 0x0000000000a617dd in main (argc=3, argv=0x2bf02e0) at /home/vagrant/php-uamqp/php-build/src/sapi/cli/php_cli.c:1403
Raw
05-summary.md

Of course this might be just me, not understanding entirely how php works and missing something obvious but the fact that the same code works at PHP-7.3+ makes me think this might be actuall a bug. php_message_handler_for_zend was changed a bit between 7.2.22 and 7.3.0 version but this looks more like something related to memory leaks detection mechanism and that function might be actually another bug. Or I'm missing some important flag in compling process that in version 7.3 was added by default or maybe there is still a memory leak but I'm not getting any notification 😅

If there is anyone who would like to reproduce this issue, feel free to use Vagrant I prepared for the extension, everything should be ready for use out of the box, there is also a README.md where I described how to compile the code and run tests.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment