xref: /php-src/sapi/fpm/fpm/fpm_request.c (revision b8360074)
1 	/* (c) 2007,2008 Andrei Nigmatulin */
2 #ifdef HAVE_TIMES
3 #include <sys/times.h>
4 #endif
5 
6 #include "fpm_config.h"
7 
8 #include "fpm.h"
9 #include "fpm_php.h"
10 #include "fpm_str.h"
11 #include "fpm_clock.h"
12 #include "fpm_conf.h"
13 #include "fpm_trace.h"
14 #include "fpm_php_trace.h"
15 #include "fpm_process_ctl.h"
16 #include "fpm_children.h"
17 #include "fpm_scoreboard.h"
18 #include "fpm_status.h"
19 #include "fpm_request.h"
20 #include "fpm_log.h"
21 
22 #include "zlog.h"
23 
24 static const char *requests_stages[] = {
25 	[FPM_REQUEST_ACCEPTING]       = "Idle",
26 	[FPM_REQUEST_READING_HEADERS] = "Reading headers",
27 	[FPM_REQUEST_INFO]            = "Getting request information",
28 	[FPM_REQUEST_EXECUTING]       = "Running",
29 	[FPM_REQUEST_END]             = "Ending",
30 	[FPM_REQUEST_FINISHED]        = "Finishing",
31 };
32 
fpm_request_get_stage_name(int stage)33 const char *fpm_request_get_stage_name(int stage) {
34 	return requests_stages[stage];
35 }
36 
fpm_request_accepting(void)37 void fpm_request_accepting(void)
38 {
39 	struct fpm_scoreboard_proc_s *proc;
40 	struct timeval now;
41 
42 	fpm_clock_get(&now);
43 
44 	fpm_scoreboard_update_begin(NULL);
45 
46 	proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
47 	if (proc == NULL) {
48 		zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
49 		return;
50 	}
51 
52 	proc->request_stage = FPM_REQUEST_ACCEPTING;
53 	proc->tv = now;
54 	fpm_scoreboard_proc_release(proc);
55 
56 	/* idle++, active-- */
57 	fpm_scoreboard_update_commit(1, -1, 0, 0, 0, 0, 0, FPM_SCOREBOARD_ACTION_INC, NULL);
58 }
59 
fpm_request_reading_headers(void)60 void fpm_request_reading_headers(void)
61 {
62 	struct fpm_scoreboard_proc_s *proc;
63 
64 	struct timeval now;
65 	clock_t now_epoch;
66 #ifdef HAVE_TIMES
67 	struct tms cpu;
68 #endif
69 
70 	fpm_clock_get(&now);
71 	now_epoch = time(NULL);
72 #ifdef HAVE_TIMES
73 	times(&cpu);
74 #endif
75 
76 	fpm_scoreboard_update_begin(NULL);
77 
78 	proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
79 	if (proc == NULL) {
80 		zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
81 		return;
82 	}
83 
84 	proc->request_stage = FPM_REQUEST_READING_HEADERS;
85 	proc->tv = now;
86 	proc->accepted = now;
87 	proc->accepted_epoch = now_epoch;
88 #ifdef HAVE_TIMES
89 	proc->cpu_accepted = cpu;
90 #endif
91 	proc->requests++;
92 	proc->request_uri[0] = '\0';
93 	proc->request_method[0] = '\0';
94 	proc->script_filename[0] = '\0';
95 	proc->query_string[0] = '\0';
96 	proc->auth_user[0] = '\0';
97 	proc->content_length = 0;
98 	fpm_scoreboard_proc_release(proc);
99 
100 	/* idle--, active++, request++ */
101 	fpm_scoreboard_update_commit(-1, 1, 0, 0, 1, 0, 0, FPM_SCOREBOARD_ACTION_INC, NULL);
102 }
103 
fpm_request_info(void)104 void fpm_request_info(void)
105 {
106 	struct fpm_scoreboard_proc_s *proc;
107 	char *request_uri = fpm_php_request_uri();
108 	char *request_method = fpm_php_request_method();
109 	char *script_filename = fpm_php_script_filename();
110 	char *query_string = fpm_php_query_string();
111 	char *auth_user = fpm_php_auth_user();
112 	size_t content_length = fpm_php_content_length();
113 	struct timeval now;
114 
115 	fpm_clock_get(&now);
116 
117 	proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
118 	if (proc == NULL) {
119 		zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
120 		return;
121 	}
122 
123 	proc->request_stage = FPM_REQUEST_INFO;
124 	proc->tv = now;
125 
126 	if (request_uri) {
127 		strlcpy(proc->request_uri, request_uri, sizeof(proc->request_uri));
128 	}
129 
130 	if (request_method) {
131 		strlcpy(proc->request_method, request_method, sizeof(proc->request_method));
132 	}
133 
134 	if (query_string) {
135 		strlcpy(proc->query_string, query_string, sizeof(proc->query_string));
136 	}
137 
138 	if (auth_user) {
139 		strlcpy(proc->auth_user, auth_user, sizeof(proc->auth_user));
140 	}
141 
142 	proc->content_length = content_length;
143 
144 	/* if cgi.fix_pathinfo is set to "1" and script cannot be found (404)
145 		the sapi_globals.request_info.path_translated is set to NULL */
146 	if (script_filename) {
147 		strlcpy(proc->script_filename, script_filename, sizeof(proc->script_filename));
148 	}
149 
150 	fpm_scoreboard_proc_release(proc);
151 }
152 
fpm_request_executing(void)153 void fpm_request_executing(void)
154 {
155 	struct fpm_scoreboard_proc_s *proc;
156 	struct timeval now;
157 
158 	fpm_clock_get(&now);
159 
160 	proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
161 	if (proc == NULL) {
162 		zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
163 		return;
164 	}
165 
166 	proc->request_stage = FPM_REQUEST_EXECUTING;
167 	proc->tv = now;
168 	fpm_scoreboard_proc_release(proc);
169 }
170 
fpm_request_end(void)171 void fpm_request_end(void)
172 {
173 	struct fpm_scoreboard_proc_s *proc;
174 	struct timeval now;
175 #ifdef HAVE_TIMES
176 	struct tms cpu;
177 #endif
178 	size_t memory = zend_memory_peak_usage(1);
179 
180 	fpm_clock_get(&now);
181 #ifdef HAVE_TIMES
182 	times(&cpu);
183 #endif
184 
185 	proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
186 	if (proc == NULL) {
187 		zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
188 		return;
189 	}
190 	proc->request_stage = FPM_REQUEST_FINISHED;
191 	proc->tv = now;
192 	timersub(&now, &proc->accepted, &proc->duration);
193 #ifdef HAVE_TIMES
194 	timersub(&proc->tv, &proc->accepted, &proc->cpu_duration);
195 	proc->last_request_cpu.tms_utime = cpu.tms_utime - proc->cpu_accepted.tms_utime;
196 	proc->last_request_cpu.tms_stime = cpu.tms_stime - proc->cpu_accepted.tms_stime;
197 	proc->last_request_cpu.tms_cutime = cpu.tms_cutime - proc->cpu_accepted.tms_cutime;
198 	proc->last_request_cpu.tms_cstime = cpu.tms_cstime - proc->cpu_accepted.tms_cstime;
199 #endif
200 	proc->memory = memory;
201 	fpm_scoreboard_proc_release(proc);
202 }
203 
fpm_request_finished(void)204 void fpm_request_finished(void)
205 {
206 	struct fpm_scoreboard_proc_s *proc;
207 	struct timeval now;
208 
209 	fpm_clock_get(&now);
210 
211 	proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
212 	if (proc == NULL) {
213 		zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
214 		return;
215 	}
216 
217 	proc->request_stage = FPM_REQUEST_FINISHED;
218 	proc->tv = now;
219 	fpm_scoreboard_proc_release(proc);
220 }
221 
fpm_request_check_timed_out(struct fpm_child_s * child,struct timeval * now,int terminate_timeout,int slowlog_timeout,int track_finished)222 void fpm_request_check_timed_out(struct fpm_child_s *child, struct timeval *now, int terminate_timeout, int slowlog_timeout, int track_finished) /* {{{ */
223 {
224 	struct fpm_scoreboard_proc_s proc, *proc_p;
225 
226 	proc_p = fpm_scoreboard_proc_acquire(child->wp->scoreboard, child->scoreboard_i, 1);
227 	if (!proc_p) {
228 		zlog(ZLOG_NOTICE, "failed to acquire scoreboard");
229 		return;
230 	}
231 
232 	proc = *proc_p;
233 	fpm_scoreboard_proc_release(proc_p);
234 
235 #if HAVE_FPM_TRACE
236 	if (child->slow_logged.tv_sec) {
237 		if (child->slow_logged.tv_sec != proc.accepted.tv_sec || child->slow_logged.tv_usec != proc.accepted.tv_usec) {
238 			child->slow_logged.tv_sec = 0;
239 			child->slow_logged.tv_usec = 0;
240 		}
241 	}
242 #endif
243 
244 	if (proc.request_stage > FPM_REQUEST_ACCEPTING && ((proc.request_stage < FPM_REQUEST_END) || track_finished)) {
245 		char purified_script_filename[sizeof(proc.script_filename)];
246 		struct timeval tv;
247 
248 		timersub(now, &proc.accepted, &tv);
249 
250 #if HAVE_FPM_TRACE
251 		if (child->slow_logged.tv_sec == 0 && slowlog_timeout &&
252 				proc.request_stage == FPM_REQUEST_EXECUTING && tv.tv_sec >= slowlog_timeout) {
253 
254 			str_purify_filename(purified_script_filename, proc.script_filename, sizeof(proc.script_filename));
255 
256 			child->slow_logged = proc.accepted;
257 			child->tracer = fpm_php_trace;
258 
259 			fpm_trace_signal(child->pid);
260 
261 			zlog(ZLOG_WARNING, "[pool %s] child %d, script '%s' (request: \"%s %s%s%s\") executing too slow (%d.%06d sec), logging",
262 				child->wp->config->name, (int) child->pid, purified_script_filename, proc.request_method, proc.request_uri,
263 				(proc.query_string[0] ? "?" : ""), proc.query_string,
264 				(int) tv.tv_sec, (int) tv.tv_usec);
265 		}
266 		else
267 #endif
268 		if (terminate_timeout && tv.tv_sec >= terminate_timeout) {
269 			str_purify_filename(purified_script_filename, proc.script_filename, sizeof(proc.script_filename));
270 			fpm_pctl_kill(child->pid, FPM_PCTL_TERM);
271 
272 			zlog(ZLOG_WARNING, "[pool %s] child %d, script '%s' (request: \"%s %s%s%s\") execution timed out (%d.%06d sec), terminating",
273 				child->wp->config->name, (int) child->pid, purified_script_filename, proc.request_method, proc.request_uri,
274 				(proc.query_string[0] ? "?" : ""), proc.query_string,
275 				(int) tv.tv_sec, (int) tv.tv_usec);
276 		}
277 	}
278 }
279 /* }}} */
280 
fpm_request_is_idle(struct fpm_child_s * child)281 int fpm_request_is_idle(struct fpm_child_s *child) /* {{{ */
282 {
283 	struct fpm_scoreboard_proc_s *proc;
284 
285 	/* no need in atomicity here */
286 	proc = fpm_scoreboard_proc_get_from_child(child);
287 	if (!proc) {
288 		return 0;
289 	}
290 
291 	return proc->request_stage == FPM_REQUEST_ACCEPTING;
292 }
293 /* }}} */
294 
fpm_request_last_activity(struct fpm_child_s * child,struct timeval * tv)295 int fpm_request_last_activity(struct fpm_child_s *child, struct timeval *tv) /* {{{ */
296 {
297 	struct fpm_scoreboard_proc_s *proc;
298 
299 	if (!tv) return -1;
300 
301 	proc = fpm_scoreboard_proc_get_from_child(child);
302 	if (!proc) {
303 		return -1;
304 	}
305 
306 	*tv = proc->tv;
307 
308 	return 1;
309 }
310 /* }}} */
311