DataDog / dd-trace-php

Datadog PHP Clients
https://docs.datadoghq.com/tracing/setup/php
Other
497 stars 155 forks source link

Segfault on PHP FPM 7.2.15 / Laravel 5.7, how to debug/proceed? #304

Closed stayallive closed 5 years ago

stayallive commented 5 years ago

As the title says I'm experiencing a segfault hitting our GraphQL endpoint, so far found nothing else. How do I provide enough information to be a useful report?

labbati commented 5 years ago

Hi, thanks for reporting this. We had other reports (#302) of segmentation fault with php 7.2. We are currently looking into this and we will update this issue as soon as we make progresses.

stayallive commented 5 years ago

Perfect, let me know if there is something I can do to provide more info / context :)

labbati commented 5 years ago

Thanks :)! One question actually: which server are you using? Nginx, apache?

labbati commented 5 years ago

Also, which OS?

stayallive commented 5 years ago

NGINX on Ubuntu 16.04. PHP is installed from: https://deb.sury.org/ (not the distro default).

To be really exact in case it helps:

~# nginx -V
nginx version: nginx/1.15.8
built with OpenSSL 1.0.2g  1 Mar 2016
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -fPIC -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now -fPIC' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --modules-path=/usr/lib/nginx/modules --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-compat --with-debug --with-pcre-jit --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-http_slice_module --with-threads --with-http_addition_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_sub_module --with-http_xslt_module=dynamic --with-stream=dynamic --with-stream_ssl_module --with-stream_ssl_preread_module --with-mail=dynamic --with-mail_ssl_module --add-dynamic-module=/build/nginx-mPKrjP/nginx-1.15.8/debian/modules/http-auth-pam --add-dynamic-module=/build/nginx-mPKrjP/nginx-1.15.8/debian/modules/http-dav-ext --add-dynamic-module=/build/nginx-mPKrjP/nginx-1.15.8/debian/modules/http-echo --add-dynamic-module=/build/nginx-mPKrjP/nginx-1.15.8/debian/modules/http-upstream-fair --add-dynamic-module=/build/nginx-mPKrjP/nginx-1.15.8/debian/modules/http-subs-filter

~# php -v
PHP 7.2.15-1+ubuntu16.04.1+deb.sury.org+1 (cli) (built: Feb  8 2019 15:37:29) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies
    with Zend OPcache v7.2.15-1+ubuntu16.04.1+deb.sury.org+1, Copyright (c) 1999-2018, by Zend Technologies

~# uname -a
Linux cert-chief-app 4.4.0-142-generic #168-Ubuntu SMP Wed Jan 16 21:00:45 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

~# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 16.04.5 LTS
Release:    16.04
Codename:   xenial

