| Summary: | AH00717: Premature end of cache headers | ||
|---|---|---|---|
| Product: | Apache httpd-2 | Reporter: | Raphaël Droz <raphael.droz> |
| Component: | mod_cache | Assignee: | Apache HTTPD Bugs Mailing List <bugs> |
| Status: | NEW --- | ||
| Severity: | normal | CC: | minfrin |
| Priority: | P2 | ||
| Version: | 2.4.10 | ||
| Target Milestone: | --- | ||
| Hardware: | PC | ||
| OS: | Linux | ||
| Attachments: |
entity headers file after a GET
entity headers file after a POST |
||
|
Description
Raphaël Droz
2016-06-23 00:18:38 UTC
Created attachment 33976 [details]
entity headers file after a POST
The bug also happens in Centos 7, fully updated on Apache 2.4.6. Oct 10 14:33:29 xxxx httpd[9828]: [cache_disk:error] [pid 9828:tid 140256116471552] [client 127.0.0.1:35658] AH00717: Premature end of cache headers. The bug is triggered when a cached GET is followed by two POSTs to the same URL. For example: curl -i -X GET https://example.com/javascript/server2.php => OK curl -i -X POST https://example.com/javascript/server2.php => OK but not cached curl -i -X POST https://example.com/javascript/server2.php => bug is triggered. The second POST generates two error messages. I see this error in some of the tests on cache-tests.fyi; mostly around updating a response with a 304. Apache abruptly closes the connection when this happens, leading to a user-visible error, so it might be worth prioritising. I'm using apache-2.4.53 and I'm still having problems with caching. Perodically I see errors related to "premature end of cache headers" and don't know how to troubleshoot it. This is on fedora34. The site is using Cloudflare. This is with loglevel cache_disk:trace3
[Wed Jul 06 04:23:49.577237 2022] [cache_disk:error] [pid 3202400:tid 3202451] (70014)End of file found: [client 162.158.190.138:47866] AH00717: Premature end of cache headers.
[Wed Jul 06 04:23:49.577247 2022] [cache_disk:debug] [pid 3202400:tid 3202451] mod_cache_disk.c(883): [client 162.158.190.138:47866] AH02987: Error reading response headers from /var/cache/httpd/W_@/Ro6/7ihAG5M_Eyw0t7jA.header.vary/@Iu/98u/9@ot3lTARaKl3p8g.header for https://example.com:443/index.php?
The 162.158.190.138 is a cloudflare address.
I don't know how to reproduce it. Where do I start to look?
I can correlate the lines from the error_log with the access_log based on time, but I can't be sure they're directly related. There were three requests during that same second, all of which were bots. One was a 200, one was a 301 and one was a 404 for a file that was never there.
The file the error_log references is there on the filesystem:
find . -name \*7ihAG5M_Eyw0t7jA\*
./W_@/Ro6/7ihAG5M_Eyw0t7jA.header.vary
./W_@/Ro6/7ihAG5M_Eyw0t7jA.header
Here are the cache options from the virtual host config:
CacheQuickHandler off
CacheLock on
CacheLockPath /tmp/mod_cache-lock
CacheLockMaxAge 5
CacheIgnoreHeaders Set-Cookie
CacheRoot "/var/cache/httpd"
# Enable the X-Cache-Detail header
CacheDetailHeader on
CacheEnable disk "/"
CacheHeader on
CacheDefaultExpire 800
CacheMaxExpire 64000
CacheIgnoreNoLastMod On
CacheDirLevels 2
CacheDirLength 3
I also notice the cache directory (/var/cache/httpd) grows boundlessly. At one time htcacheclean was running from systemd, but that doesn't look to be the case any longer.
Should I be investigating the HTTP cache control headers? Is that related or helpful?
Are there any updates on this? I'm now using fedora37 with httpd-2.4.54 and still having the same problems. [Tue Nov 29 11:37:00.966090 2022] [cache_disk:error] [pid 201098:tid 201129] (70014)End of file found: [client 172.70.210.214:62758] AH00717: Premature end of cache headers., referer: https://example.com/news Is it possible that it's related to cloudflare caching? How do we troubleshoot this? We observe the same errors in our Apache logs when our site is under heavy load. These missing headers seem to have our users see the HTML code in their browser instead of the rendered page. It's a bit annoying. We have no idea how it could be fixed sadly. Any help will be greatly appreciated. |