xref: /php-src/sapi/fpm/fpm/fpm_stdio.c (revision a19267d4)
1 	/* (c) 2007,2008 Andrei Nigmatulin */
2 
3 #include "fpm_config.h"
4 
5 #include <sys/types.h>
6 #include <sys/stat.h>
7 #include <string.h>
8 #include <fcntl.h>
9 #include <unistd.h>
10 #include <errno.h>
11 
12 #include "php_syslog.h"
13 #include "php_network.h"
14 
15 #include "fpm.h"
16 #include "fpm_children.h"
17 #include "fpm_cleanup.h"
18 #include "fpm_events.h"
19 #include "fpm_sockets.h"
20 #include "fpm_stdio.h"
21 #include "zlog.h"
22 
23 static int fd_stderr_original = -1;
24 static int fd_stdout[2];
25 static int fd_stderr[2];
26 
fpm_stdio_init_main(void)27 int fpm_stdio_init_main(void)
28 {
29 	int fd = open("/dev/null", O_RDWR);
30 
31 	if (0 > fd) {
32 		zlog(ZLOG_SYSERROR, "failed to init stdio: open(\"/dev/null\")");
33 		return -1;
34 	}
35 
36 	if (0 > dup2(fd, STDIN_FILENO) || 0 > dup2(fd, STDOUT_FILENO)) {
37 		zlog(ZLOG_SYSERROR, "failed to init stdio: dup2()");
38 		close(fd);
39 		return -1;
40 	}
41 	close(fd);
42 	return 0;
43 }
44 
fpm_use_error_log(void)45 static inline int fpm_use_error_log(void) {
46 	/*
47 	 * the error_log is NOT used when running in foreground
48 	 * and from a tty (user looking at output).
49 	 * So, error_log is used by
50 	 * - SysV init launch php-fpm as a daemon
51 	 * - Systemd launch php-fpm in foreground
52 	 */
53 #ifdef HAVE_UNISTD_H
54 	if (fpm_global_config.daemonize || (!isatty(STDERR_FILENO) && !fpm_globals.force_stderr)) {
55 #else
56 	if (fpm_global_config.daemonize) {
57 #endif
58 		return 1;
59 	}
60 	return 0;
61 }
62 
63 int fpm_stdio_init_final(void)
64 {
65 	if (0 > fpm_stdio_redirect_stderr_to_error_log() ||
66 	    0 > fpm_stdio_redirect_stderr_to_dev_null_for_syslog()) {
67 
68 		return -1;
69 	}
70 
71 	zlog_set_launched();
72 	return 0;
73 }
74 /* }}} */
75 
76 int fpm_stdio_save_original_stderr(void)
77 {
78 	/* STDERR fd gets lost after calling fpm_stdio_init_final() (check GH-8555) so it can be saved.
79 	 * It should be used only when PHP-FPM is not daemonized otherwise it might break some
80 	 * applications (e.g. GH-9754). */
81 	zlog(ZLOG_DEBUG, "saving original STDERR fd: dup()");
82 	fd_stderr_original = dup(STDERR_FILENO);
83 	if (0 > fd_stderr_original) {
84 		zlog(ZLOG_SYSERROR, "failed to save original STDERR fd, access.log records may appear in error_log: dup()");
85 		return -1;
86 	}
87 
88 	return 0;
89 }
90 
91 int fpm_stdio_restore_original_stderr(int close_after_restore)
92 {
93 	/* Restore original STDERR fd if it was previously saved. */
94 	if (-1 != fd_stderr_original) {
95 		zlog(ZLOG_DEBUG, "restoring original STDERR fd: dup2()");
96 		if (0 > dup2(fd_stderr_original, STDERR_FILENO)) {
97 			zlog(ZLOG_SYSERROR, "failed to restore original STDERR fd, access.log records may appear in error_log: dup2()");
98 			return -1;
99 		} else {
100 			if (close_after_restore) {
101 				close(fd_stderr_original);
102 			}
103 		}
104 	}
105 
106 	return 0;
107 }
108 
109 int fpm_stdio_redirect_stderr_to_error_log(void)
110 {
111 	if (fpm_use_error_log()) {
112 		/* prevent duping if logging to syslog */
113 		if (fpm_globals.error_log_fd > 0 && fpm_globals.error_log_fd != STDERR_FILENO) {
114 
115 			/* there might be messages to stderr from other parts of the code, we need to log them all */
116 			if (0 > dup2(fpm_globals.error_log_fd, STDERR_FILENO)) {
117 				zlog(ZLOG_SYSERROR, "failed to tie stderr fd with error_log fd: dup2()");
118 				return -1;
119 			}
120 		}
121 	}
122 
123 	return 0;
124 }
125 
126 int fpm_stdio_redirect_stderr_to_dev_null_for_syslog(void)
127 {
128 	if (fpm_use_error_log()) {
129 #ifdef HAVE_SYSLOG_H
130 		if (fpm_globals.error_log_fd == ZLOG_SYSLOG) {
131 			/* dup to /dev/null when using syslog */
132 			dup2(STDOUT_FILENO, STDERR_FILENO);
133 		}
134 #endif
135 	}
136 
137 	return 0;
138 }
139 
140 int fpm_stdio_init_child(struct fpm_worker_pool_s *wp) /* {{{ */
141 {
142 #ifdef HAVE_SYSLOG_H
143 	if (fpm_globals.error_log_fd == ZLOG_SYSLOG) {
144 		php_closelog(); /* ensure to close syslog not to interrupt with PHP syslog code */
145 	} else
146 #endif
147 
148 	/* Notice: child cannot use master error_log
149 	 * because not aware when being reopen
150 	 * else, should use if (!fpm_use_error_log())
151 	 */
152 	if (fpm_globals.error_log_fd > 0) {
153 		close(fpm_globals.error_log_fd);
154 	}
155 	fpm_globals.error_log_fd = -1;
156 	zlog_set_fd(-1, 0);
157 
158 	return 0;
159 }
160 /* }}} */
161 
162 #define FPM_STDIO_CMD_FLUSH "\0fscf"
163 
164 int fpm_stdio_flush_child(void)
165 {
166 	return write(STDERR_FILENO, FPM_STDIO_CMD_FLUSH, sizeof(FPM_STDIO_CMD_FLUSH));
167 }
168 
169 static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg) /* {{{ */
170 {
171 	int fd = ev->fd;
172 	char buf[1024];
173 	struct fpm_child_s *child;
174 	int is_stdout;
175 	struct fpm_event_s *event;
176 	int in_buf = 0, cmd_pos = 0, pos, start;
177 	int read_fail = 0, create_log_stream;
178 	struct zlog_stream *log_stream;
179 
180 	if (!arg) {
181 		return;
182 	}
183 	child = (struct fpm_child_s *) arg;
184 
185 	is_stdout = (fd == child->fd_stdout);
186 	if (is_stdout) {
187 		event = &child->ev_stdout;
188 	} else {
189 		event = &child->ev_stderr;
190 	}
191 
192 	create_log_stream = !child->log_stream;
193 	if (create_log_stream) {
194 		log_stream = child->log_stream = malloc(sizeof(struct zlog_stream));
195 		zlog_stream_init_ex(log_stream, ZLOG_WARNING, STDERR_FILENO);
196 		zlog_stream_set_decorating(log_stream, child->wp->config->decorate_workers_output);
197 		zlog_stream_set_wrapping(log_stream, ZLOG_TRUE);
198 		zlog_stream_set_msg_prefix(log_stream, STREAM_SET_MSG_PREFIX_FMT,
199 				child->wp->config->name, (int) child->pid, is_stdout ? "stdout" : "stderr");
200 		zlog_stream_set_msg_quoting(log_stream, ZLOG_TRUE);
201 		zlog_stream_set_is_stdout(log_stream, is_stdout);
202 		zlog_stream_set_child_pid(log_stream, (int)child->pid);
203 	} else {
204 		log_stream = child->log_stream;
205 		// if fd type (stdout/stderr) or child's pid is changed,
206 		// then the stream will be finished and msg's prefix will be reinitialized
207 		if (log_stream->is_stdout != (unsigned int)is_stdout || log_stream->child_pid != (int)child->pid) {
208 			zlog_stream_finish(log_stream);
209 			zlog_stream_set_msg_prefix(log_stream, STREAM_SET_MSG_PREFIX_FMT,
210 					child->wp->config->name, (int) child->pid, is_stdout ? "stdout" : "stderr");
211 			zlog_stream_set_is_stdout(log_stream, is_stdout);
212 			zlog_stream_set_child_pid(log_stream, (int)child->pid);
213 		}
214 	}
215 
216 	while (1) {
217 stdio_read:
218 		in_buf = read(fd, buf, sizeof(buf) - 1);
219 		if (in_buf <= 0) { /* no data */
220 			if (in_buf == 0 || !PHP_IS_TRANSIENT_ERROR(errno)) {
221 				/* pipe is closed or error */
222 				read_fail = (in_buf < 0) ? in_buf : 1;
223 			}
224 			break;
225 		}
226 		start = 0;
227 		if (cmd_pos > 0) {
228 			if 	((sizeof(FPM_STDIO_CMD_FLUSH) - cmd_pos) <= in_buf &&
229 					!memcmp(buf, &FPM_STDIO_CMD_FLUSH[cmd_pos], sizeof(FPM_STDIO_CMD_FLUSH) - cmd_pos)) {
230 				zlog_stream_finish(log_stream);
231 				start = cmd_pos;
232 			} else {
233 				zlog_stream_str(log_stream, &FPM_STDIO_CMD_FLUSH[0], cmd_pos);
234 			}
235 			cmd_pos = 0;
236 		}
237 		for (pos = start; pos < in_buf; pos++) {
238 			switch (buf[pos]) {
239 				case '\n':
240 					zlog_stream_str(log_stream, buf + start, pos - start);
241 					zlog_stream_finish(log_stream);
242 					start = pos + 1;
243 					break;
244 				case '\0':
245 					if (pos + sizeof(FPM_STDIO_CMD_FLUSH) <= in_buf) {
246 						if (!memcmp(buf + pos, FPM_STDIO_CMD_FLUSH, sizeof(FPM_STDIO_CMD_FLUSH))) {
247 							zlog_stream_str(log_stream, buf + start, pos - start);
248 							zlog_stream_finish(log_stream);
249 							start = pos + sizeof(FPM_STDIO_CMD_FLUSH);
250 							pos = start - 1;
251 						}
252 					} else if (!memcmp(buf + pos, FPM_STDIO_CMD_FLUSH, in_buf - pos)) {
253 						cmd_pos = in_buf - pos;
254 						zlog_stream_str(log_stream, buf + start, pos - start);
255 						goto stdio_read;
256 					}
257 					break;
258 			}
259 		}
260 		if (start < pos) {
261 			zlog_stream_str(log_stream, buf + start, pos - start);
262 		}
263 	}
264 
265 	if (read_fail) {
266 		if (create_log_stream) {
267 			zlog_stream_set_msg_suffix(log_stream, NULL, ", pipe is closed");
268 			zlog_stream_finish(log_stream);
269 		}
270 		if (read_fail < 0) {
271 			zlog(ZLOG_SYSERROR, "unable to read what child %d said into %s", (int) child->pid, is_stdout ? "stdout" : "stderr");
272 		}
273 
274 		fpm_event_del(event);
275 
276 		child->postponed_free = true;
277 		if (is_stdout) {
278 			close(child->fd_stdout);
279 			child->fd_stdout = -1;
280 		} else {
281 			close(child->fd_stderr);
282 			child->fd_stderr = -1;
283 		}
284 	}
285 }
286 /* }}} */
287 
288 int fpm_stdio_prepare_pipes(struct fpm_child_s *child) /* {{{ */
289 {
290 	if (0 == child->wp->config->catch_workers_output) { /* not required */
291 		return 0;
292 	}
293 
294 	if (0 > pipe(fd_stdout)) {
295 		zlog(ZLOG_SYSERROR, "failed to prepare the stdout pipe");
296 		return -1;
297 	}
298 
299 	if (0 > pipe(fd_stderr)) {
300 		zlog(ZLOG_SYSERROR, "failed to prepare the stderr pipe");
301 		close(fd_stdout[0]);
302 		close(fd_stdout[1]);
303 		return -1;
304 	}
305 
306 	if (0 > fd_set_blocked(fd_stdout[0], 0) || 0 > fd_set_blocked(fd_stderr[0], 0)) {
307 		zlog(ZLOG_SYSERROR, "failed to unblock pipes");
308 		close(fd_stdout[0]);
309 		close(fd_stdout[1]);
310 		close(fd_stderr[0]);
311 		close(fd_stderr[1]);
312 		return -1;
313 	}
314 	return 0;
315 }
316 /* }}} */
317 
318 int fpm_stdio_parent_use_pipes(struct fpm_child_s *child) /* {{{ */
319 {
320 	if (0 == child->wp->config->catch_workers_output) { /* not required */
321 		return 0;
322 	}
323 
324 	close(fd_stdout[1]);
325 	close(fd_stderr[1]);
326 
327 	child->fd_stdout = fd_stdout[0];
328 	child->fd_stderr = fd_stderr[0];
329 
330 	fpm_event_set(&child->ev_stdout, child->fd_stdout, FPM_EV_READ, fpm_stdio_child_said, child);
331 	fpm_event_add(&child->ev_stdout, 0);
332 
333 	fpm_event_set(&child->ev_stderr, child->fd_stderr, FPM_EV_READ, fpm_stdio_child_said, child);
334 	fpm_event_add(&child->ev_stderr, 0);
335 	return 0;
336 }
337 /* }}} */
338 
339 int fpm_stdio_discard_pipes(struct fpm_child_s *child) /* {{{ */
340 {
341 	if (0 == child->wp->config->catch_workers_output) { /* not required */
342 		return 0;
343 	}
344 
345 	close(fd_stdout[1]);
346 	close(fd_stderr[1]);
347 
348 	close(fd_stdout[0]);
349 	close(fd_stderr[0]);
350 	return 0;
351 }
352 /* }}} */
353 
354 void fpm_stdio_child_use_pipes(struct fpm_child_s *child) /* {{{ */
355 {
356 	if (child->wp->config->catch_workers_output) {
357 		dup2(fd_stdout[1], STDOUT_FILENO);
358 		dup2(fd_stderr[1], STDERR_FILENO);
359 		close(fd_stdout[0]); close(fd_stdout[1]);
360 		close(fd_stderr[0]); close(fd_stderr[1]);
361 	} else {
362 		/* stdout of parent is always /dev/null */
363 		dup2(STDOUT_FILENO, STDERR_FILENO);
364 	}
365 }
366 /* }}} */
367 
368 int fpm_stdio_open_error_log(int reopen) /* {{{ */
369 {
370 	int fd;
371 
372 #ifdef HAVE_SYSLOG_H
373 	if (!strcasecmp(fpm_global_config.error_log, "syslog")) {
374 		php_openlog(fpm_global_config.syslog_ident, LOG_PID | LOG_CONS, fpm_global_config.syslog_facility);
375 		fpm_globals.error_log_fd = ZLOG_SYSLOG;
376 		if (fpm_use_error_log()) {
377 			zlog_set_fd(fpm_globals.error_log_fd, 0);
378 		}
379 		return 0;
380 	}
381 #endif
382 
383 	fd = open(fpm_global_config.error_log, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR);
384 
385 	if (0 > fd) {
386 		zlog(ZLOG_SYSERROR, "failed to open error_log (%s)", fpm_global_config.error_log);
387 		return -1;
388 	}
389 
390 	if (reopen) {
391 		dup2(fd, fpm_globals.error_log_fd);
392 		close(fd);
393 		fd = fpm_globals.error_log_fd; /* for FD_CLOSEXEC to work */
394 	} else {
395 		fpm_globals.error_log_fd = fd;
396 		if (fpm_use_error_log()) {
397 			bool is_stderr = (
398 				strcmp(fpm_global_config.error_log, "/dev/stderr") == 0 ||
399 				strcmp(fpm_global_config.error_log, "/proc/self/fd/2") == 0
400 			);
401 			zlog_set_fd(fpm_globals.error_log_fd, is_stderr);
402 		}
403 	}
404 	if (0 > fcntl(fd, F_SETFD, fcntl(fd, F_GETFD) | FD_CLOEXEC)) {
405 		zlog(ZLOG_WARNING, "failed to change attribute of error_log");
406 	}
407 	return 0;
408 }
409 /* }}} */
410