Bug 29450 - Improved logging for mod_access
Summary: Improved logging for mod_access
Status: RESOLVED LATER
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_access (show other bugs)
Version: 2.0.49
Hardware: All other
: P3 enhancement (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords: MassUpdate, PatchAvailable
Depends on:
Blocks:
 
Reported: 2004-06-09 02:12 UTC by Rici Lake
Modified: 2018-11-07 21:09 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Rici Lake 2004-06-09 02:12:14 UTC
The following patch logs the location in the config file responsible for a mod_access denial. It appears 
that it is very common for inexperienced Apache users to have difficulty untangling the various 
<directory> <location> and .htaccess configurations, particularly in distributions which divide the 
configuration system into multiple files.

Following some suggestions from the apache-dev mailing list, I modified the patch to produce two log 
messages; the first at level "error" which is identical to the current behaviour, and the second at level 
"info" with the debugging information. I don't regard this as ideal, but it is hard to find consensus. I was 
going to put it at level "notice" but it turns out that level "notice" is logged regardless of the  setting of 
LogLevel, which is slightly odd behaviour.

The patch is dependent on the filename/linenumber information stored in the struct directive for the 
mod_access directives. Since I couldn't convince myself that it was safe to store the pointer from that 
structure, the patch copies the first 80 bytes of the filename into a static buffer. This is obviously not 
ideal either, but it works and the storage impact is limited to 80*(number of mod_access directives).

I think this same strategy could be extended to other directives which frequently frustrate new users, 
particularly the "AllowOverride" and "Options" directives. But it would be useful to have some better 
understanding of the memory-pool strategy for struct directive. There is a note in the source code that 
the filename/linenumber info should be removed from struct directive; I think this patch demonstrates 
the utility of that information.

---- patch follows ----

--- httpd-2.0.49-orig/modules/aaa/mod_access.c	Mon Feb  9 15:53:14 2004
+++ httpd-2.0.49/modules/aaa/mod_access.c	Tue Jun  8 20:55:00 2004
@@ -39,6 +39,9 @@
 #include <netinet/in.h>
 #endif
 
+/* If their config pathnames are longer than this, they deserve what they get */
+#define AP_ACCESS_MAXPATH 80
+
 enum allowdeny_type {
     T_ENV,
     T_ALL,
@@ -54,6 +57,7 @@
         apr_ipsubnet_t *ip;
     } x;
     enum allowdeny_type type;
+    unsigned line_number;
 } allowdeny;
 
 /* things in the 'order' array */
@@ -65,6 +69,8 @@
     int order[METHODS];
     apr_array_header_t *allows;
     apr_array_header_t *denys;
+    char filename[AP_ACCESS_MAXPATH];
+    unsigned line_number;
 } access_dir_conf;
 
 module AP_MODULE_DECLARE_DATA access_module;
@@ -80,10 +86,38 @@
     }
     conf->allows = apr_array_make(p, 1, sizeof(allowdeny));
     conf->denys = apr_array_make(p, 1, sizeof(allowdeny));
-
+    conf->filename[0] = 0;
+    conf->line_number = 0;
     return (void *)conf;
 }
 
+/* it's like you see this cute directive and you have to...*/
+static void get_name_and_number(cmd_parms *cmd, char *name, unsigned *number)
+{
+  /* There is a comment saying directive->filename might go away. It is not at
+   * all clear to me how we are supposed to get this info if it does
+   * On the other hand, no other module seems to care
+   */
+  const char *fname = NULL;
+  if (cmd->directive && cmd->directive->filename) {
+    fname = cmd->directive->filename;
+    *number = cmd->directive->line_num;
+  }
+  /* You gotta love the consistent naming convention */
+  else if (cmd->config_file && cmd->config_file->name) {
+    fname = cmd->config_file->name;
+    *number = cmd->config_file->line_number;
+  }
+  if (fname) {
+    if (apr_cpystrn(name, fname, AP_ACCESS_MAXPATH) == &name[AP_ACCESS_MAXPATH-1])
+      name[AP_ACCESS_MAXPATH-2] = name[AP_ACCESS_MAXPATH-3] = name[AP_ACCESS_MAXPATH
-4] = '.';
+  } else {
+    name[0] = name[1] = name[2] = '?'; name[3] = '\0';
+    *number = 0;
+  }
+}
+
+
 static const char *order(cmd_parms *cmd, void *dv, const char *arg)
 {
     access_dir_conf *d = (access_dir_conf *) dv;
@@ -102,6 +136,7 @@
 	if (cmd->limited & (AP_METHOD_BIT << i))
 	    d->order[i] = o;
 
+    get_name_and_number(cmd, d->filename, &d->line_number);
     return NULL;
 }
 
@@ -122,6 +157,8 @@
     a->x.from = where;
     a->limited = cmd->limited;
 
+    get_name_and_number(cmd, d->filename, &a->line_number);
+
     if (!strncasecmp(where, "env=", 4)) {
 	a->type = T_ENV;
 	a->x.from += 4;
@@ -193,7 +230,7 @@
 	return 0;
 }
 
