log.c revision 185aa71728867671e105178b4c66fbc22b65ae26
/* Licensed to the Apache Software Foundation (ASF) under one or more
* contributor license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright ownership.
* The ASF licenses this file to You under the Apache License, Version 2.0
* (the "License"); you may not use this file except in compliance with
* the License. You may obtain a copy of the License at
*
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
/*
* http_log.c: Dealing with the logs and errors
*
* Rob McCool
*
*/
#include "apr.h"
#include "apr_general.h" /* for signal stuff */
#include "apr_strings.h"
#include "apr_errno.h"
#include "apr_thread_proc.h"
#include "apr_lib.h"
#include "apr_signal.h"
#include "apr_portable.h"
#include "apr_base64.h"
#define APR_WANT_STDIO
#define APR_WANT_STRFUNC
#include "apr_want.h"
#include <stdarg.h>
#endif
#include <unistd.h>
#endif
#include <process.h> /* for getpid() on Win32 */
#endif
#include "ap_config.h"
#include "httpd.h"
#include "http_config.h"
#include "http_core.h"
#include "http_log.h"
#include "http_main.h"
#include "util_time.h"
#include "ap_mpm.h"
#if HAVE_GETTID
#endif
/* we know core's module_index is 0 */
typedef struct {
const char *t_name;
int t_val;
} TRANS;
)
#ifdef HAVE_SYSLOG
static const TRANS facilities[] = {
{"auth", LOG_AUTH},
#ifdef LOG_AUTHPRIV
{"authpriv",LOG_AUTHPRIV},
#endif
#ifdef LOG_CRON
{"cron", LOG_CRON},
#endif
#ifdef LOG_DAEMON
{"daemon", LOG_DAEMON},
#endif
#ifdef LOG_FTP
{"ftp", LOG_FTP},
#endif
#ifdef LOG_KERN
{"kern", LOG_KERN},
#endif
#ifdef LOG_LPR
{"lpr", LOG_LPR},
#endif
#ifdef LOG_MAIL
{"mail", LOG_MAIL},
#endif
#ifdef LOG_NEWS
{"news", LOG_NEWS},
#endif
#ifdef LOG_SYSLOG
{"syslog", LOG_SYSLOG},
#endif
#ifdef LOG_USER
{"user", LOG_USER},
#endif
#ifdef LOG_UUCP
{"uucp", LOG_UUCP},
#endif
#ifdef LOG_LOCAL0
{"local0", LOG_LOCAL0},
#endif
#ifdef LOG_LOCAL1
{"local1", LOG_LOCAL1},
#endif
#ifdef LOG_LOCAL2
{"local2", LOG_LOCAL2},
#endif
#ifdef LOG_LOCAL3
{"local3", LOG_LOCAL3},
#endif
#ifdef LOG_LOCAL4
{"local4", LOG_LOCAL4},
#endif
#ifdef LOG_LOCAL5
{"local5", LOG_LOCAL5},
#endif
#ifdef LOG_LOCAL6
{"local6", LOG_LOCAL6},
#endif
#ifdef LOG_LOCAL7
{"local7", LOG_LOCAL7},
#endif
{NULL, -1},
};
#endif
static const TRANS priorities[] = {
{"emerg", APLOG_EMERG},
{"alert", APLOG_ALERT},
{"crit", APLOG_CRIT},
{"error", APLOG_ERR},
{"warn", APLOG_WARNING},
{"notice", APLOG_NOTICE},
{"info", APLOG_INFO},
{"debug", APLOG_DEBUG},
{"trace1", APLOG_TRACE1},
{"trace2", APLOG_TRACE2},
{"trace3", APLOG_TRACE3},
{"trace4", APLOG_TRACE4},
{"trace5", APLOG_TRACE5},
{"trace6", APLOG_TRACE6},
{"trace7", APLOG_TRACE7},
{"trace8", APLOG_TRACE8},
{NULL, -1},
};
/* track pipe handles to close in child process */
typedef struct read_handle_t {
struct read_handle_t *next;
static read_handle_t *read_handles;
/**
* @brief The piped logging structure.
*
* Piped logs are used to move functionality out of the main server.
* For example, log rotation is done with piped logs.
*/
struct piped_log {
/** The pool to use for the piped log */
apr_pool_t *p;
/** The pipe between the server and the logging process */
#ifdef AP_HAVE_RELIABLE_PIPED_LOGS
/** The name of the program the logging process is running */
char *program;
/** The pid of the logging process */
/** How to reinvoke program when it must be replaced */
#endif
};
{
}
{
}
/* 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
* reliable pipe log children alive, this would still
* make no sense :) Cripple it on Win32.
*/
{
#ifndef WIN32
new_handle->handle = f;
#endif
}
{
while (cur) {
}
}
{
}
const char *fname)
{
if (!filename) {
fname);
return APR_EBADPATH;
}
APR_OS_DEFAULT, p)) != APR_SUCCESS) {
"%s: could not open error log file %s.",
return rc;
}
if (!stderr_pool) {
/* This is safe provided we revert it when we are finished.
* We don't manager the callers pool!
*/
stderr_pool = p;
}
== APR_SUCCESS) {
== APR_SUCCESS) {
/*
* 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 core open error logs hook, this pool won't survive.
* Neither does the stderr logger, so this isn't a problem.
*/
}
}
/* Revert, see above */
if (stderr_pool == p)
stderr_pool = NULL;
if (rc != APR_SUCCESS) {
"unable to replace stderr with error log file");
}
return rc;
}
const char *description)
{
"%s", description);
}
/* Create a child process running PROGNAME with a pipe connected to
* the childs stdin. The write-end of the pipe will be placed in
* *FPIN on successful return. If dummy_stderr is non-zero, the
* stderr for the child will be the same as the stdout of the parent.
* Otherwise the child will inherit the stderr from the parent. */
int dummy_stderr)
{
/* Child process code for 'ErrorLog "|..."';
* may want a common framework for this, since I expect it will
* be common for other foo-loggers to want this sort of thing...
*/
ap_server_root)) == APR_SUCCESS)
APR_NO_PIPE)) == APR_SUCCESS)
== APR_SUCCESS)) {
char **args;
const char *pname;
if (dummy_stderr) {
}
if (rc == APR_SUCCESS) {
/* read handle to pipe not kept open, so no need to call
* close_handle_in_child()
*/
}
}
return rc;
}
/* Open the error log for the given server_rec. If IS_MAIN is
* non-zero, s is the main server. */
{
const char *fname;
int rc;
if (*s->error_fname == '|') {
/* 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
* accept "||prog" to override, and "|$cmd" to ease conversion.
*/
if (*fname == '|')
++fname;
if (*fname == '$') {
++fname;
}
/* Spawn a new child logger. If this is the main server_rec,
* the new child must use a dummy stderr since the current
* stderr might be a pipe to the old logger. Otherwise, the
* child inherits the parents stderr. */
if (rc != APR_SUCCESS) {
"Couldn't start ErrorLog process '%s'.",
s->error_fname + 1);
return DONE;
}
}
#ifdef HAVE_SYSLOG
fname++;
return OK;
}
}
}
else {
}
}
#endif
else {
if (!fname) {
"%s: Invalid error log path %s.",
ap_server_argv0, s->error_fname);
return DONE;
}
APR_OS_DEFAULT, p)) != APR_SUCCESS) {
"%s: could not open error log file %s.",
return DONE;
}
}
return OK;
}
{
server_rec *virt, *q;
int replace_stderr;
/* 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
* 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
* read_handle a little bit early.
*/
/* HERE we need a stdout log that outlives plog.
* 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.
*/
return DONE;
}
replace_stderr = 1;
/* Replace existing stderr with new log. */
if (rv != APR_SUCCESS) {
"unable to replace stderr with error_log");
}
else {
/* We are done with stderr_pool, close it, killing
* the previous generation's stderr logger
*/
if (stderr_pool)
replace_stderr = 0;
/*
* Now that we have dup'ed s_main->error_log to stderr_log
* close it and set s_main->error_log to stderr_log. This avoids
* this fd being inherited by the next piped logger who would
* keep open the writing end of the pipe that this one uses
* as stdin. This in turn would prevent the piped logger from
* exiting.
*/
}
}
/* note that stderr may still need to be replaced with something
* because it points to the old error log, or back to the tty
* of the submitter.
* errno-as-apr_status_t is also non-portable
*/
}
if (virt->error_fname) {
if (q->error_fname != NULL
break;
}
}
if (q == virt) {
return DONE;
}
}
else {
}
}
else {
}
}
return OK;
}
}
}
{
char *end;
if (!arg)
return 0;
}
{
else if (info->c)
else
return 0;
}
{
if (info->c)
else
return 0;
}
{
}
{
#if APR_HAS_THREADS
int result;
#endif
#if HAVE_GETTID
if (tid == -1)
return 0;
}
#endif
#if APR_HAS_THREADS
&& result != AP_MPMQ_NOT_SUPPORTED)
{
}
#endif
return 0;
}
{
int option = AP_CTIME_OPTION_NONE;
switch (*arg) {
break;
break;
}
arg++;
}
/* ap_recent_ctime_ex includes the trailing \0 in time_len */
return time_len - 1;
}
{
return 0;
else
}
{
/*
* C: log conn log_id if available,
* c: log conn log id if available and not a once-per-request log line
* else: log request log id if available
*/
}
}
}
return 0;
}
{
if (!info->c)
return 0;
}
{
}
{
return 0;
}
else {
char tmp[256];
#ifdef WIN32
if (!e) {
}
#endif
* (it even returns an absolute path for sources in
* the current directory). Here we try to strip this
* down to the basename.
*/
if (*e == ')') {
*e = '\0';
}
}
#else /* _OSD_POSIX || WIN32 */
const char *p;
/* On Unix, __FILE__ may be an absolute path in a
* VPATH build. */
file = p + 1;
}
#endif /*_OSD_POSIX || WIN32 */
}
}
{
int len;
if (!status)
return 0;
if (status < APR_OS_START_EAIERR) {
}
else if (status < APR_OS_START_SYSERR) {
}
}
else {
}
return len;
}
{
if (info->r)
return 0;
}
{
if (info->s)
return 0;
}
{
#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
const char *value;
char scratch[MAX_STRING_LEN];
}
return 0;
#else
#endif
}
{
if (info->r)
return 0;
}
{
/* XXX: maybe escaping the entry is not necessary for notes? */
if (info->r)
return 0;
}
{
if (info->r)
return 0;
}
const char **idstring)
{
int len;
char *encoded;
if (r && r->request_time) {
}
else {
}
if (sizeof(pid_t) > 2) {
}
else {
}
#if APR_HAS_THREADS
{
}
#endif
/* Skip the last char, it is always '=' */
return OK;
}
{
const char **id;
/* need to cast const away */
if (r) {
}
else {
}
ap_run_generate_log_id(c, r, id);
}
{
}
/*
* This is used if no error log format is defined and during startup.
* It automatically omits the timestamp if logging to syslog.
*/
{
int len = 0;
int field_start = 0;
int item_len;
#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
char scratch[MAX_STRING_LEN];
#endif
}
#if APR_HAS_THREADS
field_start = len;
if (!item_len)
len = field_start;
else
#endif
}
if (item_len) {
}
}
if (item_len) {
}
}
/*
* handle, it is likely a client.
*/
if (info->r) {
}
else if (info->c) {
}
/* the actual error message */
*errstr_start = len;
#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
}
#else
#endif
*errstr_end = len;
field_start = len;
if (item_len)
else
len = field_start;
return len;
}
{
#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
char scratch[MAX_STRING_LEN];
#endif
int i;
int len = 0;
int field_start = 0;
int skipping = 0;
if (skipping) {
skipping = 0;
}
else {
field_start = len;
}
}
/* the actual error message */
*errstr_start = len;
#ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
}
#else
#endif
*errstr_end = len;
}
else if (skipping) {
continue;
}
len = field_start;
skipping = 1;
}
else {
if (!item_len) {
/* required item is empty. skip whole line */
buf[0] = '\0';
return 0;
}
}
else {
len = field_start;
skipping = 1;
}
}
else {
}
}
}
return len;
}
int level)
{
/* NULL if we are logging to syslog */
if (logf) {
/* Truncate for the terminator (as apr_snprintf does) */
}
}
#ifdef HAVE_SYSLOG
else {
}
#endif
}
int level,
const conn_rec *c,
{
char errstr[MAX_STRING_LEN];
/* do we need to log once-per-req or once-per-conn info? */
int log_conn_info = 0, log_req_info = 0;
int done = 0;
int line_number = 0;
if (r && r->connection) {
c = r->connection;
}
if (s == NULL) {
/*
* If we are doing stderr logging (startup), don't log messages that are
* notice
*/
#ifndef DEBUG
if ((level_and_mask != APLOG_NOTICE)
&& (level_and_mask > ap_default_loglevel)) {
return;
}
#endif
logf = stderr_log;
}
else {
c ? ap_get_conn_server_module_loglevel(c, s, module_index) :
if (s->error_log) {
/*
* If we are doing normal logging, don't log messages that are
*/
if ((level_and_mask != APLOG_NOTICE)
&& (level_and_mask > configured_level)) {
return;
}
}
else {
/*
* If we are doing syslog logging, don't log messages that are
*/
if (level_and_mask > configured_level) {
return;
}
}
/* the faked server_rec from mod_cgid does not have s->module_config */
if (s->module_config) {
if (c && !c->log_id) {
add_log_id(c, NULL);
log_conn_info = 1;
}
if (r) {
if (r->main)
else
rmain = r;
/* XXX: do we need separate log ids for subrequests? */
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;
while (!done) {
/* XXX: potential optimization: format common prefixes only once */
if (log_conn_info) {
/* once-per-connection info */
if (line_number == 0) {
}
/* this is the last line of once-per-connection info */
line_number = 0;
log_conn_info = 0;
}
}
else if (log_req_info) {
/* once-per-request info */
if (line_number == 0) {
}
/* this is the last line of once-per-request info */
line_number = 0;
log_req_info = 0;
}
}
else {
/* the actual error message */
info.r = r;
done = 1;
}
/*
* prepare and log one line
*/
if (log_format) {
}
else {
}
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.
*/
continue;
}
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 = '\0';
}
}
const server_rec *s, const char *fmt, ...)
{
}
const char *fmt, ...)
{
}
const request_rec *r, const char *fmt, ...)
{
/*
* IF APLOG_TOCLIENT is set,
* AND the error level is 'warning' or more severe,
* AND there isn't already error text associated with this request,
* THEN make the message text available to ErrorDocument and
* other error processors.
*/
if ((level & APLOG_TOCLIENT)
args)));
}
}
const conn_rec *c, const server_rec *s,
const char *fmt, ...)
{
}
{
}
{
int i;
char *result;
int len_needed = 0;
/* Piece together the command line from the pieces
* in process->argv, with spaces in between.
*/
}
*result = '\0';
}
}
"Command line: '%s'", result);
}
{
if (rv != APR_SUCCESS) {
"failed to remove PID file %s", fname);
}
else {
}
}
}
{
const char *fname;
if (!filename) {
return;
}
if (!fname) {
return;
}
/* AP_SIG_GRACEFUL and HUP call this on each restart.
* Only warn on first time through for this pid.
*
* XXX: Could just write first time through too, although
* that may screw up scripts written to do something
* based on the last modification time of the pid file.
*/
"pid file %s overwritten -- Unclean "
"shutdown of previous Apache run?",
fname);
}
!= APR_SUCCESS) {
"could not create %s", fname);
"%s: could not log pid to file %s",
exit(1);
}
}
{
const char *fname;
if (!filename) {
return APR_EGENERAL;
}
if (!fname) {
return APR_EGENERAL;
}
if (rv != APR_SUCCESS) {
return rv;
}
return rv;
}
/* If we fill the buffer, we're probably reading a corrupt pid file.
* To be nice, let's also ensure the first char is a digit. */
return APR_EGENERAL;
}
return APR_SUCCESS;
}
int nLine)
{
char time_str[APR_CTIME_LEN];
"[%s] file %s, line %d, assertion \"%s\" failed",
#if defined(WIN32)
DebugBreak();
#else
/* unix assert does an abort leading to a core dump */
abort();
#endif
}
/* piped log support */
#ifdef AP_HAVE_RELIABLE_PIPED_LOGS
/* forward declaration */
/* Spawn the piped logger process pl->program. */
{
!= APR_SUCCESS) ||
!= APR_SUCCESS) ||
!= APR_SUCCESS) ||
!= APR_SUCCESS) ||
char buf[120];
/* Something bad happened, give up and go away. */
"piped_log_spawn: unable to setup child process '%s': %s",
}
else {
char **args;
const char *pname;
if (status == APR_SUCCESS) {
/* procnew->in was dup2'd from pl->write_fd;
* since the original fd is still valid, close the copy to
* avoid a leak. */
}
else {
char buf[120];
/* Something bad happened, give up and go away. */
"unable to start piped log program '%s': %s",
}
}
return status;
}
{
int mpm_state;
switch (reason) {
case APR_OC_REASON_DEATH:
case APR_OC_REASON_LOST:
* tells other logic not to try to kill it
*/
if (stats != APR_SUCCESS) {
"can't query MPM state; not restarting "
"piped log program '%s'",
}
else if (mpm_state != AP_MPMQ_STOPPING) {
"piped log program '%s' failed unexpectedly",
/* what can we do? This could be the error log we're having
* problems opening up... */
char buf[120];
"piped_log_maintenance: unable to respawn '%s': %s",
}
}
break;
case APR_OC_REASON_UNWRITABLE:
/* We should not kill off the pipe here, since it may only be full.
* If it really is locked, we should kill it off manually. */
break;
case APR_OC_REASON_RESTART:
}
break;
case APR_OC_REASON_UNREGISTER:
break;
}
}
{
return APR_SUCCESS;
}
{
}
return piped_log_cleanup_for_exec(data);
}
const char *program,
{
pl->p = p;
APR_FULL_BLOCK, p) != APR_SUCCESS) {
return NULL;
}
return NULL;
}
return pl;
}
#else /* !AP_HAVE_RELIABLE_PIPED_LOGS */
{
return APR_SUCCESS;
}
const char *program,
{
int rc;
if (rc != APR_SUCCESS) {
"Couldn't start piped log process '%s'.",
return NULL;
}
pl->p = p;
return pl;
}
#endif
const char *program)
{
/* 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
* accept "||prog" to override, and "|$cmd" to ease conversion.
*/
if (*program == '|')
++program;
if (*program == '$') {
++program;
}
}
{
}
{
int i = 0;
return err;
return NULL;
}
i++;
}
return err;
}
(const conn_rec *c, const request_rec *r,
const char **id),