Skip to content

Commit 0901af0

Browse files
committed
make error messages more consistent
1 parent 952efe8 commit 0901af0

File tree

9 files changed

+68
-63
lines changed

9 files changed

+68
-63
lines changed

sapi/fpm/fpm/fpm_children.c

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -150,7 +150,7 @@ static void fpm_child_init(struct fpm_worker_pool_s *wp) /* {{{ */
150150
0 > fpm_env_init_child(wp) ||
151151
0 > fpm_php_init_child(wp)) {
152152

153-
zlog(ZLOG_STUFF, ZLOG_ERROR, "child failed to initialize (pool %s)", wp->config->name);
153+
zlog(ZLOG_STUFF, ZLOG_ERROR, "[pool %s] child failed to initialize", wp->config->name);
154154
exit(255);
155155
}
156156
}
@@ -241,9 +241,9 @@ void fpm_children_bury() /* {{{ */
241241
timersub(&tv1, &child->started, &tv2);
242242

243243
if (restart_child) {
244-
zlog(ZLOG_STUFF, severity, "child %d (pool %s) exited %s after %ld.%06d seconds from start", (int) pid, child->wp->config->name, buf, tv2.tv_sec, (int) tv2.tv_usec);
244+
zlog(ZLOG_STUFF, severity, "[pool %s] child %d exited %s after %ld.%06d seconds from start", child->wp->config->name, (int) pid, buf, tv2.tv_sec, (int) tv2.tv_usec);
245245
} else {
246-
zlog(ZLOG_STUFF, severity, "child %d (pool %s) has been killed by the process managment after %ld.%06d seconds from start", (int) pid, child->wp->config->name, tv2.tv_sec, (int) tv2.tv_usec);
246+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "[pool %s] child %d has been killed by the process managment after %ld.%06d seconds from start", child->wp->config->name, (int) pid, tv2.tv_sec, (int) tv2.tv_usec);
247247
}
248248

249249
fpm_child_close(child, 1 /* in event_loop */);
@@ -277,7 +277,7 @@ void fpm_children_bury() /* {{{ */
277277
}
278278

