10、Workerman 基本使用 - 调试 - 基本调试 & 运行状态
hi，我是温新，一名 PHPer
基本调试
到现在为止，一直使用的是 php start.php start，此时，代码中使用 echo、var_dump、print_r 等函数时，信息会在服务终端中显示。
但是在实际的生产环境，都是使用 daemon 模式，此时呢，echo 这些函数就不好使了。
解决方法，把调试信息写入到文件中，使用 Worker::$stdoutFile 属性设置。
<?php
/**
* debug.php
*
* 调试 - 基本调试
*/
use Workerman\Worker;
use Workerman\Connection\TcpConnection;
require_once __DIR__ . '/vendor/autoload.php';
// 将屏幕打印输出到 Worker::$stdoutFile 指定的文件中
Worker::$stdoutFile = '/tmp/workerman/workerman.log';
$worker = new Worker('tcp://0.0.0.0:8888');
$worker->count = 8;
$worker->name = 'debug-php';
$worker->onMessage = function (TcpConnection $connection, $data) {
while (true) {
sleep(1);
$connection->send('hello world');
}
};
Worker::runAll();
1、启动服务端
$ php debug.php start -d
2、客户端连接
$ telnet 127.0.0.1 8888
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
1
hello world^C
3、查看记录文件
$ cat /tmp/workerman/workerman.log
hellohellohello
查看运行状态
使用 status 可以查看服务运行状态：
$ php debug.php status
Workerman[debug.php] status
----------------------------------------------GLOBAL STATUS----------------------------------------------------
Workerman version:4.1.15 PHP version:8.2.0
start time:2024-03-01 08:56:22 run 0 days 0 hours
load average: 1.18, 1.28, 1.25 event-loop:\Workerman\Events\Event
1 workers 8 processes
worker_name exit_status exit_count
debug-php 0 0
----------------------------------------------PROCESS STATUS---------------------------------------------------
pid memory listening worker_name connections send_fail timers total_request qps status
50490 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50491 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50492 N/A tcp://0.0.0.0:8888 debug-php N/A N/A N/A N/A N/A [busy]
50493 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50494 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50495 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50496 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50497 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
----------------------------------------------PROCESS STATUS---------------------------------------------------
Summary 14M - - 0 0 0 0 0 [Summary]
从输出中，可以看到，信息分为了两大块：GLOBAL STATUS 和 PROCESS STATUS，它们的含义如下：
GLOBAL STATUS
| 字段 | 含义 |
|---|---|
| Workerman version | Workerman 版本 |
| PHP version | PHP 版本 |
| start time | 服务启动时间 |
| run | 服务运行时长 |
| load average | 服务器负载，最近 1 分钟、5 分钟、15 分钟内系统的平均负载 |
| event-loop | 使用的 IO 事件库 |
| 1 workers | 工作的哪种进程。3 种进程，包括 ChatGateway、ChatBusinessWorker、Register 进程、WebServer 进程 |
| 8 processes | 8 个进程 |
| worker_name | worker 进程名称 |
| exit_status | worker 进程退出状态码 |
| exit_count | 该状态码的退出次数 |
PROCESS STATUS
| 字段 | 含义 |
|---|---|
| pid | 进程 PID |
| memory | 该进程当前占用内存 |
| listening | 传输层协议及监听 ip 端口 |
| worker_name | 该进程运行的服务服务名 |
| connections | 该进程当前有多少个 TCP 连接实例 |
| total_request | 表示该进程从启动到现在一共接收了多少个请求 |
| send_fail | 该进程向客户端发送数据失败次数 |
| timers | 该进程活动的定时器数量 |
| qps | 当前进程每秒收到的网络请求数 |
需要注意显示 busy 的进程，这是由于进程忙于处理业务，无法上报状态，导致显示 busy。
调试 busy 进程
通过 php start.php status 可以查看到 busy 状态的进程，进程处理完成任务后，正常情况下状态会恢复为 idle，若没有恢复，则说明进程内的业务存在阻塞或者无限循环。可以利用 strace + lsof 定位问题。
1、查找 busy 进程的 PID
$ php debug.php status
Workerman[debug.php] status
----------------------------------------------GLOBAL STATUS----------------------------------------------------
Workerman version:4.1.15 PHP version:8.2.0
start time:2024-03-01 08:56:22 run 0 days 0 hours
load average: 1.18, 1.28, 1.25 event-loop:\Workerman\Events\Event
1 workers 8 processes
worker_name exit_status exit_count
debug-php 0 0
----------------------------------------------PROCESS STATUS---------------------------------------------------
pid memory listening worker_name connections send_fail timers total_request qps status
50490 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50491 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50492 N/A tcp://0.0.0.0:8888 debug-php N/A N/A N/A N/A N/A [busy]
50493 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50494 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50495 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50496 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
50497 2.11M tcp://0.0.0.0:8888 debug-php 0 0 0 0 0 [idle]
----------------------------------------------PROCESS STATUS---------------------------------------------------
Summary 14M - - 0 0 0 0 0 [Summary]
可以看到 50492 的进程为 busy 状态。
2、strace 跟踪进程
$ sudo strace -ttp 50492
strace: Process 50492 attached
16:58:03.822573 restart_syscall(<... resuming interrupted read ...>) = 0
16:58:04.542515 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:04.542850 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:05.543068 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:05.543233 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:06.543439 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:06.543615 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:07.543777 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:07.543921 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:08.544131 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:08.544340 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:09.544528 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:09.544697 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:10.544912 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:10.545088 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:11.545365 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:11.545631 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:12.545820 sendto(8, "hello world", 11, 0, NULL, 0) = 11
16:58:12.545947 nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0
16:58:13.546100 sendto(8, "hello world", 11, 0, NULL, 0) = 11
-
strace: Process 50492 attached：表明 strace 成功附加到了 PID 为 50492 的进程中，开始对其进行追踪。 -
restart_syscall(<... resuming interrupted read ...>) = 0：表示进程正在进行或恢复了一个被中断的系统调用（可能是 read 系统调用）。这里的返回值 0 通常表示成功完成。 -
sendto(8, "hello world", 11, 0, NULL, 0) = 11：显示了该进程在进行sendto系统调用，向文件描述符为 8 的套接字发送了 "hello world" 字符串，长度为 11 个字节，并且成功发送了所有数据。 -
nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffd0542b850) = 0：表示进程调用了nanosleep函数进行休眠，参数指定休眠时间为 1 秒（tv_sec=1），没有纳秒级别的精度要求（tv_nsec=0）。调用成功返回 0，意味着进程已按照指定时间休眠。
3、lsof 查看进程描述符
$ lsof -nPp 50492
lsof: WARNING: can't stat() vfat file system /boot/efi
Output information may be incomplete.
lsof: WARNING: can't stat() overlay file system /var/lib/docker/overlay2/ba08094c7c9c86fdb87ddf0cd48231699252e75e3b106be2648df826522c8361/merged
Output information may be incomplete.
lsof: WARNING: can't stat() nsfs file system /run/docker/netns/ac008c9c7c90
Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
php 50492 codeing cwd DIR 259,5 4096 21764569 /www/workerman/wm-study
php 50492 codeing rtd DIR 259,4 4096 2 /
php 50492 codeing txt REG 259,4 67557976 6822479 /usr/local/php-8.2.0/bin/php
php 50492 codeing DEL REG 0,1 29700 /dev/zero
php 50492 codeing mem REG 259,4 54818560 6822491 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/swoole.so
php 50492 codeing mem REG 259,4 55792 3933503 /usr/lib/x86_64-linux-gnu/libnss_files-2.28.so
php 50492 codeing mem REG 259,4 89016 3933497 /usr/lib/x86_64-linux-gnu/libnsl-2.28.so
php 50492 codeing mem REG 259,4 231440 3938808 /usr/lib/x86_64-linux-gnu/libevent_core-2.1.so.6.0.2
php 50492 codeing mem REG 259,4 10984352 3279225 /usr/lib/locale/locale-archive
php 50492 codeing mem REG 259,4 145712 3938812 /usr/lib/x86_64-linux-gnu/libevent_extra-2.1.so.6.0.2
php 50492 codeing mem REG 259,4 47608 3933507 /usr/lib/x86_64-linux-gnu/libnss_nis-2.28.so
php 50492 codeing mem REG 259,4 39736 3933499 /usr/lib/x86_64-linux-gnu/libnss_compat-2.28.so
php 50492 codeing mem REG 259,4 1246320 6822703 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/event.so
php 50492 codeing mem REG 259,4 485272 3407880 /usr/local/lib/libsodium.so.23.3.0
php 50492 codeing mem REG 259,4 74688 3935248 /usr/lib/x86_64-linux-gnu/libbz2.so.1.0.4
php 50492 codeing mem REG 259,4 114224 3937193 /usr/lib/x86_64-linux-gnu/libzip.so.4.0
php 50492 codeing mem REG 259,4 500088 6822544 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/sodium.so
php 50492 codeing mem REG 259,4 137520 3935235 /usr/lib/x86_64-linux-gnu/libbrotlicommon.so.1.0.7
php 50492 codeing mem REG 259,4 30632 3938820 /usr/lib/x86_64-linux-gnu/libevent_openssl-2.1.so.6.0.2
php 50492 codeing mem REG 259,4 575560 3935239 /usr/lib/x86_64-linux-gnu/libbrotlienc.so.1.0.7
php 50492 codeing mem REG 259,4 96760 6822555 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/sysvmsg.so
php 50492 codeing mem REG 259,4 485624 6822537 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/zip.so
php 50492 codeing mem REG 259,4 3778696 6822486 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/redis.so
php 50492 codeing mem REG 259,4 200752 3279208 /usr/lib/locale/C.UTF-8/LC_CTYPE
php 50492 codeing mem REG 259,4 35224 3935553 /usr/lib/x86_64-linux-gnu/libffi.so.6.0.4
php 50492 codeing mem REG 259,4 137424 3935769 /usr/lib/x86_64-linux-gnu/libgpg-error.so.0.26.1
php 50492 codeing mem REG 259,4 1236720 3936516 /usr/lib/x86_64-linux-gnu/libp11-kit.so.0.3.0
php 50492 codeing mem REG 259,4 113392 3936766 /usr/lib/x86_64-linux-gnu/libsasl2.so.2.0.25
php 50492 codeing mem REG 259,4 1193016 3935648 /usr/lib/x86_64-linux-gnu/libgcrypt.so.20.2.4
php 50492 codeing mem REG 259,4 533280 3935736 /usr/lib/x86_64-linux-gnu/libgmp.so.10.3.2
php 50492 codeing mem REG 259,4 236952 3936389 /usr/lib/x86_64-linux-gnu/libnettle.so.6.5
php 50492 codeing mem REG 259,4 229200 3935979 /usr/lib/x86_64-linux-gnu/libhogweed.so.4.5
php 50492 codeing mem REG 259,4 1748352 3935752 /usr/lib/x86_64-linux-gnu/libgnutls.so.30.23.2
php 50492 codeing mem REG 259,4 1574952 3936963 /usr/lib/x86_64-linux-gnu/libunistring.so.2.1.0
php 50492 codeing mem REG 259,4 1570256 3936861 /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.25
php 50492 codeing mem REG 259,4 29476552 3936027 /usr/lib/x86_64-linux-gnu/libicudata.so.70.1
php 50492 codeing mem REG 259,4 75776 3933155 /usr/lib/x86_64-linux-gnu/libtasn1.so.6.5.5
php 50492 codeing mem REG 259,4 100712 3935636 /usr/lib/x86_64-linux-gnu/libgcc_s.so.1
php 50492 codeing mem REG 259,4 331088 3932182 /usr/lib/x86_64-linux-gnu/libldap_r-2.4.so.2.10.10
php 50492 codeing mem REG 259,4 203600 3934153 /usr/lib/x86_64-linux-gnu/libk5crypto.so.3.1
php 50492 codeing mem REG 259,4 913280 3933999 /usr/lib/x86_64-linux-gnu/libkrb5.so.3.3
php 50492 codeing mem REG 259,4 309744 3933996 /usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2.2
php 50492 codeing mem REG 259,4 2046128 3936057 /usr/lib/x86_64-linux-gnu/libicuuc.so.70.1
php 50492 codeing mem REG 259,4 3295400 3936033 /usr/lib/x86_64-linux-gnu/libicui18n.so.70.1
php 50492 codeing mem REG 259,4 22448 3936153 /usr/lib/x86_64-linux-gnu/libkeyutils.so.1.8
php 50492 codeing mem REG 259,4 56352 3934149 /usr/lib/x86_64-linux-gnu/libkrb5support.so.0.1
php 50492 codeing mem REG 259,4 63672 3932181 /usr/lib/x86_64-linux-gnu/liblber-2.4.so.2.10.10
php 50492 codeing mem REG 259,4 18344 3935317 /usr/lib/x86_64-linux-gnu/libcom_err.so.2.1
php 50492 codeing mem REG 259,4 71520 3936660 /usr/lib/x86_64-linux-gnu/libpsl.so.5.3.1
php 50492 codeing mem REG 259,4 186696 3936850 /usr/lib/x86_64-linux-gnu/libssh2.so.1.0.1
php 50492 codeing mem REG 259,4 122280 3936745 /usr/lib/x86_64-linux-gnu/librtmp.so.1
php 50492 codeing mem REG 259,4 120752 3936063 /usr/lib/x86_64-linux-gnu/libidn2.so.0.3.4
php 50492 codeing mem REG 259,4 158128 3936399 /usr/lib/x86_64-linux-gnu/libnghttp2.so.14.17.1
php 50492 codeing mem REG 259,4 158400 3936242 /usr/lib/x86_64-linux-gnu/liblzma.so.5.2.5
php 50492 codeing mem REG 259,4 1824496 3933485 /usr/lib/x86_64-linux-gnu/libc-2.28.so
php 50492 codeing mem REG 259,4 1183192 3936839 /usr/lib/x86_64-linux-gnu/libsqlite3.so.0.8.6
php 50492 codeing mem REG 259,4 568256 3936482 /usr/lib/x86_64-linux-gnu/libonig.so.5.0.0
php 50492 codeing mem REG 259,4 432128 3936129 /usr/lib/x86_64-linux-gnu/libjpeg.so.62.2.0
php 50492 codeing mem REG 259,4 3068768 3938548 /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
php 50492 codeing mem REG 259,4 146968 3933511 /usr/lib/x86_64-linux-gnu/libpthread-2.28.so
php 50492 codeing mem REG 259,4 227248 3936615 /usr/lib/x86_64-linux-gnu/libpng16.so.16.36.0
php 50492 codeing mem REG 259,4 588232 3934179 /usr/lib/x86_64-linux-gnu/libcurl.so.4.5.0
php 50492 codeing mem REG 259,4 117184 3934117 /usr/lib/x86_64-linux-gnu/libz.so.1.2.11
php 50492 codeing mem REG 259,4 601952 3938582 /usr/lib/x86_64-linux-gnu/libssl.so.1.1
php 50492 codeing mem REG 259,4 1740024 3933775 /usr/lib/x86_64-linux-gnu/libxml2.so.2.9.4
php 50492 codeing mem REG 259,4 14592 3933489 /usr/lib/x86_64-linux-gnu/libdl-2.28.so
php 50492 codeing mem REG 259,4 1579448 3933491 /usr/lib/x86_64-linux-gnu/libm-2.28.so
php 50492 codeing mem REG 259,4 14720 3933515 /usr/lib/x86_64-linux-gnu/libutil-2.28.so
php 50492 codeing mem REG 259,4 35808 3933513 /usr/lib/x86_64-linux-gnu/librt-2.28.so
php 50492 codeing mem REG 259,4 93000 3933512 /usr/lib/x86_64-linux-gnu/libresolv-2.28.so
php 50492 codeing mem REG 259,4 745016 6822488 /usr/local/php-8.2.0/lib/php/extensions/no-debug-non-zts-20220829/bcmath.so
php 50492 codeing mem REG 259,4 55472 3935237 /usr/lib/x86_64-linux-gnu/libbrotlidec.so.1.0.7
php 50492 codeing mem REG 259,4 26402 3938790 /usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache
php 50492 codeing mem REG 259,4 165640 3933477 /usr/lib/x86_64-linux-gnu/ld-2.28.so
php 50492 codeing 0u CHR 136,1 0t0 4 /dev/pts/1
php 50492 codeing 1w REG 259,4 15 1835086 /tmp/workerman/workerman.log
php 50492 codeing 2w REG 259,4 15 1835086 /tmp/workerman/workerman.log
php 50492 codeing 3r REG 259,5 559 21764585 /www/workerman/wm-study/debug.php
php 50492 codeing 4u a_inode 0,14 0 12445 [eventpoll]
php 50492 codeing 5u IPv4 467936 0t0 TCP *:8888 (LISTEN)
php 50492 codeing 6r FIFO 0,13 0t0 484076 pipe
php 50492 codeing 7w FIFO 0,13 0t0 484076 pipe
php 50492 codeing 8u IPv4 484122 0t0 TCP 127.0.0.1:8888->127.0.0.1:53932 (ESTABLISHED)
php 50492 codeing 22u a_inode 0,14 0 12445 [eventpoll]
php 50492 codeing 23r FIFO 0,13 0t0 55943 pipe
php 50492 codeing 24w FIFO 0,13 0t0 55943 pipe
使用lsof -nPp 50492的输出显示了进程 ID 为 50492 的 PHP 进程（用户为codeing）当前打开的所有文件描述符以及相关的资源信息：
- 详细列出了进程所打开的各种类型的文件资源，包括：
-
cwd：当前工作目录是/www/workerman/wm-study -
rtd：根目录是/ -
txt：执行的主程序文本位于/usr/local/php-8.2.0/bin/php
-
- 大量的
mem类型条目展示了进程加载的共享库文件（.so文件），这是进程运行时所需的动态链接库，例如swoole.so、event.so等 - 最后一部分列出了进程的文件描述符（FD）：
-
0：标准输入，连接到终端/dev/pts/1 -
1和2：标准输出和错误输出都重定向到同一个文件/tmp/workerman/workerman.log，且均为写入模式（w） -
3：读取一个脚本文件/www/workerman/wm-study/debug.php -
4和22：内核事件多路复用机制（如epoll） -
5：监听TCP端口8888 -
6和7：组成一个管道用于进程间通信 -
8：已建立的TCP连接（源IP与目标IP都是127.0.0.1，分别在端口8888和53932之间） -
23和24：另一组管道
-
注意
8u IPv4 484122这行，127.0.0.1:8888->127.0.0.1:53932 (ESTABLISHED)，连接着一个客户端。
出现 busy 的原因
摘抄于文档
1、业务有致命错误导致进程不断退出
现象： 这种情况下能看到系统负载比较高，status中的load average为1或者更高。能看到进程的exit_count数字很高，并且不断增长
解决： debug 方式运行 (php start.php start不加-d) workerman 看下业务报错，把报错解决即可
2、代码里无限死循环
现象： top 中能看到 busy 进程占用 cpu 很高，strace -ttp pid命令没有打印出任何系统调用信息
解决： 参考鸟哥的文章通过 gdb和php源码定位，步骤总结大概如下：
- 1、
php -v查看版本 - 2、下载对应php版本的源码
- 3、
gdb --pid=busy 进程的 pid - 4、
source php 源码路径/.gdbinit， - 5、
zbacktrace打印调用栈
3、无限添加定时器
业务代码不停的添加定时器又不删除，导致进程内定时器越来越多，最终造成进程无限运行定时器。例如以下代码：
$worker = new Worker;
$worker->onConnect = function($con){
Timer::add(10, function(){});
};
Worker::runAll();
以上代码在有客户端连接上来后会增加一个定时器，但是整个业务代码里没有删除定时器的逻辑，这样随着时间推移，进程内会不断增加定时器，最终导致进程无限运行定时器导致busy。
正确的代码：
$worker = new Worker;
$worker->onConnect = function($con){
$con->timer_id = Timer::add(10, function(){});
};
$worker->onClose = function($con){
Timer::del($con->timer_id);
};
Worker::runAll();
请登录后再评论