php-fpm重启导致的程序执行中断问题详解

背景和初步排查

• 订单业务对账时报警了，有笔订单在我们自己的mongo库里没有找到
• 业务接口  /3/xx/vgift/send 调用礼物系统  sendPresent 接口完成送礼， 之后写mongo，但是php error log 里却查不到任何mongo异常日志
• 写mongo没有异常，但是库里却没记录,推断只有2个可能

1是error log 丢日志了
2是程序执行过程中操作完sendPresent后down掉了，导致没写入mongo
-第一个情况工作多年的经验来看应该不至于，那就先根据第二种情况继续查吧

• 那就去看下php-fpm 的日志，看对应的时间点有没有什么异常

[wu.daolin@web001.m6~]$ grep "2017 05:28" /var/log/php-fpm.log
[25-Jun-2017 05:28:01] NOTICE: Terminating ...

跟订单时间刚好吻合，那肯定有必要研究下了

熟悉下 php-fpm 的管理

php-fpm 是通过 php-fpm这个命令进行管理的，我们先看下这个命令

man php-fpm

这里有提到，php-fpm then responds to several POSIX signals php-fpm 会对下面几个信号作（自己的）处理

• SIGINT, SIGTERM: immediate termination
• SIGQUIT: graceful stop
• SIGUSR1: re-open log file
• SIGUSR2: graceful reload of all workers + reload of fpm conf/binary

动手验证下

sudo kill -QUIT {php-fpm-pid}

[26-Jun-2017 13:58:22] NOTICE: Finishing ...            
[26-Jun-2017 13:58:22] NOTICE: exiting, bye-bye!

sudo kill -TERM {php-fpm-pid}

[26-Jun-2017 13:59:21] NOTICE: Terminating ...            
[26-Jun-2017 13:59:21] NOTICE: exiting, bye-bye!

sudo kill -USR2 12583

[26-Jun-2017 14:00:48] NOTICE: Reloading in progress ...          
[26-Jun-2017 14:00:48] NOTICE: reloading: execvp("/usr/sbin/php-fpm", {"/usr/sbin/php-fpm", "--daemonize"})    
[26-Jun-2017 14:00:48] NOTICE: using inherited socket fd=8, "10.30.60.87:9000"        
[26-Jun-2017 14:00:48] NOTICE: using inherited socket fd=8, "10.30.60.87:9000"        
[26-Jun-2017 14:00:48] NOTICE: fpm is running, pid 12696          
[26-Jun-2017 14:00:48] NOTICE: ready to handle connections

从验证结果推断

在 05:28:01这个时间有人给php-fpm 发送了SIGTERM信号，在这个点发生很可能是个定时任务， 确认果然是这样 28 5 * * * root /etc/init.d/php-fpm restart> /dev/null

我们的 php-fpm 管理