-static int find_allowdeny(request_rec *r, apr_array_header_t *a, int method)
+static allowdeny *find_allowdeny(request_rec *r, apr_array_header_t *a, int method)
 {
 
     allowdeny *ap = (allowdeny *) a->elts;
@@ -209,16 +246,16 @@
 	switch (ap[i].type) {
 	case T_ENV:
 	    if (apr_table_get(r->subprocess_env, ap[i].x.from)) {
-		return 1;
+		return &ap[i];
 	    }
 	    break;
 
 	case T_ALL:
-	    return 1;
+	    return &ap[i];
 
 	case T_IP:
             if (apr_ipsubnet_test(ap[i].x.ip, r->connection->remote_addr)) {
-                return 1;
+                return &ap[i];
             }
             break;
 
@@ -236,7 +273,7 @@
 	    }
 
 	    if ((gothost == 2) && in_domain(ap[i].x.from, remotehost))
-		return 1;
+		return &ap[i];
 	    break;
 
 	case T_FAIL:
@@ -245,13 +282,14 @@
 	}
     }
 
-    return 0;
+    return NULL;
 }
 
 static int check_dir_access(request_rec *r)
 {
     int method = r->method_number;
     int ret = OK;
+    allowdeny *which = NULL;
     access_dir_conf *a = (access_dir_conf *)
         ap_get_module_config(r->per_dir_config, &access_module);
 
@@ -259,18 +297,18 @@
         ret = HTTP_FORBIDDEN;
         if (find_allowdeny(r, a->allows, method))
             ret = OK;
-        if (find_allowdeny(r, a->denys, method))
+        if (which = find_allowdeny(r, a->denys, method))
             ret = HTTP_FORBIDDEN;
     }
     else if (a->order[method] == DENY_THEN_ALLOW) {
-        if (find_allowdeny(r, a->denys, method))
+        if (which = find_allowdeny(r, a->denys, method))
             ret = HTTP_FORBIDDEN;
         if (find_allowdeny(r, a->allows, method))
             ret = OK;
     }
     else {
         if (find_allowdeny(r, a->allows, method)
-            && !find_allowdeny(r, a->denys, method))
+            && !(which = find_allowdeny(r, a->denys, method)))
             ret = OK;
         else
             ret = HTTP_FORBIDDEN;
@@ -281,6 +319,14 @@
         ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r,
             "client denied by server configuration: %s",
             r->filename);
+        if (which) 
+          ap_log_rerror(APLOG_MARK, APLOG_INFO, 0, r,
+            "client denied by deny directive at line %d of %s",
+                        which->line_number, a->filename);
+        else
+          ap_log_rerror(APLOG_MARK, APLOG_INFO, 0, r,
+            "client denied by order directive at line %d of %s",
+                        a->line_number, a->filename);
     }
 
     return ret;
Comment 1 Rici Lake 2004-06-09 02:15:30 UTC
Here is sample output, with LogLevel set to info. What is illustrated here is that:

-- .htaccess files are identified
-- deny directives are logged unless there isn't one (i.e. default is deny) in which case
     the order directive is logged.

[Tue Jun 08 20:57:18 2004] [error] [client 192.168.1.65] client denied by server configuration: /opt/
apache2a/htdocs/foo/
[Tue Jun 08 20:57:18 2004] [info] [client 192.168.1.65] client denied by deny directive at line 2 of /opt/
apache2a/htdocs/foo/.htaccess
[Tue Jun 08 20:57:26 2004] [error] [client 192.168.1.65] client denied by server configuration: /opt/
apache2a/htdocs/bar
[Tue Jun 08 20:57:26 2004] [info] [client 192.168.1.65] client denied by order directive at line 362 of /
opt/apache2a/conf/httpd.conf
[Tue Jun 08 20:58:18 2004] [error] [client 192.168.1.65] client denied by server configuration: /opt/
apache2a/htdocs/foo/.htaccess
[Tue Jun 08 20:58:18 2004] [info] [client 192.168.1.65] client denied by deny directive at line 411 of /
opt/apache2a/conf/httpd.conf
Comment 2 Joshua Slive 2004-06-09 16:59:39 UTC
I can't provide code review for the most important issue here (the handling of
storage), but I can confirm that this would be very helpful for debugging access
control problems.

I also support having it available always, rather than just at level "info"
(although I am the one who suggested the separate-logging approach).
Comment 3 Paul Querna 2005-06-03 04:22:58 UTC
I completely agree that logging of this should be more verbose.

Rici, do you think you can do an updated patch?
Comment 4 William A. Rowe Jr. 2018-11-07 21:09:36 UTC
Please help us to refine our list of open and current defects; this is a mass update of old and inactive Bugzilla reports which reflect user error, already resolved defects, and still-existing defects in httpd.

As repeatedly announced, the Apache HTTP Server Project has discontinued all development and patch review of the 2.2.x series of releases. The final release 2.2.34 was published in July 2017, and no further evaluation of bug reports or security risks will be considered or published for 2.2.x releases. All reports older than 2.4.x have been updated to status RESOLVED/LATER; no further action is expected unless the report still applies to a current version of httpd.

If your report represented a question or confusion about how to use an httpd feature, an unexpected server behavior, problems building or installing httpd, or working with an external component (a third party module, browser etc.) we ask you to start by bringing your question to the User Support and Discussion mailing list, see [https://httpd.apache.org/lists.html#http-users] for details. Include a link to this Bugzilla report for completeness with your question.

If your report was clearly a defect in httpd or a feature request, we ask that you retest using a modern httpd release (2.4.33 or later) released in the past year. If it can be reproduced, please reopen this bug and change the Version field above to the httpd version you have reconfirmed with.

Your help in identifying defects or enhancements still applicable to the current httpd server software release is greatly appreciated.