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@xxxxxxxxxxxxxxxx For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx
|