You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "Aaron McClimont (JIRA)" <ji...@apache.org> on 2016/05/31 03:22:12 UTC
[jira] [Commented] (TS-2961) Expires: 0 and Expires: past date
being temporarily cached
[ https://issues.apache.org/jira/browse/TS-2961?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15307146#comment-15307146 ]
Aaron McClimont commented on TS-2961:
-------------------------------------
We have been affected by this issue in real-world usage with ATS release 5.3.0 ... with quite undesirable consequences.
As above, we have also reproduced this issue in our test environment using the following:
Test Servlet Code:
{code:title=CacheCheckServlet.java}
...
protected void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {
response.setContentType("text/plain;charset=UTF-8");
response.setDateHeader("Expires", 0);
PrintWriter out = response.getWriter();
Date date = new Date();
Random random = new Random();
out.println(date.getTime() + "/" + random.nextInt());
out.flush();
}
...
{code}
Remap Config:
{code:title=remap.config}
map http://localhost/net_cachecheck http://127.0.0.1:8080/net_cachecheck
{code}
Using curl to request the content in quick succession returns the same cached response:
{code}
curl http://localhost/net_cachecheck && curl http://localhost/net_cachecheck
1464662597569/-323430243
1464662597569/-323430243
{code}
ATS Log Entries:
{code}
1464664418.035 3 127.0.0.1 TCP_REFRESH_MISS/200 245 GET http://127.0.0.1:8080/net_cachecheck - DIRECT/127.0.0.1 text/plain ats.testenvironment
1464664418.038 0 127.0.0.1 TCP_HIT/200 226 GET http://127.0.0.1:8080/net_cachecheck - NONE/- text/plain ats.testenvironment
{code}
Introducing a delay in between the requests returns different responses:
{code}
curl http://localhost/net_cachecheck && sleep 1 && curl http://localhost/net_cachecheck
1464662592336/-452418895
1464662593342/-1229787307
{code}
ATS Log Entries:
{code}
1464664446.684 2 127.0.0.1 TCP_REFRESH_MISS/200 244 GET http://127.0.0.1:8080/net_cachecheck - DIRECT/127.0.0.1 text/plain ats.testenvironment
1464664447.692 2 127.0.0.1 TCP_REFRESH_MISS/200 246 GET http://127.0.0.1:8080/net_cachecheck - DIRECT/127.0.0.1 text/plain ats.testenvironment
{code}
It appears as if there is no "expired" check being performed prior to the object reaching the cache... but rather the object is allowed to reach the cache, where it is temporarily retrievable, prior to any expired check being performed.
Is this issue known to be resolved in a newer release?
> Expires: 0 and Expires: past date being temporarily cached
> ----------------------------------------------------------
>
> Key: TS-2961
> URL: https://issues.apache.org/jira/browse/TS-2961
> Project: Traffic Server
> Issue Type: Bug
> Components: HTTP
> Affects Versions: 5.0.1
> Reporter: Nick Muerdter
> Priority: Minor
> Fix For: sometime
>
>
> While doing some integration testing with TrafficServer, I noticed some seemingly odd behavior: If my origin server returns "{{Expires: 0}}" or "{{Expires: SOME_PAST_DATE}}" headers, TrafficServer appears to cache these responses for about 1 second. This would seem to run counter to the [documentation|https://docs.trafficserver.apache.org/en/latest/admin/http-proxy-caching.en.html?highlight=expires#origin-server-directives]:
> {quote}
> By default, Traffic Server does not cache objects with the following response headers:
> - Expires: header with value of 0 (zero) or a past date
> {quote}
> I was able to reproduce this with a stock TrafficServer 5.0.1 installation pointing at an origin server that returns a random, unique output on each call. If the origin server returns a "{{Expires: 0}}" or "{{Expires: SOME_PAST_DATE}}" header, then TrafficServer appears to cache the first response briefly (around 1 second).
> I do not experience this same temporary cache when testing the other scenarios outlined in the documentation of what's not cached (for example, when the origin server responds with "{{Cache-Control: no-store}}" or "{{Set-Cookie}}").
> This isn't a huge deal for my use case personally, but the behavior I'm seeing does seem to run counter to the documentation, so I thought it was a bit odd.
> Here's some details demonstrating the cached response when requests are made in quick succession:
> {code}
> $ curl -v "http://localhost:8081/cacheable-expires-0/1" && curl -v "http://localhost:8081/cacheable-expires-0/1"
> * About to connect() to localhost port 8081 (#0)
> * Trying ::1... Connection refused
> * Trying 127.0.0.1... connected
> * Connected to localhost (127.0.0.1) port 8081 (#0)
> > GET /cacheable-expires-0/1 HTTP/1.1
> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> > Host: localhost:8081
> > Accept: */*
> >
> < HTTP/1.1 200 OK
> < X-Powered-By: Express
> < Expires: 0
> < Date: Mon, 28 Jul 2014 01:49:45 GMT
> < Age: 0
> < Transfer-Encoding: chunked
> < Connection: keep-alive
> < Server: ATS/5.0.1
> <
> * Connection #0 to host localhost left intact
> * Closing connection #0
> 36780-926573328-0.49593452527187765
> * About to connect() to localhost port 8081 (#0)
> * Trying ::1... Connection refused
> * Trying 127.0.0.1... connected
> * Connected to localhost (127.0.0.1) port 8081 (#0)
> > GET /cacheable-expires-0/1 HTTP/1.1
> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> > Host: localhost:8081
> > Accept: */*
> >
> < HTTP/1.1 200 OK
> < X-Powered-By: Express
> < Expires: 0
> < Date: Mon, 28 Jul 2014 01:49:45 GMT
> < Age: 0
> < Content-Length: 35
> < Connection: keep-alive
> < Server: ATS/5.0.1
> <
> * Connection #0 to host localhost left intact
> * Closing connection #0
> 36780-926573328-0.49593452527187765
> {code}
> In this case, the origin server only gets called once (note the response bodies are identical, which should not be happening since the origin is returning a unique response body on each call). If I add in a sleep of around 0.8 seconds between calls, then TrafficServer's cached copy appears to go away:
> {code}
> $ curl -v "http://localhost:8081/cacheable-expires-0/1" && sleep 0.8 && curl -v "http://localhost:8081/cacheable-expires-0/1"
> * About to connect() to localhost port 8081 (#0)
> * Trying ::1... Connection refused
> * Trying 127.0.0.1... connected
> * Connected to localhost (127.0.0.1) port 8081 (#0)
> > GET /cacheable-expires-0/1 HTTP/1.1
> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> > Host: localhost:8081
> > Accept: */*
> >
> < HTTP/1.1 200 OK
> < X-Powered-By: Express
> < Expires: 0
> < Date: Mon, 28 Jul 2014 01:51:16 GMT
> < Age: 0
> < Transfer-Encoding: chunked
> < Connection: keep-alive
> < Server: ATS/5.0.1
> <
> * Connection #0 to host localhost left intact
> * Closing connection #0
> 36871-310090571-0.9994140579365194
> * About to connect() to localhost port 8081 (#0)
> * Trying ::1... Connection refused
> * Trying 127.0.0.1... connected
> * Connected to localhost (127.0.0.1) port 8081 (#0)
> > GET /cacheable-expires-0/1 HTTP/1.1
> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> > Host: localhost:8081
> > Accept: */*
> >
> < HTTP/1.1 200 OK
> < X-Powered-By: Express
> < Expires: 0
> < Date: Mon, 28 Jul 2014 01:51:17 GMT
> < Age: 0
> < Transfer-Encoding: chunked
> < Connection: keep-alive
> < Server: ATS/5.0.1
> <
> * Connection #0 to host localhost left intact
> * Closing connection #0
> 36872-119374632-0.23531207791529596
> {code}
> With this sleep then the origin server is hit twice (note the response bodies differ indicating the origin server actually was hit twice).
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)