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()37 void fpm_request_accepting() /* {{{ */
38 {
39 struct fpm_scoreboard_proc_s *proc;
40 struct timeval now;
41
42 fpm_clock_get(&now);
43
44 proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
45 if (proc == NULL) {
46 zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
47 return;
48 }
49
50 proc->request_stage = FPM_REQUEST_ACCEPTING;
51 proc->tv = now;
52 fpm_scoreboard_proc_release(proc);
53
54 /* idle++, active-- */
55 fpm_scoreboard_update(1, -1, 0, 0, 0, 0, 0, FPM_SCOREBOARD_ACTION_INC, NULL);
56 }
57 /* }}} */
58
fpm_request_reading_headers()59 void fpm_request_reading_headers() /* {{{ */
60 {
61 struct fpm_scoreboard_proc_s *proc;
62
63 struct timeval now;
64 clock_t now_epoch;
65 #ifdef HAVE_TIMES
66 struct tms cpu;
67 #endif
68
69 fpm_clock_get(&now);
70 now_epoch = time(NULL);
71 #ifdef HAVE_TIMES
72 times(&cpu);
73 #endif
74
75 proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
76 if (proc == NULL) {
77 zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
78 return;
79 }
80
81 proc->request_stage = FPM_REQUEST_READING_HEADERS;
82 proc->tv = now;
83 proc->accepted = now;
84 proc->accepted_epoch = now_epoch;
85 #ifdef HAVE_TIMES
86 proc->cpu_accepted = cpu;
87 #endif
88 proc->requests++;
89 proc->request_uri[0] = '\0';
90 proc->request_method[0] = '\0';
91 proc->script_filename[0] = '\0';
92 proc->query_string[0] = '\0';
93 proc->auth_user[0] = '\0';
94 proc->content_length = 0;
95 fpm_scoreboard_proc_release(proc);
96
97 /* idle--, active++, request++ */
98 fpm_scoreboard_update(-1, 1, 0, 0, 1, 0, 0, FPM_SCOREBOARD_ACTION_INC, NULL);
99 }
100 /* }}} */
101
fpm_request_info()102 void fpm_request_info() /* {{{ */
103 {
104 struct fpm_scoreboard_proc_s *proc;
105 char *request_uri = fpm_php_request_uri();
106 char *request_method = fpm_php_request_method();
107 char *script_filename = fpm_php_script_filename();
108 char *query_string = fpm_php_query_string();
109 char *auth_user = fpm_php_auth_user();
110 size_t content_length = fpm_php_content_length();
111 struct timeval now;
112
113 fpm_clock_get(&now);
114
115 proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
116 if (proc == NULL) {
117 zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
118 return;
119 }
120
121 proc->request_stage = FPM_REQUEST_INFO;
122 proc->tv = now;
123
124 if (request_uri) {
125 strlcpy(proc->request_uri, request_uri, sizeof(proc->request_uri));
126 }
127
128 if (request_method) {
129 strlcpy(proc->request_method, request_method, sizeof(proc->request_method));
130 }
131
132 if (query_string) {
133 strlcpy(proc->query_string, query_string, sizeof(proc->query_string));
134 }
135
136 if (auth_user) {
137 strlcpy(proc->auth_user, auth_user, sizeof(proc->auth_user));
138 }
139
140 proc->content_length = content_length;
141
142 /* if cgi.fix_pathinfo is set to "1" and script cannot be found (404)
143 the sapi_globals.request_info.path_translated is set to NULL */
144 if (script_filename) {
145 strlcpy(proc->script_filename, script_filename, sizeof(proc->script_filename));
146 }
147
148 fpm_scoreboard_proc_release(proc);
149 }
150 /* }}} */
151
fpm_request_executing()152 void fpm_request_executing() /* {{{ */
153 {
154 struct fpm_scoreboard_proc_s *proc;
155 struct timeval now;
156
157 fpm_clock_get(&now);
158
159 proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
160 if (proc == NULL) {
161 zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
162 return;
163 }
164
165 proc->request_stage = FPM_REQUEST_EXECUTING;
166 proc->tv = now;
167 fpm_scoreboard_proc_release(proc);
168 }
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 /* }}} */
204
fpm_request_finished()205 void fpm_request_finished() /* {{{ */
206 {
207 struct fpm_scoreboard_proc_s *proc;
208 struct timeval now;
209
210 fpm_clock_get(&now);
211
212 proc = fpm_scoreboard_proc_acquire(NULL, -1, 0);
213 if (proc == NULL) {
214 zlog(ZLOG_WARNING, "failed to acquire proc scoreboard");
215 return;
216 }
217
218 proc->request_stage = FPM_REQUEST_FINISHED;
219 proc->tv = now;
220 fpm_scoreboard_proc_release(proc);
221 }
222 /* }}} */
223
fpm_request_check_timed_out(struct fpm_child_s * child,struct timeval * now,int terminate_timeout,int slowlog_timeout,int track_finished)224 void fpm_request_check_timed_out(struct fpm_child_s *child, struct timeval *now, int terminate_timeout, int slowlog_timeout, int track_finished) /* {{{ */
225 {
226 struct fpm_scoreboard_proc_s proc, *proc_p;
227
228 proc_p = fpm_scoreboard_proc_acquire(child->wp->scoreboard, child->scoreboard_i, 1);
229 if (!proc_p) {
230 zlog(ZLOG_WARNING, "failed to acquire scoreboard");
231 return;
232 }
233
234 proc = *proc_p;
235 fpm_scoreboard_proc_release(proc_p);
236
237 #if HAVE_FPM_TRACE
238 if (child->slow_logged.tv_sec) {
239 if (child->slow_logged.tv_sec != proc.accepted.tv_sec || child->slow_logged.tv_usec != proc.accepted.tv_usec) {
240 child->slow_logged.tv_sec = 0;
241 child->slow_logged.tv_usec = 0;
242 }
243 }
244 #endif
245
246 if (proc.request_stage > FPM_REQUEST_ACCEPTING && ((proc.request_stage < FPM_REQUEST_END) || track_finished)) {
247 char purified_script_filename[sizeof(proc.script_filename)];
248 struct timeval tv;
249
250 timersub(now, &proc.accepted, &tv);
251
252 #if HAVE_FPM_TRACE
253 if (child->slow_logged.tv_sec == 0 && slowlog_timeout &&
254 proc.request_stage == FPM_REQUEST_EXECUTING && tv.tv_sec >= slowlog_timeout) {
255
256 str_purify_filename(purified_script_filename, proc.script_filename, sizeof(proc.script_filename));
257
258 child->slow_logged = proc.accepted;
259 child->tracer = fpm_php_trace;
260
261 fpm_trace_signal(child->pid);
262
263 zlog(ZLOG_WARNING, "[pool %s] child %d, script '%s' (request: \"%s %s%s%s\") executing too slow (%d.%06d sec), logging",
264 child->wp->config->name, (int) child->pid, purified_script_filename, proc.request_method, proc.request_uri,
265 (proc.query_string[0] ? "?" : ""), proc.query_string,
266 (int) tv.tv_sec, (int) tv.tv_usec);
267 }
268 else
269 #endif
270 if (terminate_timeout && tv.tv_sec >= terminate_timeout) {
271 str_purify_filename(purified_script_filename, proc.script_filename, sizeof(proc.script_filename));
272 fpm_pctl_kill(child->pid, FPM_PCTL_TERM);
273
274 zlog(ZLOG_WARNING, "[pool %s] child %d, script '%s' (request: \"%s %s%s%s\") execution timed out (%d.%06d sec), terminating",
275 child->wp->config->name, (int) child->pid, purified_script_filename, proc.request_method, proc.request_uri,
276 (proc.query_string[0] ? "?" : ""), proc.query_string,
277 (int) tv.tv_sec, (int) tv.tv_usec);
278 }
279 }
280 }
281 /* }}} */
282
fpm_request_is_idle(struct fpm_child_s * child)283 int fpm_request_is_idle(struct fpm_child_s *child) /* {{{ */
284 {
285 struct fpm_scoreboard_proc_s *proc;
286
287 /* no need in atomicity here */
288 proc = fpm_scoreboard_proc_get_from_child(child);
289 if (!proc) {
290 return 0;
291 }
292
293 return proc->request_stage == FPM_REQUEST_ACCEPTING;
294 }
295 /* }}} */
296
fpm_request_last_activity(struct fpm_child_s * child,struct timeval * tv)297 int fpm_request_last_activity(struct fpm_child_s *child, struct timeval *tv) /* {{{ */
298 {
299 struct fpm_scoreboard_proc_s *proc;
300
301 if (!tv) return -1;
302
303 proc = fpm_scoreboard_proc_get_from_child(child);
304 if (!proc) {
305 return -1;
306 }
307
308 *tv = proc->tv;
309
310 return 1;
311 }
312 /* }}} */
313