httpd-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Raphaël Droz <raphael.d...@gmail.com>
Subject Re: [users@httpd] AW: mod_cache/mod_cache_disk responses missing Content-Type header
Date Mon, 06 Jun 2016 03:30:34 GMT
On Mon, Dec 21, 2015 at 04:25:46PM +0000, Alexander Härtig 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


Mime
View raw message