Race condition in send()

I spotted this while using tox -vvv -p all, so via pip, since pip==26.1.

The issue with tox -p all is that it can run multiple versions of Python (in my config from 3.10 to 3.14), in parallel, I bet some with zstd some without.

TL;DR:

pip wants to query /simple/setuptools/
Cache is checked, an etag is found in the cache.
The HTTP request with an If-None-Match is sent.
In the meantime the cache gets modified, from Accept-Encoding: gzip, deflate to Accept-Encoding: gzip, deflate, zstd or the other way around, by another process.
The HTTP response arrives, it's a 304 Not Modified, the cache has to be updated, but this time it does no longer loads, and the 304 itself is returned.

In details:

It all starts in those two lines of adapter.send():

        request.headers.update(self.controller.conditional_headers(request))
    resp = super().send(request, stream, timeout, verify, cert, proxies)

Here conditional_headers does a _load_from_cache which can succeed, let say it succeed.

Then super().send() will eventually call adapter.build_response() with a 304 Not Modified so build_response calls self.controller.update_cached_response which runs another _load_from_cache, which can fail if the cache was modified by another process. Let's say it fails it runs this code:

    if not cached_response:
        # we didn't have a cached response
        return response

So the 304 response is returned, up to the user. In case of pip an exception is raised because the answer don't have a Content-Type. But pip or not, the user just did a get with no If-None-Match so he does not expect a 304, either a cache hit (hopefully 200 OK) or a cache miss (hopefully 200 OK) but never a 304.

The chronology with two processes

It think it looks like this, [1] and [2] denoting two distinct processes:

[1] runs a requests.get("https://pypi.org/simple/setuptools/")
[2] runs a requests.get("https://pypi.org/simple/setuptools/")
[1] Read the cache, extract an ETag from the cache
[2] Read the cache, extract an ETag from the cache
[1] Sends the HTTP request with If-None-Match
[2] Sends the HTTP request with If-None-Match
[1] Gets a response, adapter.build_response calls self.controller.update_cached_response(), changing the headers on disk. The Accept-Encoding in my case.
[1] Returns the cached response.
[2] Gets a response, adapter.build_response calls self.controller.update_cached_response() which calls _load_from_cache which refuses to load because the headers has changed (Vary tells the answer varies on Accept-Encoding and the Accept-Encoding changed), update_cached_response returns the 304 response. build_response returns the 304 response. The user gets a 304, which is unexpected.

I created a reproducer

import argparse
import logging
import subprocess
import sys
from multiprocessing import Pool
from pathlib import Path

import requests

from cachecontrol import CacheControl
from cachecontrol.caches.file_cache import FileCache

logger = logging.getLogger()


def do_query():
    logging.basicConfig(level=logging.DEBUG, format="%(process)s %(message)s")
    session = CacheControl(requests.Session(), cache=FileCache('.web_cache'))
    response = session.get('https://pypi.org/simple/setuptools/')
    logger.info("%s: %s", sys.version_info, response)


def ensure_venv(version):
    path = Path(f"venvs/py3.{version}")
    if path.exists():
        return
    subprocess.run([f"python3.{version}", "-m", "venv", str(path)], check=True)
    subprocess.run([path / "bin" / "python", "-m", "pip", "install", "-e", ".[filecache]"])


def spawn_workers():
    workers = []
    print("Creating all venvs first")
    for i in range(10, 15):
        ensure_venv(i)
    print("Starting workers")
    for _ in range(2):
        for i in range(10, 15):
            workers.append(subprocess.Popen([f"venvs/py3.{i}/bin/python", sys.argv[0], "--worker"]))
    print(f"{len(workers)} workers started")
    for worker in workers:
        worker.wait()



def parse_arguments():
    parser = argparse.ArgumentParser(description='')
    parser.add_argument("--worker", action="store_true")
    return parser.parse_args()


def main():
    args = parse_arguments()
    if args.worker:
        do_query()
    else:
        spawn_workers()


if __name__ == '__main__':
    main()

It does not always work but sometime it does:

Output from the reproducer