279279
if (restart_child) {
280-
fpm_children_make(wp, 1 /* in event loop */, 1);
280+
fpm_children_make(wp, 1 /* in event loop */, 1, 0);
281281

282282
if (fpm_globals.is_child) {
283283
break;
@@ -297,7 +297,7 @@ static struct fpm_child_s *fpm_resources_prepare(struct fpm_worker_pool_s *wp) /
297297
c = fpm_child_alloc();
298298

299299
if (!c) {
300-
zlog(ZLOG_STUFF, ZLOG_ERROR, "malloc failed (pool %s)", wp->config->name);
300+
zlog(ZLOG_STUFF, ZLOG_ERROR, "[pool %s] malloc failed", wp->config->name);
301301
return 0;
302302
}
303303

@@ -343,15 +343,15 @@ static void fpm_parent_resources_use(struct fpm_child_s *child) /* {{{ */
343343
}
344344
/* }}} */
345345

346-
int fpm_children_make(struct fpm_worker_pool_s *wp, int in_event_loop, int nb_to_spawn) /* {{{ */
346+
int fpm_children_make(struct fpm_worker_pool_s *wp, int in_event_loop, int nb_to_spawn, int is_debug) /* {{{ */
347347
{
348348
int enough = 0;
349349
pid_t pid;
350350
struct fpm_child_s *child;
351351
int max;
352352

353353
if (wp->config->pm->style == PM_STYLE_DYNAMIC) {
354-
if (!in_event_loop) { /* stating */
354+
if (!in_event_loop) { /* starting */
355355
max = wp->config->pm->dynamic.start_servers;
356356
} else {
357357
max = wp->running_children + nb_to_spawn;
@@ -394,7 +394,7 @@ int fpm_children_make(struct fpm_worker_pool_s *wp, int in_event_loop, int nb_to
394394
fpm_clock_get(&child->started);
395395
fpm_parent_resources_use(child);
396396

397-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "child %d (pool %s) started", (int) pid, wp->config->name);
397+
zlog(ZLOG_STUFF, is_debug ? ZLOG_DEBUG : ZLOG_NOTICE, "[pool %s] child %d started", wp->config->name, (int) pid);
398398
}
399399

400400
}
@@ -405,7 +405,7 @@ int fpm_children_make(struct fpm_worker_pool_s *wp, int in_event_loop, int nb_to
405405

406406
int fpm_children_create_initial(struct fpm_worker_pool_s *wp) /* {{{ */
407407
{
408-
return fpm_children_make(wp, 0 /* not in event loop yet */, 0);
408+
return fpm_children_make(wp, 0 /* not in event loop yet */, 0, 1);
409409
}
410410
/* }}} */
411411

sapi/fpm/fpm/fpm_children.h

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@ int fpm_children_create_initial(struct fpm_worker_pool_s *wp);
1515
int fpm_children_free(struct fpm_child_s *child);
1616
void fpm_children_bury();
1717
int fpm_children_init_main();
18-
int fpm_children_make(struct fpm_worker_pool_s *wp, int in_event_loop, int nb_to_spawn);
18+
int fpm_children_make(struct fpm_worker_pool_s *wp, int in_event_loop, int nb_to_spawn, int is_debug);
1919

2020
struct fpm_child_s;
2121

sapi/fpm/fpm/fpm_conf.c

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -392,40 +392,40 @@ static int fpm_conf_process_all_pools() /* {{{ */
392392
}
393393

394394
if (wp->config->pm == NULL) {
395-
zlog(ZLOG_STUFF, ZLOG_ALERT, "pool %s: the process manager is missing (static or dynamic)", wp->config->name);
395+
zlog(ZLOG_STUFF, ZLOG_ALERT, "[pool %s] the process manager is missing (static or dynamic)", wp->config->name);
396396
return(-1);
397397
}
398398

399399
if (wp->config->pm->style == PM_STYLE_DYNAMIC) {
400400
struct fpm_pm_s *pm = wp->config->pm;
401401

402402
if (pm->dynamic.min_spare_servers <= 0) {
403-
zlog(ZLOG_STUFF, ZLOG_ALERT, "pool %s: min_spare_servers must be a positive value", wp->config->name);
403+
zlog(ZLOG_STUFF, ZLOG_ALERT, "[pool %s] min_spare_servers(%d) must be a positive value", wp->config->name, pm->dynamic.min_spare_servers);
404404
return(-1);
405405
}
406406

407407
if (pm->dynamic.max_spare_servers <= 0) {
408-
zlog(ZLOG_STUFF, ZLOG_ALERT, "pool %s: max_spare_servers must be a positive value", wp->config->name);
408+
zlog(ZLOG_STUFF, ZLOG_ALERT, "[pool %s] max_spare_servers(%d) must be a positive value", wp->config->name, pm->dynamic.max_spare_servers);
409409
return(-1);
410410
}
411411

412412
if (pm->dynamic.min_spare_servers > pm->max_children ||
413413
pm->dynamic.max_spare_servers > pm->max_children) {
414-
zlog(ZLOG_STUFF, ZLOG_ALERT, "pool %s: min_spare_servers(%d) and max_spare_servers(%d) can't be greater than max_children(%d)",
414+
zlog(ZLOG_STUFF, ZLOG_ALERT, "[pool %s] min_spare_servers(%d) and max_spare_servers(%d) cannot be greater than max_children(%d)",
415415
wp->config->name, pm->dynamic.min_spare_servers, pm->dynamic.max_spare_servers, pm->max_children);
416416
return(-1);
417417
}
418418

419419
if (pm->dynamic.max_spare_servers < pm->dynamic.min_spare_servers) {
420-
zlog(ZLOG_STUFF, ZLOG_ALERT, "pool %s: max_spare_servers must be greater or equal than min_spare_servers", wp->config->name);
420+
zlog(ZLOG_STUFF, ZLOG_ALERT, "[pool %s] max_spare_servers(%d) must not be less than min_spare_servers(%d)", wp->config->name, pm->dynamic.max_spare_servers, pm->dynamic.min_spare_servers);
421421
return(-1);
422422
}
423423

424424
if (pm->dynamic.start_servers <= 0) {
425425
pm->dynamic.start_servers = pm->dynamic.min_spare_servers + ((pm->dynamic.max_spare_servers - pm->dynamic.min_spare_servers) / 2);
426-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "pool %s: start_servers has been set to %d", wp->config->name, pm->dynamic.start_servers);
426+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "[pool %s] start_servers has been set to %d", wp->config->name, pm->dynamic.start_servers);
427427
} else if (pm->dynamic.start_servers < pm->dynamic.min_spare_servers || pm->dynamic.start_servers > pm->dynamic.max_spare_servers) {
428-
zlog(ZLOG_STUFF, ZLOG_ALERT, "pool %s: start_servers must not be less than min_spare_servers and not greaters than max_spare_servers", wp->config->name);
428+
zlog(ZLOG_STUFF, ZLOG_ALERT, "[pool %s] start_servers(%d) must not be less than min_spare_servers(%d) and not greater than max_spare_servers(%d)", wp->config->name, pm->dynamic.start_servers, pm->dynamic.min_spare_servers, pm->dynamic.max_spare_servers);
429429
return(-1);
430430
}
431431
}
@@ -434,15 +434,15 @@ static int fpm_conf_process_all_pools() /* {{{ */
434434
if (wp->config->request_slowlog_timeout) {
435435
#if HAVE_FPM_TRACE
436436
if (! (wp->config->slowlog && *wp->config->slowlog)) {
437-
zlog(ZLOG_STUFF, ZLOG_ERROR, "pool %s: 'slowlog' must be specified for use with 'request_slowlog_timeout'",
437+
zlog(ZLOG_STUFF, ZLOG_ERROR, "[pool %s] 'slowlog' must be specified for use with 'request_slowlog_timeout'",
438438
wp->config->name);
439439
return -1;
440440
}
441441
#else
442442
static int warned = 0;
443443

444444
if (!warned) {
445-
zlog(ZLOG_STUFF, ZLOG_WARNING, "pool %s: 'request_slowlog_timeout' is not supported on your system",
445+
zlog(ZLOG_STUFF, ZLOG_WARNING, "[pool %s] 'request_slowlog_timeout' is not supported on your system",
446446
wp->config->name);
447447
warned = 1;
448448
}

sapi/fpm/fpm/fpm_events.c

Lines changed: 13 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -45,29 +45,35 @@ static void fpm_got_signal(int fd, short ev, void *arg) /* {{{ */
4545

4646
switch (c) {
4747
case 'C' : /* SIGCHLD */
48-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "received SIGCHLD");
48+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "received SIGCHLD");
4949
fpm_children_bury();
5050
break;
5151
case 'I' : /* SIGINT */
52-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "received SIGINT");
52+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "received SIGINT");
53+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "Terminating ...");
5354
fpm_pctl(FPM_PCTL_STATE_TERMINATING, FPM_PCTL_ACTION_SET);
5455
break;
5556
case 'T' : /* SIGTERM */
56-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "received SIGTERM");
57+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "received SIGTERM");
58+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "Terminating ...");
5759
fpm_pctl(FPM_PCTL_STATE_TERMINATING, FPM_PCTL_ACTION_SET);
5860
break;
5961
case 'Q' : /* SIGQUIT */
60-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "received SIGQUIT");
62+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "received SIGQUIT");
63+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "Finishing ...");
6164
fpm_pctl(FPM_PCTL_STATE_FINISHING, FPM_PCTL_ACTION_SET);
6265
break;
6366
case '1' : /* SIGUSR1 */
64-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "received SIGUSR1");
67+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "received SIGUSR1");
6568
if (0 == fpm_stdio_open_error_log(1)) {
6669
zlog(ZLOG_STUFF, ZLOG_NOTICE, "log file re-opened");
70+
} else {
71+
zlog(ZLOG_STUFF, ZLOG_ERROR, "unable to re-opened log file");
6772
}
6873
break;
6974
case '2' : /* SIGUSR2 */
70-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "received SIGUSR2");
75+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "received SIGUSR2");
76+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "Reloading in progress ...");
7177
fpm_pctl(FPM_PCTL_STATE_RELOADING, FPM_PCTL_ACTION_SET);
7278
break;
7379
}
@@ -101,7 +107,7 @@ int fpm_event_loop() /* {{{ */
101107
event_add(&signal_fd_event, 0);
102108
fpm_pctl_heartbeat(-1, 0, 0);
103109
fpm_pctl_perform_idle_server_maintenance_heartbeat(-1, 0, 0);
104-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "libevent: entering main loop");
110+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "ready to handle connections");
105111
event_loop(0);
106112
return 0;
107113
}

