negative_revalidating_lifetime seems not respected

[lukenowak]

Having configuration:

CONFIG proxy.config.http.negative_revalidating_enabled INT 1
CONFIG proxy.config.http.negative_revalidating_lifetime INT 10

I have such scenario:

• with executing GET /test HTTP/1.1 origin replies HTTP/1.1 200 OK with header: Cache-Control: max-age=11, public and some content, I see TCP_MISS/200 in squid.log, I am happy with the reply
• then I configured origin to reply HTTP/1.1 503 Service Unavailable with cache-control: no-cache
• did again GET /test HTTP/1.1, got proper 200 reply from cache, in squid.log I see TCP_REFRESH_MISS/200
• sleep 15 (more then negative_revalidating_lifetime)
• did again GET /test HTTP/1.1, got:
  • surprising 200 reply
  • expected: 503 code from the origin
  • in squid.log I see TCP_REFRESH_MISS/200

It happens with 7.1.11, 8.1.0 and 8.1.1.

Note: Same happens if origin is just down, where I'd expect 5xx code from trafficserver after waiting for enough of time.

[lukenowak]

With:

CONFIG proxy.config.http.negative_revalidating_enabled INT 0

I start to got 503 replies after waiting for max-age time to pass, so it seems generally the behaviour is impacted by enabling that option.

[fdiary]

@lukenowak According to the source code, ATS can return a stale cache if is_stale_cache_response_returnable() returns true, that refers proxy.config.http.cache.max_stale_age but does NOT refer proxy.config.http.negative_revalidating_lifetime.

https://github.com/apache/trafficserver/blob/8.1.1/proxy/http/HttpTransact.cc#L5741

But I am not sure the difference between the purposes of these two variables.

[masaori335]

Descriptions of these configs seem ambiguous when and which config should be used.

• proxy.config.http.cache.max_stale_age

The maximum age allowed for a stale response before it cannot be cached.

• proxy.config.http.negative_revalidating_lifetime

How long, in seconds, to consider a stale cached document valid if proxy.config.http.negative_revalidating_enabled is enabled and Traffic Server receives a negative (5xx only) response from the origin server during revalidation.

As @fdiary pointed out, max_stale_age is used to check the age of cached contents.

trafficserver/proxy/http/HttpTransact.cc

Line 5925 in 08fe521

