TS_MILESTONE_CACHE_OPEN_READ_END is unavailable in TS_HTTP_CACHE_LOOKUP_COMPLETE_HOOK after 9.1.x
Prior to 9.1.x, HTTP transactions reached TS_MILESTONE_CACHE_OPEN_READ_END before TS_HTTP_CACHE_LOOKUP_COMPLETE_HOOK. However, after 9.1.x, the order was reversed. This has affected one of our plugins because it was failing to obtain the correct timestamp of the completion of cache reads in a timely manner.
The exact change that caused this was made in #8168. Previously, TS_MILESTONE_CACHE_OPEN_READ_END was placed at the beginning of HttpSM::state_cache_open_read. After the change, it was moved to the end of the same function. The problem is that state_cache_open_read now calls into the HTTP state machine before it reaches the milestone [1] [2]. Once the state machine is invoked, the HTTP transaction will progress further and won't return until it triggers an asynchronous operation along the way.
The new timing for TS_MILESTONE_CACHE_OPEN_READ_END varies depending on the result of the cache lookup. When it misses, the milestone will be reached as ATS attempts to connect to the origin server. When it's a hit, the milestone will be delayed even further, past the point where it prepares to send a response back to the client in TS_HTTTP_SEND_RESPONSE_HDR_HOOK.
Is it okay to revert to the previous behavior by moving the milestone back to its original location? Or were there any problems with it?
[1]: https://github.com/apache/trafficserver/blob/4cf91f8acd7290e960edefc6b5f87d8a50d2271f/proxy/http/HttpSM.cc#L2746
[2]: https://github.com/apache/trafficserver/blob/4cf91f8acd7290e960edefc6b5f87d8a50d2271f/proxy/http/HttpSM.cc#L2766
This issue has been automatically marked as stale because it has not had recent activity. Marking it stale to flag it for further consideration by the community.