Skip to content
This repository has been archived by the owner on Oct 12, 2022. It is now read-only.

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

Open
oyrm opened this issue Jul 19, 2022 · 15 comments
Open

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

oyrm opened this issue Jul 19, 2022 · 15 comments

Comments

@oyrm
Copy link

oyrm commented Jul 19, 2022

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
Copy link
Member

service是中文？

@oyrm
Copy link
Author

oyrm commented Jul 20, 2022

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

@heyanlong
Copy link
Member

我测试一下。

@heyanlong
Copy link
Member

把导致502的代码发一下

@oyrm
Copy link
Author

oyrm commented Jul 20, 2022 •
edited
Loading

把导致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
Copy link
Member

这怎么会502呢。。

@oyrm
Copy link
Author

oyrm commented Jul 20, 2022

这怎么会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
Copy link
Member

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

@oyrm
Copy link
Author

oyrm commented Jul 21, 2022

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

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

curl http://127.0.0.1/version

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

@nealwon
Copy link

nealwon commented Jul 22, 2022 •
edited
Loading

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

image

Skaywalking的扩展配置：

image

@heyanlong
Copy link
Member

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

@oyrm
Copy link
Author

oyrm commented Jul 25, 2022

怎么运行？容器内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
Copy link

这怎么会502呢。。

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

@phongvq
Copy link

phongvq commented Aug 18, 2022 •
edited
Loading

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
Copy link

yaoboqi commented Sep 14, 2022

我注意到当您的端点具有特定长度时会发生此问题。 例如， 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 ()

我也遇到此问题

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@nealwon @heyanlong @oyrm @phongvq @EwingYangs @yaoboqi