search

SkyAPM / SkyAPM-php-sdk

Replaced by https://github.com/apache/skywalking-php
https://skywalking.apache.org/
Apache License 2.0
421 stars 104 forks source link

php-fpm下访问502，无数据上报OAP #505

Open oyrm opened 2 years ago

oyrm commented 2 years ago

OAP：8.6.0 SkyAPM-php-sdk：master (220719) php： 8.1.8 (NTS) Laravel：9.0

[root@wechat-new-v2-web-659b9d7d58-g6qmz wwwroot]# gdb /usr/local/php/sbin/php-fpm -c core.28 GNU gdb (GDB) Red Hat Enterprise Linux 8.2-18.el8 Copyright (C) 2018 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: http://www.gnu.org/software/gdb/bugs/. Find the GDB manual and other documentation resources online at: http://www.gnu.org/software/gdb/documentation/.

For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/local/php/sbin/php-fpm...done.

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing [New LWP 28] Missing separate debuginfo for /usr/lib64/libpng16.so.16 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/31/bae13afed80d57aa8c4c236d252cb599672c47.debug Missing separate debuginfo for /usr/lib64/libjpeg.so.62 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/47/91ca4e7c88ca1315f87c36157076c6828be6f5.debug Missing separate debuginfo for /usr/lib64/libfreetype.so.6 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/dd/fc06c4e6b5af7e32613447e4a7a34e0ceb7721.debug Missing separate debuginfo for /usr/lib64/libxslt.so.1 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/b3/5ddab500e06d83a1b59a1a5877f883ab3dd327.debug Missing separate debuginfo for /usr/lib64/libexslt.so.0 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/87/f21a964317ec569cc2ccd144749f1deac1b2ae.debug Missing separate debuginfo for /usr/lib64/libzip.so.5 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/b9/10342e2904c88f4c63c9668efae6832741c889.debug [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". Missing separate debuginfo for /usr/lib64/libtiff.so.5 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/22/f62b250df74203783732a2f8d69d8f51190b90.debug Missing separate debuginfo for /usr/lib64/libfontconfig.so.1 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/02/f21936a10e876faf363fe26b06274549e72372.debug Missing separate debuginfo for /usr/lib64/libwebpmux.so.3 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/06/998393ae53f67d0ec018d59c46365a6a9034cb.debug Missing separate debuginfo for /usr/lib64/libwebpdemux.so.2 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/63/2d3c421128337a838338ab12c44d0352876d23.debug Missing separate debuginfo for /usr/lib64/libwebp.so.7 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/c4/75596e3e645e3faec6f7be19ee5a804d986900.debug Missing separate debuginfo for /usr/lib64/libX11.so.6 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/28/d2acfd4e3f3fef18ee17c8492b7d7ed1539ce4.debug Missing separate debuginfo for /usr/lib64/libjbig.so.2.1 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/77/4122c1f94f8239fbc3ad2485bc928547047cff.debug Missing separate debuginfo for /usr/lib64/libxcb.so.1 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/12/80aa7d248e87160ee8ace5ed22824e5381f465.debug Missing separate debuginfo for /usr/lib64/libXau.so.6 Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/31/207101ca01974ba406b3c442ee1232c7738269.debug Core was generated by `php-fpm: pool www '. Program terminated with signal SIGSEGV, Segmentation fault.

0 zend_mm_alloc_small (bin_num=0, heap=0x7f2175000040) at /root/src/php-8.1.8/Zend/zend_alloc.c:1256

1256 /root/src/php-8.1.8/Zend/zend_alloc.c: No such file or directory. Missing separate debuginfos, use: yum debuginfo-install bzip2-libs-1.0.6-26.el8.x86_64 expat-2.2.5-8.el8_6.2.x86_64 glibc-2.28-189.5.el8_6.x86_64 keyutils-libs-1.5.10-9.el8.x86_64 krb5-libs-1.18.2-14.el8.x86_64 libcom_err-1.45.6-4.el8.x86_64 libcurl-minimal-7.61.1-22.el8_6.3.x86_64 libgcc-8.5.0-10.1.el8_6.x86_64 libgcrypt-1.8.5-7.el8_6.x86_64 libgomp-8.5.0-10.1.el8_6.x86_64 libgpg-error-1.31-1.el8.x86_64 libnghttp2-1.33.0-3.el8_3.1.x86_64 libselinux-2.9-5.el8.x86_64 libuuid-2.32.1-35.el8.x86_64 libxcrypt-4.1.1-6.el8.x86_64 libxml2-2.9.7-13.el8_6.1.x86_64 openssl-libs-1.1.1k-6.el8_5.x86_64 pcre2-10.32-2.el8.x86_64 sqlite-libs-3.26.0-15.el8.x86_64 xz-libs-5.2.4-4.el8_6.x86_64 zlib-1.2.11-18.el8_5.x86_64 (gdb) bt

0 zend_mm_alloc_small (bin_num=0, heap=0x7f2175000040) at /root/src/php-8.1.8/Zend/zend_alloc.c:1256

1 _emalloc_8 () at /root/src/php-8.1.8/Zend/zend_alloc.c:2468

2 0x0000000000839d25 in tsrm_realpath (path=path@entry=0x7f2175058298 "/data/wwwroot/wechat_sfy_new/public/index.php", real_path=real_path@entry=0x0) at /root/src/php-8.1.8/Zend/zend_virtual_cwd.c:1728

3 0x000000000075d59b in tsrm_realpath_str (path=path@entry=0x7f2175058298 "/data/wwwroot/wechat_sfy_new/public/index.php") at /root/src/php-8.1.8/main/fopen_wrappers.c:462

4 0x000000000075dcae in php_resolve_path (filename=0x7f2175058298 "/data/wwwroot/wechat_sfy_new/public/index.php", filename_length=45, path=0x2198358 ".:") at /root/src/php-8.1.8/main/fopen_wrappers.c:512

5 0x000000000075d6c1 in php_fopen_primary_script (file_handle=file_handle@entry=0x7fff699dd970) at /root/src/php-8.1.8/main/fopen_wrappers.c:421

6 0x000000000047c12e in main (argc=, argv=) at /root/src/php-8.1.8/sapi/fpm/fpm/fpm_main.c:1893

[root@wechat-new-v2-web-659b9d7d58-g6qmz wwwroot]# php --ri skywalking

skywalking

Directive => Local Value => Master Value skywalking.enable => On => On skywalking.service => 全屋定制服务号v2-web => 全屋定制服务号v2-web skywalking.service_instance => no value => no value skywalking.oap_version => 8.6.0 => 8.6.0 skywalking.oap_cross_process_protocol => 3.0 => 3.0 skywalking.oap_authentication => no value => no value skywalking.grpc_address => 10.10.20.240:20185 => 10.10.20.240:20185 skywalking.grpc_tls_enable => Off => Off skywalking.grpc_tls_pem_root_certs => no value => no value skywalking.grpc_tls_pem_private_key => no value => no value skywalking.grpc_tls_pem_cert_chain => no value => no value skywalking.log_level => debug => debug skywalking.log_path => /data/wwwlogs/skywalking-php.log => /data/wwwlogs/skywalking-php.log skywalking.curl_response_enable => Off => Off skywalking.error_handler_enable => Off => Off skywalking.mq_max_message_length => 20480 => 20480 skywalking.mq_unique => 0 => 0 skywalking.sample_n_per_3_secs => -1 => -1

heyanlong commented 2 years ago

service是中文？

oyrm commented 2 years ago

service是中文？ 是的，service有中文存在，5.x的service不能定义中文？4.x版本是可以有中文的。

heyanlong commented 2 years ago

我测试一下。

heyanlong commented 2 years ago

把导致502的代码发一下

oyrm commented 2 years ago

把导致502的代码发一下

routes/web.php Route::get('/version', 'HomeController@version');

app/Http/Controllers/HomeController.php

public function version()
{
    return view('version');
}

resources/views/version.blade.php

<html lang="{{ str_replace('_', '-', app()->getLocale()) }}">
<body>
<h3>PHP={{ PHP_VERSION }}, LARAVEL={{ app()->version() }}</h3>
<h3 id='version'></h3>
<button onclick="setCookie('version_id', 'ab_test', 1)">设置Cookie</button>
<button onclick="setCookie('version_id', 'ab_test', -1)">删除Cookie</button>
</body>
<script>
    function setCookie(cname,cvalue,exdays)
    {
        var d = new Date();
        d.setTime(d.getTime()+(exdays*24*60*60*1000));
        var expires = 'expires='+d.toGMTString();
        document.cookie = cname + '=' + cvalue + '; ' + expires;
        location.reload();
    }

    function getCookie(cname)
    {
        console.log(document.cookie.split(';'));
        var name = cname + '=';
        var ca = document.cookie.split(';');
        for(var i=0; i<ca.length; i++)
        {
            var c = ca[i].trim();
            if (c.indexOf(name)==0) return c.substring(name.length,c.length);
        }
        return '';
    }
    versionId = getCookie('version_id')
    ele = document.getElementById('version')
    ele.innerText = 'version_id=' + versionId
</script>
</html>
heyanlong commented 2 years ago

这怎么会502呢。。

oyrm commented 2 years ago

这怎么会502呢。。

之前我编译过debug版本，日志如下，但是dubug编译的虽然有报错，但是页面无502，数据也可以上报；重新no debug编译就会出现502：

debug版本下php-fpm日志： [09-Jul-2022 15:19:32] WARNING: [pool www] child 31 said into stderr: "[Sat Jul 9 15:19:32 2022] Script: '-'" [09-Jul-2022 15:19:32] WARNING: [pool www] child 31 said into stderr: "[Sat Jul 9 15:19:32 2022] Script: '-'" [09-Jul-2022 15:19:32] WARNING: [pool www] child 31 said into stderr: "[Sat Jul 9 15:19:32 2022] Script: '-'" [09-Jul-2022 15:19:33] WARNING: [pool www] child 34 said into stderr: "[Sat Jul 9 15:19:33 2022] Script: '-'" [09-Jul-2022 15:19:33] WARNING: [pool www] child 34 said into stderr: "[Sat Jul 9 15:19:33 2022] Script: '-'" [09-Jul-2022 15:19:33] WARNING: [pool www] child 34 said into stderr: "[Sat Jul 9 15:19:33 2022] Script: '-'" [09-Jul-2022 15:19:41] WARNING: [pool www] child 35 said into stderr: "[Sat Jul 9 15:19:41 2022] Script: '-'"

heyanlong commented 2 years ago

方便把这个502的打包一个docker吗？删除内部代码

oyrm commented 2 years ago

方便把这个502的打包一个docker吗？删除内部代码

docker pull registry.cn-guangzhou.aliyuncs.com/oyrming/php8.1-base:skyapm5

curl http://127.0.0.1/version

日志记录目录：/data/wwwlog/

nealwon commented 2 years ago

我今天也遇到了502的问题，trace了下fpm的进程，发现请求会引发fpm的crash，trace的内容如下

image

Skaywalking的扩展配置：

image
heyanlong commented 2 years ago

怎么运行？容器内PHP和nginx都没启动

oyrm commented 2 years ago

怎么运行？容器内PHP和nginx都没启动 docker pull registry.cn-guangzhou.aliyuncs.com/oyrming/php8.1-base:skyapm5 docker run --name web -d registry.cn-guangzhou.aliyuncs.com/oyrming/php8.1-base:skyapm5 docker exec -it web bash

curl http://127.0.0.1/version 日志记录目录：/data/wwwlog/ image

EwingYangs commented 2 years ago

这怎么会502呢。。

运行一段时间后出现502的情况

phongvq commented 2 years ago

I notice that this issue happens when your endpoint has particular length. For example, both curl localhost/version and curl localhost/versioM (endpoint length = 7) cause segfault.

in my case, curl localhost/api/v1/department/12321 (endpoint length = 23) also cause php-fpm segfault.

some last lines of strace log - attached to php-fpm worker process (always stopped at loading helpers.php)

lstat("/var/www/vendor/composer/../laravel/framework/src/Illuminate/Foundation", {st_dev=makedev(0, 0x5a), st_ino=2727355, st_mode=S_IFDIR|0755, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=4096, st_atime=1660671446 /* 2022-08-16T17:37:26.947780120+0000 */, st_atime_nsec=947780120, st_mtime=1660803259 /* 2022-08-18T06:14:19.160350029+0000 */, st_mtime_nsec=160350029, st_ctime=1660803259 /* 2022-08-18T06:14:19.160350029+0000 */, st_ctime_nsec=160350029}) = 0
stat("/var/www/vendor/laravel/framework/src/Illuminate/Foundation/helpers.php", {st_dev=makedev(0, 0x5a), st_ino=2721960, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=48, st_size=24556, st_atime=1660634181 /* 2022-08-16T07:16:21.576132817+0000 */, st_atime_nsec=576132817, st_mtime=1660052602 /* 2022-08-09T13:43:22+0000 */, st_mtime_nsec=0, st_ctime=1660671444 /* 2022-08-16T17:37:24.319492176+0000 */, st_ctime_nsec=319492176}) = 0
--- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_ACCERR, si_addr=0x564b50630e30} ---

