You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Raphaël Droz <ra...@gmail.com> on 2016/06/06 03:30:34 UTC
Re: [users@httpd] AW: mod_cache/mod_cache_disk responses missing
Content-Type header
On Mon, Dec 21, 2015 at 04:25:46PM +0000, Alexander Hrtig wrote:
> By taking a closer look at the log-files I found a lot error entries with the following message:
> AH00717: Premature end of cache headers.
> I tried to google but I couldn't find anything about what causes these problems. I'm not even sure which headers are meant in this context, cache entry header or request header?
I just probably stumbled upon the very same issue.
The issue arise when a POST was issued on an URL (for which GET would be
cached).
The first POST seems fine, but the second one isn't.
See log below (Apache 2.4.10-10+deb8u4)
(I'm simply POSTing x=y)
## FIRST POST on /
> [Mon Jun 06 05:13:26.861453 2016] [cache:debug] [pid 25898:tid 139847851255552] mod_cache.c(440): [client x.x.x.x:49398] AH02463: PUT/POST/DELETE: Adding CACHE_INVALIDATE filter for /index.php
> [Mon Jun 06 05:13:27.202134 2016] [cache:debug] [pid 25898:tid 139847851255552] mod_cache.c(1731): [client x.x.x.x:49398] AH00777: cache: CACHE filter was added twice, or was added where the cache has been bypassed and will be ignored: /
> [Mon Jun 06 05:13:27.202225 2016] [cache:debug] [pid 25898:tid 139847851255552] mod_cache.c(1677): [client x.x.x.x:49398] AH02467: cache: Invalidating all cached entities in response to 'POST' request for /index.php
> [Mon Jun 06 05:13:27.202246 2016] [cache:debug] [pid 25898:tid 139847851255552] cache_storage.c(664): [client x.x.x.x:49398] AH00698: cache: Key for entity /index.php?(null) is http://mywebsite.test:80/index.php?
> [Mon Jun 06 05:13:27.202356 2016] [cache_disk:debug] [pid 25898:tid 139847851255552] mod_cache_disk.c(572): [client x.x.x.x:49398] AH00709: Recalled cached URL info header http://mywebsite.test:80/index.php?
> [Mon Jun 06 05:13:27.202368 2016] [cache_disk:debug] [pid 25898:tid 139847851255552] mod_cache_disk.c(885): [client x.x.x.x:49398] AH00720: Recalled headers for URL http://mywebsite.test:80/index.php?
> [Mon Jun 06 05:13:27.202545 2016] [cache_disk:debug] [pid 25898:tid 139847851255552] mod_cache_disk.c(1350): [client x.x.x.x:49398] AH00737: commit_entity: Headers and body for URL http://mywebsite.test:80/index.php? cached.
> [Mon Jun 06 05:13:27.202559 2016] [cache:debug] [pid 25898:tid 139847851255552] cache_storage.c(752): [client x.x.x.x:49398] AH02468: cache: Attempted to invalidate cached entity with key: http://mywebsite.test:80/index.php?
## SECOND POST on /
> [Mon Jun 06 05:13:40.044414 2016] [cache:debug] [pid 25899:tid 139847842862848] mod_cache.c(440): [client x.x.x.x:49402] AH02463: PUT/POST/DELETE: Adding CACHE_INVALIDATE filter for /index.php
> [Mon Jun 06 05:13:40.283025 2016] [cache:debug] [pid 25899:tid 139847842862848] mod_cache.c(1731): [client x.x.x.x:49402] AH00777: cache: CACHE filter was added twice, or was added where the cache has been bypassed and will be ignored: /
> [Mon Jun 06 05:13:40.283099 2016] [cache:debug] [pid 25899:tid 139847842862848] mod_cache.c(1677): [client x.x.x.x:49402] AH02467: cache: Invalidating all cached entities in response to 'POST' request for /index.php
> [Mon Jun 06 05:13:40.283125 2016] [cache:debug] [pid 25899:tid 139847842862848] cache_storage.c(664): [client x.x.x.x:49402] AH00698: cache: Key for entity /index.php?(null) is http://mywebsite.test:80/index.php?
> [Mon Jun 06 05:13:40.283183 2016] [cache_disk:debug] [pid 25899:tid 139847842862848] mod_cache_disk.c(572): [client x.x.x.x:49402] AH00709: Recalled cached URL info header http://mywebsite.test:80/index.php?
> [Mon Jun 06 05:13:40.283189 2016] [cache_disk:error] [pid 25899:tid 139847842862848] [client x.x.x.x:49402] AH00717: Premature end of cache headers.
> [Mon Jun 06 05:13:40.283201 2016] [cache_disk:error] [pid 25899:tid 139847842862848] [client x.x.x.x:49402] AH00717: Premature end of cache headers.
> [Mon Jun 06 05:13:40.283204 2016] [cache_disk:debug] [pid 25899:tid 139847842862848] mod_cache_disk.c(885): [client x.x.x.x:49402] AH00720: Recalled headers for URL http://mywebsite.test:80/index.php?
> [Mon Jun 06 05:13:40.283304 2016] [cache_disk:debug] [pid 25899:tid 139847842862848] mod_cache_disk.c(1350): [client x.x.x.x:49402] AH00737: commit_entity: Headers and body for URL http://mywebsite.test:80/index.php? cached.
> [Mon Jun 06 05:13:40.283311 2016] [cache:debug] [pid 25899:tid 139847842862848] cache_storage.c(752): [client x.x.x.x:49402] AH02468: cache: Attempted to invalidate cached entity with key: http://mywebsite.test:80/index.php?
Here are two samples responses of :
### (cached) GET /
> 200 OK
> Cache-Control: public, max-age=300
> Connection: close
> Date: Mon, 06 Jun 2016 03:22:54 GMT
> Age: 6
> Server: Apache/2.4
> Vary: Cookie,Accept-Encoding
> Content-Length: 35658
> Content-Type: text/html; charset=UTF-8
> Last-Modified: Sun, 03 Apr 2016 16:21:51 GMT
> Client-Date: Mon, 06 Jun 2016 03:23:03 GMT
> Client-Peer: x.x.x.x:80
> Client-Response-Num: 1
### (non-cached) POST /
> 200 OK
> Cache-Control: public, max-age=300
> Connection: close
> Date: Mon, 06 Jun 2016 03:24:42 GMT
> Server: Apache/2.4
> Vary: Cookie,Accept-Encoding
> Content-Type: text/html; charset=UTF-8
> Last-Modified: Sun, 03 Apr 2016 16:21:51 GMT
> Client-Date: Mon, 06 Jun 2016 03:24:51 GMT
> Client-Peer: x.x.x.x:80
> Client-Response-Num: 1
> Client-Transfer-Encoding: chunked
It lets me realize one (related or not?) issue: webapp should not issue
Cache-Control for POST requests.
hope this help tracking this down
best regards
--
GPG id: 0xF41572CEBD4218F4
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org