Bug 50024

Summary: Mod_cache/mod_mem_cache and mod_security combination bug
Product: Apache httpd-2 Reporter: christian.folini
Component: mod_cacheAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: RESOLVED LATER    
Severity: minor CC: felix.schuster, jim, nat.guyton, patrick.gasior
Priority: P2 Keywords: MassUpdate
Version: 2.2.16   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: Apache configuration
a lot of 103 coming in the error-log

Description christian.folini 2010-09-29 08:26:46 UTC
When using mod_cache/mod_mem_cache and the latest mod_security (2.5.12), a strange bug appears, that can be linked to the following entry in the error:

[Wed Sep 29 13:22:19 2010] [error] (103)Software caused connection abort: cache: error returned while trying to return mem cached data

This error message can be triggered as follows:
$> curl  --max-time 1 --limit-rate 100 http://127.0.0.1:8000/1MB

In standard use, the bug appears in about once in 1000 requests and results in a blank http response that leads to a blank page in the browser.

Reproducing the bug and triggering via curl:
============================================

$> ./configure --prefix=/data/folinic/apache/apache-2.2.16 \
 --enable-mods-shared=all --enable-cache --enable-mem-cache \
 --with-included-apr

$> httpd -V
Server version: Apache/2.2.16 (Unix)
Server built:   Sep 29 2010 14:00:03
Server's Module Magic Number: 20051115:24
Server loaded:  APR 1.4.2, APR-Util 1.3.9
Compiled using: APR 1.4.2, APR-Util 1.3.9
Architecture:   64-bit
Server MPM:     Prefork
  threaded:     no
    forked:     yes (variable process count)
Server compiled with....
 -D APACHE_MPM_DIR="server/mpm/prefork"
 -D APR_HAS_SENDFILE
 -D APR_HAS_MMAP
 -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
 -D APR_USE_SYSVSEM_SERIALIZE
 -D APR_USE_PTHREAD_SERIALIZE
 -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
 -D APR_HAS_OTHER_CHILD
 -D AP_HAVE_RELIABLE_PIPED_LOGS
 -D DYNAMIC_MODULE_LIMIT=128
 -D HTTPD_ROOT="/data/folinic/apache/apache-2.2.16"
 -D SUEXEC_BIN="/data/folinic/apache/apache-2.2.16/bin/suexec"
 -D DEFAULT_PIDLOG="logs/httpd.pid"
 -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
 -D DEFAULT_LOCKFILE="logs/accept.lock"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D AP_TYPES_CONFIG_FILE="conf/mime.types"
 -D SERVER_CONFIG_FILE="conf/httpd.conf"

$> httpd -l
Compiled in modules:
  core.c
  prefork.c
  http_core.c
  mod_so.c

$> uname -a
Linux xxxxxx 2.6.26-2-amd64 #1 SMP Sun Jun 20 20:16:30 UTC 2010 x86_64 GNU/Linu


ModSecurity:
./configure --with-apxs=/data/folinic/apache/apache-2.2.16/bin/apxs \
  --with-apu=/data/folinic/apache/apache-2.2.16/bin/apu-1-confi

Minimal Apache config:

 ServerName              www.example.com
 ServerRoot              /data/folinic/apache/apache-2.2.15

 PidFile                 /tmp/httpd.pid
 Listen                  127.0.0.1:8000

 LoadModule              log_config_module       modules/mod_log_config.so
 LoadModule              security2_module        modules/mod_security2.so
 LoadModule              cache_module            modules/mod_cache.so
 LoadModule              mem_cache_module        modules/mod_mem_cache.so
 LoadModule              unique_id_module        modules/mod_unique_id.so

 ErrorLog                /tmp/error.log

 DocumentRoot            "/tmp"

 SecRuleEngine           On

 MCacheSize              10000000
 MCacheMinObjectSize     1
 MCacheMaxObjectSize     2000000

 CacheEnable             mem 


Start the server:
$> /data/folinic/apache/apache-2.2.16/bin/httpd -X -k start \
   -f /data/folinic/apache/apache-2.2.16/conf/httpd-minimal.conf

Generate the test file:
$> dd if=/dev/zero of=/tmp/1MB bs=1024 count=1000

Trigger the error log entry:
$> curl  --max-time 1 --limit-rate 100 http://127.0.0.1:8000/1MB

