为什么我的 Drupal 间歇性变慢？ Stracing 显示大量重复的 sendto 调用

Question

我管理的一个 Drupal 站点偶尔会加载得很慢。如果我在发生这种情况时跟踪 PHP-FPM，我会看到很多 poll/recvfrom/sendto 系统调用，内容似乎相同：

[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24589, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "7[=10=][=10=]INSERT INTO menu_router\n   "..., 651, MSG_DONTWAIT, NULL, 0) = 651
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24578, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "\[=10=][=10=]INSERT INTO menu_router\n   "..., 608, MSG_DONTWAIT, NULL, 0) = 608
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24567, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "T[=10=][=10=]INSERT INTO menu_router\n   "..., 600, MSG_DONTWAIT, NULL, 0) = 600
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24556, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "2[=10=][=10=]INSERT INTO menu_router\n   "..., 566, MSG_DONTWAIT, NULL, 0) = 566
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24545, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "[=10=][=10=]INSERT INTO menu_router\n   "..., 547, MSG_DONTWAIT, NULL, 0) = 547
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24534, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "\r[=10=][=10=]INSERT INTO menu_router\n   "..., 529, MSG_DONTWAIT, NULL, 0) = 529
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24523, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "B[=10=][=10=]INSERT INTO menu_router\n   "..., 582, MSG_DONTWAIT, NULL, 0) = 582
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24512, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, ":[=10=][=10=]INSERT INTO menu_router\n   "..., 574, MSG_DONTWAIT, NULL, 0) = 574
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24501, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "([=10=][=10=]INSERT INTO menu_router\n   "..., 556, MSG_DONTWAIT, NULL, 0) = 556
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24490, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "4[=10=][=10=]INSERT INTO menu_router\n   "..., 568, MSG_DONTWAIT, NULL, 0) = 568
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24479, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "([=10=][=10=]INSERT INTO menu_router\n   "..., 556, MSG_DONTWAIT, NULL, 0) = 556
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24468, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, " [=10=][=10=]INSERT INTO menu_router\n   "..., 548, MSG_DONTWAIT, NULL, 0) = 548
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24457, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, ",[=10=][=10=]INSERT INTO menu_router\n   "..., 560, MSG_DONTWAIT, NULL, 0) = 560
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24446, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "[=10=][=10=]INSERT INTO menu_router\n   "..., 540, MSG_DONTWAIT, NULL, 0) = 540
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24435, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "6[=10=][=10=]INSERT INTO menu_router\n   "..., 570, MSG_DONTWAIT, NULL, 0) = 570
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24424, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "3[=10=][=10=]INSERT INTO menu_router\n   "..., 687, MSG_DONTWAIT, NULL, 0) = 687
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24413, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "6[=10=][=10=]INSERT INTO menu_router\n   "..., 1674, MSG_DONTWAIT, NULL, 0) = 1674
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24402, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "![=10=][=10=]INSERT INTO menu_router\n   "..., 549, MSG_DONTWAIT, NULL, 0) = 549
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24391, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "3[=10=][=10=]INSERT INTO menu_router\n   "..., 567, MSG_DONTWAIT, NULL, 0) = 567
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24380, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "$[=10=][=10=]INSERT INTO menu_router\n   "..., 552, MSG_DONTWAIT, NULL, 0) = 552
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24369, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "*[=10=][=10=]INSERT INTO menu_router\n   "..., 558, MSG_DONTWAIT, NULL, 0) = 558
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24358, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "9[=10=][=10=]INSERT INTO menu_router\n   "..., 573, MSG_DONTWAIT, NULL, 0) = 573
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24347, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "*[=10=][=10=]INSERT INTO menu_router\n   "..., 558, MSG_DONTWAIT, NULL, 0) = 558
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24336, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "-[=10=][=10=]INSERT INTO menu_router\n   "..., 561, MSG_DONTWAIT, NULL, 0) = 561
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24325, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "[=10=][=10=]INSERT INTO menu_router\n   "..., 543, MSG_DONTWAIT, NULL, 0) = 543
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=5, revents=POLLIN}])
[pid 27381] recvfrom(5, "[=10=][=10=][=10=][=10=][=10=][=10=][=10=]", 24314, MSG_DONTWAIT, NULL, NULL) = 11
[pid 27381] sendto(5, "[=10=][=10=]INSERT INTO menu_router\n   "..., 522, MSG_DONTWAIT, NULL, 0) = 522
[pid 27381] poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928 <unfinished ...>

所有超时都是合理的，所以我认为这不是问题所在。由于服务器配置与我的其他站点相同，我认为这是代码问题，但我不确定 PHP 中的什么会导致此问题。

它是 Drupal 6.28 和 PHP 5.5.20。

Answer 1

你的 recvfrom/sendto 只是 MySQL 查询，所以没有问题。

插入 menu_router table 表示 Drupal 正在重建此 table（参见：menu_rebuild() API）；

This function will clear and populate the {menu_router} table, add entries to {menu_links} for new router items, and then remove stale items from {menu_links}.

这是由 menu_rebuild_needed 变量（如果已设置）或外部模块（例如 Devel）触发的，或者只是在您的主题设置中启用了 '在每一页上重建主题注册表。”选项。

通常重建菜单是清除缓存的一次性过程。如果以上建议没有帮助，您需要通过放置断点和打印回溯来检查 module/code 到底调用了 menu_rebuild()（在 includes/menu.inc 中）。

一种方法（如果存在 Devel）是使用 dd()，例如

function menu_rebuild() {
  dd(debug_backtrace()); // Adding temporary debug line.

然后检查您的 /tmp/drupal_debug.txt 文件以获取回溯详细信息。

为什么我的 Drupal 间歇性变慢？ Stracing 显示大量重复的 sendto 调用

Why my Drupal is intermittently slow? Stracing shows a lot of repeated sendto calls

php

performance

drupal