Strace Apache 进程输出显示 24 秒等待？原因是什么？

Question

对其中一个 apache 子进程执行 strace，它显示两次系统调用之间的时间间隔为 24 秒。我如何确定导致此行为的原因。看起来两个子进程花费的时间几乎相同（24.7 和 23.92）秒。

我们使用 apache prefork 与 php5 和 mysql 5

/var/lib/php5/ 是 php 会话文件夹

带有 processid -20539 的 apache Children1 的 strace 输出

ps -u www-数据 | 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.711888 fcntl(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

带有 processid 的 apache Children2 的 strace 输出 - 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.928294 fcntl(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 输出的理解有什么问题吗？

Answer 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 中所述，那么这将解释您的漫长等待。