$ python repro.py
Creating all venvs first
Starting workers
10 workers started
468631 Looking up "https://pypi.org/simple/setuptools/" in the cache
468631 Current age based on date: 3
468631 Freshness lifetime from max-age: 600
468631 adapter.send() adding conditional headers
468631 adapter.send() sending actual request
468631 Starting new HTTPS connection (1): pypi.org:443
468634 Looking up "https://pypi.org/simple/setuptools/" in the cache
468634 Current age based on date: 3
468634 Freshness lifetime from max-age: 600
468630 Looking up "https://pypi.org/simple/setuptools/" in the cache
468634 adapter.send() adding conditional headers
468635 Looking up "https://pypi.org/simple/setuptools/" in the cache
468634 adapter.send() sending actual request
468630 Current age based on date: 3
468630 Freshness lifetime from max-age: 600
468630 adapter.send() adding conditional headers
468634 Starting new HTTPS connection (1): pypi.org:443
468635 Current age based on date: 3
468635 Freshness lifetime from max-age: 600
468630 adapter.send() sending actual request
468635 adapter.send() adding conditional headers
468630 Starting new HTTPS connection (1): pypi.org:443
468629 Looking up "https://pypi.org/simple/setuptools/" in the cache
468635 adapter.send() sending actual request
468635 Starting new HTTPS connection (1): pypi.org:443
468629 Current age based on date: 3
468629 Freshness lifetime from max-age: 600
468629 adapter.send() adding conditional headers
468629 adapter.send() sending actual request
468629 Starting new HTTPS connection (1): pypi.org:443
468632 Looking up "https://pypi.org/simple/setuptools/" in the cache
468632 Cache entry deserialization failed, entry ignored
468632 adapter.send() adding conditional headers
468632 Cache entry deserialization failed, entry ignored
468632 adapter.send() sending actual request
468632 Starting new HTTPS connection (1): pypi.org:443
468631 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468631 Attempting to acquire lock 140401415916912 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468631 Lock 140401415916912 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468631 Attempting to release lock 140401415916912 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468631 Lock 140401415916912 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468631 adapter.send() got <Response [200]>
468631 sys.version_info(major=3, minor=13, micro=12, releaselevel='final', serial=0): <Response [200]>
468636 Looking up "https://pypi.org/simple/setuptools/" in the cache
468636 Current age based on date: 0
468636 Freshness lifetime from max-age: 600
468636 adapter.send() adding conditional headers
468636 adapter.send() sending actual request
468636 Starting new HTTPS connection (1): pypi.org:443
468629 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468629 Attempting to acquire lock 140223571391248 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468629 Lock 140223571391248 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468629 Attempting to release lock 140223571391248 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468629 Lock 140223571391248 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468629 adapter.send() got <Response [200]>
468634 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468634 Attempting to acquire lock 139802845739472 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468634 Lock 139802845739472 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468634 Attempting to release lock 139802845739472 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468634 Lock 139802845739472 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468634 adapter.send() got <Response [200]>
468629 sys.version_info(major=3, minor=11, micro=9, releaselevel='final', serial=0): <Response [200]>
468630 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468635 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468634 sys.version_info(major=3, minor=11, micro=9, releaselevel='final', serial=0): <Response [200]>
468630 Attempting to acquire lock 140390081850896 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468630 Lock 140390081850896 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468635 Attempting to acquire lock 139766457490448 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468635 Lock 139766457490448 not acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock, waiting 0.05 seconds ...
468630 Attempting to release lock 140390081850896 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468630 Lock 140390081850896 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468630 adapter.send() got <Response [200]>
468632 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 200 164119
468632 adapter.send() got <Response [200]>
468628 Looking up "https://pypi.org/simple/setuptools/" in the cache
468628 Current age based on date: 0
468628 Freshness lifetime from max-age: 600
468628 adapter.send() adding conditional headers
468630 sys.version_info(major=3, minor=12, micro=2, releaselevel='final', serial=0): <Response [200]>
468628 adapter.send() sending actual request
468628 Starting new HTTPS connection (1): pypi.org:443
468633 Looking up "https://pypi.org/simple/setuptools/" in the cache
468633 Current age based on date: 0
468633 Freshness lifetime from max-age: 600
468633 adapter.send() adding conditional headers
468633 adapter.send() sending actual request
468633 Starting new HTTPS connection (1): pypi.org:443
468637 Looking up "https://pypi.org/simple/setuptools/" in the cache
468637 Cache entry deserialization failed, entry ignored
468637 adapter.send() adding conditional headers
468637 Cache entry deserialization failed, entry ignored
468637 adapter.send() sending actual request
468637 Starting new HTTPS connection (1): pypi.org:443
468632 Updating cache with response from "https://pypi.org/simple/setuptools/"
468632 etag object cached for 1209600 seconds
468632 Caching due to etag
468632 Attempting to acquire lock 139958668056224 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468632 Lock 139958668056224 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468632 Attempting to release lock 139958668056224 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468632 Lock 139958668056224 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468632 sys.version_info(major=3, minor=14, micro=0, releaselevel='final', serial=0): <Response [200]>
468636 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468636 Cache entry deserialization failed, entry ignored
468636 adapter.send() got <Response [304]>
468636 sys.version_info(major=3, minor=13, micro=12, releaselevel='final', serial=0): <Response [304]>
468635 Attempting to acquire lock 139766457490448 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468635 Lock 139766457490448 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468635 Attempting to release lock 139766457490448 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468635 Lock 139766457490448 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468635 adapter.send() got <Response [200]>
468635 sys.version_info(major=3, minor=12, micro=2, releaselevel='final', serial=0): <Response [200]>
468628 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468628 Attempting to acquire lock 140599068214416 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468628 Lock 140599068214416 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468628 Attempting to release lock 140599068214416 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468633 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0
468628 Lock 140599068214416 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468637 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 200 164119
468628 adapter.send() got <Response [200]>
468637 adapter.send() got <Response [200]>
468633 Attempting to acquire lock 140264340783984 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468633 Lock 140264340783984 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468633 Attempting to release lock 140264340783984 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468633 Lock 140264340783984 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468633 adapter.send() got <Response [200]>
468628 sys.version_info(major=3, minor=10, micro=14, releaselevel='final', serial=0): <Response [200]>
468633 sys.version_info(major=3, minor=10, micro=14, releaselevel='final', serial=0): <Response [200]>
468637 Updating cache with response from "https://pypi.org/simple/setuptools/"
468637 etag object cached for 1209600 seconds
468637 Caching due to etag
468637 Attempting to acquire lock 140034390447776 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468637 Lock 140034390447776 acquired on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468637 Attempting to release lock 140034390447776 on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468637 Lock 140034390447776 released on .web_cache/0/4/1/8/c/0418c83b80f7f7bfaec2738bfbbee53d2c1562196c0781702f6eddc8.lock
468637 sys.version_info(major=3, minor=14, micro=0, releaselevel='final', serial=0): <Response [200]>

