整体的业务流程:用户使用苹果支付,客户端拿到用户支付后用户返回的code,传给php,php 使用curl post提交给用户中心,用户中心拿到code后请去苹果支付的接口验证是否合法。
1、code有超过4000个字节长度,而curl post提交超过1024个字节后,会发送100-continue,将请求分为2步。
3、libcurl的BUG(PHP这边的HTTP Clinet使用的libcurl库封装的)
发现错误并没有解决,报错依然存在。还原之前的代码,排除掉怀疑1。
2、将抓网卡数据包的命令给运维,让其帮忙加一下任务,监听网卡流量信息。当发现问题后,停掉脚本,发给我们。我们根据错误邮件报警时间与网卡流量中的记录进行对照
后我就等着发报警邮件,发现报警之后,让运维终止掉脚本,然后通过"wireshark"分析,对比一下正常的和有问题的:
发现PHP的curl_exec函数最终调用 libcurl中的curl_easy_perform函数,线上服务的libcurl是7.29.0版本,继续看libcurl源码
ibcurl 提供的C函数API大概如下,可以看出来php的curl只是对libcurl做了一个简单的封装。libcurl API列表
上面测试均在docker 1.10.3容量里面进行, 在物理机器上并无此问题。经过上面的测试发现,在docker 1.10.3只有以PHP-FPM运行时,才会出现此问题。
经过分析fpm源码,发现了使用request_slowlog_timeout的流程。在fpm work 进程处理请求时,master进程做健康检查,其中就有slowlog_timeout。
fpm_pctl_check_request_timeout源码
为啥说ptrace是关键性函数呢?看如下两种strace跟踪系统调用。
看出来区别没?注意正常strace追踪的第8行,restart_syscall(<... resuming interrupted call ...>),重新恢复中断的调用。
1、调用ptrace的PTRACE_ATTACH命令,master会进程通过向子进程发送SIGSTOP信号,此时子进程会变成TASK_TRACED状态,被追踪状态。
即:ptrace(PTRACE_ATTACH, pid, 0, 0)); 这行代码
2、 调用ptrace的PTRACE_PEEKDATA命令,来获取子进程的栈调用信息。
即:ptrace(PTRACE_PEEKDATA, traced_pid, (void *) addr, 0); 这行代码
3、 调用ptrace的PTRACE_DETACH命令,结束追踪。master会进程通过向子进程发送 PTRACE_CONT信号,此时子进程会变成TASK_RUNING状态。
即:ptrace(PTRACE_DETACH, pid,(void *) 1, 0); 这行代码
问题在于 docker 1.10.3 中 收到 SIGCONT信号后,并没有执行restart_syscall,恢复进程执行的上下文,改变了进程运行时上下文。
因此子进程受到SIGSTOP到SIGCONT这段时间内,正在被执行的函数由于运行时上下文导致执行异常。后面的代码继续执行。
sleep(5);
echo "asdadadasdsad";
6、将docker版本从1.10.3升级到1.11.2,通过步骤5的测试,发现问题不存在。