if ((current_age < 0) || (current_age > s->txn_conf->cache_max_stale_age)) {

OTOH, negative_revalidating_lifetime is only used to set the Expires header of stale contents.

trafficserver/proxy/http/HttpTransact.cc

Line 4350 in 08fe521

time_t exp_time = s->txn_conf->negative_revalidating_lifetime + ink_local_time();

If we take the doc literary, it seems like we should refer to negative_revalidating_lifetime too when the negative_revalidating is enabled.

[lukenowak]

I have some cases (note: I am using version patched with #7422)

Cases

Case 1 - origin returns 502, negative_revalidating_enabled = 0

negative_revalidating_enabled = 0
negative_revalidating_lifetime = 0
max_stale_age = 30

1. configure origin to reply 200 with max-age = 15
2. GET results with 200 from origin
3. sleep 2
4. configure origin to reply 502 with max-age = 15
5. GET results with 200 from origin
6. sleep 15 (so it is 2 seconds more > max-age < max_stale_age)
7. GET results with 502 from origin, I see response being updated as max-age passes (due to patch)

This case, TrafficServer does not simulate "stale-if-error", expected.

Setting negative_revalidating_lifetime to some value impacts nothing.

Case 2 - origin not available anymore, negative_revalidating_enabled = 0

negative_revalidating_enabled = 0
negative_revalidating_lifetime = 0
max_stale_age = 30

1. configure origin to reply 200 with max-age = 15
2. GET results with 200 from origin
3. sleep 2
4. origin stopped
5. GET results with 200 from origin
6. sleep 15 (so it is 2 seconds more > max-age < max_stale_age)
7. GET results with 200 from ATS with Warning: 111 ApacheTrafficServer/8.1.1
8. sleep 15+2 (so it is > max_stale_age)
9. 502 from Apache Traffic Server

This case, TrafficServer simulates a bit "stale-if-error", but only when backend is down (replies nothing).

Setting negative_revalidating_lifetime to some value impacts nothing.

Case 3 - origin returns 502, negative_revalidating_enabled = 1

negative_revalidating_enabled = 1
negative_revalidating_lifetime = 0
max_stale_age = 30

1. configure origin to reply 200 with max-age = 15
2. GET results with 200 from origin
3. sleep 2
4. configure origin to reply 502 with max-age = 15
5. GET results with 200 from TrafficServer
6. sleep 15 (so it is 2 seconds more, > max-age < max_stale_age)
7. GET results with 200 from TrafficServer
8. sleep 15+2 (so it is > max_stale_age)
9. GET results with 502 from the origin, I see response being updated as max-age passes (due to patch)

In this case, TrafficServer simulates "stale-if-error", expected. max_stale_age is the switch to control the time frame of the feature.

Setting negative_revalidating_lifetime to some value impacts case of step 7 with Expires header becoming Date + negative_revalidating_lifetime, but in step 9 there is no more Expires header.

Case 4 - origin not available anymore, negative_revalidating_enabled = 1

negative_revalidating_enabled = 1
negative_revalidating_lifetime = 0
max_stale_age = 30

1. configure origin to reply 200 with max-age = 15
2. GET results with 200 from origin
3. sleep 2
4. configure origin to reply 502 with max-age = 15
5. GET results with 200 from TrafficServer
6. sleep 15 (so it is 2 seconds more, > max-age < max_stale_age)
7. GET results with 200 from ATS with Warning: 111 ApacheTrafficServer/8.1.1
8. sleep 15+2 (so it is > max_stale_age)
9. GET results with 502 from the origin, I see response being updated as max-age passes (due to patch)

In this case, TrafficServer simulates "stale-if-error", expected. max_stale_age is the switch to control the time frame of the feature.

Setting negative_revalidating_lifetime to some value impacts nothing

Conclusion

So currently the documentation (in records.config) could state:

• proxy.config.http.negative_revalidating_enabled

Add something like "proxy.config.http.cache.max_stale_age can be used to configure how long the stale response will be given for available backend returning 5xx response."

• proxy.config.http.negative_revalidating_lifetime

"...during revalidation, by setting Expire: header to value of Date: + value of the option"

• proxy.config.http.cache.max_stale_age

"...cannot be cached. Is enabled by proxy.config.http.negative_revalidating_enabled"
Well, I am not sure about this, maybe such documentation shall be kept in cache-basics as some kind of scenario, anyway this is how I understood and configure TrafficServer "negative revalidation" now.

[bryancall]

@bneradt Can you please document this? Thank you.

[bneradt]

I'm working on this and adding an AuTest. In case this is helpful to others, I'll make some initial observations.

My guess at the initial intention of this code was that setting the Expires header, observed earlier in this ticket, would set the freshness lifetime to the desired value. This doesn't work however, for at least three reasons:

First, the Expires header is set to the value of negative_revalidating_lifetime in the future from the current time:

trafficserver/proxy/http/HttpTransact.cc

Line 4350 in 08fe521

time_t exp_time = s->txn_conf->negative_revalidating_lifetime + ink_local_time();

If that actually was effective, then when proxy.config.http.negative_revalidating_enabled was enabled, every single cached response for a down server would always be considered fresh and served out of the cache because its Expires time would always be in the future. This is clearly not the intention. Rather, for this calculation to work, we'd want to set the Expires value to the time past the calculated age of the resource, not the offset from the current time.

The second reason this doesn't work is that, per RFC 7234 section 4.2.1, the max-age directive takes precedence over the Expires header field. Thus in all responses that has max-age, the Expires header would never even be inspected. Notice that @lukenowak 's examples all use max-age, and indeed most tests would because that's the easiest way to test freshness behavior. (Fixing this by setting the max-age directive, however, would not be a sufficient fix because of the following paragraph.)

Thirdly, by the time the Expires header is set in the code, we've already completed freshness calculations. Otherwise we wouldn't be in the code determining whether the stale response can be served. Recall that the negative revalidating feature influences behavior for stale cached responses in which the origin is unreachable. Thus at this point, setting the Expires header is too late to influence ATS's freshness calculation. We would have to set it then re-perform the freshness calculation. This is not done.

In order to make proxy.config.http.negative_revalidating_lifetime behave like it is documented, the three above issues would need to be addressed.

For the sake of completeness, if that were done, the intention is that things should work like this:

1. A client makes a request to a server which responds with some cacheable positive response, such as a 200 OK.
2. At a point in the future after the cached resource is stale, the client requests the resource.
3. ATS notices that the resource is stale and attempts to revalidate it against the origin.
4. The origin is either unreachable by ATS or it replies with some 5xx response.
5. ATS notices that proxy.config.http.negative_revalidating_enabled is enabled.
6. ATS recalculates the freshness of the resource using the adjusted freshness calculation as set in proxy.config.http.negative_revalidating_lifetime. If the resource is fresh enough given this adjustment, reply with it.
7. If, after this adjusted freshness calculation, the object is still stale, then ATS will respect max_stale_age. If its staleness is less than max_stale_age it will reply with it, otherwise it will return a 5xx response.

For now, with the bug described in this ticket, step 6 is broken and never results in the object's freshness being recalculated. Thus a user can only influence negative revalidating responses via max_stale_age.

[mlibbey]

Thanks Brian -- fwiw, I tried a bash script a long while back #3211 -- don't think it covered all your cases :)