This is an automated email from the ASF dual-hosted git repository. cmcfarlen pushed a commit to branch 10.2.x in repository https://gitbox.apache.org/repos/asf/trafficserver.git
commit 5336b5c43d1b3b052e709d2e311476276af77448 Author: Brian Neradt <[email protected]> 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. (cherry picked from commit 8f33dbf76b81e82ff541af58457619ed95e26f89) --- 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 b1afc073e1..749e271c1f 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; }