sapi/fpm/fpm/fpm_php_trace.c

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,7 +53,7 @@ static int fpm_php_trace_dump(struct fpm_child_s *child, FILE *slowlog TSRMLS_DC
5353

5454
zlog_print_time(&tv, buf, buf_size);
5555

56-
fprintf(slowlog, "\n%s pid %d (pool %s)\n", buf, (int) pid, child->wp->config->name);
56+
fprintf(slowlog, "\n%s [pool %s] pid %d\n", buf, child->wp->config->name, (int) pid);
5757

5858
if (0 > fpm_trace_get_strz(buf, buf_size, (long) &SG(request_info).path_translated)) {
5959
return -1;

sapi/fpm/fpm/fpm_process_ctl.c

Lines changed: 10 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -157,9 +157,9 @@ static void fpm_pctl_kill_all(int signo) /* {{{ */
157157
for (child = wp->children; child; child = child->next) {
158158
int res = kill(child->pid, signo);
159159

160-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "sending signal %d %s to child %d (pool %s)", signo,
161-
fpm_signal_names[signo] ? fpm_signal_names[signo] : "",
162-
(int) child->pid, child->wp->config->name);
160+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "[pool %s] sending signal %d %s to child %d",
161+
child->wp->config->name, signo,
162+
fpm_signal_names[signo] ? fpm_signal_names[signo] : "", (int) child->pid);
163163

164164
if (res == 0) {
165165
++alive_children;
@@ -168,7 +168,7 @@ static void fpm_pctl_kill_all(int signo) /* {{{ */
168168
}
169169

170170
if (alive_children) {
171-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "%d %s still alive", alive_children, alive_children == 1 ? "child is" : "children are");
171+
zlog(ZLOG_STUFF, ZLOG_NOTICE, "%d child(ren) still alive", alive_children);
172172
}
173173
}
174174
/* }}} */
@@ -340,10 +340,10 @@ static void fpm_pctl_perform_idle_server_maintenance(struct timeval *now) /* {{{
340340
}
341341
}
342342

343-
zlog(ZLOG_STUFF, ZLOG_DEBUG, "[%s] rate=%d idle=%d active=%d total=%d", wp->config->name, wp->idle_spawn_rate, idle, active, wp->running_children);
343+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "[pool %s] currently %d active children, %d spare children, %d running children. Spawning rate %d", wp->config->name, active, idle, wp->running_children, wp->idle_spawn_rate);
344344

345345
if ((active + idle) != wp->running_children) {
346-
zlog(ZLOG_STUFF, ZLOG_ERROR, "[%s] unable to retrieve spawning informations", wp->config->name);
346+
zlog(ZLOG_STUFF, ZLOG_ERROR, "[pool %s] unable to retrieve process activiry of one or more child(ren). Will try again later.", wp->config->name);
347347
continue;
348348
}
349349

@@ -357,8 +357,7 @@ static void fpm_pctl_perform_idle_server_maintenance(struct timeval *now) /* {{{
357357
if (idle < wp->config->pm->dynamic.min_spare_servers) {
358358
if (wp->running_children >= wp->config->pm->max_children) {
359359
if (!wp->warn_max_children) {
360-
zlog(ZLOG_STUFF, ZLOG_WARNING, "pool %s: server reached max_children setting, consider raising it",
361-
wp->config->name);
360+
zlog(ZLOG_STUFF, ZLOG_WARNING, "[pool %s] server reached max_children setting (%d), consider raising it", wp->config->name, wp->config->pm->max_children);
362361
wp->warn_max_children = 1;
363362
}
364363
wp->idle_spawn_rate = 1;
@@ -367,11 +366,11 @@ static void fpm_pctl_perform_idle_server_maintenance(struct timeval *now) /* {{{
367366
wp->warn_max_children = 0;
368367

369368
if (wp->idle_spawn_rate >= 8) {
370-
zlog(ZLOG_STUFF, ZLOG_WARNING, "pool %s seems busy (you may need to increase start_servers, or min/max_spare_servers), spawning %d children, there are %d idle, and %d total children", wp->config->name, wp->idle_spawn_rate, idle, wp->running_children);
369+
zlog(ZLOG_STUFF, ZLOG_WARNING, "[pool %s] seems busy (you may need to increase start_servers, or min/max_spare_servers), spawning %d children, there are %d idle, and %d total children", wp->config->name, wp->idle_spawn_rate, idle, wp->running_children);
371370
}
372371

373372
i = MIN(wp->idle_spawn_rate, wp->config->pm->dynamic.min_spare_servers - idle);
374-
fpm_children_make(wp, 1, i);
373+
fpm_children_make(wp, 1, i, 1);
375374

376375
/* if it's a child, stop here without creating the next event
377376
* this event is reserved to the master process
@@ -380,7 +379,7 @@ static void fpm_pctl_perform_idle_server_maintenance(struct timeval *now) /* {{{
380379
return;
381380
}
382381

383-
zlog(ZLOG_STUFF, ZLOG_NOTICE, "pool %s: %d child(ren) have been created because of not enough spare children", wp->config->name, i);
382+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "[pool %s] %d child(ren) have been created dynamically", wp->config->name, i);
384383

385384
/* Double the spawn rate for the next iteration */
386385
if (wp->idle_spawn_rate < FPM_MAX_SPAWN_RATE) {

sapi/fpm/fpm/fpm_request.c

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -132,17 +132,17 @@ void fpm_request_check_timed_out(struct fpm_child_s *child, struct timeval *now,
132132

133133
fpm_trace_signal(child->pid);
134134

135-
zlog(ZLOG_STUFF, ZLOG_WARNING, "child %d, script '%s' (pool %s) executing too slow (%d.%06d sec), logging",
136-
(int) child->pid, purified_script_filename, child->wp->config->name, (int) tv.tv_sec, (int) tv.tv_usec);
135+
zlog(ZLOG_STUFF, ZLOG_WARNING, "[pool %s] child %d, script '%s' executing too slow (%d.%06d sec), logging",
136+
child->wp->config->name, (int) child->pid, purified_script_filename, (int) tv.tv_sec, (int) tv.tv_usec);
137137
}
138138
else
139139
#endif
140140
if (terminate_timeout && tv.tv_sec >= terminate_timeout) {
141141
str_purify_filename(purified_script_filename, slot_c.script_filename, sizeof(slot_c.script_filename));
142142
fpm_pctl_kill(child->pid, FPM_PCTL_TERM);
143143

144-
zlog(ZLOG_STUFF, ZLOG_WARNING, "child %d, script '%s' (pool %s) execution timed out (%d.%06d sec), terminating",
145-
(int) child->pid, purified_script_filename, child->wp->config->name, (int) tv.tv_sec, (int) tv.tv_usec);
144+
zlog(ZLOG_STUFF, ZLOG_WARNING, "[pool %s] child %d, script '%s' execution timed out (%d.%06d sec), terminating",
145+
child->wp->config->name, (int) child->pid, purified_script_filename, (int) tv.tv_sec, (int) tv.tv_usec);
146146
}
147147
}
148148
}

