fpm开启slowlog Fsockopen出现Operation now in progress的
问题描述: 前两天老大跟我讲了一个他们原来遇到的问题,php采用fastcgi的方式启动,并且打开slow log日志,当调用fsockopen读取一个连接,这个连接超过了slowlog设置的时间,fpm进程就会抛出一个warning,用来记录关于这个满请求的一些基本信息。 详细描述
问题描述:
前两天老大跟我讲了一个他们原来遇到的问题,php采用fastcgi的方式启动,并且打开slow log日志,当调用fsockopen读取一个连接,这个连接超过了slowlog设置的时间,fpm进程就会抛出一个warning,用来记录关于这个满请求的一些基本信息。
详细描述如下:
假如我们设置的slowlog 的时间为5s,而通过fsockopen去访问一个不存在的ip和端口,连接超时时间设为10s,代码如下:
图1
我们去访问一个不存在的IP和端口,通过浏览器访问,在错误日志里面我们会收到两个warning,一个是fpm抛出来的slowlog,另外一个是PHP Warning:? fsockopen(): unable to connect to 2.3.2.1:9999 (Operation now in progress)。
正常情况来讲,fsockopen连接出错应该出现Connection timed out,但事实并非如此,似乎fpm抛出脚本超时之后就结束了,为什么?
后来在命令行下运行该脚本,却没有出现Operation now in progress,是fsockopen Connection timed out的错误,这就说明并非是fsockopen的问题,发生在fpm上。
本次问题追踪分为两个部分,本文主要介绍fpm的运行机制,关于答案请看
fpm开启slowlog Fsockopen出现Operation now in progress的问题追踪二
问题追踪
因为是在线上出现的问题,线上php的版本是5.2.8,我本地装的是php 5.3,经过测试,php 5.3也有同样的问题。
Operation now in progress 这个异常,本身是没有任何问题的,它是非阻塞connect的一个返回值,该值表明connect正在进行中,等等,非阻塞?可能问题就出现在这里,
如果使用非阻塞connect,后面应该通过调用select,检查select的写事件,一旦返回,则说明有可用数据接收。
要定位这个问题,似乎没有别的办法,只能去看fpm的源码了,在翻看源码时也确实定位到了问题根源。
不过要弄清这个问题,我们先要明白fpm的工作流程。
FPM工作流程
简述
Fpm是多进程的程序,fpm启动时它通过一个master,fork出 max_children为工作进程,并把子进程的进程id及其他相关信息保存到 struct fpm_worker_pool_s指向的children指针中。
工作进程用来接收网络请求,当有链接通过nginx问时,nginx发现我们访问的是php文件,它就会把该文件的绝对目录通过fastcgi_pass指定的网络端口传递到fpm的9000端口,
fpm接收到该请求,并从children中查找空闲进程,通过该空闲进程去处理请求。
详细介绍
图2
在翻看fpm源码过程当中,发现主进程监听的不是网络事件,而是时间事件,现在的时间超过事件所设定的时间后,则会触发fpm_got_signal函数,该函数通过管道sp[2]来进行主进程和子进程的通信,它主要用来处理SIGCHLD、SIGINT、SIGTERM、SIGQUIT、SIGUSR1、SIGUSR2这几个信号,不同的信号有不同的处理逻辑:
代码段1:
static void fpm_got_signal(struct fpm_event_s *ev, short which, void *arg) /* {{{ */ { char c; int res, ret; //fd是sp[2]管道 int fd = ev->fd; ........ switch (c) { case 'C' : /* SIGCHLD */ zlog(ZLOG_DEBUG, "received SIGCHLD"); //调用waitpid,等待子进程产生SIGCHLD fpm_children_bury(); break; case 'I' : /* SIGINT */ zlog(ZLOG_DEBUG, "received SIGINT"); zlog(ZLOG_NOTICE, "Terminating ..."); fpm_pctl(FPM_PCTL_STATE_TERMINATING, FPM_PCTL_ACTION_SET); break; case 'T' : /* SIGTERM */ zlog(ZLOG_DEBUG, "received SIGTERM"); zlog(ZLOG_NOTICE, "Terminating ..."); fpm_pctl(FPM_PCTL_STATE_TERMINATING, FPM_PCTL_ACTION_SET); break; case 'Q' : /* SIGQUIT */ zlog(ZLOG_DEBUG, "received SIGQUIT"); zlog(ZLOG_NOTICE, "Finishing ..."); fpm_pctl(FPM_PCTL_STATE_FINISHING, FPM_PCTL_ACTION_SET); break; ........ }
下面来看一个无比复杂的图:
图3
为了搞清楚细节,阅读了大部分fpm源码,画出了上面的图,很复杂,
看不懂没关系,我根据源码来慢慢讲
Fpm的main函数在sapi/fpm/fpm/fpm_main.c 1548行,
上面一部分都可以忽略,用来处理fpm启动参数和php环境的初始化,来看1824行,
代码段2:
int main(int argc,char **argv){ ......... //fpm初始化 if (0 > fpm_init(argc, argv, fpm_config ? fpm_config : CGIG(fpm_config), fpm_prefix, fpm_pid, test_conf, php_allow_to_run_as_root, force_daemon)) { //出错----- if (fpm_globals.send_config_pipe[1]) { int writeval = 0; zlog(ZLOG_DEBUG, "Sending \"0\" (error) to parent via fd=%d", fpm_globals.send_config_pipe[1]); write(fpm_globals.send_config_pipe[1], &writeval, sizeof(writeval)); close(fpm_globals.send_config_pipe[1]); } return FPM_EXIT_CONFIG; } ......... }
Fpm_init进行了初始化,也就是图中A的位置,它的主要工作正如图3所标示,下面是主要代码
代码段3:
int fpm_init(int argc, char **argv, char *config, char *prefix, char *pid, int test_conf, int run_as_root, int force_daemon) /* {{{ */ { .......... if (0 > fpm_php_init_main() || 0 > fpm_stdio_init_main() ||//初始化io 0 > fpm_conf_init_main(test_conf, force_daemon) ||//加载fpm 配置文件 0 > fpm_unix_init_main() || 0 > fpm_scoreboard_init_main() || 0 > fpm_pctl_init_main() || 0 > fpm_env_init_main() || 0 > fpm_signals_init_main() ||//注册进程信号的callback,很关键 0 > fpm_children_init_main() || 0 > fpm_sockets_init_main() ||//socket 初始化 0 > fpm_worker_pool_init_main() ||//工作池初始化 0 > fpm_event_init_main()) {//事件IO初始化 if (fpm_globals.test_successful) { exit(FPM_EXIT_OK); } else { zlog(ZLOG_ERROR, "FPM initialization failed"); return -1; } } if (0 > fpm_conf_write_pid()) {//写入fpm 的进程id zlog(ZLOG_ERROR, "FPM initialization failed"); return -1; } .......... }
主要工作已经注释到源码里,这里不细谈,
紧接着在 main函数中 有一个fpm_run函数
代码段4:
....... //fcgi_fd 是socket句柄 fcgi_fd = fpm_run(&max_requests); parent = 0; //子进程继续往下执行,父进程会在fpm_run中while /* onced forked tell zlog to also send messages through sapi_cgi_log_fastcgi() */ zlog_set_external_logger(sapi_cgi_log_fastcgi); ........
图3里下面部分操作都的封装到这个函数里了
代码段5:
int fpm_run(int *max_requests) /* {{{ */ { struct fpm_worker_pool_s *wp; /* create initial children in all pools */ for (wp = fpm_worker_all_pools; wp; wp = wp->next) { int is_parent; is_parent = fpm_children_create_initial(wp); //子进程 if (!is_parent) { goto run_child; } /* handle error */ if (is_parent == 2) {//子进程创建失败 fpm_pctl(FPM_PCTL_STATE_TERMINATING, FPM_PCTL_ACTION_SET); fpm_event_loop(1); } } /* run event loop forever */ //主进程监听事件 fpm_event_loop(0); run_child: /* only workers reach this point */ fpm_cleanups_run(FPM_CLEANUP_CHILD); *max_requests = fpm_globals.max_requests; ///返回socket句柄 return fpm_globals.listening_socket; }
该函数先创建子进程,把进程相关信息放在struct fpm_worker_pool_s *wp这个指针里,
父进程调用fpm_event_loop(0),子进程直接返回sock句柄,然后继续运行 fpm_main.c 1848之后的代码,进行accept操作;
fpm_event_loop是时间事件监听操作,
代码段6:
void fpm_event_loop(int err) /* {{{ */ { static struct fpm_event_s signal_fd_event; /* sanity check */ if (fpm_globals.parent_pid != getpid()) { return; } //注册callback = fpm_got_signal /** 设置signal_fd_event参数,ev->fd=sp[0] fpm_signals_get_fd()是管道句柄sp[0]:读; **/ fpm_event_set(&signal_fd_event, fpm_signals_get_fd(), FPM_EV_READ, &fpm_got_signal, NULL); fpm_event_add(&signal_fd_event, 0); /* add timers */ if (fpm_globals.heartbeat > 0) { //fpm超时检测处理 fpm_pctl_heartbeat(NULL, 0, NULL); } ....... while(1){ ............... //wait事件 ret = module->wait(fpm_event_queue_fd, timeout); ............. while (q) { fpm_clock_get(&now); if (q->ev) { if (timercmp(&now, &q->ev->timeout, >) || timercmp(&now, &q->ev->timeout, ==)) { //处理信号SIGCHILD fpm_got_signal fpm_event_fire(q->ev); ............. } } } }
注册fpm_got_signal回调函数,该函数会在下面的监听时间事件时执行。
注意看fpm_pctl_heartbeat函数,这里就是执行慢脚本记录的地方,跟进去看看,
fpm_process_ctl.c 442行
代码段7:
void fpm_pctl_heartbeat(struct fpm_event_s *ev, short which, void *arg) /* {{{ */ { static struct fpm_event_s heartbeat; struct timeval now; if (fpm_globals.parent_pid != getpid()) { return; /* sanity check */ } if (which == FPM_EV_TIMEOUT) { fpm_clock_get(&now);//获取时间 //检测slowlog, fpm_pctl_check_request_timeout(&now); return; } /* ensure heartbeat is not lower than FPM_PCTL_MIN_HEARTBEAT */ fpm_globals.heartbeat = MAX(fpm_globals.heartbeat, FPM_PCTL_MIN_HEARTBEAT); /* first call without setting to initialize the timer */ zlog(ZLOG_DEBUG, "heartbeat have been set up with a timeout of %dms", fpm_globals.heartbeat); fpm_event_set_timer(&heartbeat, FPM_EV_PERSIST, &fpm_pctl_heartbeat, NULL); fpm_event_add(&heartbeat, fpm_globals.heartbeat); }
调用了fpm_ptcl_check_request_timeout函数,可能会发现只有witch== FPM_EV_TIMEOUT的时候,才会调用的,上面的函数传的witch是0 ,它应该是执行不了的,是的,第一次是不会执行的,首次执行会调用463和464行,用来注册时间事件,把fpm_ptcl_hearbeat作为一个回调函数来使用的,所以这里并不影响我们,继续查看fpm_pctl_check_request_timeout函数
代码段8:
static void fpm_pctl_check_request_timeout(struct timeval *now) /* {{{ */ { ........ //检测slow log fpm_request_check_timed_out(child, now, terminate_timeout, slowlog_timeout); .......... }
又是一个调用,fpm_request_check_timed_out,继续跟
fpm_request.c 230行,终于到了,
代码段9:
void fpm_request_check_timed_out(struct fpm_child_s *child, struct timeval *now, int terminate_timeout, int slowlog_timeout) /* {{{ */ { ......... #if HAVE_FPM_TRACE /** 检测子进程运行状态和时间 **/ if (child->slow_logged.tv_sec == 0 && slowlog_timeout && proc.request_stage == FPM_REQUEST_EXECUTING && tv.tv_sec >= slowlog_timeout) { str_purify_filename(purified_script_filename, proc.script_filename, sizeof(proc.script_filename)); child->slow_logged = proc.accepted; child->tracer = fpm_php_trace;//注册输出trace信息的callback函数 //暂停子进程 fpm_trace_signal(child->pid); //记录slow log的日志 zlog(ZLOG_WARNING, "[pool %s] child %d, script '%s' (request: \"%s %s\") executing too slow (%d.%06d sec), logging", child->wp->config->name, (int) child->pid, purified_script_filename, proc.request_method, proc.request_uri, (int) tv.tv_sec, (int) tv.tv_usec); } else #endif if (terminate_timeout && tv.tv_sec >= terminate_timeout) { str_purify_filename(purified_script_filename, proc.script_filename, sizeof(proc.script_filename)); fpm_pctl_kill(child->pid, FPM_PCTL_TERM); zlog(ZLOG_WARNING, "[pool %s] child %d, script '%s' (request: \"%s %s\") execution timed out (%d.%06d sec), terminating", child->wp->config->name, (int) child->pid, purified_script_filename, proc.request_method, proc.request_uri, (int) tv.tv_sec, (int) tv.tv_usec); } } ......... }
这里是关键代码,上面的那个判断是,如果开启了慢日志 && slowlog_timeout&& 当前进程的状态为Running && 进程执行的时间大于我们配置的时间,
slowlog_timeout是php-fpm.conf中配置的request_slowlog_timeout参数,
然后会注册一个callback函数fpm_php_trace,用来在主进程中执行,暂停子进程,最后记录slowlog的日志。
if (terminate_timeout && tv.tv_sec >= terminate_timeout) { 这里开始是中断请求的代码,如果设置了request_terminate_timeout,这里就会被执行。
那上面那个暂停进程是什么意思?为什么要暂停子进程?
暂停子进程的目的,是希望能让父进程获取子进程当前运行时的详细信息,用来打印trace,
现在回到fpm_event_loop函数,来看看这个过程,回到 fpm_event_loop函数
图4
410行是epoll_wait事件,它支持select、poll、epoll
看428行,fpm_event_fire函数,将要执行fpm_got_signal函数,还记得上面说过的一个用来回调的信号处理函数吗?
图5
对就是这里,它将会在产生时间事件的时候被执行:
fpm_events.c 52行
图6
fpm_children_bury函数里调用waitpid,
图7
WNOHANG|WUNTRACED的意思是有任何进程被暂停则立即返回,
如果检测到进程被暂停,则会执行fpm_php_trace抛出trace信息到日志中,(fpm_php_trace是上面代码段9注册的callback),最后发送继续运行的信号给子进程。
图8
子进程收到继续运行的信号会,会继续运行fpm_main.c 1848之后的代码,接收用户请求,处理php脚本。
Fpm的执行流程就是这样,很复杂,涉及的代码量很多,需要慢慢看。
Fpm的工作流程大概是明白了,但是上面的问题还没有找到答案,为什么抛出慢脚本的日志后进程就挂了?
这个问题的答案请参看:fpm开启slowlog Fsockopen出现Operation now in progress的问题追踪二
原文出处:http://www.imsiren.com/archives/1088
热AI工具

Undresser.AI Undress
人工智能驱动的应用程序,用于创建逼真的裸体照片

AI Clothes Remover
用于从照片中去除衣服的在线人工智能工具。

Undress AI Tool
免费脱衣服图片

Clothoff.io
AI脱衣机

AI Hentai Generator
免费生成ai无尽的。

热门文章

热工具

记事本++7.3.1
好用且免费的代码编辑器

SublimeText3汉化版
中文版,非常好用

禅工作室 13.0.1
功能强大的PHP集成开发环境

Dreamweaver CS6
视觉化网页开发工具

SublimeText3 Mac版
神级代码编辑软件(SublimeText3)

win11和win10一样,为了保护系统推出了内存完整性功能,但是很多朋友不知道这个功能有什么用,那么win11内存完整性要不要开呢,其实这与电脑系统有关系。win11内存完整性要不要开:答:如果电脑配置高,或者只是日常办公影音可以开;如果我们的电脑配置较差,或者追求高性能的话不要开。win11内存完整性相关介绍:1、内存完整性原理是硬件虚拟化创建隔离的环境。2、它保护好我们的系统,保护内存安全。3、缺点是,开启该功能后会随时运行,占用内存,降低性能。4、而且一旦开启,关闭起来也会比较麻烦,一定

NVIDIA中有一个dlss功能,用户开启dlss后可以大大提高游戏帧数,因此有不少小伙伴都在问小编dlss怎么打开。首先要保证显卡支持dlss,游戏支持dlss,就可以在游戏中开启了。下面就来看看具体的教程。 答:dlss一般都需要在游戏中开。 开启dlss要满足设备和游戏的条件才可以。 dlss就是“光线追踪效果”,大家可以进入游戏的设置。 然后进入“图像或者图形”设置。 随后找到“光线追踪光照”点击打开即可。 d

硬件加速GPU有必要开吗?随着科技的不断发展与进步,GPU(GraphicsProcessingUnit)作为计算机图形处理的核心组件,扮演着至关重要的角色。然而,一些用户或许对于是否需要开启硬件加速功能持有疑问。本文将探讨硬件加速GPU的必要性,以及开启硬件加速对计算机性能和使用体验的影响。首先,我们需要了解硬件加速GPU的工作原理。GPU是一种专门用

要是之前将vbs关闭之后想要开启了,也是可以开启的,我们可以使用命令代码将其开启,下面一起来看看如何开启vbs吧,其实还是很简单的。win11vbs如何开启:1、首先我们点击“开始菜单”。2、然后点击“windows终端”。3、接着输入“bcdedit/sethypervisorlaunchtypeauto”。4、然后重启电脑,打开开始菜单,在搜索栏中搜索“系统信息”。5、然后找打“基于虚拟化的安全性”是否开启即可。

经常有使用win10系统的小伙伴问以太网禁用怎么开启,其实这个操作非常的简单,需要去进入网络的设置中才可以进行,接下来小编带大家一起来看看吧。win10以太网禁用怎么开启:1、首先点击右下角的网络连接图标,打开网络和Internet设置。2、然后去点击以太网。3、之后点击“更改适配器选项”。4、此时可以右击“以太网”,选择禁用就可以了。

最近很小伙伴发现电脑麦克风打不开,而现如今无论是台式电脑还是笔记本电脑都会带有麦克风的功能,这也为我们提供了大大的方便,但有很多的朋友在使用的过程中会突然发现自己的电脑麦克风没有了声音,下面小编就来教给大家电脑麦克风打开该怎么解决。具体的一起来看看吧。win10麦克风权限在开启的方法1、在Windows10系统下打开录音机时,弹出“您需要在设置中设置麦克风”的提示。2、这时我们可以点击屏幕左下角的开始按钮,在弹出的菜单中选择“设置”菜单项。3、在打开的Windows设置窗口中点击“隐私”图标。4

当我们要长时间离开电脑,但是又不想关机的时候,就可以让电脑进入休眠模式,不过在更新win11后,我们找不到win11休眠模式怎么开启了,其实只要在控制面板里打开即可。win11休眠模式怎么开启方法一:使用开始菜单点击底部开始菜单,接着点击电源按钮,在其中就能休眠了。方法二:运用高级用户菜单1、在桌上面的搜索框中搜索并打开“控制面板”,点开“硬件和声音”选项,点击电源选项下的“更改电源按钮的功能”。2、进入后,点击“更改当前不可用的设置”,、最后勾选“休眠”,并保存就能执行休眠功能了。方法三:指令

在现代社会中,手机已经成为人们生活中不可或缺的工具。智能手机的功能越来越强大,满足了人们日常生活、工作和娱乐的各种需求。而对于一些需要同时使用多个微信账号的用户来说,开启双微信功能就显得尤为重要。本文将教你如何在华为手机上开启双微信功能,让你能够方便地管理多个微信账号。首先,华为手机自带的EMUI系统已经在系统级别上支持双微信功能,因此只需按照以下步骤进行设
