From 8b26ff469c23ae5ccfcb0ae48c52993c0db38233 Mon Sep 17 00:00:00 2001 From: bneradt Date: Fri, 7 Aug 2026 10:48:19 -0500 Subject: [PATCH] Fix cache read VC replacement after a lost write lock A transaction that revalidates a stale cached object and cannot take the cache write lock is sent back through a second cache lookup while it still holds the cache read connection its first lookup opened. The read that completes for that second lookup replaces the connection the transaction is using: debug builds abort on the read connection assertion in HttpCacheSM::state_cache_open_read(), and release builds close that connection out from under the stale object saved as the retry fallback, leaving the fallback pointing into freed memory. The re-lookup runs for every cache_open_write_fail_action rather than only for the two that configure a read retry, so fail action 2, which is documented to serve the stale object instead of retrying anything, aborts a debug build several times a day under production traffic. This patch limits the re-lookup to the fail actions that configure a read retry. A transaction that loses the write lock with a cached object and no retry configured now hands that object straight to the freshness handling that serves stale content, with no second lookup. The retry actions do want that lookup, so this also makes replacing the read connection explicit and drops the saved stale object along with the connection that owns it, since neither can outlive the other. This adds an autest covering both configurations that does not depend on contention between transactions: denying the write lock through max_open_write_retries makes the failure synchronous, and each configuration aborts an unpatched debug build on the production assertion. The re-lookup arrived with the fail action 6 work in #12852, which applied it to every non-default fail action; that commit's own test notes the stale path is timing sensitive and does not exercise it. The resulting aborts resemble the ones #13487 fixed, because both land in HttpCacheSM while a cache write retry dispatches events, but they are a distinct failure. #13487 stopped HttpSM from canceling its own captive action, which aborts on the cancellation assertion in HttpCacheSM.cc:138; this is the read connection assertion ten lines later, reached with that action perfectly valid. Both fixes are needed, and neither subsumes the other. Co-Authored-By: Claude Opus 5 --- include/proxy/http/HttpConfig.h | 12 ++ src/proxy/http/HttpCacheSM.cc | 20 +-- src/proxy/http/HttpTransact.cc | 13 ++ .../cache/cache-write-lock-fail-write.conf | 24 +++ .../cache-write-lock-stale-revalidate.test.py | 32 ++++ .../cache-write-lock-stale-retry.replay.yaml | 145 ++++++++++++++++++ .../cache-write-lock-stale-serve.replay.yaml | 139 +++++++++++++++++ 7 files changed, 373 insertions(+), 12 deletions(-) create mode 100644 tests/gold_tests/cache/cache-write-lock-fail-write.conf create mode 100644 tests/gold_tests/cache/cache-write-lock-stale-revalidate.test.py create mode 100644 tests/gold_tests/cache/replay/cache-write-lock-stale-retry.replay.yaml create mode 100644 tests/gold_tests/cache/replay/cache-write-lock-stale-serve.replay.yaml diff --git a/include/proxy/http/HttpConfig.h b/include/proxy/http/HttpConfig.h index c09bdddba80..5bf58f7d7d0 100644 --- a/include/proxy/http/HttpConfig.h +++ b/include/proxy/http/HttpConfig.h @@ -420,6 +420,18 @@ enum class CacheOpenWriteFailAction_t { TOTAL_TYPES }; +/** Whether a cache_open_write_fail_action retries the cache read. + * + * @param[in] action A proxy.config.http.cache.open_write_fail_action value. + * @return Whether losing the cache write lock should retry the cache read. + */ +inline bool +is_read_retry_write_fail_action(MgmtByte action) +{ + return action == static_cast(CacheOpenWriteFailAction_t::READ_RETRY) || + action == static_cast(CacheOpenWriteFailAction_t::READ_RETRY_STALE_ON_REVALIDATE); +} + extern HttpStatsBlock http_rsb; ///////////////////////////////////////////////////////////// diff --git a/src/proxy/http/HttpCacheSM.cc b/src/proxy/http/HttpCacheSM.cc index cc8dcded3d0..4ddcc27ddcc 100644 --- a/src/proxy/http/HttpCacheSM.cc +++ b/src/proxy/http/HttpCacheSM.cc @@ -43,14 +43,6 @@ namespace { DbgCtl dbg_ctl_http_cache{"http_cache"}; - -// Helper to check if cache_open_write_fail_action has READ_RETRY behavior -inline bool -is_read_retry_action(MgmtByte action) -{ - return action == static_cast(CacheOpenWriteFailAction_t::READ_RETRY) || - action == static_cast(CacheOpenWriteFailAction_t::READ_RETRY_STALE_ON_REVALIDATE); -} } // end anonymous namespace //// @@ -145,9 +137,13 @@ HttpCacheSM::state_cache_open_read(int event, void *data) switch (event) { case CACHE_EVENT_OPEN_READ: Metrics::Gauge::increment(http_rsb.current_cache_connections); - ink_assert((cache_read_vc == nullptr) || master_sm->t_state.redirect_info.redirect_in_process); + ink_assert((cache_read_vc == nullptr) || master_sm->t_state.redirect_info.redirect_in_process || + master_sm->t_state.cache_info.write_lock_state == HttpTransact::CacheWriteLock_t::READ_RETRY); if (cache_read_vc) { - // redirect follow in progress, close the previous cache_read_vc + // A redirect follow or a read retry after losing the cache write lock + // replaces the read VC. The stale object that a read retry saved as its + // fallback lives in the VC being closed, so it cannot outlive it. + master_sm->t_state.cache_info.stale_fallback = nullptr; close_read(); } cache_read_vc = static_cast(data); @@ -234,7 +230,7 @@ HttpCacheSM::state_cache_open_write(int event, void *data) break; case CACHE_EVENT_OPEN_WRITE_FAILED: { - if (is_read_retry_action(master_sm->t_state.txn_conf->cache_open_write_fail_action)) { + if (is_read_retry_write_fail_action(master_sm->t_state.txn_conf->cache_open_write_fail_action)) { // fall back to open_read_tries // Note that when READ_RETRY actions are configured, max_cache_open_write_retries // is automatically ignored. Make sure to not disable max_cache_open_read_retries @@ -282,7 +278,7 @@ HttpCacheSM::state_cache_open_write(int event, void *data) _read_retry_event = nullptr; } - if (is_read_retry_action(master_sm->t_state.txn_conf->cache_open_write_fail_action)) { + if (is_read_retry_write_fail_action(master_sm->t_state.txn_conf->cache_open_write_fail_action)) { Dbg(dbg_ctl_http_cache, "[%" PRId64 "] [state_cache_open_write] cache open write failure %d. " "falling back to read retry...", diff --git a/src/proxy/http/HttpTransact.cc b/src/proxy/http/HttpTransact.cc index 09b16decb56..79e9fc5fa26 100644 --- a/src/proxy/http/HttpTransact.cc +++ b/src/proxy/http/HttpTransact.cc @@ -3365,6 +3365,19 @@ HttpTransact::handle_cache_write_lock(State *s) // HIT_STALE (revalidation case), the hook already fired and deferred is false. CacheHTTPInfo *obj = s->cache_info.object_read; if (obj != nullptr) { + if (!is_read_retry_write_fail_action(s->cache_open_write_fail_action)) { + // Fail actions 2 and 3 do not retry the cache read: they serve the + // object this transaction already looked up. Deciding otherwise here + // would issue a second cache lookup while the transaction still holds + // the cache read connection from the first one, and the read that + // completes on that second lookup replaces the connection out from + // under it. + TxnDbg(dbg_ctl_http_trans, "write lock lost with a cached object and no read retry configured"); + s->hdr_info.server_request.destroy(); + HandleCacheOpenReadHitFreshness(s); + return; + } + // Restore request/response times from cached object for freshness calculations and Age header. // Similar to HandleCacheOpenReadHitFreshness, handle clock skew by capping times. s->request_sent_time = obj->request_sent_time_get(); diff --git a/tests/gold_tests/cache/cache-write-lock-fail-write.conf b/tests/gold_tests/cache/cache-write-lock-fail-write.conf new file mode 100644 index 00000000000..94afd2ccac6 --- /dev/null +++ b/tests/gold_tests/cache/cache-write-lock-fail-write.conf @@ -0,0 +1,24 @@ +# +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +# Deny the cache write lock to any request carrying X-Fail-Cache-Write. With no +# write retries left, HttpCacheSM::open_write() reports the write failure +# without going to the cache at all, which makes the write lock loss +# deterministic instead of dependent upon a race between two transactions. +cond %{REMAP_PSEUDO_HOOK} +cond %{CLIENT-HEADER:X-Fail-Cache-Write} =1 +set-config proxy.config.http.cache.max_open_write_retries 0 [L] diff --git a/tests/gold_tests/cache/cache-write-lock-stale-revalidate.test.py b/tests/gold_tests/cache/cache-write-lock-stale-revalidate.test.py new file mode 100644 index 00000000000..1ff37247c84 --- /dev/null +++ b/tests/gold_tests/cache/cache-write-lock-stale-revalidate.test.py @@ -0,0 +1,32 @@ +''' +Verify losing the cache write lock while revalidating a stale object is handled. +''' +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +Test.Summary = ''' +Verify that a transaction which loses the cache write lock while revalidating a +stale object serves that object instead of tripping over the cache read +connection it still holds. +''' + +Test.ContinueOnFail = True + +# STALE_ON_REVALIDATE (action 2) serves the stale object directly. +Test.ATSReplayTest(replay_file="replay/cache-write-lock-stale-serve.replay.yaml") + +# READ_RETRY_STALE_ON_REVALIDATE (action 6) retries the cache read first. +Test.ATSReplayTest(replay_file="replay/cache-write-lock-stale-retry.replay.yaml") diff --git a/tests/gold_tests/cache/replay/cache-write-lock-stale-retry.replay.yaml b/tests/gold_tests/cache/replay/cache-write-lock-stale-retry.replay.yaml new file mode 100644 index 00000000000..6fe5975b61d --- /dev/null +++ b/tests/gold_tests/cache/replay/cache-write-lock-stale-retry.replay.yaml @@ -0,0 +1,145 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# proxy.config.http.cache.open_write_fail_action 6 +# (READ_RETRY_STALE_ON_REVALIDATE) retries the cache read when the write lock +# for a revalidation cannot be taken, hoping that whoever holds the lock has +# written a newer object. The retry has to replace the cache read connection the +# transaction opened for its first lookup, and the stale object saved as the +# fallback for that retry lives inside that connection, so neither may outlive +# the other. Debug builds used to abort in +# HttpCacheSM::state_cache_open_read() when the retry read completed. + +meta: + version: "1.0" + + blocks: + # The retried read finds the same stale object, which action 6 serves, so this + # response should never be seen. Negative revalidating is disabled below so + # that a 500 from the origin is passed through to the client rather than + # masked by the cached object, making an unexpected origin request visible in + # the proxy response. + - origin_not_expected: &origin_not_expected + server-response: + status: 500 + reason: "Internal Server Error" + headers: + fields: + - [ Content-Length, 16 ] + - [ X-Response, origin ] + +autest: + description: 'Verify a lost write lock on revalidation can retry the cache read' + + dns: + name: 'dns-stale-retry' + + server: + name: 'origin-stale-retry' + + client: + name: 'client-stale-retry' + + ats: + name: 'ts-stale-retry' + process_config: + enable_cache: true + + copy_to_config_dir: + - 'cache-write-lock-fail-write.conf' + + records_config: + proxy.config.diags.debug.enabled: 1 + proxy.config.diags.debug.tags: 'http_cache|http_trans|http_match' + # READ_RETRY_STALE_ON_REVALIDATE: retry the cache read when the write lock + # is lost, and fall back to the stale object if the retry finds nothing + # fresher. + proxy.config.http.cache.open_write_fail_action: 6 + proxy.config.http.cache.max_open_write_retry_timeout: 0 + proxy.config.http.cache.max_open_read_retries: 2 + proxy.config.http.cache.open_read_retry_time: 100 + # Pass an origin error through instead of covering it with the cached + # object, so that the proxy response below detects an origin request. + proxy.config.http.negative_revalidating_enabled: 0 + + remap_config: + - from: "http://example.com/" + to: "http://backend.example.com:{SERVER_HTTP_PORT}/" + plugins: + - name: header_rewrite.so + args: ['cache-write-lock-fail-write.conf'] + + log_validation: + traffic_out: + excludes: + - expression: "[Ff]atal|failed assertion" + description: 'Verify ATS does not abort when the retried cache read completes' + contains: + - expression: "READ_RETRY: object stale, triggering actual cache retry" + description: 'Verify the lost write lock triggered a cache read retry' + - expression: "cache_serve_stale_on_write_lock_fail" + description: 'Verify the stale object was served after the retry found nothing fresher' + +sessions: +- transactions: + + # Populate the cache with an object that is stale one second later. + - client-request: + method: GET + version: '1.1' + url: /stale-object + headers: + fields: + - [ Host, example.com ] + - [ uuid, prime-cache ] + + server-response: + status: 200 + reason: OK + headers: + fields: + - [ Content-Length, 16 ] + - [ Cache-Control, "max-age=1" ] + - [ X-Response, cached ] + + proxy-response: + status: 200 + headers: + fields: + - [ X-Response, { value: cached, as: equal } ] + + # The cached object is stale now, so ATS prepares to revalidate it and asks + # the cache for the write lock. The header below denies that lock, so the + # transaction retries its cache read and then serves the stale object. + - client-request: + delay: 2s + + method: GET + version: '1.1' + url: /stale-object + headers: + fields: + - [ Host, example.com ] + - [ uuid, revalidate-without-write-lock ] + - [ X-Fail-Cache-Write, '1' ] + + <<: *origin_not_expected + + proxy-response: + status: 200 + headers: + fields: + - [ X-Response, { value: cached, as: equal } ] diff --git a/tests/gold_tests/cache/replay/cache-write-lock-stale-serve.replay.yaml b/tests/gold_tests/cache/replay/cache-write-lock-stale-serve.replay.yaml new file mode 100644 index 00000000000..1b4924e0a09 --- /dev/null +++ b/tests/gold_tests/cache/replay/cache-write-lock-stale-serve.replay.yaml @@ -0,0 +1,139 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# proxy.config.http.cache.open_write_fail_action 2 (STALE_ON_REVALIDATE) asks +# ATS to serve the stale cached object when it cannot take the write lock to +# revalidate it. That transaction still holds the cache read connection from +# its own lookup, so the write lock failure must not send it back through +# another cache lookup: the second lookup replaces the read connection the +# transaction is using, which aborts debug builds on the canceled read +# connection assertion in HttpCacheSM::state_cache_open_read(). + +meta: + version: "1.0" + + blocks: + # The stale object has to be served out of the cache, so this response should + # never be seen. Negative revalidating is disabled below so that a 500 from + # the origin is passed through to the client rather than masked by the cached + # object, making an unexpected origin request visible in the proxy response. + - origin_not_expected: &origin_not_expected + server-response: + status: 500 + reason: "Internal Server Error" + headers: + fields: + - [ Content-Length, 16 ] + - [ X-Response, origin ] + +autest: + description: 'Verify a lost write lock on revalidation serves the stale object' + + dns: + name: 'dns-stale-serve' + + server: + name: 'origin-stale-serve' + + client: + name: 'client-stale-serve' + + ats: + name: 'ts-stale-serve' + process_config: + enable_cache: true + + copy_to_config_dir: + - 'cache-write-lock-fail-write.conf' + + records_config: + proxy.config.diags.debug.enabled: 1 + proxy.config.diags.debug.tags: 'http_cache|http_trans|http_match' + # STALE_ON_REVALIDATE: serve stale when the write lock is lost. + proxy.config.http.cache.open_write_fail_action: 2 + proxy.config.http.cache.max_open_write_retry_timeout: 0 + # Pass an origin error through instead of covering it with the cached + # object, so that the proxy response below detects an origin request. + proxy.config.http.negative_revalidating_enabled: 0 + + remap_config: + - from: "http://example.com/" + to: "http://backend.example.com:{SERVER_HTTP_PORT}/" + plugins: + - name: header_rewrite.so + args: ['cache-write-lock-fail-write.conf'] + + log_validation: + traffic_out: + excludes: + - expression: "[Ff]atal|failed assertion" + description: 'Verify ATS does not abort when the write lock is lost' + - expression: "READ_RETRY: object stale" + description: 'Verify no cache read retry is issued for a fail action that does not configure one' + contains: + - expression: "cache_serve_stale_on_write_lock_fail" + description: 'Verify the stale object was served because the write lock was lost' + +sessions: +- transactions: + + # Populate the cache with an object that is stale one second later. + - client-request: + method: GET + version: '1.1' + url: /stale-object + headers: + fields: + - [ Host, example.com ] + - [ uuid, prime-cache ] + + server-response: + status: 200 + reason: OK + headers: + fields: + - [ Content-Length, 16 ] + - [ Cache-Control, "max-age=1" ] + - [ X-Response, cached ] + + proxy-response: + status: 200 + headers: + fields: + - [ X-Response, { value: cached, as: equal } ] + + # The cached object is stale now, so ATS prepares to revalidate it and asks + # the cache for the write lock. The header below denies that lock, which used + # to drive the transaction into a second cache lookup. + - client-request: + delay: 2s + + method: GET + version: '1.1' + url: /stale-object + headers: + fields: + - [ Host, example.com ] + - [ uuid, revalidate-without-write-lock ] + - [ X-Fail-Cache-Write, '1' ] + + <<: *origin_not_expected + + proxy-response: + status: 200 + headers: + fields: + - [ X-Response, { value: cached, as: equal } ]