You are viewing a plain text version of this content. The canonical link for it is here.
Posted to bugs@httpd.apache.org by bu...@apache.org on 2016/06/23 00:18:38 UTC

[Bug 59744] New: AH00717: Premature end of cache headers

https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

            Bug ID: 59744
           Summary: AH00717: Premature end of cache headers
           Product: Apache httpd-2
           Version: 2.4.10
          Hardware: PC
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: P2
         Component: mod_cache
          Assignee: bugs@httpd.apache.org
          Reporter: raphael.droz@gmail.com

Created attachment 33975
  --> https://bz.apache.org/bugzilla/attachment.cgi?id=33975&action=edit
entity headers file after a GET

Every once in a while I can see this error message popping-up in my logs:
> AH00717: Premature end of cache headers
So far I didn't see actual "bad" consequences other than the error message
itself.

To reproduce it, it's enough to
POST twice to an already cached resource.

More information and guesses in this thread:
https://mail-archives.apache.org/mod_mbox/httpd-users/201606.mbox/%3C20160608171923.GA6425@debovo.drzraf.me%3E

Current best guess is that the first POST creates an invalid entity on which
second POST hurts.
Background: When mod_cache is used, POST are expected to be ignored.
Since this commit:
https://github.com/apache/httpd/commit/dea98c9bf110c149e7e0af381221ba09fdc52d0c
This hunk was introduced:
> "PUT/POST/DELETE: Adding CACHE_INVALIDATE filter
although I couldn't spot more precisely what could be wrong.


Attached are the entity header file after a GET request, and then after the
(cache invalidating) POST request.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

--- Comment #5 from Alex Regan <my...@gmail.com> ---
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?

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

--- Comment #1 from Raphaël Droz <ra...@gmail.com> ---
Created attachment 33976
  --> https://bz.apache.org/bugzilla/attachment.cgi?id=33976&action=edit
entity headers file after a POST

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

--- Comment #3 from Mark Nottingham <mn...@mnot.net> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

--- Comment #2 from Breno Fernandes <br...@tembosocial.com> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

--- Comment #4 from Alex Regan <my...@gmail.com> ---
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?

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

Raphaël Droz <ra...@gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |minfrin@apache.org

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 59744] AH00717: Premature end of cache headers

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=59744

--- Comment #6 from MASUREL Francois <f....@gmail.com> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org