Stale-while-revalidate plugin bug - origin clock ahead of ATS clock

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Stale-while-revalidate plugin bug - origin clock ahead of ATS clock

ryandurfey

All,

 

We have run into issues with the “stale-while-revalidate” feature.  We have found services where the stale-while-revalidate feature seems to be engaged despite the fact that no “stale-while-revalidate” cache control headers are being specified by the origin.  A sample curl is below which illustrates the max-age=1, and the actual age=23 and the “Warning: 110 Response is stale”.  The via header is decoded below as well and indicates a cache hit.

 

Our engineer realized this was being caused by the origin server clock moving ahead of the cache server clock which caused the freshness calculation to be thrown off.  The left side of the equation was calculated to be negative by the difference in the clocks and therefore be less than the max-age until the time between the two clocks is exceeded.

 

In our opinion this should be considered a bug in the plugin.  The calculation should compare the txn_start date (local ATS date) to the remote date, because the cached date can't be earlier than now().

 

This also brings up another issue. We are running the stale-while-revalidate plugin https://github.com/apache/trafficserver/tree/master/plugins/experimental/stale_while_revalidate , however according to the read.me “THIS PLUGIN IS DEPRECATED IN FAVOR OF CHANGE TO CORE”.  We are trying to figure out where this feature is implemented in the core.  Perhaps it is in a 7.x and we are not there yet.

 

Would love feedback on whether this should be considered a plugin bug worth fixing or if the core has been updated in a later version.

 

Plugin Calculation Code is here: https://github.com/apache/trafficserver/blob/master/plugins/experimental/stale_while_revalidate/stale_while_revalidate.c#L579

 

Freshness Calculation is    (state->txn_start - chi->date) < (chi->max_age + chi->stale_while_revalidate)

 

 

 

Environment

Running ATS6.2.1 at the edge

Running ATS5.3.2 at the mid (in process of upgrading)

 

 

curl 'http://<removed>/chunklist.m3u8' -vo /dev/null

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current

                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 2001:558:fe1c:10::2...

* TCP_NODELAY set

* Connected to <removed>/ (<removed>/) port 80 (#0)

> GET  /chunklist.m3u8 HTTP/1.1

> Host: <removed>/

> User-Agent: curl/7.51.0

> Accept: */*

< HTTP/1.1 200 OK

< Access-Control-Expose-Headers: Date, Server, Content-Type, Content-Length

< Access-Control-Allow-Headers: Content-Type, User-Agent, If-Modified-Since, Cache-Control, Range

< Date: Wed, 24 May 2017 16:00:31 GMT

< Access-Control-Allow-Origin: *

< Access-Control-Allow-Methods: OPTIONS, GET, POST, HEAD

< Content-Type: application/vnd.apple.mpegurl

< Access-Control-Allow-Credentials: true

< Accept-Ranges: bytes

< Server: ATS/6.2.1

< Cache-Control: max-age=1

< Content-Length: 297

< Age: 23

< Via: http/1.1 <mid host removed>/ (ApacheTrafficServer/5.3.2 [uScSsSfUpSeN:t cCSi p sS]), http/1.1 <edge host removed>/ (ApacheTrafficServer/6.2.1 [uScHs f p eN:t cCHi p s ])

< Connection: keep-alive

< Warning: 110 Response is stale

{ [297 bytes data]

* Curl_http_done: called premature == 0

100   297  100   297    0     0  16914      0 --:--:-- --:--:-- --:--:-- 17470

* Connection #0 to host edge.music-choice-vc-chaina2.top.comcast.net left intact

 

Ryan Durfey

 

Loading...