sapi/fpm/fpm/fpm_stdio.c

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -114,8 +114,8 @@ static void fpm_stdio_child_said(int fd, short which, void *arg) /* {{{ */
114114

115115
#if 0
116116
if (in_buf == 0 && !fpm_globals.is_child) {
117-
zlog(ZLOG_STUFF, ZLOG_DEBUG, "child %d (pool %s) %s pipe is closed", (int) child->pid,
118-
child->wp->config->name, is_stdout ? "stdout" : "stderr");
117+
zlog(ZLOG_STUFF, ZLOG_DEBUG, "[pool %s] child %d, %s pipe is closed", child->wp->config->name,
118+
(int) child->pid, is_stdout ? "stdout" : "stderr");
119119
}
120120
#endif
121121
}
@@ -151,8 +151,8 @@ static void fpm_stdio_child_said(int fd, short which, void *arg) /* {{{ */
151151
*nl = '\0';
152152
}
153153

154-
zlog(ZLOG_STUFF, ZLOG_WARNING, "child %d (pool %s) said into %s: \"%s\"%s", (int) child->pid,
155-
child->wp->config->name, is_stdout ? "stdout" : "stderr", buf, is_last_message ? ", pipe is closed" : "");
154+
zlog(ZLOG_STUFF, ZLOG_WARNING, "[pool %s] child %d said into %s: \"%s\"%s", child->wp->config->name,
155+
(int) child->pid, is_stdout ? "stdout" : "stderr", buf, is_last_message ? ", pipe is closed" : "");
156156

157157
if (nl) {
158158
int out_buf = 1 + nl - buf;

0 commit comments

Comments
 (0)