diff options
| -rw-r--r-- | CHANGES | 3 | ||||
| -rw-r--r-- | docs/manual/expr.xml | 3 | ||||
| -rw-r--r-- | docs/manual/mod/mod_log_debug.xml | 132 | ||||
| -rw-r--r-- | docs/manual/new_features_2_4.xml | 4 | ||||
| -rw-r--r-- | modules/loggers/config.m4 | 1 | ||||
| -rw-r--r-- | modules/loggers/mod_log_debug.c | 281 |
6 files changed, 423 insertions, 1 deletions
@@ -2,6 +2,9 @@ Changes with Apache 2.3.14 + *) mod_log_debug: New module that allows to log custom messages at various + phases in the request processing. [Stefan Fritsch] + *) mod_ssl: Add some debug logging when loading server certificates. PR 37912. [Nick Burch <nick burch alfresco com>] diff --git a/docs/manual/expr.xml b/docs/manual/expr.xml index 07fbb667ac..fc412bfc5c 100644 --- a/docs/manual/expr.xml +++ b/docs/manual/expr.xml @@ -46,6 +46,7 @@ <seealso><directive module="mod_filter">FilterProvider</directive></seealso> <seealso><a href="mod/mod_authz_core.html#reqexpr">Require expr</a></seealso> <seealso><directive module="mod_ssl">SSLRequire</directive></seealso> +<seealso><directive module="mod_log_debug">LogMessage</directive></seealso> <seealso><module>mod_include</module></seealso> <section id="grammar"> @@ -227,7 +228,7 @@ listfunction ::= listfuncname "<strong>(</strong>" word "<strong>)</strong>" <td>"<code>on</code>" if the connection uses IPv6, "<code>off</code>" otherwise</td></tr> <tr><td><code>REQUEST_STATUS</code></td> - <td>The HTTP error status of the request<td></tr> + <td>The HTTP error status of the request</td></tr> <tr><td><code>REQUEST_LOG_ID</code></td> <td>The error log id of the request (see <directive module="core">ErrorLogFormat</directive>)</td></tr> diff --git a/docs/manual/mod/mod_log_debug.xml b/docs/manual/mod/mod_log_debug.xml new file mode 100644 index 0000000000..d4f629dbaf --- /dev/null +++ b/docs/manual/mod/mod_log_debug.xml @@ -0,0 +1,132 @@ +<?xml version="1.0"?> +<!DOCTYPE modulesynopsis SYSTEM "../style/modulesynopsis.dtd"> +<?xml-stylesheet type="text/xsl" href="../style/manual.en.xsl"?> +<!-- $LastChangedRevision$ --> + +<!-- + 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 + + http://www.apache.org/licenses/LICENSE-2.0 + + 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. +--> + +<modulesynopsis metafile="mod_log_debug.xml.meta"> + +<name>mod_log_debug</name> +<description>Additional configurable debug logging</description> +<status>Experimental</status> +<sourcefile>mod_log_debug.c</sourcefile> +<identifier>log_debug_module</identifier> +<compatibility>Available in Apache 2.3.14 and later</compatibility> + +<section id="examples"><title>Examples</title> + + <ol> + <li> + Log message after request to /foo/* is processed: + + <example> + <Location /foo><br/> + LogMessage "/foo has been requested"<br/> + </Location><br/> + </example> + </li> + + <li> + Log message if request to /foo/* is processed in a sub-request: + <example> + <Location /foo><br/> + LogMessage "subrequest to /foo" hook=type_checker if=%{IS_SUBREQ}<br/> + </Location><br/> + </example> + + The default log_transaction hook is not executed for sub-requests, + therefore we have to use a different hook. + </li> + + + <li> + Log message if an IPv6 client causes a request timeout: + <example> + LogMessage "IPv6 timeout from %{REMOTE_ADDR}" + "if=-T %{IPV6} && %{REQUEST_STATUS} = 408" + </example> + Note the placing of the dobule quotes for the <code>if=</code> argument. + </li> + + <li> + Log the value of the "X-Foo" request environment variable in each + stage of the request: + <example> + <Location /><br/> + LogMessage "%{reqenv:X-Foo}" hook=all<br/> + </Location><br/> + </example> + Together with the microsecond time stamps in the error log, this + allows to determine the times spent in the different parts of the + request processing. + </li> + + </ol> +</section> + +<directivesynopsis> +<name>LogMessage</name> +<description>Log userdefined message to error log +</description> +<syntax>LogMessage <var>message</var> +[hook=<var>hook</var>] [if=<var>expression</var>] +</syntax> +<default>Unset</default> +<contextlist><context>directory</context> +</contextlist> + +<usage> + <p>This directive causes a user defined message to be logged to the + error log. The message can use variables and functions from the + <a href="../expr.html">ap_expr syntax</a>. The messages are logged at + loglevel info.</p> + + <p>The hook specifies before which phase of request procesing the message + will be logged. The following hooks are supported:</p> + + <table border="1" style="zebra"> + <columnspec><column width="1"/></columnspec> + <tr><th>Name</th></tr> + <tr><td><code>translate_name</code></td></tr> + <tr><td><code>type_checker</code></td></tr> + <tr><td><code>quick_handler</code></td></tr> + <tr><td><code>map_to_storage</code></td></tr> + <tr><td><code>check_access</code></td></tr> + <tr><td><code>check_access_ex</code></td></tr> + <tr><td><code>insert_filter</code></td></tr> + <tr><td><code>check_authn</code></td></tr> + <tr><td><code>check_authz</code></td></tr> + <tr><td><code>fixups</code></td></tr> + <tr><td><code>handler</code></td></tr> + <tr><td><code>log_transaction</code></td></tr> + </table> + + <p>The default is <code>log_transaction</code>. The special value + <code>all</code> is also supported, causing a message to be logged at each + phase. Not all hooks are executed for every request.</p> + + <p>The optional expression allows to restrict the message if a + condition is met. The details of the expression syntax are described in + the <a href="../expr.html">ap_expr documentation</a>.</p> + +</usage> + +</directivesynopsis> + +</modulesynopsis> diff --git a/docs/manual/new_features_2_4.xml b/docs/manual/new_features_2_4.xml index 6e30b0f7c6..98967c1a92 100644 --- a/docs/manual/new_features_2_4.xml +++ b/docs/manual/new_features_2_4.xml @@ -107,6 +107,10 @@ <dt><module>mod_slotmem_shm</module></dt> <dd>Provides a Slot-based shared memory provider (ala the scoreboard).</dd> + <dt><module>mod_log_debug</module></dt> + <dd>Allows to add customizable debug logging at different phases of the + request processing.</dd> + </dl> </section> diff --git a/modules/loggers/config.m4 b/modules/loggers/config.m4 index 8571e9e708..b795804ee0 100644 --- a/modules/loggers/config.m4 +++ b/modules/loggers/config.m4 @@ -5,6 +5,7 @@ dnl APACHE_MODULE(name, helptext[, objects[, structname[, default[, config]]]]) APACHE_MODPATH_INIT(loggers) APACHE_MODULE(log_config, logging configuration. You won't be able to log requests to the server without this module., , , yes) +APACHE_MODULE(log_debug, configurable debug logging, , , no) APACHE_MODULE(log_forensic, forensic logging) if test "x$enable_log_forensic" != "xno"; then diff --git a/modules/loggers/mod_log_debug.c b/modules/loggers/mod_log_debug.c new file mode 100644 index 0000000000..588cb3f34e --- /dev/null +++ b/modules/loggers/mod_log_debug.c @@ -0,0 +1,281 @@ +/* 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 + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * 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. + */ + +#include "apr_strings.h" + +#include "httpd.h" +#include "http_config.h" +#include "http_log.h" +#include "http_protocol.h" +#include "http_request.h" +#include "ap_expr.h" + +extern module log_debug_module; + +typedef struct { + ap_expr_info_t *msg_expr; + ap_expr_info_t *condition; + const char *hook; +} msg_entry; + +typedef struct { + apr_array_header_t *entries; +} log_debug_dirconf; + +const char *allhooks = "all"; +const char * const hooks[] = { + "log_transaction", /* 0 */ + "quick_handler", /* 1 */ + "handler", /* 2 */ + "translate_name", /* 3 */ + "map_to_storage", /* 4 */ + "fixups", /* 5 */ + "type_checker", /* 6 */ + "check_access", /* 7 */ + "check_access_ex", /* 8 */ + "check_authn", /* 9 */ + "check_authz", /* 10 */ + "insert_filter", /* 11 */ + NULL +}; + +static void do_debug_log(request_rec *r, const char *hookname) +{ + log_debug_dirconf *dconf = ap_get_module_config(r->per_dir_config, &log_debug_module); + int i; + if (dconf->entries == NULL) + return; + + for (i = 0; i < dconf->entries->nelts; i++) { + const char *msg, *err; + msg_entry *entry = APR_ARRAY_IDX(dconf->entries, i, msg_entry *); + if (entry->hook != allhooks && entry->hook != hookname) + continue; + if (entry->condition) { + int ret = ap_expr_exec(r, entry->condition, &err); + if (err) { + ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, + "Can't evaluate condition: %s", err); + continue; + } + if (!ret) + continue; + } + msg = ap_expr_str_exec(r, entry->msg_expr, &err); + if (err) + ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, + "Can't evaluate message expression: %s", err); + if (APLOGrdebug(r)) + ap_log_rerror(APLOG_MARK, APLOG_INFO, 0, r, "%s (%s hook, %s:%d)", + msg, hookname, entry->msg_expr->filename, + entry->msg_expr->line_number); + else + ap_log_rerror(APLOG_MARK, APLOG_INFO, 0, r, "%s", msg); + } +} + +static int log_debug_log_transaction(request_rec *r) +{ + do_debug_log(r, hooks[0]); + return DECLINED; +} + +static int log_debug_quick_handler(request_rec *r, int lookup_uri) +{ + do_debug_log(r, hooks[1]); + return DECLINED; +} + +static int log_debug_handler(request_rec *r) +{ + do_debug_log(r, hooks[2]); + return DECLINED; +} + +static int log_debug_translate_name(request_rec *r) +{ + do_debug_log(r, hooks[3]); + return DECLINED; +} + +static int log_debug_map_to_storage(request_rec *r) +{ + do_debug_log(r, hooks[4]); + return DECLINED; +} + +static int log_debug_fixups(request_rec *r) +{ + do_debug_log(r, hooks[5]); + return DECLINED; +} + +static int log_debug_type_checker(request_rec *r) +{ + do_debug_log(r, hooks[6]); + return DECLINED; +} + +static int log_debug_check_access(request_rec *r) +{ + do_debug_log(r, hooks[7]); + return DECLINED; +} + +static int log_debug_check_access_ex(request_rec *r) +{ + do_debug_log(r, hooks[8]); + return DECLINED; +} + +static int log_debug_check_authn(request_rec *r) +{ + do_debug_log(r, hooks[9]); + return DECLINED; +} + +static int log_debug_check_authz(request_rec *r) +{ + do_debug_log(r, hooks[10]); + return DECLINED; +} + +static void log_debug_insert_filter(request_rec *r) +{ + do_debug_log(r, hooks[11]); +} + +static void *log_debug_create_dconf(apr_pool_t *p, char *dirspec) +{ + log_debug_dirconf *dconf = apr_pcalloc(p, sizeof(log_debug_dirconf)); + return dconf; +} + +static void *log_debug_merge_dconf(apr_pool_t *p, void *parent_conf, void *new_conf) +{ + log_debug_dirconf *merged = apr_pcalloc(p, sizeof(log_debug_dirconf)); + const log_debug_dirconf *parent = parent_conf; + const log_debug_dirconf *new = new_conf; + + if (parent->entries == NULL) + merged->entries = new->entries; + else if (new->entries == NULL) + merged->entries = parent->entries; + else + /* apr_array_append actually creates a new array */ + merged->entries = apr_array_append(p, parent->entries, new->entries); + + return merged; +} + +static const char *cmd_log_message(cmd_parms *cmd, void *dconf_, const char *arg1, + const char *arg2, const char *arg3) +{ + msg_entry *entry = apr_pcalloc(cmd->pool, sizeof(msg_entry)); + log_debug_dirconf *dconf = dconf_; + int i, j; + const char *err; + const char *args[2] = { arg2, arg3 }; + + entry->msg_expr = ap_expr_parse_cmd(cmd, arg1, AP_EXPR_FLAG_STRING_RESULT| + AP_EXPR_FLAG_DONT_VARY, + &err, NULL); + if (err) + return apr_psprintf(cmd->pool, + "Could not parse message expression '%s': %s", + arg1, err); + + for (i = 0; i < 2; i++) { + if (args[i] == NULL) + break; + + if (strncasecmp(args[i], "hook=", 5) == 0) { + const char *name = args[i] + 5; + j = 0; + while (hooks[j]) { + if (strcasecmp(hooks[j], name) == 0) { + entry->hook = hooks[j]; + break; + } + j++; + } + if (entry->hook == NULL) { + if (strcmp(name, "*") == 0 || strcasecmp(name, allhooks) == 0) + entry->hook = allhooks; + else + return apr_psprintf(cmd->pool, "Invalid hook name: %s", name); + } + } + else if (strncasecmp(args[i], "if=", 3) == 0) { + const char *expr = args[i] + 3; + entry->condition = ap_expr_parse_cmd(cmd, expr, + AP_EXPR_FLAG_DONT_VARY, + &err, NULL); + if (err) + return apr_psprintf(cmd->pool, + "Could not parse expression '%s': %s", + expr, err); + } + else { + return apr_psprintf(cmd->pool, "Invalid argument %s", args[i]); + } + } + if (entry->hook == NULL) + entry->hook = hooks[0]; + + if (!dconf->entries) + dconf->entries = apr_array_make(cmd->pool, 4, sizeof(msg_entry *)); + + APR_ARRAY_PUSH(dconf->entries, msg_entry *) = entry; + + return NULL; +} + +static const command_rec log_debug_cmds[] = +{ + AP_INIT_TAKE123("LogMessage", cmd_log_message, NULL, RSRC_CONF|ACCESS_CONF, + "Log a debug message to the error log if this config block is used for " + " a request"), + {NULL} +}; + +static void register_hooks(apr_pool_t *p) +{ + ap_hook_log_transaction(log_debug_log_transaction, NULL, NULL, APR_HOOK_FIRST); + ap_hook_quick_handler(log_debug_quick_handler, NULL, NULL, APR_HOOK_FIRST); + ap_hook_handler(log_debug_handler, NULL, NULL, APR_HOOK_FIRST); + ap_hook_translate_name(log_debug_translate_name, NULL, NULL, APR_HOOK_FIRST); + ap_hook_map_to_storage(log_debug_map_to_storage, NULL, NULL, APR_HOOK_FIRST); + ap_hook_fixups(log_debug_fixups, NULL, NULL, APR_HOOK_FIRST); + ap_hook_type_checker(log_debug_type_checker, NULL, NULL, APR_HOOK_FIRST); + ap_hook_check_access(log_debug_check_access, NULL, NULL, APR_HOOK_FIRST, AP_AUTH_INTERNAL_PER_URI); + ap_hook_check_access_ex(log_debug_check_access_ex, NULL, NULL, APR_HOOK_FIRST, AP_AUTH_INTERNAL_PER_URI); + ap_hook_check_authn(log_debug_check_authn, NULL, NULL, APR_HOOK_FIRST, AP_AUTH_INTERNAL_PER_URI); + ap_hook_check_authz(log_debug_check_authz, NULL, NULL, APR_HOOK_FIRST, AP_AUTH_INTERNAL_PER_URI); + ap_hook_insert_filter(log_debug_insert_filter, NULL, NULL, APR_HOOK_FIRST); +} + +AP_DECLARE_MODULE(log_debug) = +{ + STANDARD20_MODULE_STUFF, + log_debug_create_dconf, /* create per-dir config */ + log_debug_merge_dconf, /* merge per-dir config */ + NULL, /* server config */ + NULL, /* merge server config */ + log_debug_cmds, /* command apr_table_t */ + register_hooks /* register hooks */ +}; + |