1 /* Licensed to the Apache Software Foundation (ASF) under one or more
2 * contributor license agreements. See the NOTICE file distributed with
3 * this work for additional information regarding copyright ownership.
4 * The ASF licenses this file to You under the Apache License, Version 2.0
5 * (the "License"); you may not use this file except in compliance with
6 * the License. You may obtain a copy of the License at
8 * http://www.apache.org/licenses/LICENSE-2.0
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
18 * http_log.c: Dealing with the logs and errors
25 #include "apr_general.h" /* for signal stuff */
26 #include "apr_strings.h"
27 #include "apr_errno.h"
28 #include "apr_thread_proc.h"
30 #include "apr_signal.h"
31 #include "apr_portable.h"
32 #include "apr_base64.h"
34 #define APR_WANT_STDIO
35 #define APR_WANT_STRFUNC
44 #if APR_HAVE_PROCESS_H
45 #include <process.h> /* for getpid() on Win32 */
48 #include "ap_config.h"
50 #include "http_config.h"
51 #include "http_core.h"
53 #include "http_main.h"
54 #include "util_time.h"
58 #include <sys/syscall.h>
59 #include <sys/types.h>
62 /* we know core's module_index is 0 */
63 #undef APLOG_MODULE_INDEX
64 #define APLOG_MODULE_INDEX AP_CORE_MODULE_INDEX
72 APR_HOOK_LINK(error_log)
73 APR_HOOK_LINK(generate_log_id)
76 int AP_DECLARE_DATA ap_default_loglevel = DEFAULT_LOGLEVEL;
80 static const TRANS facilities[] = {
83 {"authpriv",LOG_AUTHPRIV},
89 {"daemon", LOG_DAEMON},
107 {"syslog", LOG_SYSLOG},
116 {"local0", LOG_LOCAL0},
119 {"local1", LOG_LOCAL1},
122 {"local2", LOG_LOCAL2},
125 {"local3", LOG_LOCAL3},
128 {"local4", LOG_LOCAL4},
131 {"local5", LOG_LOCAL5},
134 {"local6", LOG_LOCAL6},
137 {"local7", LOG_LOCAL7},
143 static const TRANS priorities[] = {
144 {"emerg", APLOG_EMERG},
145 {"alert", APLOG_ALERT},
146 {"crit", APLOG_CRIT},
147 {"error", APLOG_ERR},
148 {"warn", APLOG_WARNING},
149 {"notice", APLOG_NOTICE},
150 {"info", APLOG_INFO},
151 {"debug", APLOG_DEBUG},
152 {"trace1", APLOG_TRACE1},
153 {"trace2", APLOG_TRACE2},
154 {"trace3", APLOG_TRACE3},
155 {"trace4", APLOG_TRACE4},
156 {"trace5", APLOG_TRACE5},
157 {"trace6", APLOG_TRACE6},
158 {"trace7", APLOG_TRACE7},
159 {"trace8", APLOG_TRACE8},
163 static apr_pool_t *stderr_pool = NULL;
165 static apr_file_t *stderr_log = NULL;
167 /* track pipe handles to close in child process */
168 typedef struct read_handle_t {
169 struct read_handle_t *next;
173 static read_handle_t *read_handles;
176 * @brief The piped logging structure.
178 * Piped logs are used to move functionality out of the main server.
179 * For example, log rotation is done with piped logs.
182 /** The pool to use for the piped log */
184 /** The pipe between the server and the logging process */
185 apr_file_t *read_fd, *write_fd;
186 #ifdef AP_HAVE_RELIABLE_PIPED_LOGS
187 /** The name of the program the logging process is running */
189 /** The pid of the logging process */
191 /** How to reinvoke program when it must be replaced */
192 apr_cmdtype_e cmdtype;
196 AP_DECLARE(apr_file_t *) ap_piped_log_read_fd(piped_log *pl)
201 AP_DECLARE(apr_file_t *) ap_piped_log_write_fd(piped_log *pl)
206 /* remember to close this handle in the child process
208 * On Win32 this makes zero sense, because we don't
209 * take the parent process's child procs.
210 * If the win32 parent instead passed each and every
211 * logger write handle from itself down to the child,
212 * and the parent manages all aspects of keeping the
213 * reliable pipe log children alive, this would still
214 * make no sense :) Cripple it on Win32.
216 static void close_handle_in_child(apr_pool_t *p, apr_file_t *f)
219 read_handle_t *new_handle;
221 new_handle = apr_pcalloc(p, sizeof(read_handle_t));
222 new_handle->next = read_handles;
223 new_handle->handle = f;
224 read_handles = new_handle;
228 void ap_logs_child_init(apr_pool_t *p, server_rec *s)
230 read_handle_t *cur = read_handles;
233 apr_file_close(cur->handle);
238 AP_DECLARE(void) ap_open_stderr_log(apr_pool_t *p)
240 apr_file_open_stderr(&stderr_log, p);
243 AP_DECLARE(apr_status_t) ap_replace_stderr_log(apr_pool_t *p,
246 apr_file_t *stderr_file;
248 char *filename = ap_server_root_relative(p, fname);
250 ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT,
251 APR_EBADPATH, NULL, APLOGNO(00085) "Invalid -E error log file %s",
255 if ((rc = apr_file_open(&stderr_file, filename,
256 APR_APPEND | APR_WRITE | APR_CREATE | APR_LARGEFILE,
257 APR_OS_DEFAULT, p)) != APR_SUCCESS) {
258 ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00086)
259 "%s: could not open error log file %s.",
260 ap_server_argv0, fname);
264 /* This is safe provided we revert it when we are finished.
265 * We don't manager the callers pool!
269 if ((rc = apr_file_open_stderr(&stderr_log, stderr_pool))
271 apr_file_flush(stderr_log);
272 if ((rc = apr_file_dup2(stderr_log, stderr_file, stderr_pool))
274 apr_file_close(stderr_file);
276 * You might ponder why stderr_pool should survive?
277 * The trouble is, stderr_pool may have s_main->error_log,
278 * so we aren't in a position to destory stderr_pool until
279 * the next recycle. There's also an apparent bug which
280 * is not; if some folk decided to call this function before
281 * the core open error logs hook, this pool won't survive.
282 * Neither does the stderr logger, so this isn't a problem.
286 /* Revert, see above */
287 if (stderr_pool == p)
290 if (rc != APR_SUCCESS) {
291 ap_log_error(APLOG_MARK, APLOG_CRIT, rc, NULL, APLOGNO(00087)
292 "unable to replace stderr with error log file");
297 static void log_child_errfn(apr_pool_t *pool, apr_status_t err,
298 const char *description)
300 ap_log_error(APLOG_MARK, APLOG_ERR, err, NULL, APLOGNO(00088)
304 /* Create a child process running PROGNAME with a pipe connected to
305 * the childs stdin. The write-end of the pipe will be placed in
306 * *FPIN on successful return. If dummy_stderr is non-zero, the
307 * stderr for the child will be the same as the stdout of the parent.
308 * Otherwise the child will inherit the stderr from the parent. */
309 static int log_child(apr_pool_t *p, const char *progname,
310 apr_file_t **fpin, apr_cmdtype_e cmdtype,
313 /* Child process code for 'ErrorLog "|..."';
314 * may want a common framework for this, since I expect it will
315 * be common for other foo-loggers to want this sort of thing...
318 apr_procattr_t *procattr;
322 if (((rc = apr_procattr_create(&procattr, p)) == APR_SUCCESS)
323 && ((rc = apr_procattr_dir_set(procattr,
324 ap_server_root)) == APR_SUCCESS)
325 && ((rc = apr_procattr_cmdtype_set(procattr, cmdtype)) == APR_SUCCESS)
326 && ((rc = apr_procattr_io_set(procattr,
329 APR_NO_PIPE)) == APR_SUCCESS)
330 && ((rc = apr_procattr_error_check_set(procattr, 1)) == APR_SUCCESS)
331 && ((rc = apr_procattr_child_errfn_set(procattr, log_child_errfn))
336 apr_tokenize_to_argv(progname, &args, p);
337 pname = apr_pstrdup(p, args[0]);
338 procnew = (apr_proc_t *)apr_pcalloc(p, sizeof(*procnew));
341 if ((rc = apr_file_open_stdout(&errfile, p)) == APR_SUCCESS)
342 rc = apr_procattr_child_err_set(procattr, errfile, NULL);
345 rc = apr_proc_create(procnew, pname, (const char * const *)args,
348 if (rc == APR_SUCCESS) {
349 apr_pool_note_subprocess(p, procnew, APR_KILL_AFTER_TIMEOUT);
350 (*fpin) = procnew->in;
351 /* read handle to pipe not kept open, so no need to call
352 * close_handle_in_child()
360 /* Open the error log for the given server_rec. If IS_MAIN is
361 * non-zero, s is the main server. */
362 static int open_error_log(server_rec *s, int is_main, apr_pool_t *p)
367 if (*s->error_fname == '|') {
368 apr_file_t *dummy = NULL;
369 apr_cmdtype_e cmdtype = APR_PROGRAM_ENV;
370 fname = s->error_fname + 1;
372 /* In 2.4 favor PROGRAM_ENV, accept "||prog" syntax for compatibility
373 * and "|$cmd" to override the default.
374 * Any 2.2 backport would continue to favor SHELLCMD_ENV so there
375 * accept "||prog" to override, and "|$cmd" to ease conversion.
380 cmdtype = APR_SHELLCMD_ENV;
384 /* Spawn a new child logger. If this is the main server_rec,
385 * the new child must use a dummy stderr since the current
386 * stderr might be a pipe to the old logger. Otherwise, the
387 * child inherits the parents stderr. */
388 rc = log_child(p, fname, &dummy, cmdtype, is_main);
389 if (rc != APR_SUCCESS) {
390 ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00089)
391 "Couldn't start ErrorLog process '%s'.",
396 s->error_log = dummy;
400 else if (!strncasecmp(s->error_fname, "syslog", 6)) {
401 if ((fname = strchr(s->error_fname, ':'))) {
405 for (fac = facilities; fac->t_name; fac++) {
406 if (!strcasecmp(fname, fac->t_name)) {
407 openlog(ap_server_argv0, LOG_NDELAY|LOG_CONS|LOG_PID,
415 openlog(ap_server_argv0, LOG_NDELAY|LOG_CONS|LOG_PID, LOG_LOCAL7);
422 fname = ap_server_root_relative(p, s->error_fname);
424 ap_log_error(APLOG_MARK, APLOG_STARTUP, APR_EBADPATH, NULL, APLOGNO(00090)
425 "%s: Invalid error log path %s.",
426 ap_server_argv0, s->error_fname);
429 if ((rc = apr_file_open(&s->error_log, fname,
430 APR_APPEND | APR_WRITE | APR_CREATE | APR_LARGEFILE,
431 APR_OS_DEFAULT, p)) != APR_SUCCESS) {
432 ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00091)
433 "%s: could not open error log file %s.",
434 ap_server_argv0, fname);
442 int ap_open_logs(apr_pool_t *pconf, apr_pool_t *p /* plog */,
443 apr_pool_t *ptemp, server_rec *s_main)
445 apr_pool_t *stderr_p;
446 server_rec *virt, *q;
450 /* Register to throw away the read_handles list when we
451 * cleanup plog. Upon fork() for the apache children,
452 * this read_handles list is closed so only the parent
453 * can relaunch a lost log child. These read handles
454 * are always closed on exec.
455 * We won't care what happens to our stderr log child
456 * between log phases, so we don't mind losing stderr's
457 * read_handle a little bit early.
459 apr_pool_cleanup_register(p, &read_handles, ap_pool_cleanup_set_null,
460 apr_pool_cleanup_null);
462 /* HERE we need a stdout log that outlives plog.
463 * We *presume* the parent of plog is a process
464 * or global pool which spans server restarts.
465 * Create our stderr_pool as a child of the plog's
468 apr_pool_create(&stderr_p, apr_pool_parent_get(p));
469 apr_pool_tag(stderr_p, "stderr_pool");
471 if (open_error_log(s_main, 1, stderr_p) != OK) {
476 if (s_main->error_log) {
479 /* Replace existing stderr with new log. */
480 apr_file_flush(s_main->error_log);
481 rv = apr_file_dup2(stderr_log, s_main->error_log, stderr_p);
482 if (rv != APR_SUCCESS) {
483 ap_log_error(APLOG_MARK, APLOG_CRIT, rv, s_main, APLOGNO(00092)
484 "unable to replace stderr with error_log");
487 /* We are done with stderr_pool, close it, killing
488 * the previous generation's stderr logger
491 apr_pool_destroy(stderr_pool);
492 stderr_pool = stderr_p;
495 * Now that we have dup'ed s_main->error_log to stderr_log
496 * close it and set s_main->error_log to stderr_log. This avoids
497 * this fd being inherited by the next piped logger who would
498 * keep open the writing end of the pipe that this one uses
499 * as stdin. This in turn would prevent the piped logger from
502 apr_file_close(s_main->error_log);
503 s_main->error_log = stderr_log;
506 /* note that stderr may still need to be replaced with something
507 * because it points to the old error log, or back to the tty
509 * XXX: This is BS - /dev/null is non-portable
510 * errno-as-apr_status_t is also non-portable
512 if (replace_stderr && freopen("/dev/null", "w", stderr) == NULL) {
513 ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, APLOGNO(00093)
514 "unable to replace stderr with /dev/null");
517 for (virt = s_main->next; virt; virt = virt->next) {
518 if (virt->error_fname) {
519 for (q=s_main; q != virt; q = q->next) {
520 if (q->error_fname != NULL
521 && strcmp(q->error_fname, virt->error_fname) == 0) {
527 if (open_error_log(virt, 0, p) != OK) {
532 virt->error_log = q->error_log;
536 virt->error_log = s_main->error_log;
542 AP_DECLARE(void) ap_error_log2stderr(server_rec *s) {
543 apr_file_t *errfile = NULL;
545 apr_file_open_stderr(&errfile, s->process->pool);
546 if (s->error_log != NULL) {
547 apr_file_dup2(s->error_log, errfile, s->process->pool);
551 static int cpystrn(char *buf, const char *arg, int buflen)
556 end = apr_cpystrn(buf, arg, buflen);
561 static int log_remote_address(const ap_errorlog_info *info, const char *arg,
562 char *buf, int buflen)
564 if (info->r && !(arg && *arg == 'c'))
565 return apr_snprintf(buf, buflen, "%s:%d", info->r->useragent_ip,
566 info->r->useragent_addr->port);
568 return apr_snprintf(buf, buflen, "%s:%d", info->c->client_ip,
569 info->c->client_addr->port);
574 static int log_local_address(const ap_errorlog_info *info, const char *arg,
575 char *buf, int buflen)
578 return apr_snprintf(buf, buflen, "%s:%d", info->c->local_ip,
579 info->c->local_addr->port);
584 static int log_pid(const ap_errorlog_info *info, const char *arg,
585 char *buf, int buflen)
587 pid_t pid = getpid();
588 return apr_snprintf(buf, buflen, "%" APR_PID_T_FMT, pid);
591 static int log_tid(const ap_errorlog_info *info, const char *arg,
592 char *buf, int buflen)
598 if (arg && *arg == 'g') {
599 pid_t tid = syscall(SYS_gettid);
602 return apr_snprintf(buf, buflen, "%"APR_PID_T_FMT, tid);
606 if (ap_mpm_query(AP_MPMQ_IS_THREADED, &result) == APR_SUCCESS
607 && result != AP_MPMQ_NOT_SUPPORTED)
609 apr_os_thread_t tid = apr_os_thread_current();
610 return apr_snprintf(buf, buflen, "%pT", &tid);
616 static int log_ctime(const ap_errorlog_info *info, const char *arg,
617 char *buf, int buflen)
619 int time_len = buflen;
620 int option = AP_CTIME_OPTION_NONE;
624 case 'u': option |= AP_CTIME_OPTION_USEC;
626 case 'c': option |= AP_CTIME_OPTION_COMPACT;
632 ap_recent_ctime_ex(buf, apr_time_now(), option, &time_len);
634 /* ap_recent_ctime_ex includes the trailing \0 in time_len */
638 static int log_loglevel(const ap_errorlog_info *info, const char *arg,
639 char *buf, int buflen)
644 return cpystrn(buf, priorities[info->level].t_name, buflen);
647 static int log_log_id(const ap_errorlog_info *info, const char *arg,
648 char *buf, int buflen)
651 * C: log conn log_id if available,
652 * c: log conn log id if available and not a once-per-request log line
653 * else: log request log id if available
655 if (arg && !strcasecmp(arg, "c")) {
656 if (info->c && (*arg != 'C' || !info->r)) {
657 return cpystrn(buf, info->c->log_id, buflen);
660 else if (info->rmain) {
661 return cpystrn(buf, info->rmain->log_id, buflen);
666 static int log_keepalives(const ap_errorlog_info *info, const char *arg,
667 char *buf, int buflen)
672 return apr_snprintf(buf, buflen, "%d", info->c->keepalives);
675 static int log_module_name(const ap_errorlog_info *info, const char *arg,
676 char *buf, int buflen)
678 return cpystrn(buf, ap_find_module_short_name(info->module_index), buflen);
681 static int log_file_line(const ap_errorlog_info *info, const char *arg,
682 char *buf, int buflen)
684 if (info->file == NULL) {
688 const char *file = info->file;
689 #if defined(_OSD_POSIX) || defined(WIN32) || defined(__MVS__)
691 char *e = strrchr(file, '/');
694 e = strrchr(file, '\\');
698 /* In OSD/POSIX, the compiler returns for __FILE__
699 * a string like: __FILE__="*POSIX(/usr/include/stdio.h)"
700 * (it even returns an absolute path for sources in
701 * the current directory). Here we try to strip this
702 * down to the basename.
704 if (e != NULL && e[1] != '\0') {
705 apr_snprintf(tmp, sizeof(tmp), "%s", &e[1]);
706 e = &tmp[strlen(tmp)-1];
712 #else /* _OSD_POSIX || WIN32 */
714 /* On Unix, __FILE__ may be an absolute path in a
716 if (file[0] == '/' && (p = ap_strrchr_c(file, '/')) != NULL) {
719 #endif /*_OSD_POSIX || WIN32 */
720 return apr_snprintf(buf, buflen, "%s(%d)", file, info->line);
724 static int log_apr_status(const ap_errorlog_info *info, const char *arg,
725 char *buf, int buflen)
727 apr_status_t status = info->status;
732 if (status < APR_OS_START_EAIERR) {
733 len = apr_snprintf(buf, buflen, "(%d)", status);
735 else if (status < APR_OS_START_SYSERR) {
736 len = apr_snprintf(buf, buflen, "(EAI %d)",
737 status - APR_OS_START_EAIERR);
739 else if (status < 100000 + APR_OS_START_SYSERR) {
740 len = apr_snprintf(buf, buflen, "(OS %d)",
741 status - APR_OS_START_SYSERR);
744 len = apr_snprintf(buf, buflen, "(os 0x%08x)",
745 status - APR_OS_START_SYSERR);
747 apr_strerror(status, buf + len, buflen - len);
748 len += strlen(buf + len);
752 static int log_server_name(const ap_errorlog_info *info, const char *arg,
753 char *buf, int buflen)
756 return cpystrn(buf, ap_get_server_name((request_rec *)info->r), buflen);
761 static int log_virtual_host(const ap_errorlog_info *info, const char *arg,
762 char *buf, int buflen)
765 return cpystrn(buf, info->s->server_hostname, buflen);
771 static int log_table_entry(const apr_table_t *table, const char *name,
772 char *buf, int buflen)
774 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
776 char scratch[MAX_STRING_LEN];
778 if ((value = apr_table_get(table, name)) != NULL) {
779 ap_escape_errorlog_item(scratch, value, MAX_STRING_LEN);
780 return cpystrn(buf, scratch, buflen);
785 return cpystrn(buf, apr_table_get(table, name), buflen);
789 static int log_header(const ap_errorlog_info *info, const char *arg,
790 char *buf, int buflen)
793 return log_table_entry(info->r->headers_in, arg, buf, buflen);
798 static int log_note(const ap_errorlog_info *info, const char *arg,
799 char *buf, int buflen)
801 /* XXX: maybe escaping the entry is not necessary for notes? */
803 return log_table_entry(info->r->notes, arg, buf, buflen);
808 static int log_env_var(const ap_errorlog_info *info, const char *arg,
809 char *buf, int buflen)
812 return log_table_entry(info->r->subprocess_env, arg, buf, buflen);
817 static int core_generate_log_id(const conn_rec *c, const request_rec *r,
818 const char **idstring)
820 apr_uint64_t id, tmp;
825 if (r && r->request_time) {
826 id = (apr_uint64_t)r->request_time;
829 id = (apr_uint64_t)apr_time_now();
833 if (sizeof(pid_t) > 2) {
849 apr_uintptr_t tmp2 = (apr_uintptr_t)c->current_thread;
856 len = apr_base64_encode_len(sizeof(id)); /* includes trailing \0 */
857 encoded = apr_palloc(r ? r->pool : c->pool, len);
858 apr_base64_encode(encoded, (char *)&id, sizeof(id));
860 /* Skip the last char, it is always '=' */
861 encoded[len - 2] = '\0';
868 static void add_log_id(const conn_rec *c, const request_rec *r)
871 /* need to cast const away */
873 id = &((request_rec *)r)->log_id;
876 id = &((conn_rec *)c)->log_id;
879 ap_run_generate_log_id(c, r, id);
882 AP_DECLARE(void) ap_register_log_hooks(apr_pool_t *p)
884 ap_hook_generate_log_id(core_generate_log_id, NULL, NULL,
885 APR_HOOK_REALLY_LAST);
887 ap_register_errorlog_handler(p, "a", log_remote_address, 0);
888 ap_register_errorlog_handler(p, "A", log_local_address, 0);
889 ap_register_errorlog_handler(p, "e", log_env_var, 0);
890 ap_register_errorlog_handler(p, "E", log_apr_status, 0);
891 ap_register_errorlog_handler(p, "F", log_file_line, 0);
892 ap_register_errorlog_handler(p, "i", log_header, 0);
893 ap_register_errorlog_handler(p, "k", log_keepalives, 0);
894 ap_register_errorlog_handler(p, "l", log_loglevel, 0);
895 ap_register_errorlog_handler(p, "L", log_log_id, 0);
896 ap_register_errorlog_handler(p, "m", log_module_name, 0);
897 ap_register_errorlog_handler(p, "n", log_note, 0);
898 ap_register_errorlog_handler(p, "P", log_pid, 0);
899 ap_register_errorlog_handler(p, "t", log_ctime, 0);
900 ap_register_errorlog_handler(p, "T", log_tid, 0);
901 ap_register_errorlog_handler(p, "v", log_virtual_host, 0);
902 ap_register_errorlog_handler(p, "V", log_server_name, 0);
906 * This is used if no error log format is defined and during startup.
907 * It automatically omits the timestamp if logging to syslog.
909 static int do_errorlog_default(const ap_errorlog_info *info, char *buf,
910 int buflen, int *errstr_start, int *errstr_end,
911 const char *errstr_fmt, va_list args)
916 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
917 char scratch[MAX_STRING_LEN];
920 if (!info->using_syslog && !info->startup) {
922 len += log_ctime(info, "u", buf + len, buflen - len);
927 if (!info->startup) {
929 len += log_module_name(info, NULL, buf + len, buflen - len);
931 len += log_loglevel(info, NULL, buf + len, buflen - len);
932 len += cpystrn(buf + len, "] [pid ", buflen - len);
934 len += log_pid(info, NULL, buf + len, buflen - len);
937 len += cpystrn(buf + len, ":tid ", buflen - len);
938 item_len = log_tid(info, NULL, buf + len, buflen - len);
948 if (info->level >= APLOG_DEBUG) {
949 item_len = log_file_line(info, NULL, buf + len, buflen - len);
952 len += cpystrn(buf + len, ": ", buflen - len);
957 item_len = log_apr_status(info, NULL, buf + len, buflen - len);
960 len += cpystrn(buf + len, ": ", buflen - len);
965 * useragent_ip/client_ip can be client or backend server. If we have
966 * a scoreboard handle, it is likely a client.
969 len += apr_snprintf(buf + len, buflen - len,
970 info->r->connection->sbh ? "[client %s:%d] " : "[remote %s:%d] ",
971 info->r->useragent_ip, info->r->useragent_addr->port);
974 len += apr_snprintf(buf + len, buflen - len,
975 info->c->sbh ? "[client %s:%d] " : "[remote %s:%d] ",
976 info->c->client_ip, info->c->client_addr->port);
979 /* the actual error message */
981 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
982 if (apr_vsnprintf(scratch, MAX_STRING_LEN, errstr_fmt, args)) {
983 len += ap_escape_errorlog_item(buf + len, scratch,
988 len += apr_vsnprintf(buf + len, buflen - len, errstr_fmt, args);
993 len += cpystrn(buf + len, ", referer: ", buflen - len);
994 item_len = log_header(info, "Referer", buf + len, buflen - len);
1003 static int do_errorlog_format(apr_array_header_t *fmt, ap_errorlog_info *info,
1004 char *buf, int buflen, int *errstr_start,
1005 int *errstr_end, const char *err_fmt, va_list args)
1007 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
1008 char scratch[MAX_STRING_LEN];
1012 int field_start = 0;
1014 ap_errorlog_format_item *items = (ap_errorlog_format_item *)fmt->elts;
1016 for (i = 0; i < fmt->nelts; ++i) {
1017 ap_errorlog_format_item *item = &items[i];
1018 if (item->flags & AP_ERRORLOG_FLAG_FIELD_SEP) {
1027 if (item->flags & AP_ERRORLOG_FLAG_MESSAGE) {
1028 /* the actual error message */
1029 *errstr_start = len;
1030 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
1031 if (apr_vsnprintf(scratch, MAX_STRING_LEN, err_fmt, args)) {
1032 len += ap_escape_errorlog_item(buf + len, scratch,
1037 len += apr_vsnprintf(buf + len, buflen - len, err_fmt, args);
1041 else if (skipping) {
1044 else if (info->level != -1 && (int)item->min_loglevel > info->level) {
1049 int item_len = (*item->func)(info, item->arg, buf + len,
1052 if (item->flags & AP_ERRORLOG_FLAG_REQUIRED) {
1053 /* required item is empty. skip whole line */
1057 else if (item->flags & AP_ERRORLOG_FLAG_NULL_AS_HYPHEN) {
1073 static void write_logline(char *errstr, apr_size_t len, apr_file_t *logf,
1076 /* NULL if we are logging to syslog */
1078 /* Truncate for the terminator (as apr_snprintf does) */
1079 if (len > MAX_STRING_LEN - sizeof(APR_EOL_STR)) {
1080 len = MAX_STRING_LEN - sizeof(APR_EOL_STR);
1082 strcpy(errstr + len, APR_EOL_STR);
1083 apr_file_puts(errstr, logf);
1084 apr_file_flush(logf);
1088 syslog(level < LOG_PRIMASK ? level : APLOG_DEBUG, "%s", errstr);
1093 static void log_error_core(const char *file, int line, int module_index,
1095 apr_status_t status, const server_rec *s,
1097 const request_rec *r, apr_pool_t *pool,
1098 const char *fmt, va_list args)
1100 char errstr[MAX_STRING_LEN];
1101 apr_file_t *logf = NULL;
1102 int level_and_mask = level & APLOG_LEVELMASK;
1103 const request_rec *rmain = NULL;
1104 core_server_config *sconf = NULL;
1105 ap_errorlog_info info;
1107 /* do we need to log once-per-req or once-per-conn info? */
1108 int log_conn_info = 0, log_req_info = 0;
1109 apr_array_header_t **lines = NULL;
1111 int line_number = 0;
1113 if (r && r->connection) {
1119 * If we are doing stderr logging (startup), don't log messages that are
1120 * above the default server log level unless it is a startup/shutdown
1124 if ((level_and_mask != APLOG_NOTICE)
1125 && (level_and_mask > ap_default_loglevel)) {
1133 int configured_level = r ? ap_get_request_module_loglevel(r, module_index) :
1134 c ? ap_get_conn_server_module_loglevel(c, s, module_index) :
1135 ap_get_server_module_loglevel(s, module_index);
1138 * If we are doing normal logging, don't log messages that are
1139 * above the module's log level unless it is a startup/shutdown notice
1141 if ((level_and_mask != APLOG_NOTICE)
1142 && (level_and_mask > configured_level)) {
1146 logf = s->error_log;
1150 * If we are doing syslog logging, don't log messages that are
1151 * above the module's log level (including a startup/shutdown notice)
1153 if (level_and_mask > configured_level) {
1158 /* the faked server_rec from mod_cgid does not have s->module_config */
1159 if (s->module_config) {
1160 sconf = ap_get_core_module_config(s->module_config);
1161 if (c && !c->log_id) {
1162 add_log_id(c, NULL);
1163 if (sconf->error_log_conn && sconf->error_log_conn->nelts > 0)
1172 if (!rmain->log_id) {
1173 /* XXX: do we need separate log ids for subrequests? */
1174 if (sconf->error_log_req && sconf->error_log_req->nelts > 0)
1177 * XXX: potential optimization: only create log id if %L is
1178 * XXX: actually used
1180 add_log_id(c, rmain);
1192 info.using_syslog = (logf == NULL);
1193 info.startup = ((level & APLOG_STARTUP) == APLOG_STARTUP);
1197 apr_array_header_t *log_format;
1198 int len = 0, errstr_start = 0, errstr_end = 0;
1199 /* XXX: potential optimization: format common prefixes only once */
1200 if (log_conn_info) {
1201 /* once-per-connection info */
1202 if (line_number == 0) {
1203 lines = (apr_array_header_t **)sconf->error_log_conn->elts;
1207 info.module_index = APLOG_NO_MODULE;
1210 log_format = lines[line_number++];
1212 if (line_number == sconf->error_log_conn->nelts) {
1213 /* this is the last line of once-per-connection info */
1218 else if (log_req_info) {
1219 /* once-per-request info */
1220 if (line_number == 0) {
1221 lines = (apr_array_header_t **)sconf->error_log_req->elts;
1225 info.module_index = APLOG_NO_MODULE;
1228 log_format = lines[line_number++];
1230 if (line_number == sconf->error_log_req->nelts) {
1231 /* this is the last line of once-per-request info */
1237 /* the actual error message */
1240 info.level = level_and_mask;
1241 info.module_index = module_index;
1244 info.status = status;
1245 log_format = sconf ? sconf->error_log_format : NULL;
1250 * prepare and log one line
1254 len += do_errorlog_format(log_format, &info, errstr + len,
1255 MAX_STRING_LEN - len,
1256 &errstr_start, &errstr_end, fmt, args);
1259 len += do_errorlog_default(&info, errstr + len, MAX_STRING_LEN - len,
1260 &errstr_start, &errstr_end, fmt, args);
1266 * Don't log empty lines. This can happen with once-per-conn/req
1267 * info if an item with AP_ERRORLOG_FLAG_REQUIRED is NULL.
1271 write_logline(errstr, len, logf, level_and_mask);
1275 * We don't call the error_log hook for per-request/per-conn
1276 * lines, and we only pass the actual log message, not the
1277 * prefix and suffix.
1279 errstr[errstr_end] = '\0';
1280 ap_run_error_log(&info, errstr + errstr_start);
1287 AP_DECLARE(void) ap_log_error_(const char *file, int line, int module_index,
1288 int level, apr_status_t status,
1289 const server_rec *s, const char *fmt, ...)
1293 va_start(args, fmt);
1294 log_error_core(file, line, module_index, level, status, s, NULL, NULL,
1299 AP_DECLARE(void) ap_log_perror_(const char *file, int line, int module_index,
1300 int level, apr_status_t status, apr_pool_t *p,
1301 const char *fmt, ...)
1305 va_start(args, fmt);
1306 log_error_core(file, line, module_index, level, status, NULL, NULL, NULL,
1311 AP_DECLARE(void) ap_log_rerror_(const char *file, int line, int module_index,
1312 int level, apr_status_t status,
1313 const request_rec *r, const char *fmt, ...)
1317 va_start(args, fmt);
1318 log_error_core(file, line, module_index, level, status, r->server, NULL, r,
1322 * IF APLOG_TOCLIENT is set,
1323 * AND the error level is 'warning' or more severe,
1324 * AND there isn't already error text associated with this request,
1325 * THEN make the message text available to ErrorDocument and
1326 * other error processors.
1330 if ((level & APLOG_TOCLIENT)
1331 && ((level & APLOG_LEVELMASK) <= APLOG_WARNING)
1332 && (apr_table_get(r->notes, "error-notes") == NULL)) {
1333 apr_table_setn(r->notes, "error-notes",
1334 ap_escape_html(r->pool, apr_pvsprintf(r->pool, fmt,
1340 AP_DECLARE(void) ap_log_cserror_(const char *file, int line, int module_index,
1341 int level, apr_status_t status,
1342 const conn_rec *c, const server_rec *s,
1343 const char *fmt, ...)
1347 va_start(args, fmt);
1348 log_error_core(file, line, module_index, level, status, s, c,
1349 NULL, NULL, fmt, args);
1353 AP_DECLARE(void) ap_log_cerror_(const char *file, int line, int module_index,
1354 int level, apr_status_t status,
1355 const conn_rec *c, const char *fmt, ...)
1359 va_start(args, fmt);
1360 log_error_core(file, line, module_index, level, status, c->base_server, c,
1361 NULL, NULL, fmt, args);
1365 AP_DECLARE(void) ap_log_command_line(apr_pool_t *plog, server_rec *s)
1368 process_rec *process = s->process;
1372 /* Piece together the command line from the pieces
1373 * in process->argv, with spaces in between.
1375 for (i = 0; i < process->argc; i++) {
1376 len_needed += strlen(process->argv[i]) + 1;
1379 result = (char *) apr_palloc(plog, len_needed);
1382 for (i = 0; i < process->argc; i++) {
1383 strcat(result, process->argv[i]);
1384 if ((i+1)< process->argc) {
1385 strcat(result, " ");
1388 ap_log_error(APLOG_MARK, APLOG_NOTICE, 0, s, APLOGNO(00094)
1389 "Command line: '%s'", result);
1392 AP_DECLARE(void) ap_remove_pid(apr_pool_t *p, const char *rel_fname)
1395 const char *fname = ap_server_root_relative(p, rel_fname);
1397 if (fname != NULL) {
1398 rv = apr_file_remove(fname, p);
1399 if (rv != APR_SUCCESS) {
1400 ap_log_error(APLOG_MARK, APLOG_ERR, rv, ap_server_conf, APLOGNO(00095)
1401 "failed to remove PID file %s", fname);
1404 ap_log_error(APLOG_MARK, APLOG_INFO, 0, ap_server_conf, APLOGNO(00096)
1405 "removed PID file %s (pid=%" APR_PID_T_FMT ")",
1411 AP_DECLARE(void) ap_log_pid(apr_pool_t *p, const char *filename)
1413 apr_file_t *pid_file = NULL;
1415 static pid_t saved_pid = -1;
1424 fname = ap_server_root_relative(p, filename);
1426 ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, APR_EBADPATH,
1427 NULL, APLOGNO(00097) "Invalid PID file path %s, ignoring.", filename);
1432 if (mypid != saved_pid
1433 && apr_stat(&finfo, fname, APR_FINFO_MTIME, p) == APR_SUCCESS) {
1434 /* AP_SIG_GRACEFUL and HUP call this on each restart.
1435 * Only warn on first time through for this pid.
1437 * XXX: Could just write first time through too, although
1438 * that may screw up scripts written to do something
1439 * based on the last modification time of the pid file.
1441 ap_log_perror(APLOG_MARK, APLOG_WARNING, 0, p, APLOGNO(00098)
1442 "pid file %s overwritten -- Unclean "
1443 "shutdown of previous Apache run?",
1447 if ((rv = apr_file_open(&pid_file, fname,
1448 APR_WRITE | APR_CREATE | APR_TRUNCATE,
1449 APR_UREAD | APR_UWRITE | APR_GREAD | APR_WREAD, p))
1451 ap_log_error(APLOG_MARK, APLOG_ERR, rv, NULL, APLOGNO(00099)
1452 "could not create %s", fname);
1453 ap_log_error(APLOG_MARK, APLOG_ERR, 0, NULL, APLOGNO(00100)
1454 "%s: could not log pid to file %s",
1455 ap_server_argv0, fname);
1458 apr_file_printf(pid_file, "%" APR_PID_T_FMT APR_EOL_STR, mypid);
1459 apr_file_close(pid_file);
1463 AP_DECLARE(apr_status_t) ap_read_pid(apr_pool_t *p, const char *filename,
1466 const apr_size_t BUFFER_SIZE = sizeof(long) * 3 + 2; /* see apr_ltoa */
1467 apr_file_t *pid_file = NULL;
1471 apr_size_t bytes_read;
1474 return APR_EGENERAL;
1477 fname = ap_server_root_relative(p, filename);
1479 ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, APR_EBADPATH,
1480 NULL, APLOGNO(00101) "Invalid PID file path %s, ignoring.", filename);
1481 return APR_EGENERAL;
1484 rv = apr_file_open(&pid_file, fname, APR_READ, APR_OS_DEFAULT, p);
1485 if (rv != APR_SUCCESS) {
1489 buf = apr_palloc(p, BUFFER_SIZE);
1491 rv = apr_file_read_full(pid_file, buf, BUFFER_SIZE - 1, &bytes_read);
1492 if (rv != APR_SUCCESS && rv != APR_EOF) {
1496 /* If we fill the buffer, we're probably reading a corrupt pid file.
1497 * To be nice, let's also ensure the first char is a digit. */
1498 if (bytes_read == 0 || bytes_read == BUFFER_SIZE - 1 || !apr_isdigit(*buf)) {
1499 return APR_EGENERAL;
1502 buf[bytes_read] = '\0';
1503 *mypid = strtol(buf, &endptr, 10);
1505 apr_file_close(pid_file);
1509 AP_DECLARE(void) ap_log_assert(const char *szExp, const char *szFile,
1512 char time_str[APR_CTIME_LEN];
1514 apr_ctime(time_str, apr_time_now());
1515 ap_log_error(APLOG_MARK, APLOG_CRIT, 0, NULL, APLOGNO(00102)
1516 "[%s] file %s, line %d, assertion \"%s\" failed",
1517 time_str, szFile, nLine, szExp);
1521 /* unix assert does an abort leading to a core dump */
1526 /* piped log support */
1528 #ifdef AP_HAVE_RELIABLE_PIPED_LOGS
1529 /* forward declaration */
1530 static void piped_log_maintenance(int reason, void *data, apr_wait_t status);
1532 /* Spawn the piped logger process pl->program. */
1533 static apr_status_t piped_log_spawn(piped_log *pl)
1535 apr_procattr_t *procattr;
1536 apr_proc_t *procnew = NULL;
1537 apr_status_t status;
1539 if (((status = apr_procattr_create(&procattr, pl->p)) != APR_SUCCESS) ||
1540 ((status = apr_procattr_dir_set(procattr, ap_server_root))
1542 ((status = apr_procattr_cmdtype_set(procattr, pl->cmdtype))
1544 ((status = apr_procattr_child_in_set(procattr,
1548 ((status = apr_procattr_child_errfn_set(procattr, log_child_errfn))
1550 ((status = apr_procattr_error_check_set(procattr, 1)) != APR_SUCCESS)) {
1552 /* Something bad happened, give up and go away. */
1553 ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00103)
1554 "piped_log_spawn: unable to setup child process '%s': %s",
1555 pl->program, apr_strerror(status, buf, sizeof(buf)));
1561 apr_tokenize_to_argv(pl->program, &args, pl->p);
1562 pname = apr_pstrdup(pl->p, args[0]);
1563 procnew = apr_pcalloc(pl->p, sizeof(apr_proc_t));
1564 status = apr_proc_create(procnew, pname, (const char * const *) args,
1565 NULL, procattr, pl->p);
1567 if (status == APR_SUCCESS) {
1569 /* procnew->in was dup2'd from pl->write_fd;
1570 * since the original fd is still valid, close the copy to
1572 apr_file_close(procnew->in);
1574 apr_proc_other_child_register(procnew, piped_log_maintenance, pl,
1575 pl->write_fd, pl->p);
1576 close_handle_in_child(pl->p, pl->read_fd);
1580 /* Something bad happened, give up and go away. */
1581 ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00104)
1582 "unable to start piped log program '%s': %s",
1583 pl->program, apr_strerror(status, buf, sizeof(buf)));
1591 static void piped_log_maintenance(int reason, void *data, apr_wait_t status)
1593 piped_log *pl = data;
1598 case APR_OC_REASON_DEATH:
1599 case APR_OC_REASON_LOST:
1600 pl->pid = NULL; /* in case we don't get it going again, this
1601 * tells other logic not to try to kill it
1603 apr_proc_other_child_unregister(pl);
1604 stats = ap_mpm_query(AP_MPMQ_MPM_STATE, &mpm_state);
1605 if (stats != APR_SUCCESS) {
1606 ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00105)
1607 "can't query MPM state; not restarting "
1608 "piped log program '%s'",
1611 else if (mpm_state != AP_MPMQ_STOPPING) {
1612 ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00106)
1613 "piped log program '%s' failed unexpectedly",
1615 if ((stats = piped_log_spawn(pl)) != APR_SUCCESS) {
1616 /* what can we do? This could be the error log we're having
1617 * problems opening up... */
1619 ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00107)
1620 "piped_log_maintenance: unable to respawn '%s': %s",
1621 pl->program, apr_strerror(stats, buf, sizeof(buf)));
1626 case APR_OC_REASON_UNWRITABLE:
1627 /* We should not kill off the pipe here, since it may only be full.
1628 * If it really is locked, we should kill it off manually. */
1631 case APR_OC_REASON_RESTART:
1632 if (pl->pid != NULL) {
1633 apr_proc_kill(pl->pid, SIGTERM);
1638 case APR_OC_REASON_UNREGISTER:
1644 static apr_status_t piped_log_cleanup_for_exec(void *data)
1646 piped_log *pl = data;
1648 apr_file_close(pl->read_fd);
1649 apr_file_close(pl->write_fd);
1654 static apr_status_t piped_log_cleanup(void *data)
1656 piped_log *pl = data;
1658 if (pl->pid != NULL) {
1659 apr_proc_kill(pl->pid, SIGTERM);
1661 return piped_log_cleanup_for_exec(data);
1665 AP_DECLARE(piped_log *) ap_open_piped_log_ex(apr_pool_t *p,
1666 const char *program,
1667 apr_cmdtype_e cmdtype)
1671 pl = apr_palloc(p, sizeof (*pl));
1673 pl->program = apr_pstrdup(p, program);
1675 pl->cmdtype = cmdtype;
1676 if (apr_file_pipe_create_ex(&pl->read_fd,
1678 APR_FULL_BLOCK, p) != APR_SUCCESS) {
1681 apr_pool_cleanup_register(p, pl, piped_log_cleanup,
1682 piped_log_cleanup_for_exec);
1683 if (piped_log_spawn(pl) != APR_SUCCESS) {
1684 apr_pool_cleanup_kill(p, pl, piped_log_cleanup);
1685 apr_file_close(pl->read_fd);
1686 apr_file_close(pl->write_fd);
1692 #else /* !AP_HAVE_RELIABLE_PIPED_LOGS */
1694 static apr_status_t piped_log_cleanup(void *data)
1696 piped_log *pl = data;
1698 apr_file_close(pl->write_fd);
1702 AP_DECLARE(piped_log *) ap_open_piped_log_ex(apr_pool_t *p,
1703 const char *program,
1704 apr_cmdtype_e cmdtype)
1707 apr_file_t *dummy = NULL;
1710 rc = log_child(p, program, &dummy, cmdtype, 0);
1711 if (rc != APR_SUCCESS) {
1712 ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00108)
1713 "Couldn't start piped log process '%s'.",
1714 (program == NULL) ? "NULL" : program);
1718 pl = apr_palloc(p, sizeof (*pl));
1721 pl->write_fd = dummy;
1722 apr_pool_cleanup_register(p, pl, piped_log_cleanup, piped_log_cleanup);
1729 AP_DECLARE(piped_log *) ap_open_piped_log(apr_pool_t *p,
1730 const char *program)
1732 apr_cmdtype_e cmdtype = APR_PROGRAM_ENV;
1734 /* In 2.4 favor PROGRAM_ENV, accept "||prog" syntax for compatibility
1735 * and "|$cmd" to override the default.
1736 * Any 2.2 backport would continue to favor SHELLCMD_ENV so there
1737 * accept "||prog" to override, and "|$cmd" to ease conversion.
1739 if (*program == '|')
1741 if (*program == '$') {
1742 cmdtype = APR_SHELLCMD_ENV;
1746 return ap_open_piped_log_ex(p, program, cmdtype);
1749 AP_DECLARE(void) ap_close_piped_log(piped_log *pl)
1751 apr_pool_cleanup_run(pl->p, pl, piped_log_cleanup);
1754 AP_DECLARE(const char *) ap_parse_log_level(const char *str, int *val)
1756 char *err = "Log level keyword must be one of emerg/alert/crit/error/warn/"
1757 "notice/info/debug/trace1/.../trace8";
1763 while (priorities[i].t_name != NULL) {
1764 if (!strcasecmp(str, priorities[i].t_name)) {
1765 *val = priorities[i].t_val;
1773 AP_IMPLEMENT_HOOK_VOID(error_log,
1774 (const ap_errorlog_info *info, const char *errstr),
1777 AP_IMPLEMENT_HOOK_RUN_FIRST(int, generate_log_id,
1778 (const conn_rec *c, const request_rec *r,
1780 (c, r, id), DECLINED)