最近老高发现服务器的CPU总是被某个php-fpm占用过高,记录一下如何排查。

发现

如何发现的呢?当然是使用top命令,发现系统的load average>3,这说明系统已经处于比较高的负载中。

尝试解决

当我把php-fpm重启后,没过一会儿又开始cpu狂飙!这是什么鬼?

开始排查

首先,我们开启在php-fmp.conf中开启错误日志,慢执行日志还有常规日志

error_log = /var/log/php/error.log
access.log = /var/log/php/access.$pool.log
access.format = "%R - %u %t \"%m %r%Q%q\" %s %f %{mili}d %{kilo}M %{system}C%%"
slowlog = /var/log/php/slow.$pool.log
request_slowlog_timeout = 3s

重启php-fpm后我们开始监视日志

# 查看慢执行日志

[15-May-2015 12:50:22]  [pool www] pid 1819
script_filename = /home/ftp/phpergao/wwwroot/index.php
[0x00007f2d286c2790] replace() /home/ftp/phpergao/wwwroot/usr/plugins/CdnHelper/Plugin.php:72
[0x00007fff78ab00f0] replace() unknown:0
[0x00007f2d286c2420] call_user_func_array() /home/ftp/phpergao/wwwroot/var/Typecho/Plugin.php:489
[0x00007fff78ab0430] __call() unknown:0
[0x00007f2d286c1f78] contentEx() /home/ftp/phpergao/wwwroot/var/Widget/Abstract/Contents.php:141
[0x00007f2d286c1b78] ___content() /home/ftp/phpergao/wwwroot/var/Typecho/Widget.php:385
[0x00007fff78ab0850] __get() unknown:0
[0x00007f2d286c1870] content() /home/ftp/phpergao/wwwroot/var/Widget/Abstract/Contents.php:783
[0x00007f2d286c1628] content() /home/ftp/phpergao/wwwroot/var/Widget/Archive.php:1401
[0x00007f2d286c14d0] content() /home/ftp/phpergao/wwwroot/usr/themes/just/index.php:32
[0x00007f2d286c10f8] +++ dump failed

[15-May-2015 19:18:48]  [pool www] pid 5597
script_filename = /home/ftp/phpergao/wwwroot/index.php
[0x00007ff17fcf0168] __call() /home/ftp/phpergao/wwwroot/var/Typecho/Plugin.php:483
[0x00007fff915493c0] __call() unknown:0
[0x00007ff17fcefca8] ___title() /home/ftp/phpergao/wwwroot/var/Typecho/Widget.php:387
[0x00007fff915497e0] __get() unknown:0
[0x00007ff17fcef960] title() /home/ftp/phpergao/wwwroot/var/Widget/Abstract/Contents.php:809
[0x00007ff17fcef6d0] title() /home/ftp/phpergao/wwwroot/usr/themes/just/index.php:23
[0x00007ff17fcef2f8] +++ dump failed

其中contentEx引起了我的注意,这个方法是一个钩子,系统在获取到文章内容后执行,老高的有几个插件都挂载在此,突然就有想法了。

于是立即暂停有关的插件,过一阵负载变为load average: 0.39, 0.29, 0.42。

记录程序运行细节

记录程序运行时间


跟踪php的系统调用

老高使用strace查看php主进程以及fork出的子进程的系统调用,并输出到/tmp/output.txt

strace -o /tmp/output.txt -T -tt -F -e trace=all -p 31920

将输出的文件用scp拷贝到本地电脑上,经过分析,并发+插件几乎拖死了CPU。

结论

  1. 某些数据的展示与否最好把性能也考虑上
  2. 正则的效率不高,能不用尽量不用
  3. 主题中如果同一个变量要使用多次,请将其先保存至一个临时变量
  4. 缓存很重要
  5. strace是个好工具

这篇文章也可以学习一下 PHP高效率写法(详解原因)

如果你选mysql数据库作为数据持久化的工具,那么就需要一个合理的日志配置,这样有助于排错和数据备份及恢复!

首先我们可以通过下面的MySQL的sql查询正在运行中的日志配置。

