granicus.if.org Git - apache/blob - server/log.c

   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
   7  *
   8  *     http://www.apache.org/licenses/LICENSE-2.0
   9  *
  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.
  15  */
  16
  17 /*
  18  * http_log.c: Dealing with the logs and errors
  19  *
  20  * Rob McCool
  21  *
  22  */
  23
  24 #include "apr.h"
  25 #include "apr_general.h"        /* for signal stuff */
  26 #include "apr_strings.h"
  27 #include "apr_errno.h"
  28 #include "apr_thread_proc.h"
  29 #include "apr_lib.h"
  30 #include "apr_signal.h"
  31 #include "apr_portable.h"
  32 #include "apr_base64.h"
  33
  34 #define APR_WANT_STDIO
  35 #define APR_WANT_STRFUNC
  36 #include "apr_want.h"
  37
  38 #if APR_HAVE_STDARG_H
  39 #include <stdarg.h>
  40 #endif
  41 #if APR_HAVE_UNISTD_H
  42 #include <unistd.h>
  43 #endif
  44 #if APR_HAVE_PROCESS_H
  45 #include <process.h>            /* for getpid() on Win32 */
  46 #endif
  47
  48 #include "ap_config.h"
  49 #include "httpd.h"
  50 #include "http_config.h"
  51 #include "http_core.h"
  52 #include "http_log.h"
  53 #include "http_main.h"
  54 #include "util_time.h"
  55 #include "ap_mpm.h"
  56 #include "ap_listen.h"
  57
  58 #if HAVE_GETTID
  59 #include <sys/syscall.h>
  60 #include <sys/types.h>
  61 #endif
  62
  63 /* we know core's module_index is 0 */
  64 #undef APLOG_MODULE_INDEX
  65 #define APLOG_MODULE_INDEX AP_CORE_MODULE_INDEX
  66
  67 typedef struct {
  68     const char *t_name;
  69     int t_val;
  70 } TRANS;
  71
  72 APR_HOOK_STRUCT(
  73     APR_HOOK_LINK(error_log)
  74     APR_HOOK_LINK(generate_log_id)
  75 )
  76
  77 int AP_DECLARE_DATA ap_default_loglevel = DEFAULT_LOGLEVEL;
  78
  79 #ifdef HAVE_SYSLOG
  80
  81 static const TRANS facilities[] = {
  82     {"auth",    LOG_AUTH},
  83 #ifdef LOG_AUTHPRIV
  84     {"authpriv",LOG_AUTHPRIV},
  85 #endif
  86 #ifdef LOG_CRON
  87     {"cron",    LOG_CRON},
  88 #endif
  89 #ifdef LOG_DAEMON
  90     {"daemon",  LOG_DAEMON},
  91 #endif
  92 #ifdef LOG_FTP
  93     {"ftp", LOG_FTP},
  94 #endif
  95 #ifdef LOG_KERN
  96     {"kern",    LOG_KERN},
  97 #endif
  98 #ifdef LOG_LPR
  99     {"lpr", LOG_LPR},
 100 #endif
 101 #ifdef LOG_MAIL
 102     {"mail",    LOG_MAIL},
 103 #endif
 104 #ifdef LOG_NEWS
 105     {"news",    LOG_NEWS},
 106 #endif
 107 #ifdef LOG_SYSLOG
 108     {"syslog",  LOG_SYSLOG},
 109 #endif
 110 #ifdef LOG_USER
 111     {"user",    LOG_USER},
 112 #endif
 113 #ifdef LOG_UUCP
 114     {"uucp",    LOG_UUCP},
 115 #endif
 116 #ifdef LOG_LOCAL0
 117     {"local0",  LOG_LOCAL0},
 118 #endif
 119 #ifdef LOG_LOCAL1
 120     {"local1",  LOG_LOCAL1},
 121 #endif
 122 #ifdef LOG_LOCAL2
 123     {"local2",  LOG_LOCAL2},
 124 #endif
 125 #ifdef LOG_LOCAL3
 126     {"local3",  LOG_LOCAL3},
 127 #endif
 128 #ifdef LOG_LOCAL4
 129     {"local4",  LOG_LOCAL4},
 130 #endif
 131 #ifdef LOG_LOCAL5
 132     {"local5",  LOG_LOCAL5},
 133 #endif
 134 #ifdef LOG_LOCAL6
 135     {"local6",  LOG_LOCAL6},
 136 #endif
 137 #ifdef LOG_LOCAL7
 138     {"local7",  LOG_LOCAL7},
 139 #endif
 140     {NULL,      -1},
 141 };
 142 #endif
 143
 144 static const TRANS priorities[] = {
 145     {"emerg",   APLOG_EMERG},
 146     {"alert",   APLOG_ALERT},
 147     {"crit",    APLOG_CRIT},
 148     {"error",   APLOG_ERR},
 149     {"warn",    APLOG_WARNING},
 150     {"notice",  APLOG_NOTICE},
 151     {"info",    APLOG_INFO},
 152     {"debug",   APLOG_DEBUG},
 153     {"trace1",  APLOG_TRACE1},
 154     {"trace2",  APLOG_TRACE2},
 155     {"trace3",  APLOG_TRACE3},
 156     {"trace4",  APLOG_TRACE4},
 157     {"trace5",  APLOG_TRACE5},
 158     {"trace6",  APLOG_TRACE6},
 159     {"trace7",  APLOG_TRACE7},
 160     {"trace8",  APLOG_TRACE8},
 161     {NULL,      -1},
 162 };
 163
 164 static apr_pool_t *stderr_pool = NULL;
 165
 166 static apr_file_t *stderr_log = NULL;
 167
 168 /* track pipe handles to close in child process */
 169 typedef struct read_handle_t {
 170     struct read_handle_t *next;
 171     apr_file_t *handle;
 172 } read_handle_t;
 173
 174 static read_handle_t *read_handles;
 175
 176 /**
 177  * @brief The piped logging structure.
 178  *
 179  * Piped logs are used to move functionality out of the main server.
 180  * For example, log rotation is done with piped logs.
 181  */
 182 struct piped_log {
 183     /** The pool to use for the piped log */
 184     apr_pool_t *p;
 185     /** The pipe between the server and the logging process */
 186     apr_file_t *read_fd, *write_fd;
 187 #ifdef AP_HAVE_RELIABLE_PIPED_LOGS
 188     /** The name of the program the logging process is running */
 189     char *program;
 190     /** The pid of the logging process */
 191     apr_proc_t *pid;
 192     /** How to reinvoke program when it must be replaced */
 193     apr_cmdtype_e cmdtype;
 194 #endif
 195 };
 196
 197 AP_DECLARE(apr_file_t *) ap_piped_log_read_fd(piped_log *pl)
 198 {
 199     return pl->read_fd;
 200 }
 201
 202 AP_DECLARE(apr_file_t *) ap_piped_log_write_fd(piped_log *pl)
 203 {
 204     return pl->write_fd;
 205 }
 206
 207 /* remember to close this handle in the child process
 208  *
 209  * On Win32 this makes zero sense, because we don't
 210  * take the parent process's child procs.
 211  * If the win32 parent instead passed each and every
 212  * logger write handle from itself down to the child,
 213  * and the parent manages all aspects of keeping the
 214  * reliable pipe log children alive, this would still
 215  * make no sense :)  Cripple it on Win32.
 216  */
 217 static void close_handle_in_child(apr_pool_t *p, apr_file_t *f)
 218 {
 219 #ifndef WIN32
 220     read_handle_t *new_handle;
 221
 222     new_handle = apr_pcalloc(p, sizeof(read_handle_t));
 223     new_handle->next = read_handles;
 224     new_handle->handle = f;
 225     read_handles = new_handle;
 226 #endif
 227 }
 228
 229 void ap_logs_child_init(apr_pool_t *p, server_rec *s)
 230 {
 231     read_handle_t *cur = read_handles;
 232
 233     while (cur) {
 234         apr_file_close(cur->handle);
 235         cur = cur->next;
 236     }
 237 }
 238
 239 AP_DECLARE(void) ap_open_stderr_log(apr_pool_t *p)
 240 {
 241     apr_file_open_stderr(&stderr_log, p);
 242 }
 243
 244 AP_DECLARE(apr_status_t) ap_replace_stderr_log(apr_pool_t *p,
 245                                                const char *fname)
 246 {
 247     apr_file_t *stderr_file;
 248     apr_status_t rc;
 249     char *filename = ap_server_root_relative(p, fname);
 250     if (!filename) {
 251         ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT,
 252                      APR_EBADPATH, NULL, APLOGNO(00085) "Invalid -E error log file %s",
 253                      fname);
 254         return APR_EBADPATH;
 255     }
 256     if ((rc = apr_file_open(&stderr_file, filename,
 257                             APR_APPEND | APR_WRITE | APR_CREATE | APR_LARGEFILE,
 258                             APR_OS_DEFAULT, p)) != APR_SUCCESS) {
 259         ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00086)
 260                      "%s: could not open error log file %s.",
 261                      ap_server_argv0, fname);
 262         return rc;
 263     }
 264     if (!stderr_pool) {
 265         /* This is safe provided we revert it when we are finished.
 266          * We don't manager the callers pool!
 267          */
 268         stderr_pool = p;
 269     }
 270     if ((rc = apr_file_open_stderr(&stderr_log, stderr_pool))
 271             == APR_SUCCESS) {
 272         apr_file_flush(stderr_log);
 273         if ((rc = apr_file_dup2(stderr_log, stderr_file, stderr_pool))
 274                 == APR_SUCCESS) {
 275             apr_file_close(stderr_file);
 276             /*
 277              * You might ponder why stderr_pool should survive?
 278              * The trouble is, stderr_pool may have s_main->error_log,
 279              * so we aren't in a position to destory stderr_pool until
 280              * the next recycle.  There's also an apparent bug which
 281              * is not; if some folk decided to call this function before
 282              * the core open error logs hook, this pool won't survive.
 283              * Neither does the stderr logger, so this isn't a problem.
 284              */
 285         }
 286     }
 287     /* Revert, see above */
 288     if (stderr_pool == p)
 289         stderr_pool = NULL;
 290
 291     if (rc != APR_SUCCESS) {
 292         ap_log_error(APLOG_MARK, APLOG_CRIT, rc, NULL, APLOGNO(00087)
 293                      "unable to replace stderr with error log file");
 294     }
 295     return rc;
 296 }
 297
 298 static void log_child_errfn(apr_pool_t *pool, apr_status_t err,
 299                             const char *description)
 300 {
 301     ap_log_error(APLOG_MARK, APLOG_ERR, err, NULL, APLOGNO(00088)
 302                  "%s", description);
 303 }
 304
 305 /* Create a child process running PROGNAME with a pipe connected to
 306  * the childs stdin.  The write-end of the pipe will be placed in
 307  * *FPIN on successful return.  If dummy_stderr is non-zero, the
 308  * stderr for the child will be the same as the stdout of the parent.
 309  * Otherwise the child will inherit the stderr from the parent. */
 310 static int log_child(apr_pool_t *p, const char *progname,
 311                      apr_file_t **fpin, apr_cmdtype_e cmdtype,
 312                      int dummy_stderr)
 313 {
 314     /* Child process code for 'ErrorLog "|..."';
 315      * may want a common framework for this, since I expect it will
 316      * be common for other foo-loggers to want this sort of thing...
 317      */
 318     apr_status_t rc;
 319     apr_procattr_t *procattr;
 320     apr_proc_t *procnew;
 321     apr_file_t *errfile;
 322
 323     if (((rc = apr_procattr_create(&procattr, p)) == APR_SUCCESS)
 324         && ((rc = apr_procattr_dir_set(procattr,
 325                                        ap_server_root)) == APR_SUCCESS)
 326         && ((rc = apr_procattr_cmdtype_set(procattr, cmdtype)) == APR_SUCCESS)
 327         && ((rc = apr_procattr_io_set(procattr,
 328                                       APR_FULL_BLOCK,
 329                                       APR_NO_PIPE,
 330                                       APR_NO_PIPE)) == APR_SUCCESS)
 331         && ((rc = apr_procattr_error_check_set(procattr, 1)) == APR_SUCCESS)
 332         && ((rc = apr_procattr_child_errfn_set(procattr, log_child_errfn))
 333                 == APR_SUCCESS)) {
 334         char **args;
 335
 336         apr_tokenize_to_argv(progname, &args, p);
 337         procnew = (apr_proc_t *)apr_pcalloc(p, sizeof(*procnew));
 338
 339         if (dummy_stderr) {
 340             if ((rc = apr_file_open_stdout(&errfile, p)) == APR_SUCCESS)
 341                 rc = apr_procattr_child_err_set(procattr, errfile, NULL);
 342         }
 343
 344         rc = apr_proc_create(procnew, args[0], (const char * const *)args,
 345                              NULL, procattr, p);
 346
 347         if (rc == APR_SUCCESS) {
 348             apr_pool_note_subprocess(p, procnew, APR_KILL_AFTER_TIMEOUT);
 349             (*fpin) = procnew->in;
 350             /* read handle to pipe not kept open, so no need to call
 351              * close_handle_in_child()
 352              */
 353         }
 354     }
 355
 356     return rc;
 357 }
 358
 359 /* Open the error log for the given server_rec.  If IS_MAIN is
 360  * non-zero, s is the main server. */
 361 static int open_error_log(server_rec *s, int is_main, apr_pool_t *p)
 362 {
 363     const char *fname;
 364     int rc;
 365
 366     if (*s->error_fname == '|') {
 367         apr_file_t *dummy = NULL;
 368         apr_cmdtype_e cmdtype = APR_PROGRAM_ENV;
 369         fname = s->error_fname + 1;
 370
 371         /* In 2.4 favor PROGRAM_ENV, accept "||prog" syntax for compatibility
 372          * and "|$cmd" to override the default.
 373          * Any 2.2 backport would continue to favor SHELLCMD_ENV so there
 374          * accept "||prog" to override, and "|$cmd" to ease conversion.
 375          */
 376         if (*fname == '|')
 377             ++fname;
 378         if (*fname == '$') {
 379             cmdtype = APR_SHELLCMD_ENV;
 380             ++fname;
 381         }
 382
 383         /* Spawn a new child logger.  If this is the main server_rec,
 384          * the new child must use a dummy stderr since the current
 385          * stderr might be a pipe to the old logger.  Otherwise, the
 386          * child inherits the parents stderr. */
 387         rc = log_child(p, fname, &dummy, cmdtype, is_main);
 388         if (rc != APR_SUCCESS) {
 389             ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00089)
 390                          "Couldn't start ErrorLog process '%s'.",
 391                          s->error_fname + 1);
 392             return DONE;
 393         }
 394
 395         s->error_log = dummy;
 396     }
 397
 398 #ifdef HAVE_SYSLOG
 399     else if (!strncasecmp(s->error_fname, "syslog", 6)) {
 400         if ((fname = strchr(s->error_fname, ':'))) {
 401             const TRANS *fac;
 402
 403             fname++;
 404             for (fac = facilities; fac->t_name; fac++) {
 405                 if (!strcasecmp(fname, fac->t_name)) {
 406                     openlog(ap_server_argv0, LOG_NDELAY|LOG_CONS|LOG_PID,
 407                             fac->t_val);
 408                     s->error_log = NULL;
 409                     return OK;
 410                 }
 411             }
 412         }
 413         else {
 414             openlog(ap_server_argv0, LOG_NDELAY|LOG_CONS|LOG_PID, LOG_LOCAL7);
 415         }
 416
 417         s->error_log = NULL;
 418     }
 419 #endif
 420     else {
 421         fname = ap_server_root_relative(p, s->error_fname);
 422         if (!fname) {
 423             ap_log_error(APLOG_MARK, APLOG_STARTUP, APR_EBADPATH, NULL, APLOGNO(00090)
 424                          "%s: Invalid error log path %s.",
 425                          ap_server_argv0, s->error_fname);
 426             return DONE;
 427         }
 428         if ((rc = apr_file_open(&s->error_log, fname,
 429                                APR_APPEND | APR_WRITE | APR_CREATE | APR_LARGEFILE,
 430                                APR_OS_DEFAULT, p)) != APR_SUCCESS) {
 431             ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00091)
 432                          "%s: could not open error log file %s.",
 433                          ap_server_argv0, fname);
 434             return DONE;
 435         }
 436     }
 437
 438     return OK;
 439 }
 440
 441 int ap_open_logs(apr_pool_t *pconf, apr_pool_t *p /* plog */,
 442                  apr_pool_t *ptemp, server_rec *s_main)
 443 {
 444     apr_pool_t *stderr_p;
 445     server_rec *virt, *q;
 446     int replace_stderr;
 447
 448
 449     /* Register to throw away the read_handles list when we
 450      * cleanup plog.  Upon fork() for the apache children,
 451      * this read_handles list is closed so only the parent
 452      * can relaunch a lost log child.  These read handles
 453      * are always closed on exec.
 454      * We won't care what happens to our stderr log child
 455      * between log phases, so we don't mind losing stderr's
 456      * read_handle a little bit early.
 457      */
 458     apr_pool_cleanup_register(p, &read_handles, ap_pool_cleanup_set_null,
 459                               apr_pool_cleanup_null);
 460
 461     /* HERE we need a stdout log that outlives plog.
 462      * We *presume* the parent of plog is a process
 463      * or global pool which spans server restarts.
 464      * Create our stderr_pool as a child of the plog's
 465      * parent pool.
 466      */
 467     apr_pool_create(&stderr_p, apr_pool_parent_get(p));
 468     apr_pool_tag(stderr_p, "stderr_pool");
 469
 470     if (open_error_log(s_main, 1, stderr_p) != OK) {
 471         return DONE;
 472     }
 473
 474     replace_stderr = 1;
 475     if (s_main->error_log) {
 476         apr_status_t rv;
 477
 478         /* Replace existing stderr with new log. */
 479         apr_file_flush(s_main->error_log);
 480         rv = apr_file_dup2(stderr_log, s_main->error_log, stderr_p);
 481         if (rv != APR_SUCCESS) {
 482             ap_log_error(APLOG_MARK, APLOG_CRIT, rv, s_main, APLOGNO(00092)
 483                          "unable to replace stderr with error_log");
 484         }
 485         else {
 486             /* We are done with stderr_pool, close it, killing
 487              * the previous generation's stderr logger
 488              */
 489             if (stderr_pool)
 490                 apr_pool_destroy(stderr_pool);
 491             stderr_pool = stderr_p;
 492             replace_stderr = 0;
 493             /*
 494              * Now that we have dup'ed s_main->error_log to stderr_log
 495              * close it and set s_main->error_log to stderr_log. This avoids
 496              * this fd being inherited by the next piped logger who would
 497              * keep open the writing end of the pipe that this one uses
 498              * as stdin. This in turn would prevent the piped logger from
 499              * exiting.
 500              */
 501             apr_file_close(s_main->error_log);
 502             s_main->error_log = stderr_log;
 503         }
 504     }
 505     /* note that stderr may still need to be replaced with something
 506      * because it points to the old error log, or back to the tty
 507      * of the submitter.
 508      * XXX: This is BS - /dev/null is non-portable
 509      *      errno-as-apr_status_t is also non-portable
 510      */
 511
 512 #ifdef WIN32
 513 #define NULL_DEVICE "nul"
 514 #else
 515 #define NULL_DEVICE "/dev/null"
 516 #endif
 517
 518     if (replace_stderr && freopen(NULL_DEVICE, "w", stderr) == NULL) {
 519         ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, APLOGNO(00093)
 520                      "unable to replace stderr with %s", NULL_DEVICE);
 521     }
 522
 523     for (virt = s_main->next; virt; virt = virt->next) {
 524         if (virt->error_fname) {
 525             for (q=s_main; q != virt; q = q->next) {
 526                 if (q->error_fname != NULL
 527                     && strcmp(q->error_fname, virt->error_fname) == 0) {
 528                     break;
 529                 }
 530             }
 531
 532             if (q == virt) {
 533                 if (open_error_log(virt, 0, p) != OK) {
 534                     return DONE;
 535                 }
 536             }
 537             else {
 538                 virt->error_log = q->error_log;
 539             }
 540         }
 541         else {
 542             virt->error_log = s_main->error_log;
 543         }
 544     }
 545     return OK;
 546 }
 547
 548 AP_DECLARE(void) ap_error_log2stderr(server_rec *s) {
 549     apr_file_t *errfile = NULL;
 550
 551     apr_file_open_stderr(&errfile, s->process->pool);
 552     if (s->error_log != NULL) {
 553         apr_file_dup2(s->error_log, errfile, s->process->pool);
 554     }
 555 }
 556
 557 static int cpystrn(char *buf, const char *arg, int buflen)
 558 {
 559     char *end;
 560     if (!arg)
 561         return 0;
 562     end = apr_cpystrn(buf, arg, buflen);
 563     return end - buf;
 564 }
 565
 566
 567 static int log_remote_address(const ap_errorlog_info *info, const char *arg,
 568                               char *buf, int buflen)
 569 {
 570     if (info->r && !(arg && *arg == 'c'))
 571         return apr_snprintf(buf, buflen, "%s:%d", info->r->useragent_ip,
 572                             info->r->useragent_addr ? info->r->useragent_addr->port : 0);
 573     else if (info->c)
 574         return apr_snprintf(buf, buflen, "%s:%d", info->c->client_ip,
 575                             info->c->client_addr ? info->c->client_addr->port : 0);
 576     else
 577         return 0;
 578 }
 579
 580 static int log_local_address(const ap_errorlog_info *info, const char *arg,
 581                              char *buf, int buflen)
 582 {
 583     if (info->c)
 584         return apr_snprintf(buf, buflen, "%s:%d", info->c->local_ip,
 585                             info->c->local_addr->port);
 586     else
 587         return 0;
 588 }
 589
 590 static int log_pid(const ap_errorlog_info *info, const char *arg,
 591                    char *buf, int buflen)
 592 {
 593     pid_t pid = getpid();
 594     return apr_snprintf(buf, buflen, "%" APR_PID_T_FMT, pid);
 595 }
 596
 597 static int log_tid(const ap_errorlog_info *info, const char *arg,
 598                    char *buf, int buflen)
 599 {
 600 #if APR_HAS_THREADS
 601     int result;
 602 #endif
 603 #if HAVE_GETTID
 604     if (arg && *arg == 'g') {
 605         pid_t tid = syscall(SYS_gettid);
 606         if (tid == -1)
 607             return 0;
 608         return apr_snprintf(buf, buflen, "%"APR_PID_T_FMT, tid);
 609     }
 610 #endif
 611 #if APR_HAS_THREADS
 612     if (ap_mpm_query(AP_MPMQ_IS_THREADED, &result) == APR_SUCCESS
 613         && result != AP_MPMQ_NOT_SUPPORTED)
 614     {
 615         apr_os_thread_t tid = apr_os_thread_current();
 616         return apr_snprintf(buf, buflen, "%pT", &tid);
 617     }
 618 #endif
 619     return 0;
 620 }
 621
 622 static int log_ctime(const ap_errorlog_info *info, const char *arg,
 623                      char *buf, int buflen)
 624 {
 625     int time_len = buflen;
 626     int option = AP_CTIME_OPTION_NONE;
 627
 628     while (arg && *arg) {
 629         switch (*arg) {
 630             case 'u':   option |= AP_CTIME_OPTION_USEC;
 631                         break;
 632             case 'c':   option |= AP_CTIME_OPTION_COMPACT;
 633                         break;
 634         }
 635         arg++;
 636     }
 637
 638     ap_recent_ctime_ex(buf, apr_time_now(), option, &time_len);
 639
 640     /* ap_recent_ctime_ex includes the trailing \0 in time_len */
 641     return time_len - 1;
 642 }
 643
 644 static int log_loglevel(const ap_errorlog_info *info, const char *arg,
 645                         char *buf, int buflen)
 646 {
 647     if (info->level < 0)
 648         return 0;
 649     else
 650         return cpystrn(buf, priorities[info->level].t_name, buflen);
 651 }
 652
 653 static int log_log_id(const ap_errorlog_info *info, const char *arg,
 654                       char *buf, int buflen)
 655 {
 656     /*
 657      * C: log conn log_id if available,
 658      * c: log conn log id if available and not a once-per-request log line
 659      * else: log request log id if available
 660      */
 661     if (arg && !strcasecmp(arg, "c")) {
 662         if (info->c && (*arg != 'C' || !info->r)) {
 663             return cpystrn(buf, info->c->log_id, buflen);
 664         }
 665     }
 666     else if (info->rmain) {
 667         return cpystrn(buf, info->rmain->log_id, buflen);
 668     }
 669     return 0;
 670 }
 671
 672 static int log_keepalives(const ap_errorlog_info *info, const char *arg,
 673                           char *buf, int buflen)
 674 {
 675     if (!info->c)
 676         return 0;
 677
 678     return apr_snprintf(buf, buflen, "%d", info->c->keepalives);
 679 }
 680
 681 static int log_module_name(const ap_errorlog_info *info, const char *arg,
 682                            char *buf, int buflen)
 683 {
 684     return cpystrn(buf, ap_find_module_short_name(info->module_index), buflen);
 685 }
 686
 687 static int log_file_line(const ap_errorlog_info *info, const char *arg,
 688                          char *buf, int buflen)
 689 {
 690     if (info->file == NULL) {
 691         return 0;
 692     }
 693     else {
 694         const char *file = info->file;
 695 #if defined(_OSD_POSIX) || defined(WIN32) || defined(__MVS__)
 696         char tmp[256];
 697         char *e = strrchr(file, '/');
 698 #ifdef WIN32
 699         if (!e) {
 700             e = strrchr(file, '\\');
 701         }
 702 #endif
 703
 704         /* In OSD/POSIX, the compiler returns for __FILE__
 705          * a string like: __FILE__="*POSIX(/usr/include/stdio.h)"
 706          * (it even returns an absolute path for sources in
 707          * the current directory). Here we try to strip this
 708          * down to the basename.
 709          */
 710         if (e != NULL && e[1] != '\0') {
 711             apr_snprintf(tmp, sizeof(tmp), "%s", &e[1]);
 712             e = &tmp[strlen(tmp)-1];
 713             if (*e == ')') {
 714                 *e = '\0';
 715             }
 716             file = tmp;
 717         }
 718 #else /* _OSD_POSIX || WIN32 */
 719         const char *p;
 720         /* On Unix, __FILE__ may be an absolute path in a
 721          * VPATH build. */
 722         if (file[0] == '/' && (p = ap_strrchr_c(file, '/')) != NULL) {
 723             file = p + 1;
 724         }
 725 #endif /*_OSD_POSIX || WIN32 */
 726         return apr_snprintf(buf, buflen, "%s(%d)", file, info->line);
 727     }
 728 }
 729
 730 static int log_apr_status(const ap_errorlog_info *info, const char *arg,
 731                           char *buf, int buflen)
 732 {
 733     apr_status_t status = info->status;
 734     int len;
 735     if (!status)
 736         return 0;
 737
 738     if (status < APR_OS_START_EAIERR) {
 739         len = apr_snprintf(buf, buflen, "(%d)", status);
 740     }
 741     else if (status < APR_OS_START_SYSERR) {
 742         len = apr_snprintf(buf, buflen, "(EAI %d)",
 743                            status - APR_OS_START_EAIERR);
 744     }
 745     else if (status < 100000 + APR_OS_START_SYSERR) {
 746         len = apr_snprintf(buf, buflen, "(OS %d)",
 747                            status - APR_OS_START_SYSERR);
 748     }
 749     else {
 750         len = apr_snprintf(buf, buflen, "(os 0x%08x)",
 751                            status - APR_OS_START_SYSERR);
 752     }
 753     apr_strerror(status, buf + len, buflen - len);
 754     len += strlen(buf + len);
 755     return len;
 756 }
 757
 758 static int log_server_name(const ap_errorlog_info *info, const char *arg,
 759                            char *buf, int buflen)
 760 {
 761     if (info->r)
 762         return cpystrn(buf, ap_get_server_name((request_rec *)info->r), buflen);
 763
 764     return 0;
 765 }
 766
 767 static int log_virtual_host(const ap_errorlog_info *info, const char *arg,
 768                             char *buf, int buflen)
 769 {
 770     if (info->s)
 771         return cpystrn(buf, info->s->server_hostname, buflen);
 772
 773     return 0;
 774 }
 775
 776
 777 static int log_table_entry(const apr_table_t *table, const char *name,
 778                            char *buf, int buflen)
 779 {
 780 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
 781     const char *value;
 782     char scratch[MAX_STRING_LEN];
 783
 784     if ((value = apr_table_get(table, name)) != NULL) {
 785         ap_escape_errorlog_item(scratch, value, MAX_STRING_LEN);
 786         return cpystrn(buf, scratch, buflen);
 787     }
 788
 789     return 0;
 790 #else
 791     return cpystrn(buf, apr_table_get(table, name), buflen);
 792 #endif
 793 }
 794
 795 static int log_header(const ap_errorlog_info *info, const char *arg,
 796                       char *buf, int buflen)
 797 {
 798     if (info->r)
 799         return log_table_entry(info->r->headers_in, arg, buf, buflen);
 800
 801     return 0;
 802 }
 803
 804 static int log_note(const ap_errorlog_info *info, const char *arg,
 805                       char *buf, int buflen)
 806 {
 807     /* XXX: maybe escaping the entry is not necessary for notes? */
 808     if (info->r)
 809         return log_table_entry(info->r->notes, arg, buf, buflen);
 810
 811     return 0;
 812 }
 813
 814 static int log_env_var(const ap_errorlog_info *info, const char *arg,
 815                       char *buf, int buflen)
 816 {
 817     if (info->r)
 818         return log_table_entry(info->r->subprocess_env, arg, buf, buflen);
 819
 820     return 0;
 821 }
 822
 823 static int core_generate_log_id(const conn_rec *c, const request_rec *r,
 824                                  const char **idstring)
 825 {
 826     apr_uint64_t id, tmp;
 827     pid_t pid;
 828     int len;
 829     char *encoded;
 830
 831     if (r && r->request_time) {
 832         id = (apr_uint64_t)r->request_time;
 833     }
 834     else {
 835         id = (apr_uint64_t)apr_time_now();
 836     }
 837
 838     pid = getpid();
 839     if (sizeof(pid_t) > 2) {
 840         tmp = pid;
 841         tmp = tmp << 40;
 842         id ^= tmp;
 843         pid = pid >> 24;
 844         tmp = pid;
 845         tmp = tmp << 56;
 846         id ^= tmp;
 847     }
 848     else {
 849         tmp = pid;
 850         tmp = tmp << 40;
 851         id ^= tmp;
 852     }
 853 #if APR_HAS_THREADS
 854     {
 855         apr_uintptr_t tmp2 = (apr_uintptr_t)c->current_thread;
 856         tmp = tmp2;
 857         tmp = tmp << 32;
 858         id ^= tmp;
 859     }
 860 #endif
 861
 862     len = apr_base64_encode_len(sizeof(id)); /* includes trailing \0 */
 863     encoded = apr_palloc(r ? r->pool : c->pool, len);
 864     apr_base64_encode(encoded, (char *)&id, sizeof(id));
 865
 866     /* Skip the last char, it is always '=' */
 867     encoded[len - 2] = '\0';
 868
 869     *idstring = encoded;
 870
 871     return OK;
 872 }
 873
 874 static void add_log_id(const conn_rec *c, const request_rec *r)
 875 {
 876     const char **id;
 877     /* need to cast const away */
 878     if (r) {
 879         id = &((request_rec *)r)->log_id;
 880     }
 881     else {
 882         id = &((conn_rec *)c)->log_id;
 883     }
 884
 885     ap_run_generate_log_id(c, r, id);
 886 }
 887
 888 AP_DECLARE(void) ap_register_log_hooks(apr_pool_t *p)
 889 {
 890     ap_hook_generate_log_id(core_generate_log_id, NULL, NULL,
 891                             APR_HOOK_REALLY_LAST);
 892
 893     ap_register_errorlog_handler(p, "a", log_remote_address, 0);
 894     ap_register_errorlog_handler(p, "A", log_local_address, 0);
 895     ap_register_errorlog_handler(p, "e", log_env_var, 0);
 896     ap_register_errorlog_handler(p, "E", log_apr_status, 0);
 897     ap_register_errorlog_handler(p, "F", log_file_line, 0);
 898     ap_register_errorlog_handler(p, "i", log_header, 0);
 899     ap_register_errorlog_handler(p, "k", log_keepalives, 0);
 900     ap_register_errorlog_handler(p, "l", log_loglevel, 0);
 901     ap_register_errorlog_handler(p, "L", log_log_id, 0);
 902     ap_register_errorlog_handler(p, "m", log_module_name, 0);
 903     ap_register_errorlog_handler(p, "n", log_note, 0);
 904     ap_register_errorlog_handler(p, "P", log_pid, 0);
 905     ap_register_errorlog_handler(p, "t", log_ctime, 0);
 906     ap_register_errorlog_handler(p, "T", log_tid, 0);
 907     ap_register_errorlog_handler(p, "v", log_virtual_host, 0);
 908     ap_register_errorlog_handler(p, "V", log_server_name, 0);
 909 }
 910
 911 /*
 912  * This is used if no error log format is defined and during startup.
 913  * It automatically omits the timestamp if logging to syslog.
 914  */
 915 static int do_errorlog_default(const ap_errorlog_info *info, char *buf,
 916                                int buflen, int *errstr_start, int *errstr_end,
 917                                const char *errstr_fmt, va_list args)
 918 {
 919     int len = 0;
 920     int field_start = 0;
 921     int item_len;
 922 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
 923     char scratch[MAX_STRING_LEN];
 924 #endif
 925
 926     if (!info->using_syslog && !info->startup) {
 927         buf[len++] = '[';
 928         len += log_ctime(info, "u", buf + len, buflen - len);
 929         buf[len++] = ']';
 930         buf[len++] = ' ';
 931     }
 932
 933     if (!info->startup) {
 934         buf[len++] = '[';
 935         len += log_module_name(info, NULL, buf + len, buflen - len);
 936         buf[len++] = ':';
 937         len += log_loglevel(info, NULL, buf + len, buflen - len);
 938         len += cpystrn(buf + len, "] [pid ", buflen - len);
 939
 940         len += log_pid(info, NULL, buf + len, buflen - len);
 941 #if APR_HAS_THREADS
 942         field_start = len;
 943         len += cpystrn(buf + len, ":tid ", buflen - len);
 944         item_len = log_tid(info, NULL, buf + len, buflen - len);
 945         if (!item_len)
 946             len = field_start;
 947         else
 948             len += item_len;
 949 #endif
 950         buf[len++] = ']';
 951         buf[len++] = ' ';
 952     }
 953
 954     if (info->level >= APLOG_DEBUG) {
 955         item_len = log_file_line(info, NULL, buf + len, buflen - len);
 956         if (item_len) {
 957             len += item_len;
 958             len += cpystrn(buf + len, ": ", buflen - len);
 959         }
 960     }
 961
 962     if (info->status) {
 963         item_len = log_apr_status(info, NULL, buf + len, buflen - len);
 964         if (item_len) {
 965             len += item_len;
 966             len += cpystrn(buf + len, ": ", buflen - len);
 967         }
 968     }
 969
 970     /*
 971      * useragent_ip/client_ip can be client or backend server. If we have
 972      * a scoreboard handle, it is likely a client.
 973      */
 974     if (info->r) {
 975         len += apr_snprintf(buf + len, buflen - len,
 976                             info->r->connection->sbh ? "[client %s:%d] " : "[remote %s:%d] ",
 977                             info->r->useragent_ip,
 978                             info->r->useragent_addr ? info->r->useragent_addr->port : 0);
 979     }
 980     else if (info->c) {
 981         len += apr_snprintf(buf + len, buflen - len,
 982                             info->c->sbh ? "[client %s:%d] " : "[remote %s:%d] ",
 983                             info->c->client_ip,
 984                             info->c->client_addr ? info->c->client_addr->port : 0);
 985     }
 986
 987     /* the actual error message */
 988     *errstr_start = len;
 989 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
 990     if (apr_vsnprintf(scratch, MAX_STRING_LEN, errstr_fmt, args)) {
 991         len += ap_escape_errorlog_item(buf + len, scratch,
 992                                        buflen - len);
 993
 994     }
 995 #else
 996     len += apr_vsnprintf(buf + len, buflen - len, errstr_fmt, args);
 997 #endif
 998     *errstr_end = len;
 999
1000     field_start = len;
1001     len += cpystrn(buf + len, ", referer: ", buflen - len);
1002     item_len = log_header(info, "Referer", buf + len, buflen - len);
1003     if (item_len)
1004         len += item_len;
1005     else
1006         len = field_start;
1007
1008     return len;
1009 }
1010
1011 static int do_errorlog_format(apr_array_header_t *fmt, ap_errorlog_info *info,
1012                               char *buf, int buflen, int *errstr_start,
1013                               int *errstr_end, const char *err_fmt, va_list args)
1014 {
1015 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
1016     char scratch[MAX_STRING_LEN];
1017 #endif
1018     int i;
1019     int len = 0;
1020     int field_start = 0;
1021     int skipping = 0;
1022     ap_errorlog_format_item *items = (ap_errorlog_format_item *)fmt->elts;
1023
1024     AP_DEBUG_ASSERT(fmt->nelts > 0);
1025     for (i = 0; i < fmt->nelts; ++i) {
1026         ap_errorlog_format_item *item = &items[i];
1027         if (item->flags & AP_ERRORLOG_FLAG_FIELD_SEP) {
1028             if (skipping) {
1029                 skipping = 0;
1030             }
1031             else {
1032                 field_start = len;
1033             }
1034         }
1035
1036         if (item->flags & AP_ERRORLOG_FLAG_MESSAGE) {
1037             /* the actual error message */
1038             *errstr_start = len;
1039 #ifndef AP_UNSAFE_ERROR_LOG_UNESCAPED
1040             if (apr_vsnprintf(scratch, MAX_STRING_LEN, err_fmt, args)) {
1041                 len += ap_escape_errorlog_item(buf + len, scratch,
1042                                                buflen - len);
1043
1044             }
1045 #else
1046             len += apr_vsnprintf(buf + len, buflen - len, err_fmt, args);
1047 #endif
1048             *errstr_end = len;
1049         }
1050         else if (skipping) {
1051             continue;
1052         }
1053         else if (info->level != -1 && (int)item->min_loglevel > info->level) {
1054             len = field_start;
1055             skipping = 1;
1056         }
1057         else {
1058             int item_len = (*item->func)(info, item->arg, buf + len,
1059                                          buflen - len);
1060             if (!item_len) {
1061                 if (item->flags & AP_ERRORLOG_FLAG_REQUIRED) {
1062                     /* required item is empty. skip whole line */
1063                     buf[0] = '\0';
1064                     return 0;
1065                 }
1066                 else if (item->flags & AP_ERRORLOG_FLAG_NULL_AS_HYPHEN) {
1067                     buf[len++] = '-';
1068                 }
1069                 else {
1070                     len = field_start;
1071                     skipping = 1;
1072                 }
1073             }
1074             else {
1075                 len += item_len;
1076             }
1077         }
1078     }
1079     return len;
1080 }
1081
1082 static void write_logline(char *errstr, apr_size_t len, apr_file_t *logf,
1083                           int level)
1084 {
1085     /* NULL if we are logging to syslog */
1086     if (logf) {
1087         /* Truncate for the terminator (as apr_snprintf does) */
1088         if (len > MAX_STRING_LEN - sizeof(APR_EOL_STR)) {
1089             len = MAX_STRING_LEN - sizeof(APR_EOL_STR);
1090         }
1091         strcpy(errstr + len, APR_EOL_STR);
1092         apr_file_puts(errstr, logf);
1093         apr_file_flush(logf);
1094     }
1095 #ifdef HAVE_SYSLOG
1096     else {
1097         syslog(level < LOG_PRIMASK ? level : APLOG_DEBUG, "%.*s",
1098                (int)len, errstr);
1099     }
1100 #endif
1101 }
1102
1103 static void log_error_core(const char *file, int line, int module_index,
1104                            int level,
1105                            apr_status_t status, const server_rec *s,
1106                            const conn_rec *c,
1107                            const request_rec *r, apr_pool_t *pool,
1108                            const char *fmt, va_list args)
1109 {
1110     char errstr[MAX_STRING_LEN];
1111     apr_file_t *logf = NULL;
1112     int level_and_mask = level & APLOG_LEVELMASK;
1113     const request_rec *rmain = NULL;
1114     core_server_config *sconf = NULL;
1115     ap_errorlog_info info;
1116
1117     /* do we need to log once-per-req or once-per-conn info? */
1118     int log_conn_info = 0, log_req_info = 0;
1119     apr_array_header_t **lines = NULL;
1120     int done = 0;
1121     int line_number = 0;
1122
1123     if (r) {
1124         AP_DEBUG_ASSERT(r->connection != NULL);
1125         c = r->connection;
1126     }
1127
1128     if (s == NULL) {
1129         /*
1130          * If we are doing stderr logging (startup), don't log messages that are
1131          * above the default server log level unless it is a startup/shutdown
1132          * notice
1133          */
1134 #ifndef DEBUG
1135         if ((level_and_mask != APLOG_NOTICE)
1136             && (level_and_mask > ap_default_loglevel)) {
1137             return;
1138         }
1139 #endif
1140
1141         logf = stderr_log;
1142     }
1143     else {
1144         int configured_level = r ? ap_get_request_module_loglevel(r, module_index)        :
1145                                c ? ap_get_conn_server_module_loglevel(c, s, module_index) :
1146                                    ap_get_server_module_loglevel(s, module_index);
1147         if (s->error_log) {
1148             /*
1149              * If we are doing normal logging, don't log messages that are
1150              * above the module's log level unless it is a startup/shutdown notice
1151              */
1152             if ((level_and_mask != APLOG_NOTICE)
1153                 && (level_and_mask > configured_level)) {
1154                 return;
1155             }
1156
1157             logf = s->error_log;
1158         }
1159         else {
1160             /*
1161              * If we are doing syslog logging, don't log messages that are
1162              * above the module's log level (including a startup/shutdown notice)
1163              */
1164             if (level_and_mask > configured_level) {
1165                 return;
1166             }
1167         }
1168
1169         /* the faked server_rec from mod_cgid does not have s->module_config */
1170         if (s->module_config) {
1171             sconf = ap_get_core_module_config(s->module_config);
1172             if (c && !c->log_id) {
1173                 add_log_id(c, NULL);
1174                 if (sconf->error_log_conn && sconf->error_log_conn->nelts > 0)
1175                     log_conn_info = 1;
1176             }
1177             if (r) {
1178                 if (r->main)
1179                     rmain = r->main;
1180                 else
1181                     rmain = r;
1182
1183                 if (!rmain->log_id) {
1184                     /* XXX: do we need separate log ids for subrequests? */
1185                     if (sconf->error_log_req && sconf->error_log_req->nelts > 0)
1186                         log_req_info = 1;
1187                     /*
1188                      * XXX: potential optimization: only create log id if %L is
1189                      * XXX: actually used
1190                      */
1191                     add_log_id(c, rmain);
1192                 }
1193             }
1194         }
1195     }
1196
1197     info.s             = s;
1198     info.c             = c;
1199     info.pool          = pool;
1200     info.file          = NULL;
1201     info.line          = 0;
1202     info.status        = 0;
1203     info.using_syslog  = (logf == NULL);
1204     info.startup       = ((level & APLOG_STARTUP) == APLOG_STARTUP);
1205     info.format        = fmt;
1206
1207     while (!done) {
1208         apr_array_header_t *log_format;
1209         int len = 0, errstr_start = 0, errstr_end = 0;
1210         /* XXX: potential optimization: format common prefixes only once */
1211         if (log_conn_info) {
1212             /* once-per-connection info */
1213             if (line_number == 0) {
1214                 lines = (apr_array_header_t **)sconf->error_log_conn->elts;
1215                 info.r = NULL;
1216                 info.rmain = NULL;
1217                 info.level = -1;
1218                 info.module_index = APLOG_NO_MODULE;
1219             }
1220
1221             log_format = lines[line_number++];
1222
1223             if (line_number == sconf->error_log_conn->nelts) {
1224                 /* this is the last line of once-per-connection info */
1225                 line_number = 0;
1226                 log_conn_info = 0;
1227             }
1228         }
1229         else if (log_req_info) {
1230             /* once-per-request info */
1231             if (line_number == 0) {
1232                 lines = (apr_array_header_t **)sconf->error_log_req->elts;
1233                 info.r = rmain;
1234                 info.rmain = rmain;
1235                 info.level = -1;
1236                 info.module_index = APLOG_NO_MODULE;
1237             }
1238
1239             log_format = lines[line_number++];
1240
1241             if (line_number == sconf->error_log_req->nelts) {
1242                 /* this is the last line of once-per-request info */
1243                 line_number = 0;
1244                 log_req_info = 0;
1245             }
1246         }
1247         else {
1248             /* the actual error message */
1249             info.r            = r;
1250             info.rmain        = rmain;
1251             info.level        = level_and_mask;
1252             info.module_index = module_index;
1253             info.file         = file;
1254             info.line         = line;
1255             info.status       = status;
1256             log_format = sconf ? sconf->error_log_format : NULL;
1257             done = 1;
1258         }
1259
1260         /*
1261          * prepare and log one line
1262          */
1263
1264         if (log_format && !info.startup) {
1265             len += do_errorlog_format(log_format, &info, errstr + len,
1266                                       MAX_STRING_LEN - len,
1267                                       &errstr_start, &errstr_end, fmt, args);
1268         }
1269         else {
1270             len += do_errorlog_default(&info, errstr + len, MAX_STRING_LEN - len,
1271                                        &errstr_start, &errstr_end, fmt, args);
1272         }
1273
1274         if (!*errstr) {
1275             /*
1276              * Don't log empty lines. This can happen with once-per-conn/req
1277              * info if an item with AP_ERRORLOG_FLAG_REQUIRED is NULL.
1278              */
1279             continue;
1280         }
1281         write_logline(errstr, len, logf, level_and_mask);
1282
1283         if (done) {
1284             /*
1285              * We don't call the error_log hook for per-request/per-conn
1286              * lines, and we only pass the actual log message, not the
1287              * prefix and suffix.
1288              */
1289             errstr[errstr_end] = '\0';
1290             ap_run_error_log(&info, errstr + errstr_start);
1291         }
1292
1293         *errstr = '\0';
1294     }
1295 }
1296
1297 /* For internal calls to log_error_core with self-composed arg lists */
1298 static void log_error_va_glue(const char *file, int line, int module_index,
1299                               int level, apr_status_t status,
1300                               const server_rec *s, const conn_rec *c,
1301                               const request_rec *r, apr_pool_t *pool,
1302                               const char *fmt, ...)
1303 {
1304     va_list args;
1305
1306     va_start(args, fmt);
1307     log_error_core(file, line, module_index, level, status, s, c, r, pool,
1308                    fmt, args);
1309     va_end(args);
1310 }
1311
1312 AP_DECLARE(void) ap_log_error_(const char *file, int line, int module_index,
1313                                int level, apr_status_t status,
1314                                const server_rec *s, const char *fmt, ...)
1315 {
1316     va_list args;
1317
1318     va_start(args, fmt);
1319     log_error_core(file, line, module_index, level, status, s, NULL, NULL,
1320                    NULL, fmt, args);
1321     va_end(args);
1322 }
1323
1324 AP_DECLARE(void) ap_log_perror_(const char *file, int line, int module_index,
1325                                 int level, apr_status_t status, apr_pool_t *p,
1326                                 const char *fmt, ...)
1327 {
1328     va_list args;
1329
1330     va_start(args, fmt);
1331     log_error_core(file, line, module_index, level, status, NULL, NULL, NULL,
1332                    p, fmt, args);
1333     va_end(args);
1334 }
1335
1336 AP_DECLARE(void) ap_log_rerror_(const char *file, int line, int module_index,
1337                                 int level, apr_status_t status,
1338                                 const request_rec *r, const char *fmt, ...)
1339 {
1340     va_list args;
1341
1342     va_start(args, fmt);
1343     log_error_core(file, line, module_index, level, status, r->server, NULL, r,
1344                    NULL, fmt, args);
1345
1346     /*
1347      * IF APLOG_TOCLIENT is set,
1348      * AND the error level is 'warning' or more severe,
1349      * AND there isn't already error text associated with this request,
1350      * THEN make the message text available to ErrorDocument and
1351      * other error processors.
1352      */
1353     va_end(args);
1354     va_start(args,fmt);
1355     if ((level & APLOG_TOCLIENT)
1356         && ((level & APLOG_LEVELMASK) <= APLOG_WARNING)
1357         && (apr_table_get(r->notes, "error-notes") == NULL)) {
1358         apr_table_setn(r->notes, "error-notes",
1359                        ap_escape_html(r->pool, apr_pvsprintf(r->pool, fmt,
1360                                                              args)));
1361     }
1362     va_end(args);
1363 }
1364
1365 AP_DECLARE(void) ap_log_cserror_(const char *file, int line, int module_index,
1366                                  int level, apr_status_t status,
1367                                  const conn_rec *c, const server_rec *s,
1368                                  const char *fmt, ...)
1369 {
1370     va_list args;
1371
1372     va_start(args, fmt);
1373     log_error_core(file, line, module_index, level, status, s, c,
1374                    NULL, NULL, fmt, args);
1375     va_end(args);
1376 }
1377
1378 AP_DECLARE(void) ap_log_cerror_(const char *file, int line, int module_index,
1379                                 int level, apr_status_t status,
1380                                 const conn_rec *c, const char *fmt, ...)
1381 {
1382     va_list args;
1383
1384     va_start(args, fmt);
1385     log_error_core(file, line, module_index, level, status, c->base_server, c,
1386                    NULL, NULL, fmt, args);
1387     va_end(args);
1388 }
1389
1390 #define BYTES_LOGGED_PER_LINE 16
1391 #define LOG_BYTES_BUFFER_SIZE (BYTES_LOGGED_PER_LINE * 3 + 2)
1392
1393 static void fmt_data(unsigned char *buf, const void *vdata, apr_size_t len, apr_size_t *off)
1394 {
1395     const unsigned char *data = (const unsigned char *)vdata;
1396     unsigned char *chars;
1397     unsigned char *hex;
1398     apr_size_t this_time = 0;
1399
1400     memset(buf, ' ', LOG_BYTES_BUFFER_SIZE - 1);
1401     buf[LOG_BYTES_BUFFER_SIZE - 1] = '\0';
1402
1403     chars = buf; /* start character dump here */
1404     hex   = buf + BYTES_LOGGED_PER_LINE + 1; /* start hex dump here */
1405     while (*off < len && this_time < BYTES_LOGGED_PER_LINE) {
1406         unsigned char c = data[*off];
1407
1408         if (apr_isprint(c)
1409             && c != '\\') {  /* backslash will be escaped later, which throws
1410                               * off the formatting
1411                               */
1412             *chars = c;
1413         }
1414         else {
1415             *chars = '.';
1416         }
1417
1418         if ((c >> 4) >= 10) {
1419             *hex = 'a' + ((c >> 4) - 10);
1420         }
1421         else {
1422             *hex = '0' + (c >> 4);
1423         }
1424
1425         if ((c & 0x0F) >= 10) {
1426             *(hex + 1) = 'a' + ((c & 0x0F) - 10);
1427         }
1428         else {
1429             *(hex + 1) = '0' + (c & 0x0F);
1430         }
1431
1432         chars += 1;
1433         hex += 2;
1434         *off += 1;
1435         ++this_time;
1436     }
1437 }
1438
1439 static void log_data_core(const char *file, int line, int module_index,
1440                           int level, const server_rec *s,
1441                           const conn_rec *c, const request_rec *r,
1442                           const char *label, const void *data, apr_size_t len,
1443                           unsigned int flags)
1444 {
1445     unsigned char buf[LOG_BYTES_BUFFER_SIZE];
1446     apr_size_t off;
1447     char prefix[20];
1448
1449     if (!(flags & AP_LOG_DATA_SHOW_OFFSET)) {
1450         prefix[0] = '\0';
1451     }
1452
1453     if (len > 0xffff) { /* bug in caller? */
1454         len = 0xffff;
1455     }
1456
1457     if (label) {
1458         log_error_va_glue(file, line, module_index, level, APR_SUCCESS, s,
1459                           c, r, NULL, "%s (%" APR_SIZE_T_FMT " bytes)",
1460                           label, len);
1461     }
1462
1463     off = 0;
1464     while (off < len) {
1465         if (flags & AP_LOG_DATA_SHOW_OFFSET) {
1466             apr_snprintf(prefix, sizeof prefix, "%04x: ", (unsigned int)off);
1467         }
1468         fmt_data(buf, data, len, &off);
1469         log_error_va_glue(file, line, module_index, level, APR_SUCCESS, s,
1470                           c, r, NULL, "%s%s", prefix, buf);
1471     }
1472 }
1473
1474 AP_DECLARE(void) ap_log_data_(const char *file, int line,
1475                               int module_index, int level,
1476                               const server_rec *s, const char *label,
1477                               const void *data, apr_size_t len,
1478                               unsigned int flags)
1479 {
1480     log_data_core(file, line, module_index, level, s, NULL, NULL, label,
1481                   data, len, flags);
1482 }
1483
1484 AP_DECLARE(void) ap_log_rdata_(const char *file, int line,
1485                                int module_index, int level,
1486                                const request_rec *r, const char *label,
1487                                const void *data, apr_size_t len,
1488                                unsigned int flags)
1489 {
1490     log_data_core(file, line, module_index, level, r->server, NULL, r, label,
1491                   data, len, flags);
1492 }
1493
1494 AP_DECLARE(void) ap_log_cdata_(const char *file, int line,
1495                                int module_index, int level,
1496                                const conn_rec *c, const char *label,
1497                                const void *data, apr_size_t len,
1498                                unsigned int flags)
1499 {
1500     log_data_core(file, line, module_index, level, c->base_server, c, NULL,
1501                   label, data, len, flags);
1502 }
1503
1504 AP_DECLARE(void) ap_log_csdata_(const char *file, int line, int module_index,
1505                                 int level, const conn_rec *c, const server_rec *s,
1506                                 const char *label, const void *data,
1507                                 apr_size_t len, unsigned int flags)
1508 {
1509     log_data_core(file, line, module_index, level, s, c, NULL, label, data,
1510                   len, flags);
1511 }
1512
1513 AP_DECLARE(void) ap_log_command_line(apr_pool_t *plog, server_rec *s)
1514 {
1515     int i;
1516     process_rec *process = s->process;
1517     char *result;
1518     int len_needed = 0;
1519
1520     /* Piece together the command line from the pieces
1521      * in process->argv, with spaces in between.
1522      */
1523     for (i = 0; i < process->argc; i++) {
1524         len_needed += strlen(process->argv[i]) + 1;
1525     }
1526
1527     result = (char *) apr_palloc(plog, len_needed);
1528     *result = '\0';
1529
1530     for (i = 0; i < process->argc; i++) {
1531         strcat(result, process->argv[i]);
1532         if ((i+1)< process->argc) {
1533             strcat(result, " ");
1534         }
1535     }
1536     ap_log_error(APLOG_MARK, APLOG_NOTICE, 0, s, APLOGNO(00094)
1537                  "Command line: '%s'", result);
1538 }
1539
1540 /* grab bag function to log commonly logged and shared info */
1541 AP_DECLARE(void) ap_log_mpm_common(server_rec *s)
1542 {
1543     ap_log_error(APLOG_MARK, APLOG_DEBUG , 0, s, APLOGNO(02639)
1544                  "Using SO_REUSEPORT: %s (%d)",
1545                  ap_have_so_reuseport ? "yes" : "no",
1546                  ap_num_listen_buckets);
1547 }
1548
1549 AP_DECLARE(void) ap_remove_pid(apr_pool_t *p, const char *rel_fname)
1550 {
1551     apr_status_t rv;
1552     const char *fname = ap_server_root_relative(p, rel_fname);
1553
1554     if (fname != NULL) {
1555         rv = apr_file_remove(fname, p);
1556         if (rv != APR_SUCCESS) {
1557             ap_log_error(APLOG_MARK, APLOG_ERR, rv, ap_server_conf, APLOGNO(00095)
1558                          "failed to remove PID file %s", fname);
1559         }
1560         else {
1561             ap_log_error(APLOG_MARK, APLOG_INFO, 0, ap_server_conf, APLOGNO(00096)
1562                          "removed PID file %s (pid=%" APR_PID_T_FMT ")",
1563                          fname, getpid());
1564         }
1565     }
1566 }
1567
1568 AP_DECLARE(void) ap_log_pid(apr_pool_t *p, const char *filename)
1569 {
1570     apr_file_t *pid_file = NULL;
1571     apr_finfo_t finfo;
1572     static pid_t saved_pid = -1;
1573     pid_t mypid;
1574     apr_status_t rv;
1575     const char *fname;
1576
1577     if (!filename) {
1578         return;
1579     }
1580
1581     fname = ap_server_root_relative(p, filename);
1582     if (!fname) {
1583         ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, APR_EBADPATH,
1584                      NULL, APLOGNO(00097) "Invalid PID file path %s, ignoring.", filename);
1585         return;
1586     }
1587
1588     mypid = getpid();
1589     if (mypid != saved_pid
1590         && apr_stat(&finfo, fname, APR_FINFO_MTIME, p) == APR_SUCCESS) {
1591         /* AP_SIG_GRACEFUL and HUP call this on each restart.
1592          * Only warn on first time through for this pid.
1593          *
1594          * XXX: Could just write first time through too, although
1595          *      that may screw up scripts written to do something
1596          *      based on the last modification time of the pid file.
1597          */
1598         ap_log_perror(APLOG_MARK, APLOG_WARNING, 0, p, APLOGNO(00098)
1599                       "pid file %s overwritten -- Unclean "
1600                       "shutdown of previous Apache run?",
1601                       fname);
1602     }
1603
1604     if ((rv = apr_file_open(&pid_file, fname,
1605                             APR_WRITE | APR_CREATE | APR_TRUNCATE,
1606                             APR_UREAD | APR_UWRITE | APR_GREAD | APR_WREAD, p))
1607         != APR_SUCCESS) {
1608         ap_log_error(APLOG_MARK, APLOG_ERR, rv, NULL, APLOGNO(00099)
1609                      "could not create %s", fname);
1610         ap_log_error(APLOG_MARK, APLOG_ERR, 0, NULL, APLOGNO(00100)
1611                      "%s: could not log pid to file %s",
1612                      ap_server_argv0, fname);
1613         exit(1);
1614     }
1615     apr_file_printf(pid_file, "%" APR_PID_T_FMT APR_EOL_STR, mypid);
1616     apr_file_close(pid_file);
1617     saved_pid = mypid;
1618 }
1619
1620 AP_DECLARE(apr_status_t) ap_read_pid(apr_pool_t *p, const char *filename,
1621                                      pid_t *mypid)
1622 {
1623     const apr_size_t BUFFER_SIZE = sizeof(long) * 3 + 2; /* see apr_ltoa */
1624     apr_file_t *pid_file = NULL;
1625     apr_status_t rv;
1626     const char *fname;
1627     char *buf, *endptr;
1628     apr_size_t bytes_read;
1629
1630     if (!filename) {
1631         return APR_EGENERAL;
1632     }
1633
1634     fname = ap_server_root_relative(p, filename);
1635     if (!fname) {
1636         ap_log_error(APLOG_MARK, APLOG_STARTUP|APLOG_CRIT, APR_EBADPATH,
1637                      NULL, APLOGNO(00101) "Invalid PID file path %s, ignoring.", filename);
1638         return APR_EGENERAL;
1639     }
1640
1641     rv = apr_file_open(&pid_file, fname, APR_READ, APR_OS_DEFAULT, p);
1642     if (rv != APR_SUCCESS) {
1643         return rv;
1644     }
1645
1646     buf = apr_palloc(p, BUFFER_SIZE);
1647
1648     rv = apr_file_read_full(pid_file, buf, BUFFER_SIZE - 1, &bytes_read);
1649     if (rv != APR_SUCCESS && rv != APR_EOF) {
1650         return rv;
1651     }
1652
1653     /* If we fill the buffer, we're probably reading a corrupt pid file.
1654      * To be nice, let's also ensure the first char is a digit. */
1655     if (bytes_read == 0 || bytes_read == BUFFER_SIZE - 1 || !apr_isdigit(*buf)) {
1656         return APR_EGENERAL;
1657     }
1658
1659     buf[bytes_read] = '\0';
1660     *mypid = strtol(buf, &endptr, 10);
1661
1662     apr_file_close(pid_file);
1663     return APR_SUCCESS;
1664 }
1665
1666 AP_DECLARE(void) ap_log_assert(const char *szExp, const char *szFile,
1667                                int nLine)
1668 {
1669     char time_str[APR_CTIME_LEN];
1670
1671     apr_ctime(time_str, apr_time_now());
1672     ap_log_error(APLOG_MARK, APLOG_CRIT, 0, NULL, APLOGNO(00102)
1673                  "[%s] file %s, line %d, assertion \"%s\" failed",
1674                  time_str, szFile, nLine, szExp);
1675 #if defined(WIN32)
1676     DebugBreak();
1677 #else
1678     /* unix assert does an abort leading to a core dump */
1679     abort();
1680 #endif
1681 }
1682
1683 /* piped log support */
1684
1685 #ifdef AP_HAVE_RELIABLE_PIPED_LOGS
1686 /* forward declaration */
1687 static void piped_log_maintenance(int reason, void *data, apr_wait_t status);
1688
1689 /* Spawn the piped logger process pl->program. */
1690 static apr_status_t piped_log_spawn(piped_log *pl)
1691 {
1692     apr_procattr_t *procattr;
1693     apr_proc_t *procnew = NULL;
1694     apr_status_t status;
1695
1696     if (((status = apr_procattr_create(&procattr, pl->p)) != APR_SUCCESS) ||
1697         ((status = apr_procattr_dir_set(procattr, ap_server_root))
1698          != APR_SUCCESS) ||
1699         ((status = apr_procattr_cmdtype_set(procattr, pl->cmdtype))
1700          != APR_SUCCESS) ||
1701         ((status = apr_procattr_child_in_set(procattr,
1702                                              pl->read_fd,
1703                                              pl->write_fd))
1704          != APR_SUCCESS) ||
1705         ((status = apr_procattr_child_errfn_set(procattr, log_child_errfn))
1706          != APR_SUCCESS) ||
1707         ((status = apr_procattr_error_check_set(procattr, 1)) != APR_SUCCESS)) {
1708         /* Something bad happened, give up and go away. */
1709         ap_log_error(APLOG_MARK, APLOG_STARTUP, status, NULL, APLOGNO(00103)
1710                      "piped_log_spawn: unable to setup child process '%s'",
1711                      pl->program);
1712     }
1713     else {
1714         char **args;
1715
1716         apr_tokenize_to_argv(pl->program, &args, pl->p);
1717         procnew = apr_pcalloc(pl->p, sizeof(apr_proc_t));
1718         status = apr_proc_create(procnew, args[0], (const char * const *) args,
1719                                  NULL, procattr, pl->p);
1720
1721         if (status == APR_SUCCESS) {
1722             pl->pid = procnew;
1723             /* procnew->in was dup2'd from pl->write_fd;
1724              * since the original fd is still valid, close the copy to
1725              * avoid a leak. */
1726             apr_file_close(procnew->in);
1727             procnew->in = NULL;
1728             apr_proc_other_child_register(procnew, piped_log_maintenance, pl,
1729                                           pl->write_fd, pl->p);
1730             close_handle_in_child(pl->p, pl->read_fd);
1731         }
1732         else {
1733             /* Something bad happened, give up and go away. */
1734             ap_log_error(APLOG_MARK, APLOG_STARTUP, status, NULL, APLOGNO(00104)
1735                          "unable to start piped log program '%s'",
1736                          pl->program);
1737         }
1738     }
1739
1740     return status;
1741 }
1742
1743
1744 static void piped_log_maintenance(int reason, void *data, apr_wait_t status)
1745 {
1746     piped_log *pl = data;
1747     apr_status_t rv;
1748     int mpm_state;
1749
1750     switch (reason) {
1751     case APR_OC_REASON_DEATH:
1752     case APR_OC_REASON_LOST:
1753         pl->pid = NULL; /* in case we don't get it going again, this
1754                          * tells other logic not to try to kill it
1755                          */
1756         apr_proc_other_child_unregister(pl);
1757         rv = ap_mpm_query(AP_MPMQ_MPM_STATE, &mpm_state);
1758         if (rv != APR_SUCCESS) {
1759             ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00105)
1760                          "can't query MPM state; not restarting "
1761                          "piped log program '%s'",
1762                          pl->program);
1763         }
1764         else if (mpm_state != AP_MPMQ_STOPPING) {
1765             ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL, APLOGNO(00106)
1766                          "piped log program '%s' failed unexpectedly",
1767                          pl->program);
1768             if ((rv = piped_log_spawn(pl)) != APR_SUCCESS) {
1769                 /* what can we do?  This could be the error log we're having
1770                  * problems opening up... */
1771                 ap_log_error(APLOG_MARK, APLOG_STARTUP, rv, NULL, APLOGNO(00107)
1772                              "piped_log_maintenance: unable to respawn '%s'",
1773                              pl->program);
1774             }
1775         }
1776         break;
1777
1778     case APR_OC_REASON_UNWRITABLE:
1779         /* We should not kill off the pipe here, since it may only be full.
1780          * If it really is locked, we should kill it off manually. */
1781     break;
1782
1783     case APR_OC_REASON_RESTART:
1784         if (pl->pid != NULL) {
1785             apr_proc_kill(pl->pid, SIGTERM);
1786             pl->pid = NULL;
1787         }
1788         break;
1789
1790     case APR_OC_REASON_UNREGISTER:
1791         break;
1792     }
1793 }
1794
1795
1796 static apr_status_t piped_log_cleanup_for_exec(void *data)
1797 {
1798     piped_log *pl = data;
1799
1800     apr_file_close(pl->read_fd);
1801     apr_file_close(pl->write_fd);
1802     return APR_SUCCESS;
1803 }
1804
1805
1806 static apr_status_t piped_log_cleanup(void *data)
1807 {
1808     piped_log *pl = data;
1809
1810     if (pl->pid != NULL) {
1811         apr_proc_kill(pl->pid, SIGTERM);
1812     }
1813     return piped_log_cleanup_for_exec(data);
1814 }
1815
1816
1817 AP_DECLARE(piped_log *) ap_open_piped_log_ex(apr_pool_t *p,
1818                                              const char *program,
1819                                              apr_cmdtype_e cmdtype)
1820 {
1821     piped_log *pl;
1822
1823     pl = apr_palloc(p, sizeof (*pl));
1824     pl->p = p;
1825     pl->program = apr_pstrdup(p, program);
1826     pl->pid = NULL;
1827     pl->cmdtype = cmdtype;
1828     if (apr_file_pipe_create_ex(&pl->read_fd,
1829                                 &pl->write_fd,
1830                                 APR_FULL_BLOCK, p) != APR_SUCCESS) {
1831         return NULL;
1832     }
1833     apr_pool_cleanup_register(p, pl, piped_log_cleanup,
1834                               piped_log_cleanup_for_exec);
1835     if (piped_log_spawn(pl) != APR_SUCCESS) {
1836         apr_pool_cleanup_kill(p, pl, piped_log_cleanup);
1837         apr_file_close(pl->read_fd);
1838         apr_file_close(pl->write_fd);
1839         return NULL;
1840     }
1841     return pl;
1842 }
1843
1844 #else /* !AP_HAVE_RELIABLE_PIPED_LOGS */
1845
1846 static apr_status_t piped_log_cleanup(void *data)
1847 {
1848     piped_log *pl = data;
1849
1850     apr_file_close(pl->write_fd);
1851     return APR_SUCCESS;
1852 }
1853
1854 AP_DECLARE(piped_log *) ap_open_piped_log_ex(apr_pool_t *p,
1855                                              const char *program,
1856                                              apr_cmdtype_e cmdtype)
1857 {
1858     piped_log *pl;
1859     apr_file_t *dummy = NULL;
1860     int rc;
1861
1862     rc = log_child(p, program, &dummy, cmdtype, 0);
1863     if (rc != APR_SUCCESS) {
1864         ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL, APLOGNO(00108)
1865                      "Couldn't start piped log process '%s'.",
1866                      (program == NULL) ? "NULL" : program);
1867         return NULL;
1868     }
1869
1870     pl = apr_palloc(p, sizeof (*pl));
1871     pl->p = p;
1872     pl->read_fd = NULL;
1873     pl->write_fd = dummy;
1874     apr_pool_cleanup_register(p, pl, piped_log_cleanup, piped_log_cleanup);
1875
1876     return pl;
1877 }
1878
1879 #endif
1880
1881 AP_DECLARE(piped_log *) ap_open_piped_log(apr_pool_t *p,
1882                                           const char *program)
1883 {
1884     apr_cmdtype_e cmdtype = APR_PROGRAM_ENV;
1885
1886     /* In 2.4 favor PROGRAM_ENV, accept "||prog" syntax for compatibility
1887      * and "|$cmd" to override the default.
1888      * Any 2.2 backport would continue to favor SHELLCMD_ENV so there
1889      * accept "||prog" to override, and "|$cmd" to ease conversion.
1890      */
1891     if (*program == '|')
1892         ++program;
1893     if (*program == '$') {
1894         cmdtype = APR_SHELLCMD_ENV;
1895         ++program;
1896     }
1897
1898     return ap_open_piped_log_ex(p, program, cmdtype);
1899 }
1900
1901 AP_DECLARE(void) ap_close_piped_log(piped_log *pl)
1902 {
1903     apr_pool_cleanup_run(pl->p, pl, piped_log_cleanup);
1904 }
1905
1906 AP_DECLARE(const char *) ap_parse_log_level(const char *str, int *val)
1907 {
1908     char *err = "Log level keyword must be one of emerg/alert/crit/error/warn/"
1909                 "notice/info/debug/trace1/.../trace8";
1910     int i = 0;
1911
1912     if (str == NULL)
1913         return err;
1914
1915     while (priorities[i].t_name != NULL) {
1916         if (!strcasecmp(str, priorities[i].t_name)) {
1917             *val = priorities[i].t_val;
1918             return NULL;
1919         }
1920         i++;
1921     }
1922     return err;
1923 }
1924
1925 AP_IMPLEMENT_HOOK_VOID(error_log,
1926                        (const ap_errorlog_info *info, const char *errstr),
1927                        (info, errstr))
1928
1929 AP_IMPLEMENT_HOOK_RUN_FIRST(int, generate_log_id,
1930                             (const conn_rec *c, const request_rec *r,
1931                              const char **id),
1932                             (c, r, id), DECLINED)