To help with the reproduction I added the following patch:

the patch

diff --git a/cachecontrol/adapter.py b/cachecontrol/adapter.py
index 4f4c185..c16e2d9 100644
--- a/cachecontrol/adapter.py
+++ b/cachecontrol/adapter.py
@@ -4,6 +4,7 @@
 from __future__ import annotations
 
 import functools
+import logging
 import weakref
 import zlib
 from typing import TYPE_CHECKING, Any, Collection, Mapping
@@ -71,10 +72,12 @@ class CacheControlAdapter(HTTPAdapter):
                 return self.build_response(request, cached_response, from_cache=True)
 
             # check for etags and add headers if appropriate
+            logging.info("adapter.send() adding conditional headers")
             request.headers.update(self.controller.conditional_headers(request))
 
+        logging.info("adapter.send() sending actual request")
         resp = super().send(request, stream, timeout, verify, cert, proxies)
-
+        logging.info("adapter.send() got %s", resp)
         return resp
 
     def build_response(  # type: ignore[override]
diff --git a/cachecontrol/controller.py b/cachecontrol/controller.py
index 733684f..a3c5899 100644
--- a/cachecontrol/controller.py
+++ b/cachecontrol/controller.py
@@ -263,10 +263,10 @@ class CacheController:
             logger.debug("Adjusted current age from min-fresh: %i", current_age)
 
         # Return entry if it is fresh enough
-        if freshness_lifetime > current_age:
-            logger.debug('The response is "fresh", returning cached response')
-            logger.debug("%i > %i", freshness_lifetime, current_age)
-            return resp
+        # if freshness_lifetime > current_age:
+        #     logger.debug('The response is "fresh", returning cached response')
+        #     logger.debug("%i > %i", freshness_lifetime, current_age)
+        #     return resp
 
         # we're not fresh. If we don't have an Etag, clear it out
         if "etag" not in headers:

To log a bit and to disable the 10 minute cache-control: max-age=600, public provided by pypi.org, else we have to wait 10 minutes between retries.

The first column in the output is the PID, filtering the interesting lines from the output, and adding comments gives:

468632 Looking up "https://pypi.org/simple/setuptools/" in the cache  # This is the 3.14 process with zstd, the cache has no zstd, it'll fail
468632 Cache entry deserialization failed, entry ignored  # First read of the cache to see if we can return from it
468632 adapter.send() adding conditional headers
468632 Cache entry deserialization failed, entry ignored  # 2nd read from the cache to extract the etags
468632 adapter.send() sending actual request
468632 Starting new HTTPS connection (1): pypi.org:443  # Doing an actual normal HTTP request, no cache headers.

468636 Looking up "https://pypi.org/simple/setuptools/" in the cache  # This is a Python 3.13 without zstd, it can read the cache as the request match (`Accept-Encoding: gzip, deflate` for the query and in the cache)
468636 adapter.send() adding conditional headers
468636 adapter.send() sending actual request
468636 Starting new HTTPS connection (1): pypi.org:443  # This is a validation request, with If-None-Match.

468632 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 200 164119  # Response for the Accept-Encoding: gzip, deflate, zstd query.
468632 adapter.send() got <Response [200]>
468632 Updating cache with response from "https://pypi.org/simple/setuptools/"  # Alters cache, adding Accept-Encoding: gzip, deflate, zstd query.
468632 etag object cached for 1209600 seconds
468632 Caching due to etag
468632 sys.version_info(major=3, minor=14, micro=0, releaselevel='final', serial=0): <Response [200]>  # Gives 200 OK from server to user.

468636 https://pypi.org:443 "GET /simple/setuptools/ HTTP/1.1" 304 0  # Got server response, needs to update cache
468636 Cache entry deserialization failed, entry ignored  # But can't update cache: Accept-Encoding has changed, serializer refuses to deserialize it!
468636 adapter.send() got <Response [304]>
468636 sys.version_info(major=3, minor=13, micro=12, releaselevel='final', serial=0): <Response [304]>  # Giving 304 to the end user :(

Navigation Menu

Repository navigation

Race condition in send() #424

The chronology with two processes

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Race condition in send() #424

Description

The chronology with two processes

Activity

JulienPalard commented on May 19, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions