用strace调试慢速wordpress站点

Question

我试图找到一个运行非常慢的wordpress站点的底部:在请求页面时，它挂起大约20秒，然后页面才开始加载。

我尝试过通常的方式: WP调试模式，检查缓慢的MySQL查询，禁用插件，检查Apache没有排队请求等等，没有喜悦。现在，我已经使用strace来观察Apache (我以mod_php的身份运行PHP )，试图了解到底发生了什么。不幸的是，我的内核-fu很弱，我需要一些帮助来集成strace输出。

我正在使用-r运行strace，如果我正确地理解了手册页，这将指示之前的sys调用占用的时间。

看一看输出，我看到几个电话占用了5秒，例如：

 0.000114 accept4(4, {sa_family=AF_INET6, sin6_port=htons(46242), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28], SOCK_CLOEXEC) = 13
 0.000116 getsockname(13, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
 0.000109 fcntl(13, F_GETFL)        = 0x2 (flags O_RDWR)
 0.000061 fcntl(13, F_SETFL, O_RDWR|O_NONBLOCK) = 0
 0.000078 read(13, "GET /wp-content/uploads/fake-ici"..., 8000) = 593
 0.000144 stat("/var/www/wp-content/uploads/fake-icicles-500x500.jpg", {st_mode=S_IFREG|0777, st_size=34241, ...}) = 0
 0.000197 open("/var/www/wp-content/uploads/fake-icicles-500x500.jpg", O_RDONLY|O_CLOEXEC) = 14
 0.000100 close(14)                 = 0
 0.000097 read(13, 0x7f66f397b048, 8000) = -1 EAGAIN (Resource temporarily unavailable)
 0.000079 writev(13, [{"HTTP/1.1 304 Not Modified\r\nDate:"..., 182}], 1) = 182
 0.000161 write(8, "127.0.0.1 - - [26/Oct/2016:14:17"..., 235) = 235
 0.000112 times({tms_utime=3107, tms_stime=70, tms_cutime=0, tms_cstime=0}) = 1802798719
 0.000090 poll([{fd=13, events=POLLIN}], 1, 5000) = 0 (Timeout)
 5.005144 shutdown(13, SHUT_WR)     = 0
 0.000130 poll([{fd=13, events=POLLIN}], 1, 2000) = 1 ([{fd=13, revents=POLLIN|POLLHUP}])
 1.000750 read(13, "", 512)         = 0

我的解释是，使用id 13轮询文件描述符需要5秒，并且超时(从末尾到第4行)。13看起来像为将HTTP响应写回客户端而打开的套接字的ID。这是正确的吗？我还能从上面学到什么吗？我是否应该担心在输出中途读取()上的“资源暂时不可用”？

Answer 1

是的，你的解释是对的。

实际上，据我所知，您看到的是一个HTTP KeepAlive。

发生了什么：

接收一个连接并接受它，使用文件描述符= 13：

 0.000114 accept4(4, {sa_family=AF_INET6, sin6_port=htons(46242), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28], SOCK_CLOEXEC) = 13

您收到一个HTTP请求：

 0.000078 read(13, "GET /wp-content/uploads/fake-ici"..., 8000) = 593

您将写入响应，在本例中为304“未修改”，而不是整个文件，因为请求是一个条件GET，可能是因为If-修改-因为我没有读取打开的文件，但不确定)：

 0.000079 writev(13, [{"HTTP/1.1 304 Not Modified\r\nDate:"..., 182}], 1) = 182

将一个条目写入日志文件：

 0.000161 write(8, "127.0.0.1 - - [26/Oct/2016:14:17"..., 235) = 235

然后，由于KeepAlive等待对同一个套接字的另一个请求，默认情况下，Apache为5秒：

 0.000090 poll([{fd=13, events=POLLIN}], 1, 5000) = 0 (Timeout)

在保持活动间隔期间没有其他请求到达，因此您开始关闭TCP连接：

 5.005144 shutdown(13, SHUT_WR)     = 0

至于读取返回的-EAGAIN (资源暂时不可用)这是正常的，检查这里比我的更好的描述：https://stackoverflow.com/questions/10318191/reading-socket-eagain-resource-temporarily-unavailable#10318268