刚好我们熟悉一下SHOW VARIABLES LIKE的用法!这个命令是用来查询MySQL运行时配置的语句,LIKE后面的可以接通配符查找!

还有对应的设置语法叫SET GLOBAL,后面我们会用到。

mysql> SHOW VARIABLES LIKE '%log%';
+-----------------------------------------+---------------------------------+
| Variable_name                           | Value                           |
+-----------------------------------------+---------------------------------+
| back_log                                | 50                              |
| binlog_cache_size                       | 32768                           |
| binlog_direct_non_transactional_updates | OFF                             |
| binlog_format                           | STATEMENT                       |
| expire_logs_days                        | 0                               |
| general_log                             | OFF                             |
| general_log_file                        | /var/run/mysqld/mysqld.log      |
| innodb_flush_log_at_trx_commit          | 1                               |
| innodb_locks_unsafe_for_binlog          | OFF                             |
| innodb_log_buffer_size                  | 1048576                         |
| innodb_log_file_size                    | 5242880                         |
| innodb_log_files_in_group               | 2                               |
| innodb_log_group_home_dir               | ./                              |
| innodb_mirrored_log_groups              | 1                               |
| log                                     | OFF                             |
| log_bin                                 | OFF                             |
| log_bin_trust_function_creators         | OFF                             |
| log_bin_trust_routine_creators          | OFF                             |
| log_error                               | /var/log/mysqld.log             |
*| log_output                              | FILE                            |*
| log_queries_not_using_indexes           | OFF                             |
| log_slave_updates                       | OFF                             |
| log_slow_queries                        | OFF                             |
| log_warnings                            | 1                               |
| max_binlog_cache_size                   | 18446744073709547520            |
| max_binlog_size                         | 1073741824                      |
| max_relay_log_size                      | 0                               |
| relay_log                               |                                 |
| relay_log_index                         |                                 |
| relay_log_info_file                     | relay-log.info                  |
| relay_log_purge                         | ON                              |
| relay_log_space_limit                   | 0                               |
| slow_query_log                          | OFF                             |
| slow_query_log_file                     | /var/run/mysqld/mysqld-slow.log |
| sql_log_bin                             | ON                              |
| sql_log_off                             | OFF                             |
| sql_log_update                          | ON                              |
| sync_binlog                             | 0                               |
+-----------------------------------------+---------------------------------+
38 rows in set (0.00 sec)

请注意log_output一行,次配置决定将日志输出到文件还是table中。

我们可以通过SHOW VARIABLES LIKE 'log_output';查询此配置。

通过文件配置

mysql的配置文件位于 /etc/my.cnf

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
user=mysql
symbolic-links=0
# 错误日志
log-error=/var/log/mysql/error_mysql.log
# Slow Query
log-slow-queries=/var/log/mysql/slow_mysql.log
long_query_time=2
# 记录没有使用索引的查询
#log-queries-not-using-indexes

# 常规查询日志,老高主要用于调试PDO参数绑定的查询
general_log=1
general_log_file=/var/log/mysql/general_mysql.log
# < MySql5.1.12
#log = /var/log/mysql/general_mysql.log


[mysqld_safe]
# syslog指将日志记录至系统日志
#syslog
pid-file=/var/run/mysqld/mysqld.pid
log_error=/var/log/mysql/error_mysqld.log

接下来需要重启服务器即可是配置生效!

热配置

有时候可能想在不重启mysql的方式开启日志,怎么办?

当然我们可以通过MySQL的sql查询开启。

以下操作假设你已经以root方式登录进入MySQL交互界面

常规日志

# 查看常规日志配置
SHOW VARIABLES LIKE 'general_log%';

下面我们开启他

# 设置日志文件路径,请先保证路径存在
SET GLOBAL general_log_file='/var/log/mysql/general_mysql.log';
# 开启日志
SET GLOBAL general_log=ON;

# 关闭日志
SET GLOBAL general_log=OFF;

查看常规日志配置

错误日志

聪明的朋友,既然已经知道SET GLOBALSHOW VARIABLES LIKE这两个命令,我相信其他的日志配置就难不倒你了。

所以在此老高就不啰嗦了。