X-Git-Url: https://granicus.if.org/sourcecode?a=blobdiff_plain;f=server%2Flog.c;h=bfec379d2a663b01ce0b65515d48a304e3d42b5c;hb=c20d5efb4c6f4fca3713c98f98d475bb022523f9;hp=e865628183659012d0a92760eee213cf00322d20;hpb=3ad914e110b4c8ca1111e5f521c8238b61c9fe8c;p=apache diff --git a/server/log.c b/server/log.c index e865628183..bfec379d2a 100644 --- a/server/log.c +++ b/server/log.c @@ -41,6 +41,9 @@ #if APR_HAVE_UNISTD_H #include #endif +#if APR_HAVE_PROCESS_H +#include /* for getpid() on Win32 */ +#endif #include "ap_config.h" #include "httpd.h" @@ -50,8 +53,16 @@ #include "http_main.h" #include "util_time.h" #include "ap_mpm.h" +#include "ap_listen.h" + +#if HAVE_GETTID +#include +#include +#endif -APLOG_USE_MODULE(core); +/* we know core's module_index is 0 */ +#undef APLOG_MODULE_INDEX +#define APLOG_MODULE_INDEX AP_CORE_MODULE_INDEX typedef struct { const char *t_name; @@ -60,6 +71,7 @@ typedef struct { APR_HOOK_STRUCT( APR_HOOK_LINK(error_log) + APR_HOOK_LINK(generate_log_id) ) int AP_DECLARE_DATA ap_default_loglevel = DEFAULT_LOGLEVEL; @@ -162,9 +174,9 @@ typedef struct read_handle_t { static read_handle_t *read_handles; /** - * @brief The piped logging structure. + * @brief The piped logging structure. * - * Piped logs are used to move functionality out of the main server. + * Piped logs are used to move functionality out of the main server. * For example, log rotation is done with piped logs. */ struct piped_log { @@ -192,23 +204,13 @@ AP_DECLARE(apr_file_t *) ap_piped_log_write_fd(piped_log *pl) return pl->write_fd; } -/* clear_handle_list() is called when plog is cleared; at that - * point we need to forget about our old list of pipe read - * handles. We let the plog cleanups close the actual pipes. - */ -static apr_status_t clear_handle_list(void *v) -{ - read_handles = NULL; - return APR_SUCCESS; -} - /* remember to close this handle in the child process * * On Win32 this makes zero sense, because we don't * take the parent process's child procs. * If the win32 parent instead passed each and every * logger write handle from itself down to the child, - * and the parent manages all aspects of keeping the + * and the parent manages all aspects of keeping the * reliable pipe log children alive, this would still * make no sense :) Cripple it on Win32. */ @@ -247,14 +249,14 @@ AP_DECLARE(apr_status_t) ap_replace_stderr_log(apr_pool_t *p, char *filename = ap_server_root_relative(p, fname); if (!filename) { ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, - APR_EBADPATH, NULL, "Invalid -E error log file %s", + APR_EBADPATH, NULL, APLOGNO(00085) "Invalid -E error log file %s", fname); return APR_EBADPATH; } if ((rc = apr_file_open(&stderr_file, filename, APR_APPEND | APR_WRITE | APR_CREATE | APR_LARGEFILE, APR_OS_DEFAULT, p)) != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, + ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00086) "%s: could not open error log file %s.", ap_server_argv0, fname); return rc; @@ -265,18 +267,18 @@ AP_DECLARE(apr_status_t) ap_replace_stderr_log(apr_pool_t *p, */ stderr_pool = p; } - if ((rc = apr_file_open_stderr(&stderr_log, stderr_pool)) + if ((rc = apr_file_open_stderr(&stderr_log, stderr_pool)) == APR_SUCCESS) { apr_file_flush(stderr_log); - if ((rc = apr_file_dup2(stderr_log, stderr_file, stderr_pool)) + if ((rc = apr_file_dup2(stderr_log, stderr_file, stderr_pool)) == APR_SUCCESS) { apr_file_close(stderr_file); /* * You might ponder why stderr_pool should survive? * The trouble is, stderr_pool may have s_main->error_log, * so we aren't in a position to destory stderr_pool until - * the next recycle. There's also an apparent bug which - * is not; if some folk decided to call this function before + * the next recycle. There's also an apparent bug which + * is not; if some folk decided to call this function before * the core open error logs hook, this pool won't survive. * Neither does the stderr logger, so this isn't a problem. */ @@ -287,7 +289,7 @@ AP_DECLARE(apr_status_t) ap_replace_stderr_log(apr_pool_t *p, stderr_pool = NULL; if (rc != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_CRIT, rc, NULL, + ap_log_error(APLOG_MARK, APLOG_CRIT, rc, NULL, APLOGNO(00087) "unable to replace stderr with error log file"); } return rc; @@ -296,7 +298,7 @@ AP_DECLARE(apr_status_t) ap_replace_stderr_log(apr_pool_t *p, static void log_child_errfn(apr_pool_t *pool, apr_status_t err, const char *description) { - ap_log_error(APLOG_MARK, APLOG_ERR, err, NULL, + ap_log_error(APLOG_MARK, APLOG_ERR, err, NULL, APLOGNO(00088) "%s", description); } @@ -327,13 +329,11 @@ static int log_child(apr_pool_t *p, const char *progname, APR_NO_PIPE, APR_NO_PIPE)) == APR_SUCCESS) && ((rc = apr_procattr_error_check_set(procattr, 1)) == APR_SUCCESS) - && ((rc = apr_procattr_child_errfn_set(procattr, log_child_errfn)) + && ((rc = apr_procattr_child_errfn_set(procattr, log_child_errfn)) == APR_SUCCESS)) { char **args; - const char *pname; apr_tokenize_to_argv(progname, &args, p); - pname = apr_pstrdup(p, args[0]); procnew = (apr_proc_t *)apr_pcalloc(p, sizeof(*procnew)); if (dummy_stderr) { @@ -341,7 +341,7 @@ static int log_child(apr_pool_t *p, const char *progname, rc = apr_procattr_child_err_set(procattr, errfile, NULL); } - rc = apr_proc_create(procnew, pname, (const char * const *)args, + rc = apr_proc_create(procnew, args[0], (const char * const *)args, NULL, procattr, p); if (rc == APR_SUCCESS) { @@ -370,7 +370,7 @@ static int open_error_log(server_rec *s, int is_main, apr_pool_t *p) /* In 2.4 favor PROGRAM_ENV, accept "||prog" syntax for compatibility * and "|$cmd" to override the default. - * Any 2.2 backport would continue to favor SHELLCMD_ENV so there + * Any 2.2 backport would continue to favor SHELLCMD_ENV so there * accept "||prog" to override, and "|$cmd" to ease conversion. */ if (*fname == '|') @@ -386,7 +386,7 @@ static int open_error_log(server_rec *s, int is_main, apr_pool_t *p) * child inherits the parents stderr. */ rc = log_child(p, fname, &dummy, cmdtype, is_main); if (rc != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, + ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00089) "Couldn't start ErrorLog process '%s'.", s->error_fname + 1); return DONE; @@ -420,7 +420,7 @@ static int open_error_log(server_rec *s, int is_main, apr_pool_t *p) else { fname = ap_server_root_relative(p, s->error_fname); if (!fname) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, APR_EBADPATH, NULL, + ap_log_error(APLOG_MARK, APLOG_STARTUP, APR_EBADPATH, NULL, APLOGNO(00090) "%s: Invalid error log path %s.", ap_server_argv0, s->error_fname); return DONE; @@ -428,7 +428,7 @@ static int open_error_log(server_rec *s, int is_main, apr_pool_t *p) if ((rc = apr_file_open(&s->error_log, fname, APR_APPEND | APR_WRITE | APR_CREATE | APR_LARGEFILE, APR_OS_DEFAULT, p)) != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, + ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00091) "%s: could not open error log file %s.", ap_server_argv0, fname); return DONE; @@ -449,17 +449,17 @@ int ap_open_logs(apr_pool_t *pconf, apr_pool_t *p /* plog */, /* Register to throw away the read_handles list when we * cleanup plog. Upon fork() for the apache children, * this read_handles list is closed so only the parent - * can relaunch a lost log child. These read handles + * can relaunch a lost log child. These read handles * are always closed on exec. - * We won't care what happens to our stderr log child - * between log phases, so we don't mind losing stderr's + * We won't care what happens to our stderr log child + * between log phases, so we don't mind losing stderr's * read_handle a little bit early. */ - apr_pool_cleanup_register(p, NULL, clear_handle_list, + apr_pool_cleanup_register(p, &read_handles, ap_pool_cleanup_set_null, apr_pool_cleanup_null); /* HERE we need a stdout log that outlives plog. - * We *presume* the parent of plog is a process + * We *presume* the parent of plog is a process * or global pool which spans server restarts. * Create our stderr_pool as a child of the plog's * parent pool. @@ -479,7 +479,7 @@ int ap_open_logs(apr_pool_t *pconf, apr_pool_t *p /* plog */, apr_file_flush(s_main->error_log); rv = apr_file_dup2(stderr_log, s_main->error_log, stderr_p); if (rv != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_CRIT, rv, s_main, + ap_log_error(APLOG_MARK, APLOG_CRIT, rv, s_main, APLOGNO(00092) "unable to replace stderr with error_log"); } else { @@ -498,8 +498,8 @@ int ap_open_logs(apr_pool_t *pconf, apr_pool_t *p /* plog */, * as stdin. This in turn would prevent the piped logger from * exiting. */ - apr_file_close(s_main->error_log); - s_main->error_log = stderr_log; + apr_file_close(s_main->error_log); + s_main->error_log = stderr_log; } } /* note that stderr may still need to be replaced with something @@ -508,9 +508,16 @@ int ap_open_logs(apr_pool_t *pconf, apr_pool_t *p /* plog */, * XXX: This is BS - /dev/null is non-portable * errno-as-apr_status_t is also non-portable */ - if (replace_stderr && freopen("/dev/null", "w", stderr) == NULL) { - ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, - "unable to replace stderr with /dev/null"); + +#ifdef WIN32 +#define NULL_DEVICE "nul" +#else +#define NULL_DEVICE "/dev/null" +#endif + + if (replace_stderr && freopen(NULL_DEVICE, "w", stderr) == NULL) { + ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, APLOGNO(00093) + "unable to replace stderr with %s", NULL_DEVICE); } for (virt = s_main->next; virt; virt = virt->next) { @@ -560,9 +567,12 @@ static int cpystrn(char *buf, const char *arg, int buflen) static int log_remote_address(const ap_errorlog_info *info, const char *arg, char *buf, int buflen) { - if (info->c) - return apr_snprintf(buf, buflen, "%s:%d", info->c->remote_ip, - info->c->remote_addr->port); + if (info->r && !(arg && *arg == 'c')) + return apr_snprintf(buf, buflen, "%s:%d", info->r->useragent_ip, + info->r->useragent_addr ? info->r->useragent_addr->port : 0); + else if (info->c) + return apr_snprintf(buf, buflen, "%s:%d", info->c->client_ip, + info->c->client_addr ? info->c->client_addr->port : 0); else return 0; } @@ -589,7 +599,16 @@ static int log_tid(const ap_errorlog_info *info, const char *arg, { #if APR_HAS_THREADS int result; - +#endif +#if HAVE_GETTID + if (arg && *arg == 'g') { + pid_t tid = syscall(SYS_gettid); + if (tid == -1) + return 0; + return apr_snprintf(buf, buflen, "%"APR_PID_T_FMT, tid); + } +#endif +#if APR_HAS_THREADS if (ap_mpm_query(AP_MPMQ_IS_THREADED, &result) == APR_SUCCESS && result != AP_MPMQ_NOT_SUPPORTED) { @@ -606,7 +625,7 @@ static int log_ctime(const ap_errorlog_info *info, const char *arg, int time_len = buflen; int option = AP_CTIME_OPTION_NONE; - while(arg && *arg) { + while (arg && *arg) { switch (*arg) { case 'u': option |= AP_CTIME_OPTION_USEC; break; @@ -644,8 +663,8 @@ static int log_log_id(const ap_errorlog_info *info, const char *arg, return cpystrn(buf, info->c->log_id, buflen); } } - else if (info->r) { - return cpystrn(buf, info->r->log_id, buflen); + else if (info->rmain) { + return cpystrn(buf, info->rmain->log_id, buflen); } return 0; } @@ -736,53 +755,73 @@ static int log_apr_status(const ap_errorlog_info *info, const char *arg, return len; } -static int log_header(const ap_errorlog_info *info, const char *arg, - char *buf, int buflen) +static int log_server_name(const ap_errorlog_info *info, const char *arg, + char *buf, int buflen) +{ + if (info->r) + return cpystrn(buf, ap_get_server_name((request_rec *)info->r), buflen); + + return 0; +} + +static int log_virtual_host(const ap_errorlog_info *info, const char *arg, + char *buf, int buflen) +{ + if (info->s) + return cpystrn(buf, info->s->server_hostname, buflen); + + return 0; +} + + +static int log_table_entry(const apr_table_t *table, const char *name, + char *buf, int buflen) { - const char *header; - int len = 0; #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED + const char *value; char scratch[MAX_STRING_LEN]; -#endif - if ( info->r && (header = apr_table_get(info->r->headers_in, arg)) -#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED - && ap_escape_errorlog_item(scratch, header, MAX_STRING_LEN) -#endif - ) { - len = cpystrn(buf, -#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED - scratch, + if ((value = apr_table_get(table, name)) != NULL) { + ap_escape_errorlog_item(scratch, value, MAX_STRING_LEN); + return cpystrn(buf, scratch, buflen); + } + + return 0; #else - header, + return cpystrn(buf, apr_table_get(table, name), buflen); #endif - buflen); - } - return len; } +static int log_header(const ap_errorlog_info *info, const char *arg, + char *buf, int buflen) +{ + if (info->r) + return log_table_entry(info->r->headers_in, arg, buf, buflen); + return 0; +} +static int log_note(const ap_errorlog_info *info, const char *arg, + char *buf, int buflen) +{ + /* XXX: maybe escaping the entry is not necessary for notes? */ + if (info->r) + return log_table_entry(info->r->notes, arg, buf, buflen); -AP_DECLARE(void) ap_register_builtin_errorlog_handlers(apr_pool_t *p) + return 0; +} + +static int log_env_var(const ap_errorlog_info *info, const char *arg, + char *buf, int buflen) { - ap_register_errorlog_handler(p, "a", log_remote_address, 0); - ap_register_errorlog_handler(p, "A", log_local_address, 0); - ap_register_errorlog_handler(p, "E", log_apr_status, 0); - ap_register_errorlog_handler(p, "F", log_file_line, 0); - ap_register_errorlog_handler(p, "i", log_header, 0); - ap_register_errorlog_handler(p, "k", log_keepalives, 0); - ap_register_errorlog_handler(p, "l", log_loglevel, 0); - ap_register_errorlog_handler(p, "L", log_log_id, 0); - ap_register_errorlog_handler(p, "m", log_module_name, 0); - ap_register_errorlog_handler(p, "P", log_pid, 0); - ap_register_errorlog_handler(p, "t", log_ctime, 0); - ap_register_errorlog_handler(p, "T", log_tid, 0); + if (info->r) + return log_table_entry(info->r->subprocess_env, arg, buf, buflen); - /* XXX: TODO: envvars, notes */ + return 0; } -static void add_log_id(const conn_rec *c, const request_rec *r) +static int core_generate_log_id(const conn_rec *c, const request_rec *r, + const char **idstring) { apr_uint64_t id, tmp; pid_t pid; @@ -820,23 +859,53 @@ static void add_log_id(const conn_rec *c, const request_rec *r) } #endif - len = apr_base64_encode_len(sizeof(id)); + len = apr_base64_encode_len(sizeof(id)); /* includes trailing \0 */ encoded = apr_palloc(r ? r->pool : c->pool, len); apr_base64_encode(encoded, (char *)&id, sizeof(id)); - /* - * Only the first 11 chars are significant, the last (12th) char is - * always '='. - */ - encoded[11] = '\0'; + /* Skip the last char, it is always '=' */ + encoded[len - 2] = '\0'; + + *idstring = encoded; + return OK; +} + +static void add_log_id(const conn_rec *c, const request_rec *r) +{ + const char **id; /* need to cast const away */ if (r) { - ((request_rec *)r)->log_id = encoded; + id = &((request_rec *)r)->log_id; } else { - ((conn_rec *)c)->log_id = encoded; + id = &((conn_rec *)c)->log_id; } + + ap_run_generate_log_id(c, r, id); +} + +AP_DECLARE(void) ap_register_log_hooks(apr_pool_t *p) +{ + ap_hook_generate_log_id(core_generate_log_id, NULL, NULL, + APR_HOOK_REALLY_LAST); + + ap_register_errorlog_handler(p, "a", log_remote_address, 0); + ap_register_errorlog_handler(p, "A", log_local_address, 0); + ap_register_errorlog_handler(p, "e", log_env_var, 0); + ap_register_errorlog_handler(p, "E", log_apr_status, 0); + ap_register_errorlog_handler(p, "F", log_file_line, 0); + ap_register_errorlog_handler(p, "i", log_header, 0); + ap_register_errorlog_handler(p, "k", log_keepalives, 0); + ap_register_errorlog_handler(p, "l", log_loglevel, 0); + ap_register_errorlog_handler(p, "L", log_log_id, 0); + ap_register_errorlog_handler(p, "m", log_module_name, 0); + ap_register_errorlog_handler(p, "n", log_note, 0); + ap_register_errorlog_handler(p, "P", log_pid, 0); + ap_register_errorlog_handler(p, "t", log_ctime, 0); + ap_register_errorlog_handler(p, "T", log_tid, 0); + ap_register_errorlog_handler(p, "v", log_virtual_host, 0); + ap_register_errorlog_handler(p, "V", log_server_name, 0); } /* @@ -898,14 +967,21 @@ static int do_errorlog_default(const ap_errorlog_info *info, char *buf, } } - if (info->c) { - /* - * remote_ip can be client or backend server. If we have a scoreboard - * handle, it is likely a client. - */ + /* + * useragent_ip/client_ip can be client or backend server. If we have + * a scoreboard handle, it is likely a client. + */ + if (info->r) { + len += apr_snprintf(buf + len, buflen - len, + info->r->connection->sbh ? "[client %s:%d] " : "[remote %s:%d] ", + info->r->useragent_ip, + info->r->useragent_addr ? info->r->useragent_addr->port : 0); + } + else if (info->c) { len += apr_snprintf(buf + len, buflen - len, info->c->sbh ? "[client %s:%d] " : "[remote %s:%d] ", - info->c->remote_ip, info->c->remote_addr->port); + info->c->client_ip, + info->c->client_addr ? info->c->client_addr->port : 0); } /* the actual error message */ @@ -945,6 +1021,7 @@ static int do_errorlog_format(apr_array_header_t *fmt, ap_errorlog_info *info, int skipping = 0; ap_errorlog_format_item *items = (ap_errorlog_format_item *)fmt->elts; + AP_DEBUG_ASSERT(fmt->nelts > 0); for (i = 0; i < fmt->nelts; ++i) { ap_errorlog_format_item *item = &items[i]; if (item->flags & AP_ERRORLOG_FLAG_FIELD_SEP) { @@ -973,6 +1050,10 @@ static int do_errorlog_format(apr_array_header_t *fmt, ap_errorlog_info *info, else if (skipping) { continue; } + else if (info->level != -1 && (int)item->min_loglevel > info->level) { + len = field_start; + skipping = 1; + } else { int item_len = (*item->func)(info, item->arg, buf + len, buflen - len); @@ -1013,7 +1094,8 @@ static void write_logline(char *errstr, apr_size_t len, apr_file_t *logf, } #ifdef HAVE_SYSLOG else { - syslog(level < LOG_PRIMASK ? level : APLOG_DEBUG, "%s", errstr); + syslog(level < LOG_PRIMASK ? level : APLOG_DEBUG, "%.*s", + (int)len, errstr); } #endif } @@ -1038,7 +1120,8 @@ static void log_error_core(const char *file, int line, int module_index, int done = 0; int line_number = 0; - if (r && r->connection) { + if (r) { + AP_DEBUG_ASSERT(r->connection != NULL); c = r->connection; } @@ -1083,39 +1166,43 @@ static void log_error_core(const char *file, int line, int module_index, } } - sconf = ap_get_module_config(s->module_config, &core_module); - if (c && !c->log_id) { - add_log_id(c, NULL); - if (sconf->error_log_conn && sconf->error_log_conn->nelts > 0) - log_conn_info = 1; - } - if (r) { - if (r->main) - rmain = r->main; - else - rmain = r; - - if (!rmain->log_id) { - /* XXX: do we need separate log ids for subrequests? */ - if (sconf->error_log_req && sconf->error_log_req->nelts > 0) - log_req_info = 1; - /* - * XXX: potential optimization: only create log id if %L is - * XXX: actually used - */ - add_log_id(c, rmain); + /* the faked server_rec from mod_cgid does not have s->module_config */ + if (s->module_config) { + sconf = ap_get_core_module_config(s->module_config); + if (c && !c->log_id) { + add_log_id(c, NULL); + if (sconf->error_log_conn && sconf->error_log_conn->nelts > 0) + log_conn_info = 1; + } + if (r) { + if (r->main) + rmain = r->main; + else + rmain = r; + + if (!rmain->log_id) { + /* XXX: do we need separate log ids for subrequests? */ + if (sconf->error_log_req && sconf->error_log_req->nelts > 0) + log_req_info = 1; + /* + * XXX: potential optimization: only create log id if %L is + * XXX: actually used + */ + add_log_id(c, rmain); + } } } } info.s = s; info.c = c; - info.file = file; - info.line = line; - info.status = status; + info.pool = pool; + info.file = NULL; + info.line = 0; + info.status = 0; info.using_syslog = (logf == NULL); info.startup = ((level & APLOG_STARTUP) == APLOG_STARTUP); - + info.format = fmt; while (!done) { apr_array_header_t *log_format; @@ -1159,10 +1246,13 @@ static void log_error_core(const char *file, int line, int module_index, } else { /* the actual error message */ - info.r = r; - info.rmain = rmain; - info.level = level_and_mask; + info.r = r; + info.rmain = rmain; + info.level = level_and_mask; info.module_index = module_index; + info.file = file; + info.line = line; + info.status = status; log_format = sconf ? sconf->error_log_format : NULL; done = 1; } @@ -1171,7 +1261,7 @@ static void log_error_core(const char *file, int line, int module_index, * prepare and log one line */ - if (log_format) { + if (log_format && !info.startup) { len += do_errorlog_format(log_format, &info, errstr + len, MAX_STRING_LEN - len, &errstr_start, &errstr_end, fmt, args); @@ -1181,8 +1271,7 @@ static void log_error_core(const char *file, int line, int module_index, &errstr_start, &errstr_end, fmt, args); } - if (!*errstr) - { + if (!*errstr) { /* * Don't log empty lines. This can happen with once-per-conn/req * info if an item with AP_ERRORLOG_FLAG_REQUIRED is NULL. @@ -1191,17 +1280,35 @@ static void log_error_core(const char *file, int line, int module_index, } write_logline(errstr, len, logf, level_and_mask); - if (!log_format) { - /* only pass the real error string to the hook */ + if (done) { + /* + * We don't call the error_log hook for per-request/per-conn + * lines, and we only pass the actual log message, not the + * prefix and suffix. + */ errstr[errstr_end] = '\0'; - ap_run_error_log(file, line, module_index, level, status, s, r, pool, - errstr + errstr_start); + ap_run_error_log(&info, errstr + errstr_start); } *errstr = '\0'; } } +/* For internal calls to log_error_core with self-composed arg lists */ +static void log_error_va_glue(const char *file, int line, int module_index, + int level, apr_status_t status, + const server_rec *s, const conn_rec *c, + const request_rec *r, apr_pool_t *pool, + const char *fmt, ...) +{ + va_list args; + + va_start(args, fmt); + log_error_core(file, line, module_index, level, status, s, c, r, pool, + fmt, args); + va_end(args); +} + AP_DECLARE(void) ap_log_error_(const char *file, int line, int module_index, int level, apr_status_t status, const server_rec *s, const char *fmt, ...) @@ -1280,13 +1387,136 @@ AP_DECLARE(void) ap_log_cerror_(const char *file, int line, int module_index, va_end(args); } +#define BYTES_LOGGED_PER_LINE 16 +#define LOG_BYTES_BUFFER_SIZE (BYTES_LOGGED_PER_LINE * 3 + 2) + +static void fmt_data(unsigned char *buf, const void *vdata, apr_size_t len, apr_size_t *off) +{ + const unsigned char *data = (const unsigned char *)vdata; + unsigned char *chars; + unsigned char *hex; + apr_size_t this_time = 0; + + memset(buf, ' ', LOG_BYTES_BUFFER_SIZE - 1); + buf[LOG_BYTES_BUFFER_SIZE - 1] = '\0'; + + chars = buf; /* start character dump here */ + hex = buf + BYTES_LOGGED_PER_LINE + 1; /* start hex dump here */ + while (*off < len && this_time < BYTES_LOGGED_PER_LINE) { + unsigned char c = data[*off]; + + if (apr_isprint(c) + && c != '\\') { /* backslash will be escaped later, which throws + * off the formatting + */ + *chars = c; + } + else { + *chars = '.'; + } + + if ((c >> 4) >= 10) { + *hex = 'a' + ((c >> 4) - 10); + } + else { + *hex = '0' + (c >> 4); + } + + if ((c & 0x0F) >= 10) { + *(hex + 1) = 'a' + ((c & 0x0F) - 10); + } + else { + *(hex + 1) = '0' + (c & 0x0F); + } + + chars += 1; + hex += 2; + *off += 1; + ++this_time; + } +} + +static void log_data_core(const char *file, int line, int module_index, + int level, const server_rec *s, + const conn_rec *c, const request_rec *r, + const char *label, const void *data, apr_size_t len, + unsigned int flags) +{ + unsigned char buf[LOG_BYTES_BUFFER_SIZE]; + apr_size_t off; + char prefix[20]; + + if (!(flags & AP_LOG_DATA_SHOW_OFFSET)) { + prefix[0] = '\0'; + } + + if (len > 0xffff) { /* bug in caller? */ + len = 0xffff; + } + + if (label) { + log_error_va_glue(file, line, module_index, level, APR_SUCCESS, s, + c, r, NULL, "%s (%" APR_SIZE_T_FMT " bytes)", + label, len); + } + + off = 0; + while (off < len) { + if (flags & AP_LOG_DATA_SHOW_OFFSET) { + apr_snprintf(prefix, sizeof prefix, "%04x: ", (unsigned int)off); + } + fmt_data(buf, data, len, &off); + log_error_va_glue(file, line, module_index, level, APR_SUCCESS, s, + c, r, NULL, "%s%s", prefix, buf); + } +} + +AP_DECLARE(void) ap_log_data_(const char *file, int line, + int module_index, int level, + const server_rec *s, const char *label, + const void *data, apr_size_t len, + unsigned int flags) +{ + log_data_core(file, line, module_index, level, s, NULL, NULL, label, + data, len, flags); +} + +AP_DECLARE(void) ap_log_rdata_(const char *file, int line, + int module_index, int level, + const request_rec *r, const char *label, + const void *data, apr_size_t len, + unsigned int flags) +{ + log_data_core(file, line, module_index, level, r->server, NULL, r, label, + data, len, flags); +} + +AP_DECLARE(void) ap_log_cdata_(const char *file, int line, + int module_index, int level, + const conn_rec *c, const char *label, + const void *data, apr_size_t len, + unsigned int flags) +{ + log_data_core(file, line, module_index, level, c->base_server, c, NULL, + label, data, len, flags); +} + +AP_DECLARE(void) ap_log_csdata_(const char *file, int line, int module_index, + int level, const conn_rec *c, const server_rec *s, + const char *label, const void *data, + apr_size_t len, unsigned int flags) +{ + log_data_core(file, line, module_index, level, s, c, NULL, label, data, + len, flags); +} + AP_DECLARE(void) ap_log_command_line(apr_pool_t *plog, server_rec *s) { int i; process_rec *process = s->process; char *result; int len_needed = 0; - + /* Piece together the command line from the pieces * in process->argv, with spaces in between. */ @@ -1303,10 +1533,38 @@ AP_DECLARE(void) ap_log_command_line(apr_pool_t *plog, server_rec *s) strcat(result, " "); } } - ap_log_error(APLOG_MARK, APLOG_NOTICE, 0, s, + ap_log_error(APLOG_MARK, APLOG_NOTICE, 0, s, APLOGNO(00094) "Command line: '%s'", result); } +/* grab bag function to log commonly logged and shared info */ +AP_DECLARE(void) ap_log_mpm_common(server_rec *s) +{ + ap_log_error(APLOG_MARK, APLOG_DEBUG , 0, s, APLOGNO(02639) + "Using SO_REUSEPORT: %s (%d)", + ap_have_so_reuseport ? "yes" : "no", + ap_num_listen_buckets); +} + +AP_DECLARE(void) ap_remove_pid(apr_pool_t *p, const char *rel_fname) +{ + apr_status_t rv; + const char *fname = ap_server_root_relative(p, rel_fname); + + if (fname != NULL) { + rv = apr_file_remove(fname, p); + if (rv != APR_SUCCESS) { + ap_log_error(APLOG_MARK, APLOG_ERR, rv, ap_server_conf, APLOGNO(00095) + "failed to remove PID file %s", fname); + } + else { + ap_log_error(APLOG_MARK, APLOG_INFO, 0, ap_server_conf, APLOGNO(00096) + "removed PID file %s (pid=%" APR_PID_T_FMT ")", + fname, getpid()); + } + } +} + AP_DECLARE(void) ap_log_pid(apr_pool_t *p, const char *filename) { apr_file_t *pid_file = NULL; @@ -1323,7 +1581,7 @@ AP_DECLARE(void) ap_log_pid(apr_pool_t *p, const char *filename) fname = ap_server_root_relative(p, filename); if (!fname) { ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, APR_EBADPATH, - NULL, "Invalid PID file path %s, ignoring.", filename); + NULL, APLOGNO(00097) "Invalid PID file path %s, ignoring.", filename); return; } @@ -1337,7 +1595,7 @@ AP_DECLARE(void) ap_log_pid(apr_pool_t *p, const char *filename) * that may screw up scripts written to do something * based on the last modification time of the pid file. */ - ap_log_perror(APLOG_MARK, APLOG_WARNING, 0, p, + ap_log_perror(APLOG_MARK, APLOG_WARNING, 0, p, APLOGNO(00098) "pid file %s overwritten -- Unclean " "shutdown of previous Apache run?", fname); @@ -1347,9 +1605,9 @@ AP_DECLARE(void) ap_log_pid(apr_pool_t *p, const char *filename) APR_WRITE | APR_CREATE | APR_TRUNCATE, APR_UREAD | APR_UWRITE | APR_GREAD | APR_WREAD, p)) != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_ERR, rv, NULL, + ap_log_error(APLOG_MARK, APLOG_ERR, rv, NULL, APLOGNO(00099) "could not create %s", fname); - ap_log_error(APLOG_MARK, APLOG_ERR, 0, NULL, + ap_log_error(APLOG_MARK, APLOG_ERR, 0, NULL, APLOGNO(00100) "%s: could not log pid to file %s", ap_server_argv0, fname); exit(1); @@ -1376,7 +1634,7 @@ AP_DECLARE(apr_status_t) ap_read_pid(apr_pool_t *p, const char *filename, fname = ap_server_root_relative(p, filename); if (!fname) { ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, APR_EBADPATH, - NULL, "Invalid PID file path %s, ignoring.", filename); + NULL, APLOGNO(00101) "Invalid PID file path %s, ignoring.", filename); return APR_EGENERAL; } @@ -1411,7 +1669,7 @@ AP_DECLARE(void) ap_log_assert(const char *szExp, const char *szFile, char time_str[APR_CTIME_LEN]; apr_ctime(time_str, apr_time_now()); - ap_log_error(APLOG_MARK, APLOG_CRIT, 0, NULL, + ap_log_error(APLOG_MARK, APLOG_CRIT, 0, NULL, APLOGNO(00102) "[%s] file %s, line %d, assertion \"%s\" failed", time_str, szFile, nLine, szExp); #if defined(WIN32) @@ -1447,20 +1705,17 @@ static apr_status_t piped_log_spawn(piped_log *pl) ((status = apr_procattr_child_errfn_set(procattr, log_child_errfn)) != APR_SUCCESS) || ((status = apr_procattr_error_check_set(procattr, 1)) != APR_SUCCESS)) { - char buf[120]; /* Something bad happened, give up and go away. */ - ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, - "piped_log_spawn: unable to setup child process '%s': %s", - pl->program, apr_strerror(status, buf, sizeof(buf))); + ap_log_error(APLOG_MARK, APLOG_STARTUP, status, NULL, APLOGNO(00103) + "piped_log_spawn: unable to setup child process '%s'", + pl->program); } else { char **args; - const char *pname; apr_tokenize_to_argv(pl->program, &args, pl->p); - pname = apr_pstrdup(pl->p, args[0]); procnew = apr_pcalloc(pl->p, sizeof(apr_proc_t)); - status = apr_proc_create(procnew, pname, (const char * const *) args, + status = apr_proc_create(procnew, args[0], (const char * const *) args, NULL, procattr, pl->p); if (status == APR_SUCCESS) { @@ -1475,11 +1730,10 @@ static apr_status_t piped_log_spawn(piped_log *pl) close_handle_in_child(pl->p, pl->read_fd); } else { - char buf[120]; /* Something bad happened, give up and go away. */ - ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, - "unable to start piped log program '%s': %s", - pl->program, apr_strerror(status, buf, sizeof(buf))); + ap_log_error(APLOG_MARK, APLOG_STARTUP, status, NULL, APLOGNO(00104) + "unable to start piped log program '%s'", + pl->program); } } @@ -1490,7 +1744,7 @@ static apr_status_t piped_log_spawn(piped_log *pl) static void piped_log_maintenance(int reason, void *data, apr_wait_t status) { piped_log *pl = data; - apr_status_t stats; + apr_status_t rv; int mpm_state; switch (reason) { @@ -1500,24 +1754,23 @@ static void piped_log_maintenance(int reason, void *data, apr_wait_t status) * tells other logic not to try to kill it */ apr_proc_other_child_unregister(pl); - stats = ap_mpm_query(AP_MPMQ_MPM_STATE, &mpm_state); - if (stats != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, + rv = ap_mpm_query(AP_MPMQ_MPM_STATE, &mpm_state); + if (rv != APR_SUCCESS) { + ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00105) "can't query MPM state; not restarting " "piped log program '%s'", pl->program); } else if (mpm_state != AP_MPMQ_STOPPING) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, + ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00106) "piped log program '%s' failed unexpectedly", pl->program); - if ((stats = piped_log_spawn(pl)) != APR_SUCCESS) { + if ((rv = piped_log_spawn(pl)) != APR_SUCCESS) { /* what can we do? This could be the error log we're having * problems opening up... */ - char buf[120]; - ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, - "piped_log_maintenance: unable to respawn '%s': %s", - pl->program, apr_strerror(stats, buf, sizeof(buf))); + ap_log_error(APLOG_MARK, APLOG_STARTUP, rv, NULL, APLOGNO(00107) + "piped_log_maintenance: unable to respawn '%s'", + pl->program); } } break; @@ -1608,7 +1861,7 @@ AP_DECLARE(piped_log *) ap_open_piped_log_ex(apr_pool_t *p, rc = log_child(p, program, &dummy, cmdtype, 0); if (rc != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, + ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00108) "Couldn't start piped log process '%s'.", (program == NULL) ? "NULL" : program); return NULL; @@ -1632,7 +1885,7 @@ AP_DECLARE(piped_log *) ap_open_piped_log(apr_pool_t *p, /* In 2.4 favor PROGRAM_ENV, accept "||prog" syntax for compatibility * and "|$cmd" to override the default. - * Any 2.2 backport would continue to favor SHELLCMD_ENV so there + * Any 2.2 backport would continue to favor SHELLCMD_ENV so there * accept "||prog" to override, and "|$cmd" to ease conversion. */ if (*program == '|') @@ -1670,8 +1923,10 @@ AP_DECLARE(const char *) ap_parse_log_level(const char *str, int *val) } AP_IMPLEMENT_HOOK_VOID(error_log, - (const char *file, int line, int module_index, int level, - apr_status_t status, const server_rec *s, - const request_rec *r, apr_pool_t *pool, - const char *errstr), (file, line, module_index, level, - status, s, r, pool, errstr)) + (const ap_errorlog_info *info, const char *errstr), + (info, errstr)) + +AP_IMPLEMENT_HOOK_RUN_FIRST(int, generate_log_id, + (const conn_rec *c, const request_rec *r, + const char **id), + (c, r, id), DECLINED)