首页
下载
文档
社区
视频
捐赠
源代码
赞助商
AOT 编译器
AI 助理
商业产品
PHP AOT 原生编译器
Swoole-Compiler 代码加密器
CRMEB 新零售社交电商系统
登录
注册
全部
提问
分享
讨论
建议
公告
开发框架
CodeGalaxy
发表新帖
协程client问题
### Swoole版本,PHP版本,以及操作系统版本信息 swoole 4.3.6 php 7.1.2 centos 7 linux kernel 4.18.20 gcc 4.8.5 ### 相关代码 ```php // tcp process server的onWokerStart中 \Swoole\Runtime:: enableCoroutine(); // onReceive中 $client = new \Swoole\Coroutine\Client(SWOOLE_SOCK_TCP); $client->set([ 'timeout' => 0.1, 'read_timeout' => 0.6, 'open_length_check' => true, 'package_length_type' => 'V', 'package_length_offset' => 6, 'package_body_offset' => 10, 'open_tcp_nodelay' => true, ]); $client->send('xxx'); // time 10:16:52.417825 $data1 = $client->recv(); if (empty($data1)) { if ($data1 === '') { // return ...; } $data2 = $server->conn->peek(1024 * 512); // 打日志 file_put_contents(...) // 关闭连接 $client->close(); // 10:16:53.391886 } $data2 = $client->peek(1024 * 512); ``` 我们在线上日志发现, 有极低概念(百万分之一), data1值是false, data2是一个完整的响应包, 然后我们增加了tcpdump日志, 发现如下 ``` 10: 16: 52.417825 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [P.], seq 12053294: 12054452, ack 97354404, win 1444, options [nop, nop, TS val 3110516436 ecr 3592632624], length 1158 10: 16: 52.419234 IP 10.144.32.87.18030 > 10.167.45.33.13550: Flags [.], ack 12054452, win 126, options [nop, nop, TS val 3592633775 ecr 3110516436], length 0 10: 16: 52.589367 IP 10.144.32.87.18030 > 10.167.45.33.13550: Flags [.], seq 97354404: 97355852, ack 12054452, win 127, options [nop, nop, TS val 3592633946 ecr 3110516436], length 1448 10: 16: 52.589379 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [.], ack 97355852, win 1444, options [nop, nop, TS val 3110516607 ecr 3592633946], length 0 10: 16: 52.589415 IP 10.144.32.87.18030 > 10.167.45.33.13550: Flags [P.], seq 97355852: 97359728, ack 12054452, win 127, options [nop, nop, TS val 3592633946 ecr 3110516436], length 3876 10: 16: 52.589424 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [.], ack 97359728, win 1422, options [nop, nop, TS val 3110516608 ecr 3592633946], length 0 10: 16: 53.391886 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [R.], seq 12054452, ack 97359728, win 1444, options [nop, nop, TS val 3110517410 ecr 3592633946], length 0 ``` 时间点1: 10:16: 52.417825发送的请求包, 对方很快分几次返回了响应包; 时间点2: 10:16: 52.589424也就是170ms后返回了完整的包体(这里可以确认响应是完整的, 因为有另外的日志计算过协议包头中存放长度值为5324字节, 而tcpdump中响应1448+3876=5324) 时间点3: 10: 16: 53.391886这个是过了recv函数, 进入下面if结构执行$client->close的时间 为什么这种情况下, client没有在时间点2到时间点3之间去处理响应包, 而在超时时间过了即时间点3才执行recv后面的代码呢, 是worker阻塞了? bug? 我这里没记录strace日志, 可能什么原因呢
发布于5年前 · 1 次浏览 · 来自
提问
lg430
### Swoole版本,PHP版本,以及操作系统版本信息 swoole 4.3.6 php 7.1.2 centos 7 linux kernel 4.18.20 gcc 4.8.5 ### 相关代码 ```php // tcp process server的onWokerStart中 \Swoole\Runtime:: enableCoroutine(); // onReceive中 $client = new \Swoole\Coroutine\Client(SWOOLE_SOCK_TCP); $client->set([ 'timeout' => 0.1, 'read_timeout' => 0.6, 'open_length_check' => true, 'package_length_type' => 'V', 'package_length_offset' => 6, 'package_body_offset' => 10, 'open_tcp_nodelay' => true, ]); $client->send('xxx'); // time 10:16:52.417825 $data1 = $client->recv(); if (empty($data1)) { if ($data1 === '') { // return ...; } $data2 = $server->conn->peek(1024 * 512); // 打日志 file_put_contents(...) // 关闭连接 $client->close(); // 10:16:53.391886 } $data2 = $client->peek(1024 * 512); ``` 我们在线上日志发现, 有极低概念(百万分之一), data1值是false, data2是一个完整的响应包, 然后我们增加了tcpdump日志, 发现如下 ``` 10: 16: 52.417825 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [P.], seq 12053294: 12054452, ack 97354404, win 1444, options [nop, nop, TS val 3110516436 ecr 3592632624], length 1158 10: 16: 52.419234 IP 10.144.32.87.18030 > 10.167.45.33.13550: Flags [.], ack 12054452, win 126, options [nop, nop, TS val 3592633775 ecr 3110516436], length 0 10: 16: 52.589367 IP 10.144.32.87.18030 > 10.167.45.33.13550: Flags [.], seq 97354404: 97355852, ack 12054452, win 127, options [nop, nop, TS val 3592633946 ecr 3110516436], length 1448 10: 16: 52.589379 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [.], ack 97355852, win 1444, options [nop, nop, TS val 3110516607 ecr 3592633946], length 0 10: 16: 52.589415 IP 10.144.32.87.18030 > 10.167.45.33.13550: Flags [P.], seq 97355852: 97359728, ack 12054452, win 127, options [nop, nop, TS val 3592633946 ecr 3110516436], length 3876 10: 16: 52.589424 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [.], ack 97359728, win 1422, options [nop, nop, TS val 3110516608 ecr 3592633946], length 0 10: 16: 53.391886 IP 10.167.45.33.13550 > 10.144.32.87.18030: Flags [R.], seq 12054452, ack 97359728, win 1444, options [nop, nop, TS val 3110517410 ecr 3592633946], length 0 ``` 时间点1: 10:16: 52.417825发送的请求包, 对方很快分几次返回了响应包; 时间点2: 10:16: 52.589424也就是170ms后返回了完整的包体(这里可以确认响应是完整的, 因为有另外的日志计算过协议包头中存放长度值为5324字节, 而tcpdump中响应1448+3876=5324) 时间点3: 10: 16: 53.391886这个是过了recv函数, 进入下面if结构执行$client->close的时间 为什么这种情况下, client没有在时间点2到时间点3之间去处理响应包, 而在超时时间过了即时间点3才执行recv后面的代码呢, 是worker阻塞了? bug? 我这里没记录strace日志, 可能什么原因呢
赞
0
收藏
提问
分享
讨论
建议
公告
开发框架
CodeGalaxy
登录
后参与评论
评论
2020-10-15
Rango
1. 可以考虑升级一下版本 2. `recv()`返回`false`请打印一下错误码,如果是`ETIMEDOUT`可能是有其他阻塞逻辑导致超时定时器先于`recv`发生,导致了返回`false` 3. `recv()`返回`false`之后,可以重试一次,看是否可以获取到数据
赞
0
回复
2020-10-16
lg430
回复
Rango
strace日志找到了 17:01:09.254871 sendto(17, "\2275+\0@\275\0\0\2\0\0\0\0\0\0\0\22\21\r\n\t\0016\275\0\0\1\0\0\0\2\1"..., 48464, 0, NULL, 0) = 48464 <0.831675> 在时间点2和时间点3中间, 有一个其他的socket发送操作, 耗时达831ms, 这个是发送的数据较多导致发送缓冲区出不够了吗, 默认的发送缓冲区是多少呢
赞
0
回复
2020-10-16
lg430
回复
Rango
我的timeout如上面设置的0.1, 为啥send会阻塞这么久 strace日志我的参数strace -T -tt -p 205732 -o strace205732
赞
0
回复
2020-10-16
鲁飞
回复
lg430
超时这个升级试下。
赞
0
回复