gdb full stack trace

#0  0x000055f22f6023a8 in ?? ()
#1  0x000055f22f5f4208 in ?? ()
#2  0x000055f22f5f40bf in ?? ()
#3  0x000055f22f5f7909 in ?? ()
#4  0x000055f22f5f438c in ?? ()
#5  0x000055f22f5f40bf in ?? ()
#6  0x000055f22f5f850c in ?? ()
#7  0x000055f22f5f3af4 in ?? ()
#8  0x000055f22f5f3b20 in ?? ()
#9  0x000055f22f5d5e6e in ?? ()
#10 0x000055f22f5d763a in compile_file ()
#11 0x000055f22f4b3a4e in ?? ()
#12 0x00007f5d7f520334 in ?? () from /usr/local/lib/php/extensions/no-debug-non-zts-20210902/opcache.so
#13 0x00007f5d7f522c84 in persistent_compile_file () from /usr/local/lib/php/extensions/no-debug-non-zts-20210902/opcache.so
#14 0x000055f22f6463a0 in ?? ()
#15 0x000055f22f6527fd in ?? ()
#16 0x000055f22f678bf5 in execute_ex ()
#17 0x000055f22f68196f in zend_execute ()
#18 0x000055f22f614eed in zend_execute_scripts ()
#19 0x000055f22f5b1231 in php_execute_script ()
#20 0x000055f22f32e72d in ?? ()
#21 0x00007f5d82275d0a in __libc_start_main (main=0x55f22f32d880, argc=4, argv=0x7ffe56fd5878, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe56fd5868)
   bc-start.c:308
