#610796 libapache2-mod-log-sql: http status in database table differs from status in apache log file

Package:
libapache2-mod-log-sql
Source:
libapache-mod-log-sql
Description:
Use SQL to store/write your Apache queries logs - Base
Submitter:
Thomas Mayer
Date:
2024-08-22 09:27:02 UTC
Severity:
normal
Tags:
#610796#5
Date:
2011-01-22 16:15:50 UTC
From:
To:
I called a non-existent page on my server and expected an entry with
status=404.

The apache error log tells me:
nat-wh-hadi.rz.uni-karlsruhe.de - - [22/Jan/2011:15:54:44 +0000] "GET
/thisdoesnotexist.html HTTP/1.1" 404 639 "-" "Mozilla/5.0 (X11; U; Linux
x86_64; de; rv:1.9.2.13) Gecko/20101206 Ubuntu/10.04 (lucid) Firefox/3.6.13"

But in the database I have:
mysql> select request_uri, status from accesslog where request_uri
='/thisdoesnotexist.html';
+------------------------+--------+
| request_uri            | status |
+------------------------+--------+
| /thisdoesnotexist.html |    200 |
+------------------------+--------+

As far as I can see, this happens when using typo3 with mod_rewrite enable
(to get typo3 realurl extension to work).

I have told typo3 to throw an 404 error if a page is not found in
localconf.php:
$TYPO3_CONF_VARS['FE']['pageNotFound_handling'] = '1';
$TYPO3_CONF_VARS['FE']['pageNotFound_handling_statheader'] = 'HTTP/1.1 404
Not Found';

However this only works great in the apache logs but not in mod-log. The
status should NEVER be different.

I think it has to do with mod_rewrite, because in the following case it
works great:
- create a php file with 404 error:
<?php
header("HTTP/1.0 404 Not Found");
- get this file with a browser
=> the database table contains:
mysql> select request_uri, status from accesslog where request_uri
='/fileadmin/notfound.php';
+-------------------------+--------+
| request_uri             | status |
+-------------------------+--------+
| /fileadmin/notfound.php |    404 |
+-------------------------+--------+

I'm running debian with all updates installed.

my .htaccess for mod_rewrite looks like this:

RewriteEngine On
RewriteRule ^sitemap\.xml$ ./?eID=dd_googlesitemap [L]
RewriteRule ^typo3$ - [L]
RewriteRule ^typo3/.*$ - [L]

RewriteCond %{REQUEST_FILENAME} !-f
RewriteCond %{REQUEST_FILENAME} !-d
RewriteCond %{REQUEST_FILENAME} !-l
RewriteRule .* index.php

#610796#10
Date:
2012-02-05 19:45:02 UTC
From:
To:
using up-to-date debian squeeze, the problem still exists.

#610796#15
Date:
2013-09-12 18:00:07 UTC
From:
To:
using up-to-date debian wheezy, the problem still is not solved:

The http response header returns a http status 404:

Date: Thu, 12 Sep 2013 17:52:37 GMT
Server: Apache/2.2.22 (Debian)
X-Powered-By: PHP/5.4.4-14+deb7u4
[...]
Content-Type: text/html; charset=UTF-8

404 Not Found
===

while mod-log-sql writes this to the database:

select request_uri, status from accesslog where request_uri
='/thisdoesnotexist2.html';
+-------------------------+--------+
| request_uri             | status |
+-------------------------+--------+
| /thisdoesnotexist2.html |    200 |
+-------------------------+--------+

#610796#20
Date:
2015-09-21 19:38:35 UTC
From:
To:
I ran into this thread because I wanted to use mod_log_sql with
mod_rewrite. I ran into the exact problem described in this thread.

I managed to fix it by patching libapache2-mod-log-sql and compiling it
myself.

The adjustment is in functions.h:
https://github.com/OutOfOrder/mod_log_sql/blob/1.100/functions.h#L91-L98

In this function, request_rec->status is used, but as described in
http://httpd.apache.org/docs/2.2/developer/API.html#log_handlers:
log. Apache handles this by bundling the entire chain of redirects into a
list of request_rec structures which are threaded through the r->prev and
r->next pointers. The request_rec which is passed to the logging handlers
in such cases is the one which was originally built for the initial request
from the client; note that the bytes_sent field will only be correct in the
last request in the chain (the one for which a response was actually sent).

This is the root cause of the problem. By checking if request_rec is not
null, and if that's the case, using the next request's status code, the
correct status codes are stored in the database. This solution works for
requests through mod_rewrite as well as requests which are not rewritten.

Best,
Luc van Donkersgoed

#610796#25
Date:
2015-09-22 11:31:50 UTC
From:
To:
Hi Luc,

Would you be able to provide a patch for this?

Cheers,

Thomas Goirand (zigo)

#610796#30
Date:
2015-09-22 22:05:12 UTC
From:
To:
Hi Thomas,

I've created a patch for the file at https://github.com/OutOfOrder/mod_log_sql/blob/1.100/functions.h

This is the patch:


diff --git a/functions.h b/functions.h
index b35634a..dcbf710 100644
--- a/functions.h
+++ b/functions.h
@@ -90,10 +90,16 @@ static const char *extract_request_query(request_rec *r, char *a)

 static const char *extract_status(request_rec *r, char *a)
 {
-	if (r->status <= 0) {
+	int status = r->status;
+	if (r->next){
+	request_rec *r2 = r->next;
+	status = r2->status;
+	}
+
+	if (status <= 0) {
 	return "-";
 	} else {
-	return apr_psprintf(r->pool, "%d", r->status);
+	return apr_psprintf(r->pool, "%d", status);
 	}
 }

I'm not sure if this is the final solution for every use case, but it fixes the issues at my REST API. Maybe someone else needs the `if` to be a `while` statement.

Best,
Luc van Donkersgoed

#610796#35
Date:
2024-08-22 09:23:40 UTC
From:
To:
Hi,

this bug showed up as candidate for a Bug of the Day[1] and thus I
checked the log.  Seems the last message contains a patch and thus I'm
tagging the bug accordingly.  Since the packaging is even moved to
Salsa[2] I consider it a good candidate for a soon upload.

There is another candidate for easy fixing (#787405) and the RC bug
#1075140 definitely needs care.

Could you please give some status update for this package if you need
some help?

Kind regards
    Andreas.

[1] https://salsa.debian.org/tille/tiny_qa_tools/-/wikis/Tiny-QA-tasks
[2] https://salsa.debian.org/debian/libapache-mod-log-sql