(It's a server provisioned by Laravel Forge)

labbati commented 5 years ago

Thanks, very useful 👍 ! cc @pawelchcki!

labbati commented 5 years ago

Hi, we weren't able to reproduce the same issue using any of our test environments, including php-fpm and nginx/apache. So we added the possibility to log a low level stacktrace when a segfault occurs. This is included in the new release 0.13.2.

In order to achieve this, the following is required:

If you could do this and provide us with such stacktrace it would be awesome.

Note: please review the dump before uploading it as it may contain reserved data that you want to remove (e.g. passwords).

Thanks for the patience and the help!

stayallive commented 5 years ago

And here it is:

``` 2019/02/19 08:41:39 [error] 3687#3687: *9913 FastCGI sent in stderr: "PHP message: Datadog PHP Trace extension (DEBUG MODE) PHP message: Received Signal 11 PHP message: Note: Backtrace below might be incomplete and have wrong entries due to optimized runtime PHP message: Backtrace: PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(ddtrace_backtrace_handler+0x4f) [0x7f27b885df17] PHP message: /lib/x86_64-linux-gnu/libc.so.6(+0x354b0) [0x7f27ccb264b0] PHP message: php-fpm: pool www(_emalloc+0x74) [0x555a569625e4] PHP message: php-fpm: pool www(zend_objects_new+0x28) [0x555a569c46a8] PHP message: php-fpm: pool www(_object_and_properties_init+0x51) [0x555a5698cef1] PHP message: php-fpm: pool www(+0x32fe46) [0x555a56a2be46] PHP message: php-fpm: pool www(execute_ex+0x4da8) [0x555a56a387b8] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x5 2019/02/19 08:41:39 [error] 3687#3687: *9913 FastCGI sent in stderr: "bug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so 2019/02/19 08:41:39 [error] 3687#3687: *9913 FastCGI sent in stderr: "722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(zend_call_function+0x742) [0x555a56979d72] PHP message: php-fpm: pool www(+0x1b9d81) [0x555a568b 2019/02/19 08:41:39 [error] 3687#3687: *9913 FastCGI sent in stderr: "age: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: / 2019/02/19 08:41:39 [error] 3687#3687: *9913 FastCGI sent in stderr: "e: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php 2019/02/19 08:41:39 [error] 3687#3687: *9913 FastCGI sent in stderr: "26] PHP message: php-fpm: pool www(zend_call_function+0x742) [0x555a56979d72] PHP message: php-fpm: pool www(+0x1b9d81) [0x555a568b5d81] PHP message: php-fpm: pool www(+0x2d2e05) [0x555a569cee05] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(zend_call_function+0x742) [0x555a56979d72] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x3407) [0x7f27b885d407] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(ddtrace_wrap_fcall+0x2e1) [0x7f27b885d878] PHP message: php-fpm: pool www(+0x3370b9) [0x555a56a330b9] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(zend_call_function+0x742) [0x555a56979d72] PHP message: php-fpm: pool www(+0x1b9d81) [0x555a568b5d81] PHP message: php-fpm: pool www(+0x2d2e05) [0x555a569cee05] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a56a36722] PHP message: /opt/datadog-php/extensions/ddtrace-20170718-debug.so(+0x2c26) [0x7f27b885cc26] PHP message: php-fpm: pool www(+0x2d2cce) [0x555a569cecce] PHP message: php-fpm: pool www(execute_ex+0x2d12) [0x555a 2019/02/19 08:41:39 [error] 3687#3687: *9913 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: XXX.XXX.XXX.XXX, server: cert.chief.app, request: "POST /graphql/query HTTP/2.0", upstream: "fastcgi://unix:/var/run/php/php7.2-fpm.sock:", host: "cert.chief.app", referrer: "https://cert.chief.app/domains" ```
labbati commented 5 years ago

Hi @stayallive thanks for the info above. Super useful! Resolving this issue is at the moment our top priority. If you are interested (depending of course on your scheduling) I am also available to a live chat on our public slack channel (datadoghq.slack.com) so we can move much quicker! Of course we would also update this conversation for the benefit of the community! Just let me know! And thanks again!

cc @pawelchcki for the core dump ^^

pawelchcki commented 5 years ago

Thanks @stayallive and @labbati - looking at it now.

From first glance it looks like this error happens outside of extension code (hence the backtrace is a bit cryptic), but it already seems to point to some memory issue (in our extension), which have left the object pool in incorrect state.

I'll have to take a closer look at the _object_and_properties_init and try to create reproduction test.

Thanks agian for stack trace its superuseful!

PaulBehrendtVentoro commented 5 years ago

Hey there,

we are experiencing a similar issue, but using Laravel and using AWS's default AMI for PHP 7.2 on ElasticBeanstalk (Amazon Linux (RHEL); apache; php-fpm). No graphQL and so far only observed for one route.

If i add 98-ddtrace.ini to conf.d and restart apache, the following is logged to apache error log:

[core:notice] [pid 3735] AH00052: child pid 22794 exit signal Segmentation fault (11)

labbati commented 5 years ago

Hi! We just release 0.13.4 which brings some fixes to the memory management and it is supposed to fix the segmentation faults in php-fpm 7.2.

Special thanks to @stayallive for helping us debugging the memory issues in his environment! His help and guidance were of paramount importance.

It would be great if you can install it in your hosts to make sure the error disappeared.

labbati commented 5 years ago

Hi! I assume things are still going well on 7.2 😄. Closing this issue for now, thank you @stayallive for all the help in spotting the real underlying memory leak in out library. Feel free to re-open if you still experience any trouble.