#22 0x000055f22f32faaa in _start ()
yaoboqi commented 2 years ago

我注意到当您的端点具有特定长度时会发生此问题。 例如， and (endpoint length = 7) 都会curl localhost/version导致curl localhost/versioM段错误。

就我而言，curl localhost/api/v1/department/12321（端点长度= 23）也会导致php-fpm segfault。

strace 日志的最后几行 - 附加到 php-fpm 工作进程（总是在加载时停止helpers.php）

lstat("/var/www/vendor/composer/../laravel/framework/src/Illuminate/Foundation", {st_dev=makedev(0, 0x5a), st_ino=2727355, st_mode=S_IFDIR|0755, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=4096, st_atime=1660671446 /* 2022-08-16T17:37:26.947780120+0000 */, st_atime_nsec=947780120, st_mtime=1660803259 /* 2022-08-18T06:14:19.160350029+0000 */, st_mtime_nsec=160350029, st_ctime=1660803259 /* 2022-08-18T06:14:19.160350029+0000 */, st_ctime_nsec=160350029}) = 0
stat("/var/www/vendor/laravel/framework/src/Illuminate/Foundation/helpers.php", {st_dev=makedev(0, 0x5a), st_ino=2721960, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=48, st_size=24556, st_atime=1660634181 /* 2022-08-16T07:16:21.576132817+0000 */, st_atime_nsec=576132817, st_mtime=1660052602 /* 2022-08-09T13:43:22+0000 */, st_mtime_nsec=0, st_ctime=1660671444 /* 2022-08-16T17:37:24.319492176+0000 */, st_ctime_nsec=319492176}) = 0
--- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_ACCERR, si_addr=0x564b50630e30} ---

