![Strace Apache 进程输出显示等待 24 秒?可能是什么原因?](https://linux22.com/image/589527/Strace%20Apache%20%E8%BF%9B%E7%A8%8B%E8%BE%93%E5%87%BA%E6%98%BE%E7%A4%BA%E7%AD%89%E5%BE%85%2024%20%E7%A7%92%EF%BC%9F%E5%8F%AF%E8%83%BD%E6%98%AF%E4%BB%80%E4%B9%88%E5%8E%9F%E5%9B%A0%EF%BC%9F.png)
对其中一个 apache 子进程执行 strace,显示两次系统调用之间间隔 24 秒。我如何确定导致此行为的原因?看起来两个子进程所用的时间几乎相同(24.7 秒和 23.92 秒)。
我们正在使用 apache prefork 和 php5 以及 mysql 5
/var/lib/php5/ 是 php 会话文件夹
apache children1 的 strace 输出,其进程号为 -20539
ps -u www-data | grep apache2 | awk'{print"-p" $1}'| xargs strace -o /strace/strace.log -ff -s4096 -r
20539 0.000064 关闭(13)= 0
20539 0.000060 打开(“/var/lib/php5/sess_9t2cvnvdoruh666rjpm515idm0”,O_RDWR|O_CREAT,0600)= 13
20539 0.000065 羊群(13,LOCK_EX)= 0
20539 24.711888fcntl(13,F_SETFD,FD_CLOEXEC) = 0
20539 0.000056 fstat(13,{st_mode=S_IFREG|0600,st_size=211,...})= 0
20539 0.000080 lseek (13,0,SEEK_SET) = 0
apache children2 的 strace 输出,其中 processid 为 - 20556
20556 0.000056 关闭(13)= 0
20556 0.000058 打开(“/var/lib/php5/sess_9t2cvnvdoruh666rjpm515idm0”,O_RDWR|O_CREAT,0600)= 13
20556 0.000062 羊群(13,LOCK_EX)= 0
20556 23.928294fcntl(13,F_SETFD,FD_CLOEXEC) = 0
20556 0.000055 fstat(13,{st_mode=S_IFREG|0600,st_size=211,...})= 0
20556 0.000083 lseek (13,0,SEEK_SET) = 0
文件描述符(13)调用的文件可能有问题吗?我对 strace 输出的理解有什么问题吗?
答案1
在过程中看一下lsof -p <pid>
值得注意的是,您正在寻找 FD 13
即来自我的一个httpd部署。
httpd 10865 apache 13w REG 8,5 1113187 59310687 /var/log/httpd/some_site.log
我会观察获取文件独占锁的争用情况,本例中如 FD 13 所示,如果其他进程正在争用锁,如 fcntl 所示,那么这就可以解释您的长时间等待。