You are viewing a plain text version of this content. The canonical link for it is here.

Posted to issues@trafficserver.apache.org by "mkrug1981 (via GitHub)" <gi...@apache.org> on 2023/12/27 09:08:25 UTC

[I] ATS 9.2.x and origin 301/302 chase redirections [trafficserver]

mkrug1981 opened a new issue, #10955:
URL: https://github.com/apache/trafficserver/issues/10955

   We are running Trafficserver 9.2.3 and observed an issue where trafficserver seems not to work as expected by following 302 redirects.
   
   Following the redirect from Origin, ATS now serves the content on the first attempt. Unfortunately, re-querying the same object always results in a timeout.
   After some debugging, it appears that the second and subsequent requests never get the content and always hit a timeout.
   The debug logs show 'cache open read failure' in a retry loop.
   
   ```
   [Dec 22 09:13:55.428] [ET_NET 19] DEBUG: <HttpTransact.cc:1499 (HandleRequest)> (http_seq) [453] request valid.
   [Dec 22 09:13:55.429] [ET_NET 19] DEBUG: <HttpTransact.cc:2148 (DecideCacheLookup)> (http_trans) [453] Will do cache lookup.
   [Dec 22 09:13:55.429] [ET_NET 19] DEBUG: <HttpTransact.cc:2149 (DecideCacheLookup)> (http_seq) [453] Will do cache lookup
   [Dec 22 09:13:55.429] [ET_NET 19] DEBUG: <HttpSM.cc:7636 (call_transact_and_set_next_state)> (http) [453] State Transition: SM_ACTION_API_POST_REMAP -> SM_ACTION_CACHE_LOOKUP
   [Dec 22 09:13:55.429] [ET_NET 19] DEBUG: <HttpSM.cc:4860 (do_cache_lookup_and_read)> (http_seq) [453] Issuing cache lookup for URL http://ida-mkrug-cdn.check.com/aaa/test100MB.nff
   [Dec 22 09:13:56.440] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:13:56.451] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, EVENT_INTERVAL]
   [Dec 22 09:13:56.451] [ET_NET 19] DEBUG: <HttpCacheSM.cc:142 (state_cache_open_read)> (http_cache) [453] [state_cache_open_read] cache open read failure 1. retrying cache open read...
   [Dec 22 09:13:57.426] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:13:57.436] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, EVENT_INTERVAL]
   [Dec 22 09:13:57.436] [ET_NET 19] DEBUG: <HttpCacheSM.cc:142 (state_cache_open_read)> (http_cache) [453] [state_cache_open_read] cache open read failure 2. retrying cache open read...
   [Dec 22 09:13:58.388] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:13:58.398] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, EVENT_INTERVAL]
   [Dec 22 09:13:58.398] [ET_NET 19] DEBUG: <HttpCacheSM.cc:142 (state_cache_open_read)> (http_cache) [453] [state_cache_open_read] cache open read failure 3. retrying cache open read...
   [Dec 22 09:13:59.355] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:13:59.365] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, EVENT_INTERVAL]
   [Dec 22 09:13:59.365] [ET_NET 19] DEBUG: <HttpCacheSM.cc:142 (state_cache_open_read)> (http_cache) [453] [state_cache_open_read] cache open read failure 4. retrying cache open read...
   [Dec 22 09:14:00.368] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:14:00.378] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, EVENT_INTERVAL]
   [Dec 22 09:14:00.378] [ET_NET 19] DEBUG: <HttpCacheSM.cc:142 (state_cache_open_read)> (http_cache) [453] [state_cache_open_read] cache open read failure 5. retrying cache open read...
   [Dec 22 09:14:01.367] [ET_NET 19] DEBUG: <HttpCacheSM.cc:100 (state_cache_open_read)> (http_cache) [453] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:14:01.367] [ET_NET 19] DEBUG: <HttpSM.cc:2741 (main_handler)> (http) [453] CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED, 1103
   [Dec 22 09:14:01.367] [ET_NET 19] DEBUG: <HttpSM.cc:2671 (state_cache_open_read)> (http) [453] [&HttpSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED/TS_EVENT_CACHE_OPEN_READ_FAILED]
   [Dec 22 09:14:01.367] [ET_NET 19] DEBUG: <HttpSM.cc:2703 (state_cache_open_read)> (http) [453] [453] cache_open_read - CACHE_EVENT_OPEN_READ_FAILED with ECACHE_DOC_BUSY (-20401)
   [Dec 22 09:14:01.367] [ET_NET 19] DEBUG: <HttpSM.cc:2706 (state_cache_open_read)> (http) [453] open read failed.
   ```
   I have tried as well to set proxy.config.http.redirect_use_orig_cache_key 1 but after doing that, I get the timeout right at the first try. The 302 response itself seems to be a success based on the logs but neither a 301 or 302 itself is cached. I suppose because the inflight transaction never finishes.
   
   
   **System details:**
   
   - OS - Rocky Linux release 8.8 (Green Obsidian)
   - ATS - 9.2.3-24
   
   **ATS settings:**
   
   ```
   Initial settings:
   ##### /opt/trafficserver/bin/traffic_ctl config match proxy.config.http.redirect_use_orig_cache_key proxy.config.http.number_of_redirections
   proxy.config.http.redirect_use_orig_cache_key: 0 
   proxy.config.http.number_of_redirections: 1
   
   ##### /opt/trafficserver/bin/traffic_ctl config match open_read_retries open_write_retries
   proxy.config.http.cache.max_open_read_retries: 150
   proxy.config.http.cache.max_open_write_retries: 150
   proxy.config.http.cache.open_read_retry_time: 10
   proxy.config.http.cache.open_write_fail_action: 0
   
   ##### /opt/trafficserver/etc/trafficserver/remap.config /opt/trafficserver/etc/trafficserver/parent.config
   /opt/trafficserver/etc/trafficserver/remap.config:map http://ida-mkrug-cdn.check.com/ http://ida-mkrug-cdn.check.com/
   /opt/trafficserver/etc/trafficserver/parent.config:dest_domain=ida-mkrug-cdn.check.com port=80 parent="y.y.y.y80|0.999" round_robin=consistent_hash go_direct=true qstring=ignore parent_is_proxy=false
   ```
   ```
   Following settings seems to make it better but the issue still persists##### /opt/trafficserver/bin/traffic_ctl config match open_read_retries open_write_retries
   proxy.config.http.cache.max_open_read_retries: 5
   proxy.config.http.cache.max_open_write_retries: 5
   ```
   
   I have used initial another origin but for troubleshotting I have setting a simple nginx instance with following configuration
   [traffic.out-clean-2nd-sanitized.txt](https://github.com/apache/trafficserver/files/13777142/traffic.out-clean-2nd-sanitized.txt)
   [traffic.out-clean-1st-sanitized.txt](https://github.com/apache/trafficserver/files/13777143/traffic.out-clean-1st-sanitized.txt)
   
   **Origin nginx settings**
   ```
   
       server {
           listen       80;
           listen       [::]:80;
           server_name  _;
           root         /usr/share/nginx/html;
   
           error_page 404 /404.html;
       error_page 301 302 @30x; # keep original HTTP status code w/o `=`
       location @30x {
           default_type ""; # will remove Content-Type completely
           # `300` is a filler: client will get the original HTTP status code
           return 300;
           add_header Cache-Control "public, max-age=3600";
       }
       add_header X-Cache-Server $server_addr;
       location /aaa/test100MB.nff {
           add_header Cache-Control "public, max-age=3600";
           return 301 /redirect/test100MB.nff;
           keepalive_timeout 0;
       }
       location ^~ /redirect/ {
       root  /usr/share/nginx/html/;
       add_header Cache-Control "public, max-age=3600";
       index  index.html;
       }
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficserver.apache.org.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org