elastic / elastic/apm-agent-php

Simple Hello World Program Leaks Under Valgrind

Open
#599 0 comments 0 reactions 0 assignees View on GitHub
8.12-candidate agent-php bug priority: high triaged
Dominant language
PHP
Stars
268
Forks
86
PR merge metrics
No merged PRs in 30d

Description

**Describe the bug**
I've started poking around the edges of the PHP Agent's memory usage [with valgrind](https://valgrind.org/). I've noticed that even with a small hello world program that PHP will leak some blocks with the agent installed and that these blocks aren't leaked when the agent's not installed. (see reproduction below)

Questions:

1. Looking at the reproduction below, does anything pop out as a potential culprit?
2. Are there instructions anywhere for building the PHP Agent extension with debug symbols enabled?

Next Steps:

1. Run with an agent that has its debugging symbols to see if we can zero in on the issue
2. Try with non-trivial PHP code that exercises the `curl` and `PDO` functions/methods we've instrumented

## To Reproduce

### Install Docker Container with Valgrind

I've [setup a GitHub repository](https://github.com/astorm/elastic-apm-php-valgrind) with a docker file that will spin up an unbuntu environment with a version of the PHP command line _with_ debugging symbols installed AND a copy of valgrind.

$ git clone git@github.com:astorm/elastic-apm-php-valgrind.git
$ cd elastic-apm-php-valgrind
$ docker build -t astorm/debug .

Once you've run the above commands to build a container image, run-and-shell into it (from the same directory) and move to the `/working` directory

$ docker run -it -v `pwd`:/working astorm/debug bash
root@e68a4421fd0f:/# cd /working
root@e68a4421fd0f:/working# ls
Dockerfile invoke-valgrind.bash php74-default.supp test.php

You can invoke valgrind via the `invoke-valgrind.bash` shell script (look inside `./invoke-valgrind.bash` if you're curious about the specific valgrind flags)

# ./invoke-valgrind.bash

By default, this will run valgrind with a suppressions file to hide certain warnings, but at the end of the run you should see

==16== HEAP SUMMARY:
==16== in use at exit: 0 bytes in 0 blocks
==16== total heap usage: 15,549 allocs, 15,549 frees, 2,408,310 bytes allocated
==16==
==16== All heap blocks were freed -- no leaks are possible

### Run with Agent

Once you've done the above, you'll want to install the PHP Agent inside the docker container.

root@e68a4421fd0f:/working# curl -LO 'https://github.com/elastic/apm-agent-php/releases/download/v1.3.1/apm-agent-php_1.3.1_all.deb'
//...
root@e68a4421fd0f:/working# dpkg -i apm-agent-php_1.3.1_all.deb

and then invoke valgrind

# ./invoke-valgrind.bash

You'll get a large amount of output, much of it warnings. However, in the heap summary section you'll see we end up with some leaks

==83== HEAP SUMMARY:
==83== in use at exit: 87 bytes in 4 blocks
==83== total heap usage: 17,402 allocs, 17,398 frees, 4,898,194 bytes allocated
==83==
==83== 16 bytes in 1 blocks are still reachable in loss record 1 of 4
==83== at 0x4843839: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==83== by 0x401440D: malloc (rtld-malloc.h:56)
==83== by 0x401440D: allocate_dtv_entry (dl-tls.c:673)
==83== by 0x401440D: allocate_and_init (dl-tls.c:698)
==83== by 0x401440D: tls_get_addr_tail (dl-tls.c:896)
==83== by 0x401BC5B: __tls_get_addr (tls_get_addr.S:55)
==83== by 0x83E7319: ???
==83== by 0x4016D91: call_destructors (dl-close.c:128)
==83== by 0x5122414: _dl_catch_exception (dl-error-skeleton.c:182)
==83== by 0x4017370: _dl_close_worker.part.0.isra.0 (dl-close.c:300)
==83== by 0x40182F5: _dl_close_worker (dl-close.c:149)
==83== by 0x40182F5: _dl_close (dl-close.c:873)
==83== by 0x51223B7: _dl_catch_exception (dl-error-skeleton.c:208)
==83== by 0x5122482: _dl_catch_error (dl-error-skeleton.c:227)
==83== by 0x503E02D: _dlerror_run (dlerror.c:138)
==83== by 0x503DD57: dlclose@@GLIBC_2.34 (dlclose.c:31)
==83==
==83== 20 bytes in 1 blocks are still reachable in loss record 2 of 4
==83== at 0x4843839: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==83== by 0x401440D: malloc (rtld-malloc.h:56)
==83== by 0x401440D: allocate_dtv_entry (dl-tls.c:673)
==83== by 0x401440D: allocate_and_init (dl-tls.c:698)
==83== by 0x401440D: tls_get_addr_tail (dl-tls.c:896)
==83== by 0x401BC5B: __tls_get_addr (tls_get_addr.S:55)
==83== by 0x80CDB93: ???
==83== by 0x80CDFBC: ???
==83== by 0x80D0E3F: ???
==83== by 0x80BE551: ???
==83== by 0x4011B1D: call_init.part.0 (dl-init.c:70)
==83== by 0x4011C07: call_init (dl-init.c:33)
==83== by 0x4011C07: _dl_init (dl-init.c:117)
==83== by 0x5122414: _dl_catch_exception (dl-error-skeleton.c:182)
==83== by 0x40165C9: dl_open_worker (dl-open.c:788)
==83== by 0x51223B7: _dl_catch_exception (dl-error-skeleton.c:208)
==83==
==83== 35 bytes in 1 blocks are indirectly lost in loss record 3 of 4
==83== at 0x4843839: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==83== by 0x5055BDE: strdup (strdup.c:42)
==83== by 0x7FF0435: ???
==83== by 0x7F4CCF7: ???
==83== by 0x7F66717: ???
==83== by 0x7F5A2AB: ???
==83== by 0x436528: ZEND_DO_FCALL_BY_NAME_SPEC_RETVAL_UNUSED_HANDLER (zend_vm_execute.h:1442)
==83== by 0x436528: execute_ex (zend_vm_execute.h:53513)
==83== by 0x3A1EA3: zend_call_function (zend_execute_API.c:820)
==83== by 0x3A218B: _call_user_function_ex (zend_execute_API.c:645)
==83== by 0x7F7A170: ???
==83== by 0x7F7A611: ???
==83== by 0x7F785EE: ???
==83==
==83== 51 (16 direct, 35 indirect) bytes in 1 blocks are definitely lost in loss record 4 of 4
==83== at 0x4843839: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==83== by 0x7FF0448: ???
==83== by 0x7F4CCF7: ???
==83== by 0x7F66717: ???
==83== by 0x7F5A2AB: ???
==83== by 0x436528: ZEND_DO_FCALL_BY_NAME_SPEC_RETVAL_UNUSED_HANDLER (zend_vm_execute.h:1442)
==83== by 0x436528: execute_ex (zend_vm_execute.h:53513)
==83== by 0x3A1EA3: zend_call_function (zend_execute_API.c:820)
==83== by 0x3A218B: _call_user_function_ex (zend_execute_API.c:645)
==83== by 0x7F7A170: ???
==83== by 0x7F7A611: ???
==83== by 0x7F785EE: ???
==83== by 0x7F6AD5C: ???
==83==
==83== LEAK SUMMARY:
==83== definitely lost: 16 bytes in 1 blocks
==83== indirectly lost: 35 bytes in 1 blocks
==83== possibly lost: 0 bytes in 0 blocks
==83== still reachable: 36 bytes in 2 blocks
==83== suppressed: 0 bytes in 0 blocks

**Expected behavior**
With the agent install PHP runs clean under valgrind (clean meaning `in use at exit: 0 bytes in 0 blocks`/`All heap blocks were freed -- no leaks are possible`)

**Actual behavior**
With the agent installed PHP runs with leaks under valgrind. (see above)

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.