Bug 1094990

Summary: Possible error in mod_cache's "Avoiding the Thundering Herd"
Product: Red Hat Enterprise Linux 6 Reporter: Coty Sutherland <csutherl>
Component: httpdAssignee: Luboš Uhliarik <luhliari>
Status: CLOSED ERRATA QA Contact: Ondřej Pták <optak>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.5CC: iweiss, jkaluza, jorton, macbogucki, optak, pwall
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: httpd-2.2.15-36.el6 Doc Type: Bug Fix
Doc Text:
Cause: There was a race condition between removing and renaming cached file in mod_cache. There was also problem with cache hash generation consistency when the Range requests have been handled. Consequence: mod_cache could pass multiple requests to the backend server to refresh the cache instead of single request. Fix: Race conditions have been fixed and cache object's hashes are now generated consistently even when Range requests are handled. Result: mod_cache now passes only single request to backend when refreshing the cache.
 Story Points: ---
Clone Of:
: 1269550 1828903 (view as bug list) Environment:
Last Closed: 2014-10-14 08:09:06 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1269550    
Attachments:
Description Flags
reproducer configuration none

Description Coty Sutherland 2014-05-06 21:32:06 UTC 
Description of problem:
mod_cache in Apache 2.2 has a feature, "Avoiding the Thundering Herd"
(http://httpd.apache.org/docs/2.2/mod/mod_cache.html#thunderingherd),
which allows httpd to serve stale content while the page is re-validating. That feature doesn't seem to be working.

Version-Release number of selected component (if applicable):
httpd-2.2.15-30.el6_5.x86_64

How reproducible:
Every time when following the steps below. It takes specific modules in use together.

Steps to Reproduce:
1. Install httpd and Tomcat to proxy to. I used the sample/hello.jsp as an endpoint.
2. Configure it with the attached virtual host in the httpd.conf-bad configuration.
3. Use ab to benchmark test which will cause it to cache whatever content you hit.

ab -k -c 2 -t 30 http://host/url

4. Monitor the error_log to see that it is caching content multiple times a second. Example:

[Tue May 06 21:02:07 2014] [debug] mod_cache.c(765): cache: Caching url: /tc/sample/hello.jsp
....
[Tue May 06 21:02:07 2014] [debug] mod_cache.c(765): cache: Caching url: /tc/sample/hello.jsp


Actual results:
The content is cached multiple times.

Expected results:
Content should be cached once, then the cache should be locked so that it does not get cached again at the same time.

Additional info:
This is already logged against upstream 2.2.27 in the attached ASF bug.
Comment 2 Coty Sutherland 2014-05-06 21:36:14 UTC 
Created attachment 893015 [details]
reproducer configuration
Comment 18 Ondřej Pták 2014-09-15 14:06:56 UTC 
httpd-2.2.15-29.el6
===================
:: [   PASS   ] :: Downloading test.jsp (Expected 0, got 0)
:: [   PASS   ] :: File 'test.jsp' should contain '>Hello World!<' 
:: [   PASS   ] :: Downloading test page multiple times with ab tool (Expected 0, got 0)
:: [   PASS   ] :: Command 'sleep 20;killall ab' (Expected 0, got 0)
:: [   FAIL   ] :: Checking for duplicit info about caching in httpd log (Expected 1, got 0)
:: [   FAIL   ] :: Checking for duplicit info about caching in tomcat log (Expected 1, got 0)
:: [   PASS   ] :: File '/var/log/httpd/my_error_log' should not contain 'Permission denied' 


httpd-2.2.15-38.el6
===================
:: [   PASS   ] :: Downloading test.jsp (Expected 0, got 0)
:: [   PASS   ] :: File 'test.jsp' should contain '>Hello World!<' 
:: [   PASS   ] :: Downloading test page multiple times with ab tool (Expected 0, got 0)
:: [   PASS   ] :: Command 'sleep 20;killall ab' (Expected 0, got 0)
:: [   PASS   ] :: Checking for duplicit info about caching in httpd log (Expected 1, got 1)
:: [   PASS   ] :: Checking for duplicit info about caching in tomcat log (Expected 1, got 1)
:: [   PASS   ] :: File '/var/log/httpd/my_error_log' should not contain 'Permission denied'
Comment 19 Paweł Wall 2014-09-16 06:59:07 UTC 
I still see the problem with mod_cache
It's better after I instaled apache upgrade httpd-2.2.15-39
When i have page in cache i have one response to tomcat server
The problem occurs if the cache is empty
 
The content is cached multiple times.

I instaled lasted version apache
[root@pol-ivmx-gpi-www1 ~]# rpm -qa | grep httpd
httpd-tools-2.2.15-39.el6.x86_64
httpd-devel-2.2.15-39.el6.x86_64
httpd-2.2.15-39.el6.x86_64
httpd-manual-2.2.15-39.el6.noarch
[root@pol-ivmx-gpi-www1 ~]# rpm -qa | grep mod_ssl
mod_ssl-2.2.15-39.el6.x86_64

My httpd.conf file
----------------------------------
<Virtualhost *:80>
...
    CacheRoot /tmp/cache
    CacheEnable disk /
    CacheDisable /gpi-theme/
    CacheMinFileSize 0
    CacheMaxFileSize 1048576
    CacheDirLevels 2
    CacheDirLength 2
    CacheLock on
    CacheLockPath /tmp/mod_cache-lock
    CacheLockMaxAge 5
    CacheIgnoreHeaders ETag Set-Cookie
    Header unset Expires
    Header unset Cache-Control
    Header always set Cache-Control "max-age=30,stale-while-revalidate=15"
</Vitualhost>
-------------------------------------
Permision to directory /tmp/mod_cache-lock and /tmp/cache
drwxr-xr-x   4 apache apache    4096 09-03 13:23 cache
drwx------   9 apache apache    4096 09-03 10:47 mod_cache-lock

First i clear web_cache

[root@pol-ivmx-gpi-www1 tmp]# rm -rf /tmp/cache/* /tmp/mod_cache-lock/*
[root@pol-ivmx-gpi-www1 tmp]# service httpd restart
Zatrzymywanie httpd:                                       [  OK  ]
Uruchamianie httpd:                                        [  OK  ]

How to generate error with mod_cache?

On apache web serwer run ApacheBench
/usr/bin/ab -k -c 5 -n 100000 http://ivmx-gpi.tge.pl/pl/moce-wytworcze

On apache server error_log i see

[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(162): Adding CACHE_SAVE filter for /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(169): Adding CACHE_REMOVE_URL filter for /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(184): (17)File exists: Cache locked for url, not caching response: /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2396): proxy: AJP: backend socket is disconnected.
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2460): proxy: AJP: fam 2 socket created to connect to pol-ivmx-gpi-app1
[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(184): (17)File exists: Cache locked for url, not caching response: /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2396): proxy: AJP: backend socket is disconnected.
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2460): proxy: AJP: fam 2 socket created to connect to pol-ivmx-gpi-app1
[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(184): (17)File exists: Cache locked for url, not caching response: /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2396): proxy: AJP: backend socket is disconnected.
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2460): proxy: AJP: fam 2 socket created to connect to pol-ivmx-gpi-app1
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(184): (17)File exists: Cache locked for url, not caching response: /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2396): proxy: AJP: backend socket is disconnected.
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2460): proxy: AJP: fam 2 socket created to connect to pol-ivmx-gpi-app1
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 04
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 04
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(516): ajp_unmarshal_response: status = 200
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(537): ajp_unmarshal_response: Number of headers is = 7
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[0] [Set-Cookie] = [JSESSIONID=F9B3452C898A4E7FA40D6517CDB26CA6.gpi-app1; Path=/; HttpOnly]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[1] [Set-Cookie] = [COOKIE_SUPPORT=true; Expires=Thu, 03-Sep-2015 12:18:24 GMT; Path=/]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[2] [Liferay-Portal] = [Liferay Portal Community Edition 6.1.1 CE GA2 (Paton / Build 6101 / July 31, 2012)]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[3] [ETag] = ["82371ff2"]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[4] [Set-Cookie] = [COOKIE_SUPPORT=true; Expires=Thu, 03-Sep-2015 12:18:24 GMT; Path=/]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[5] [Content-Type] = [text/html;charset=UTF-8]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(609): ajp_unmarshal_response: ap_set_content_type done
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[6] [Content-Length] = [48943]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] mod_headers.c(743): headers: ap_headers_output_filter()
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 05
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(697): ajp_parse_type: got 05
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(616): proxy: got response from 192.168.92.152:8009 (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2044): proxy: AJP: has released connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] mod_cache.c(184): (17)File exists: Cache locked for url, not caching response: /pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:24 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:24 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 04
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 04
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(516): ajp_unmarshal_response: status = 200
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(537): ajp_unmarshal_response: Number of headers is = 7
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[0] [Set-Cookie] = [JSESSIONID=0628F13F06E0DA2148AD634195B86FE6.gpi-app1; Path=/; HttpOnly]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[1] [Set-Cookie] = [COOKIE_SUPPORT=true; Expires=Thu, 03-Sep-2015 12:18:24 GMT; Path=/]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[2] [Liferay-Portal] = [Liferay Portal Community Edition 6.1.1 CE GA2 (Paton / Build 6101 / July 31, 2012)]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[3] [ETag] = ["277f6886"]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[4] [Set-Cookie] = [COOKIE_SUPPORT=true; Expires=Thu, 03-Sep-2015 12:18:25 GMT; Path=/]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[5] [Content-Type] = [text/html;charset=UTF-8]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(609): ajp_unmarshal_response: ap_set_content_type done
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[6] [Content-Length] = [48943]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] mod_headers.c(743): headers: ap_headers_output_filter()
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 05
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 05
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(616): proxy: got response from 192.168.92.152:8009 (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:25 2014] [debug] proxy_util.c(2044): proxy: AJP: has released connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(184): (17)File exists: Cache locked for url, not caching response: /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(45): proxy: AJP: canonicalising URL //pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] proxy_util.c(1521): [client 192.168.92.150] proxy: ajp: found worker ajp://pol-ivmx-gpi-app1:8009/ for ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy.c(1020): Running scheme ajp handler (attempt 0)
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_http.c(1957): proxy: HTTP: declining URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(709): proxy: AJP: serving URL ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] proxy_util.c(2026): proxy: AJP: has acquired connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:25 2014] [debug] proxy_util.c(2082): proxy: connecting ajp://pol-ivmx-gpi-app1:8009/pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:25 2014] [debug] proxy_util.c(2209): proxy: connected /pl/moce-wytworcze to pol-ivmx-gpi-app1:8009
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(224): Into ajp_marshal_into_msgb
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[0] [Connection] = [Keep-Alive]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[1] [Host] = [ivmx-gpi.tge.pl]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[2] [User-Agent] = [ApacheBench/2.3]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(290): ajp_marshal_into_msgb: Header[3] [Accept] = [*/*]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(450): ajp_marshal_into_msgb: Done
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(269): proxy: APR_BUCKET_IS_EOS
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(274): proxy: data to read (max 8186 at 4)
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(289): proxy: got 0 bytes of data
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 04
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 04
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(516): ajp_unmarshal_response: status = 200
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(537): ajp_unmarshal_response: Number of headers is = 7
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[0] [Set-Cookie] = [JSESSIONID=D79950CE820FFBDD2013FE28DBAEA700.gpi-app1; Path=/; HttpOnly]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[1] [Set-Cookie] = [COOKIE_SUPPORT=true; Expires=Thu, 03-Sep-2015 12:18:24 GMT; Path=/]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[2] [Liferay-Portal] = [Liferay Portal Community Edition 6.1.1 CE GA2 (Paton / Build 6101 / July 31, 2012)]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[3] [ETag] = ["f82a16fe"]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[4] [Set-Cookie] = [COOKIE_SUPPORT=true; Expires=Thu, 03-Sep-2015 12:18:25 GMT; Path=/]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[5] [Content-Type] = [text/html;charset=UTF-8]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(609): ajp_unmarshal_response: ap_set_content_type done
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(599): ajp_unmarshal_response: Header[6] [Content-Length] = [48943]
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] mod_headers.c(743): headers: ap_headers_output_filter()
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(786): cache: Caching url: /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(792): cache: Removing CACHE_REMOVE_URL filter.
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(976): disk_cache: Stored headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 03
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(687): ajp_read_header: ajp_ilink_received 05
[Wed Sep 03 14:18:25 2014] [debug] ajp_header.c(697): ajp_parse_type: got 05
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(1078): disk_cache: Body for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze? cached.
[Wed Sep 03 14:18:25 2014] [debug] mod_proxy_ajp.c(616): proxy: got response from 192.168.92.152:8009 (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:25 2014] [debug] proxy_util.c(2044): proxy: AJP: has released connection for (pol-ivmx-gpi-app1)
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(319): cache: running CACHE_OUT filter
[Wed Sep 03 14:18:25 2014] [debug] mod_cache.c(333): cache: serving /pl/moce-wytworcze
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(493): disk_cache: Recalled cached URL info header http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?
[Wed Sep 03 14:18:25 2014] [debug] mod_disk_cache.c(766): disk_cache: Recalled headers for URL http://ivmx-gpi.tge.pl:80/pl/moce-wytworcze?


On tomcat server log i see multiple response

192.168.92.150 - - [03/Sep/2014:14:18:24 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 F9B3452C898A4E7FA40D6517CDB26CA6.gpi-app1 384 383
192.168.92.150 - - [03/Sep/2014:14:18:25 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 0628F13F06E0DA2148AD634195B86FE6.gpi-app1 523 523
192.168.92.150 - - [03/Sep/2014:14:18:25 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 D79950CE820FFBDD2013FE28DBAEA700.gpi-app1 546 545
192.168.92.150 - - [03/Sep/2014:14:18:25 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 4B1BD068CE1D7B4B22DE308BA128E5DE.gpi-app1 582 581
192.168.92.150 - - [03/Sep/2014:14:18:25 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 383DF12338D52317F7EC95C11EB7EFDA.gpi-app1 596 595
192.168.92.150 - - [03/Sep/2014:14:18:25 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 D5087431578A45C447443D360886E08E.gpi-app1 305 304
192.168.92.150 - - [03/Sep/2014:14:18:25 +0200] "GET /pl/moce-wytworcze HTTP/1.0" 200 48943 508CC4C2AB6BF0B25D822B517462ADAC.gpi-app1 199 198

When i have this page in cache is OK
i have one response for 30 seconds
192.168.92.150 - - [03/Sep/2014:14:58:07 +0200] "GET /moce-wytworcze HTTP/1.0" 200 48675 B58ED2E0CBE6B0CC2061345130D8723F.gpi-app1 133 132
192.168.92.150 - - [03/Sep/2014:14:58:37 +0200] "GET /moce-wytworcze HTTP/1.0" 200 48675 F3A4E966287A7F883BE8BBEEEDD4B48B.gpi-app1 127 127

The problem occurs if the cache is empty or page not found in the cache
Comment 20 Jan Kaluža 2014-09-16 10:00:29 UTC 
(In reply to Paweł Wall from comment #19)
> I still see the problem with mod_cache
> It's better after I instaled apache upgrade httpd-2.2.15-39
> When i have page in cache i have one response to tomcat server
> The problem occurs if the cache is empty

This is expected and cannot be successfully solved. It is described upstream in "Initial caching of an entry" section of <http://httpd.apache.org/docs/2.2/mod/mod_cache.html#thunderingherd>.

Technically, it cannot be solved because of following reasons:

1. mod_cache does not know if the response will be cached until it receives it for firs time.

2. There are multiple requests sent in the same time handled by multiple processes and it is not possible with the current way how httpd works to synchronize them and send just single request to backend server. The synchronization part of this is done by mod_cache and when the cache is empty, it has to respect previous point 1.
Comment 21 errata-xmlrpc 2014-10-14 08:09:06 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2014-1386.html