如何分析 PHP-fpm 的慢执行日志 slow_log？

英文原文 / 翻译 / 2592 / 0 / 创建于 5年前

file

通过使用 PHP 慢日志和 PHP FPM 错误日志来定位严重的性能问题来提升 Drupal 或 WordPress 网站的稳定性。

查找你的 Web 网站出现问题的重要手段之一是检查你的 PHP 日志。这篇文章将指导你有关如何使用 PHP 慢日志和 PHP FPM 错误日志来找出性能问题和网站错误。

开始之前

确认你已经具备如下条件：

一个 SFTP 命令行工具（CLI）
了解 PHP 使用

使用 SFTP 下载 PHP 慢日志和 PHP FPM 错误日志

把自己添加到站点团队成员中。
从站点的仪表板获取（测试，开发，实时或 Multidev）环境的 SFTP连接信息。
打开命令行提示符并粘贴 SFTP 连接信息。

进入日志目录中，使用 get 命令把 PHP 慢日志下载到用于分析的本地机器上。

> $ sftp -o Port=2222 live.91f33beg-d11b-4020a-0005e0-07ca0f4ce7bz@appserver.live.91f33beg-d11b-4020a-0005e0-07ca0f4ce7bz.drush.in
> live.91fd3bea-d11b-401a-85e0-0@appserver.live.91f33beg-d11b-4020a-0005e0-07ca0f4ce7bz.drush.in's password:
> live.91fd3bea-d11b-401a-85e0-0@appserver.live.91f33beg-d11b-4020a-0005e0-07ca0f4ce7bz.drush.in's password:
> Connected to appserver.live.91f33beg-d11b-4020a-0005e0-07ca0f4ce7bz.drush.in.
> sftp> cd logs
> sftp> ls -l
> -rw-r--r--    1 16193    16193      153146 Dec 15 22:34 newrelic.log
> -rw-r--r--    1 16193    16193    55123460 Dec 15 22:59 nginx-access.log
> -rw-r--r--    1 16193    16193     3479688 Dec 09 08:07 nginx-access.log-20141209.gz
> -rw-r--r--    1 16193    16193     5524355 Dec 10 08:07 nginx-access.log-20141210.gz
> -rw-r--r--    1 16193    16193     5602638 Dec 11 08:06 nginx-access.log-20141211.gz
> -rw-r--r--    1 16193    16193     6033991 Dec 12 08:07 nginx-access.log-20141212.gz
> -rw-r--r--    1 16193    16193     5793730 Dec 13 08:07 nginx-access.log-20141213.gz
> -rw-r--r--    1 16193    16193     4688934 Dec 14 08:07 nginx-access.log-20141214.gz
> -rw-r--r--    1 16193    16193     5867636 Dec 15 08:07 nginx-access.log-20141215.gz
> -rw-r--r--    1 16193    16193        3499 Dec 15 22:46 nginx-error.log
> -rw-r--r--    1 16193    16193     1126685 Dec 14 08:07 nginx-error.log-20141214
> -rw-r--r--    1 16193    16193        5017 Dec 15 11:52 php-error.log
> -rw-------    1 16193    16193      642388 Dec 15 22:55 php-fpm-error.log
> -rw-------    1 16193    16193     1067358 Dec 12 20:07 php-fpm-error.log-20141212
> -rw-------    1 16193    16193     7209576 Dec 15 22:55 php-slow.log
> sftp> get php-slow.log
> Fetching /srv/bindings/d142301948514750b2ff39988as6f4b9158e5/logs/php-slow.log to php-slow.log
> /srv/bindings/d142301948514750b2ff39988as6f4b9158e5/logs/php-slow.log 100% 7041KB 370.6KB/s   00:19
> sftp> get php-fpm-error.log
> Fetching /srv/bindings/b6126cf3069a4ba5983f3e9eaf35d627/logs/php-fpm-error.log to php-fpm-error.log
> /srv/bindings/b6126cf3069a4ba5983f3e9eaf35d627/logs/php-fpm-error.log                                                                              100%  717KB 238.9KB/s   00:03
> sftp> exit
> $

分析 PHP 的慢查询日志

可以使用 grep 命令来快速定位某个函数调用被记录的次数，记录的次数越多，优化的优先级就越高：

> $ grep -o 'stream_wrappers.inc' php-slow.log | wc -l
56
> $ grep -o 'page.tpl' php-slow.log | wc -l
48
> $ grep -o '.tpl' php-slow.log | wc -l
73
> $ grep -o 'tdm_'.&ast;.'module' php-slow.log | wc -l
1995
> $

分析 PHP FPM 错误日志

也可以通过分析 NGINX 生成的 PHP FPM 的错误日志定位问题，例如 PHP worker 执行超时和结束。每一个 PHP worker 有一个唯一的进程 ID ，这个 ID 也会被记录在 PHP 慢日志中。因此你可以在 PHP FPM 错误日志中与 PHP 错误日志之间建立关联。在下面的例子中，worker 的 ID 是119057。

// PHP FPM 错误日志内容
[16-Dec-2014 14:54:21] NOTICE: [pool www] child 119057 exited with code 0 after 323.614265 seconds from start

// PHP 慢日志内容
[16-Dec-2014 03:13:50]  [pool www] pid 119057
script_filename = /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/index.php
[0x0000000003160c28] drupal_substr() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/sites/all/modules/contrib/cdn/cdn.module:37
[0x000000000315f820] cdn_file_url_alter() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/module.inc:1101
[0x000000000315f498] drupal_alter() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/file.inc:375
[0x000000000315f148] file_create_url() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/sites/all/modules/contrib/cdn/cdn.basic.css.inc:155
[0x00007fff92553cb0] _cdn_build_css_path() unknown:0
[0x000000000315e160] preg_replace_callback() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/sites/all/modules/contrib/cdn/cdn.basic.css.inc:95
[0x000000000315d7e8] _cdn_build_css_cache() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/sites/all/modules/contrib/cdn/cdn.basic.css.inc:33
[0x000000000315bce0] _cdn_aggregate_css() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:3391
[0x000000000315ad98] drupal_pre_render_styles() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:5931
[0x000000000315a568] drupal_render() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:3127
[0x000000000315a030] drupal_get_css() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/theme.inc:2707
[0x0000000003158210] template_process_html() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/theme.inc:1125
[0x00000000031572c0] theme() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:5967
[0x0000000003156da0] drupal_render() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:5814
[0x0000000003155c68] drupal_render_page() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:2701
[0x00000000031558b0] drupal_deliver_html_page() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/common.inc:2589
[0x0000000003155200] drupal_deliver_page() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/includes/menu.inc:532
[0x0000000003155020] menu_execute_active_handler() /srv/bindings/d9e7c7e384eb453f8ac80cee5d4d791bad2wqq34d/code/index.php:21

通过使用这些方法和文件来定位 PHP 错误和性能问题，能够极大地提高网站的稳定性。