search

apache / trafficserver

Apache Traffic Server™ is a fast, scalable and extensible HTTP/1.1 and HTTP/2 compliant caching proxy server.
https://trafficserver.apache.org/
Apache License 2.0
1.82k stars 806 forks source link

cache-request-method AuTest fails on master #8616

Closed bneradt closed 2 years ago

bneradt commented 2 years ago

After merging in this PR: https://github.com/apache/trafficserver/pull/8545

CI now fails.

This is the sequence of events that led to this:

  1. PR #8545 was created. CI ran and passed.
  2. While that PR was up for review, PR #8484 was put up and merged in.
  3. PR #8545 was then merged in.
  4. CI now fails for the test added in #8545 to verify its behavior.

It looks like #8484 breaks the patch in #8545 by causing the TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE to fire before some of the revalidation checks are performed.

Here are the logs for a relevant transaction:

[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <InkAPI.cc:5422 (TSHttpTxnCacheLookupStatusGet)> (cache) Entering TSHttpTxnCacheLookupStatusGet: 5                                                                      
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpSM.cc:1429 (state_api_callback)> (http) [4] [&HttpSM::state_api_callback, HTTP_API_CONTINUE/TS_EVENT_HTTP_CONTINUE]                                            
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpSM.cc:1469 (state_api_callout)> (http) [4] [&HttpSM::state_api_callout, HTTP_API_CONTINUE/TS_EVENT_HTTP_CONTINUE]                          
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2823 (HandleCacheOpenReadHit)> (http_seq) [4] [HttpTransact::HandleCacheOpenReadHit] Authentication not needed                              
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2885 (HandleCacheOpenReadHit)> (http) [4] setting cache_hit_but_revalidate                                                                                 
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2894 (HandleCacheOpenReadHit)> (http_trans) [4] CacheOpenRead --- needs_auth          = 0                                           
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2895 (HandleCacheOpenReadHit)> (http_trans) [4] CacheOpenRead --- needs_revalidate    = 0                                                                            
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2896 (HandleCacheOpenReadHit)> (http_trans) [4] CacheOpenRead --- response_returnable = 0                                      
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2897 (HandleCacheOpenReadHit)> (http_trans) [4] CacheOpenRead --- needs_cache_auth    = 0                                                
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2898 (HandleCacheOpenReadHit)> (http_trans) [4] CacheOpenRead --- send_revalidate     = 1                                                                                                       
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2901 (HandleCacheOpenReadHit)> (http_trans) [4] CacheOpenRead --- HIT-STALE                                                                   
[Jan 19 01:46:17.613] [ET_NET 3] DEBUG: <HttpTransact.cc:2903 (HandleCacheOpenReadHit)> (http_seq) [4] [HttpTransact::HandleCacheOpenReadHit] Revalidate document with server

Notice that the behavior of ATS is still correct: the send_revalidate flag is true. But the TSHttpTxnCacheLookupStatusGet is called before this state is detected, therefore the plugin gets the wrong status flag (fresh instead of a miss).

It looks like with #8484, the need_to_revalidate revalidate function is no longer called before TSHttpTxnCacheLookupStatusGet is called, and thus the cache_hit_but_revalidate flag isn't set yet.

bneradt commented 2 years ago

Oh, I see. With #8484, need_to_revalidate is no longer ever called: https://github.com/apache/trafficserver/blob/c0e3ddb985689ae2f71ca486421caf67cc83cfc3/proxy/http/HttpTransact.cc#L2702

@serrislew : I think we maybe want to call need_to_revalidate here? https://github.com/apache/trafficserver/pull/8484/files#diff-7f286e5169bc2d28c13f1ceaf3bb482b36cdb0743fbac4040fd4cd5a9c0897c1R1973

(That doesn't fix this issue, but it's an observation I'm making while looking at the code.)