NOTE that the error does only appear starting with the 2nd curl call.
Comment 1 Keith Mashinter 2010-10-08 19:47:44 UTC
I'm having a similar error a number of times a day on Apache/2.2.16 (Win32) when processing 500-1000 requests per minute, 500-1000 KB per minute, as a reverse proxy-cache-mem_cache.  Maybe this is related to https://issues.apache.org/bugzilla/show_bug.cgi?id=45868 

[Thu Oct 07 09:16:34 2010] [error] (620018)APR does not understand this error code: cache: error returned while trying to return mem cached data
[Thu Oct 07 09:51:23 2010] [error] (620018)APR does not understand this error code: cache: error returned while trying to return mem cached data
[Thu Oct 07 10:17:46 2010] [error] (620018)APR does not understand this error code: cache: error returned while trying to return mem cached data
[Thu Oct 07 11:26:11 2010] [error] (620018)APR does not understand this error code: cache: error returned while trying to return mem cached data
[Thu Oct 07 11:26:29 2010] [error] (620018)APR does not understand this error code: cache: error returned while trying to return mem cached data
[Thu Oct 07 11:39:20 2010] [error] (620018)APR does not understand this error code: cache: error returned while trying to return mem cached data
Comment 2 Keith Mashinter 2010-10-08 19:50:47 UTC
I my Apache/2.2.16 (Win32) configuration, however, I'm not using mod_security.  I'm using Apache mod_proxy as an HTTP proxy/cache to a Tomcat 5.5.30 server.
Comment 3 Bill Chipman 2012-04-11 22:42:23 UTC
We are using Apache/2.2.12 (Win32) at several client sites. We also do not use mod-security. Our clients are experiencing blank replies or replies associated with a different request when we enable mod-cache. Mod-cache is now turned off and we will not be able to enable it until there is a resolution. 
I'm using Apache mod_proxy as an HTTP reverse proxy/cache to a Zope 2.12 set of server nodes. We are also using SSL off-load in our configuration.
Comment 4 Anthony Gerrard 2012-06-19 07:11:04 UTC
We're also experiencing many hundreds of occurrences of this error a month.  We're using mod_proxy to reverse proxy onto 2 Zope origin servers via Haproxy and cache the response using mod_cache.

Each "Software caused connection abort" error in the error logs corresponds to a line in the access log with a status code of 103.

Cross referencing the apache access logs with the haproxy ones it looks like the error usually, if not exclusively occurs when the request is being served from the cache.
Comment 5 patrick.gasior 2012-08-08 19:44:01 UTC
Also, for every line we see the cache error message there is also /var/log/messages, I see the following:

   Jul 26 14:01:54 lnxvmdmzwebp05 kernel: mod_cache.so[1041]: segfault at 0000000000000001 rip 0000000000000001 rsp 00007fffee881848 error 14
Comment 6 Jeff Trawick 2012-08-08 19:51:11 UTC
Anyone with httpd child process crashes should try to get backtraces.  Here's some doc for Unix:
http://httpd.apache.org/dev/debugging.html#crashes
Comment 7 Lawrence 2016-11-21 05:09:17 UTC
does anybody has this 103 error code even only Mod_cache is enable ? I have seen a lot of error log in below within error_log
[Sun Nov 20 22:51:36 2016] [error] (103)Software caused connection abort: cache: error returned while trying to return disk cached data



let me know whether the new verision fixed this or not?
Comment 8 Jim Jagielski 2016-11-22 20:25:40 UTC
It would be good to know what the interaction w/ mod_security is and if the bug exists actually in the httpd codebase or not.
Comment 9 christian.folini 2016-11-23 05:15:18 UTC
Thanks for picking this up Jim. I have not seen the bug in years. Apache went from 2.2 to 2.4 and ModSec from 2.5 to 2.9. I can not really tell if it is still around.
Comment 10 Lawrence 2016-11-23 15:39:26 UTC
Created attachment 34470 [details]
Apache configuration

when using the cache enable configuration, the 103 error code come very often
Comment 11 Lawrence 2016-11-23 15:40:54 UTC
Created attachment 34471 [details]
a lot of 103 coming in the error-log

please share it is relative to the client side issues or server side as well ?
Comment 12 Lawrence 2016-11-23 15:41:29 UTC
both error log and configuration are uploaded now. please help to check
Comment 13 William A. Rowe Jr. 2018-11-07 21:08:51 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.