gdb 完整堆栈跟踪

#0  0x000055f22f6023a8 in ?? ()
#1  0x000055f22f5f4208 in ?? ()
#2  0x000055f22f5f40bf in ?? ()
#3  0x000055f22f5f7909 in ?? ()
#4  0x000055f22f5f438c in ?? ()
#5  0x000055f22f5f40bf in ?? ()
#6  0x000055f22f5f850c in ?? ()
#7  0x000055f22f5f3af4 in ?? ()
#8  0x000055f22f5f3b20 in ?? ()
#9  0x000055f22f5d5e6e in ?? ()
#10 0x000055f22f5d763a in compile_file ()
#11 0x000055f22f4b3a4e in ?? ()
#12 0x00007f5d7f520334 in ?? () from /usr/local/lib/php/extensions/no-debug-non-zts-20210902/opcache.so
#13 0x00007f5d7f522c84 in persistent_compile_file () from /usr/local/lib/php/extensions/no-debug-non-zts-20210902/opcache.so
#14 0x000055f22f6463a0 in ?? ()
#15 0x000055f22f6527fd in ?? ()
#16 0x000055f22f678bf5 in execute_ex ()
#17 0x000055f22f68196f in zend_execute ()
#18 0x000055f22f614eed in zend_execute_scripts ()
#19 0x000055f22f5b1231 in php_execute_script ()
#20 0x000055f22f32e72d in ?? ()
#21 0x00007f5d82275d0a in __libc_start_main (main=0x55f22f32d880, argc=4, argv=0x7ffe56fd5878, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe56fd5868)
   bc-start.c:308
#22 0x000055f22f32faaa in _start ()

我也遇到此问题