(trafficserver) branch master updated: HttpSM.cc: fix cache read end milestone order (#13325)

[bneradt]

This is an automated email from the ASF dual-hosted git repository.

bneradt pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/trafficserver.git


The following commit(s) were added to refs/heads/master by this push:
     new 8f33dbf76b HttpSM.cc: fix cache read end milestone order (#13325)
8f33dbf76b is described below

commit 8f33dbf76b81e82ff541af58457619ed95e26f89
Author: Brian Neradt <brian.ner...@gmail.com>
AuthorDate: Wed Jun 24 20:39:52 2026 -0500

    HttpSM.cc: fix cache read end milestone order (#13325)
    
    The log-milestone-fields AuTest intermittently logged a valid
    TCP_MEM_HIT with hit_proc rendered as unset. That field is computed from
    TS_MILESTONE_UA_BEGIN_WRITE minus TS_MILESTONE_CACHE_OPEN_READ_END, so
    the failing logs showed the client write-begin milestone could be
    observed before the cache open-read end milestone on a fast cache-hit
    path.
    
    The cache had already delivered the open-read result in
    state_cache_open_read(), so that ordering pointed at milestone stamping
    rather than an actual cache sequencing problem.
    TS_MILESTONE_CACHE_OPEN_READ_END was marked after cache-open-read state
    handling, and that handling can advance into cache serving and stamp
    TS_MILESTONE_UA_BEGIN_WRITE first.
    
    This records TS_MILESTONE_CACHE_OPEN_READ_END in the terminal
    cache-open-read handling paths before they can advance to later
    transaction milestones. The compatibility-key retry path is left
    unstamped so the retried lookup owns a coherent cache-read begin/end
    pair.
---
 src/proxy/http/HttpSM.cc | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/src/proxy/http/HttpSM.cc b/src/proxy/http/HttpSM.cc
index 4a3cb451f9..1a77bd48eb 100644
--- a/src/proxy/http/HttpSM.cc
+++ b/src/proxy/http/HttpSM.cc
@@ -2689,6 +2689,11 @@ HttpSM::state_cache_open_read(int event, void *data)
       Metrics::Counter::increment(http_rsb.cache_compat_key_reads);
     }
 
+    // Record the cache open-read completion before state handling can advance
+    // into cache serving and stamp later transaction milestones.
+    ATS_PROBE1(milestone_cache_open_read_end, sm_id);
+    milestones[TS_MILESTONE_CACHE_OPEN_READ_END] = ink_get_hrtime();
+
     ink_assert(t_state.cache_info.object_read != nullptr);
     call_transact_and_set_next_state(HttpTransact::HandleCacheOpenRead);
     break;
@@ -2715,6 +2720,11 @@ HttpSM::state_cache_open_read(int event, void *data)
       t_state.cache_lookup_result = HttpTransact::CacheLookupResult_t::MISS;
     }
 
+    // Record the final cache open-read completion after any compatibility-key
+    // retry has been ruled out.
+    ATS_PROBE1(milestone_cache_open_read_end, sm_id);
+    milestones[TS_MILESTONE_CACHE_OPEN_READ_END] = ink_get_hrtime();
+
     ink_assert(t_state.transact_return_point == nullptr);
     t_state.transact_return_point = HttpTransact::HandleCacheOpenRead;
 
@@ -2739,9 +2749,6 @@ HttpSM::state_cache_open_read(int event, void *data)
     break;
   }
 
-  ATS_PROBE1(milestone_cache_open_read_end, sm_id);
-  milestones[TS_MILESTONE_CACHE_OPEN_READ_END] = ink_get_hrtime();
-
   return 0;
 }