`experimental-image-proxy`: hangs indefinitely when CDN stalls mid-blob-download (FinishPipe deadlock)

[dustymabe]

In Fedora CoreOS we've been running into an odd bug in our upgrade tests in our pipeline. I filed an issue for that over in coreos/fedora-coreos-tracker#2149 (it's a good read if you have time).

Following on from that I had AI analyze to see if the bug was fixed in newer code and it thinks it isn't and needs to be fixed. I generated this AI bug report which I think summarizes the problem well:

Summary

skopeo experimental-image-proxy hangs permanently when an HTTP connection stalls mid-transfer during a blob download. The proxy's FinishPipe handler blocks on wg.Wait() while holding the handler mutex, which deadlocks the entire proxy — no further requests can be processed, and the calling application (rpm-ostree, bootc, etc.) hangs indefinitely.

This was observed during an automated Fedora CoreOS upgrade via zincati/rpm-ostree. The Akamai CDN serving a Quay.io blob stopped sending data at 76% completion while keeping the TCP connection alive. Because there is no idle timeout anywhere in the pipeline (containers/image HTTP client, skopeo proxy goroutine, or the proxy protocol), the entire system deadlocked permanently.

Environment

• OS: Fedora CoreOS (cosa-devsh VM, QEMU NAT networking)
• Package: rpm-ostree-2025.6-6.fc42.x86_64
• skopeo: bundled with rpm-ostree (protocol version 0.2.6)
• Image: quay.io/fedora/fedora-coreos@sha256:c6a73015376ade9c5ae50e8cca5356e542a51edb8df4a05590abfaf268edeaa9
• Triggered by: zincati.service (automatic update agent)
• Proxy invocation: setpriv --no-new-privs --init-groups --reuid rpm-ostree --bounding-set -all --pdeathsig TERM -- skopeo experimental-image-proxy --no-creds

Symptoms

With CONTAINERS_IMAGE_PROXY_DEBUG=1, the process prints the following and then hangs forever:

DEBUG new_with_config: Spawned skopeo pid=3978 config=ImageProxyConfig { authfile: None, auth_data: None, auth_anonymous: true, ... }
DEBUG new_with_config: Remote protocol version: 0.2.6 ...
Fetching ostree-remote-image:fedora:docker://quay.io/fedora/fedora-coreos@sha256:c6a730...
DEBUG open_image: opening image ...
DEBUG finish_pipe: closing pipe ... pipeid=7
DEBUG finish_pipe: closing pipe ... pipeid=8
layers already present: 36; layers needed: 15 (245.6 MB)
DEBUG Fetching base
DEBUG get_layer_info: Getting layer info ...
DEBUG fetching sha256:a283e9be7391dc4a3d858e321574277c621faad113a8f6b36e0511cd05352448
DEBUG get_blob: fetching blob ... size=2759859
DEBUG layer progress: [0/15] Fetching ostree chunk a283e9be7391dc4a3d8 (2.8 MB)
DEBUG finish_pipe: closing pipe ... pipeid=8
    ← hangs here forever, no further output

Root Cause Analysis

Three issues combine to produce a permanent deadlock:

1. CDN stalls mid-transfer (trigger)

The Akamai CDN edge server (23.61.255.227, serving cdn01.quay.io) stopped sending data after delivering 76% (2,124,175 of 2,759,859 bytes) of a blob. The TCP connection remained alive — keepalive ACKs continued flowing — but no application data was sent. ss -tnpi output during the hang:

ESTAB  0  0  10.0.2.15:50856  23.61.255.227:443  users:(("skopeo",pid=3978,fd=6))
  bytes_received:2124175
  lastsnd:1341635   ← last data sent ~22 minutes ago
  lastrcv:1341446   ← last data received ~22 minutes ago
  lastack:12438     ← TCP keepalive ACKs still flowing (~12 sec ago)
  rcv_wnd:2636640   ← skopeo advertising 2.5 MB receive window (not a flow control issue)

2. No idle timeout on HTTP body reads (containers/image)

The containers/image library's HTTP transport (pkg/tlsclientconfig/tlsclientconfig.go:88-101) sets TCP-level timeouts but has no HTTP body read timeout:

func NewTransport() *http.Transport {
    direct := &net.Dialer{
        Timeout:   30 * time.Second,  // TCP connect only
        KeepAlive: 30 * time.Second,  // TCP keepalive interval
    }
    tr := &http.Transport{
        Proxy:               http.ProxyFromEnvironment,
        DialContext:         direct.DialContext,
        TLSHandshakeTimeout: 10 * time.Second,
        IdleConnTimeout:     90 * time.Second,  // idle conn pool, NOT active reads
        MaxIdleConns:        100,
        // No ResponseHeaderTimeout
        // No overall Timeout on http.Client
        // No body-read idle timeout
    }
    return tr
}

The bodyReader wrapper (docker/body_reader.go:139) tracks lastSuccessTime (line 147) but only uses it for debug logging (line 224-226), never to enforce a deadline. Its reconnection logic only handles hard failures (ECONNRESET, ErrUnexpectedEOF), not stalls where the connection stays open but no data arrives.

3. FinishPipe holds mutex during wg.Wait() — deadlocks entire proxy (skopeo/container-libs)

In the proxy handler (common/pkg/json-proxy/handler.go):

GetBlob (line 427) spawns a goroutine that copies the blob from the HTTP response body to a pipe:

func (h *handler) GetBlob(ctx context.Context, args []any) (replyBuf, error) {
    h.lock.Lock()
    defer h.lock.Unlock()
    // ...
    go func() {
        defer blobr.Close()
        defer f.wg.Done()
        // ...
        n, err := io.Copy(f.w, tr)  // line 472 — blocks if HTTP body stalls
        // ...
    }()
    // returns pipeid + fd to client
}

The goroutine at line 466 does not use any context — it does a raw io.Copy with no cancellation mechanism. If the HTTP body read stalls, this goroutine blocks forever.

FinishPipe (line 664) waits for the goroutine to complete while holding the handler mutex:

func (h *handler) FinishPipe(ctx context.Context, args []any) (replyBuf, error) {
    h.lock.Lock()         // line 665
    defer h.lock.Unlock() // line 666
    // ...
    f.wg.Wait()           // line 682 — blocks forever if goroutine is stuck
    // ...
}

Since h.lock is held, all other handler methods (GetBlob, GetManifest, OpenImage, etc.) are blocked. The proxy cannot process any requests — including a potential shutdown/cleanup — until the stalled goroutine completes, which it never will because the CDN has stopped sending data.

Deadlock Diagram

rpm-ostree (pid 3980)                 skopeo proxy (pid 3986)              Akamai CDN

  sendto(29, FinishPipe[8]) ────────►  recvfrom(3, FinishPipe[8])
                                       h.lock.Lock()  ← acquired
                                       f.wg.Wait()    ← BLOCKED
  recvmsg(29) ← BLOCKED                  │
    waiting for response                  │  goroutine still running:
    that never comes                      │  io.Copy(pipe, httpBody)
                                          │     │
                                          │     └──► Read(fd=6) ──────────► CDN stalled
                                          │          EAGAIN                  no data
                                          │          epoll: no events        keepalive OK
                                          │          goroutine parked        connection alive
                                          │                                  but silent
                                          ▼
                                       wg never Done()
                                       lock never released
                                       proxy fully deadlocked

Protocol Message Trace (from strace -f)

The image proxy protocol uses a SOCK_SEQPACKET Unix socket. JSON requests are sent from rpm-ostree, and JSON responses (with optional file descriptors via SCM_RIGHTS) come back from skopeo. The strace shows 9 requests sent but only 8 responses received:

#	Request	Response	Status
1	version handshake	"0.2.6"	OK
2	OpenImage(docker://quay.io/...)	value: 1	OK
3	GetManifest(1)	sha256:c6a7..., pipeid=7, fd passed	OK
4	FinishPipe(7)	null	OK
5	get config/metadata	null, pipeid=8, fd passed	OK
6	FinishPipe(8)	null	OK
7	GetLayerInfo(1)	8178 bytes of layer JSON	OK
8	GetBlob(1, "sha256:a283e9...", 2759859)	value: 2759859, pipeid=8, fd passed	OK
9	FinishPipe(8)	NO RESPONSE	DEADLOCK

Evidence from strace — skopeo received all 9 requests on fd 3:

[pid  3978] recvfrom(3, "{\"method\":\"OpenImage\",\"args\":[\"docker://quay.io/...\"]}", ...)
[pid  3984] recvfrom(3, "{\"method\":\"GetManifest\",\"args\":[1]}", ...)
[pid  3984] recvfrom(3, "{\"method\":\"FinishPipe\",\"args\":[7]}", ...)
[pid  3986] recvfrom(3, "{\"method\":\"FinishPipe\",\"args\":[8]}", ...)
[pid  3986] recvfrom(3, "{\"method\":\"GetLayerInfo\",\"args\":[1]}", ...)
[pid  3986] recvfrom(3, "{\"method\":\"GetBlob\",\"args\":[1,\"sha256:a283e9...\",2759859]}", ...)
[pid  3986] recvfrom(3, "{\"method\":\"FinishPipe\",\"args\":[8]}", ...)   ← received, never responded

But only 8 sendmsg(3, ...) responses were sent — the 9th (for FinishPipe(8)) was never sent because the handler is stuck in wg.Wait().

Evidence from strace — rpm-ostree blocked waiting for the response:

[pid  3980] sendto(29, '{"method":"FinishPipe","args":[8]}', ...) = 34
[pid  3980] recvmsg(29, ...    ← BLOCKED, waiting for response that never comes

Evidence from strace — skopeo's blob streaming goroutine stalled:

[pid  3986] write(8, ..., 4264) = 4264    # last chunk written to pipe (fd 8)
[pid  3986] read(6, ...) = -1 EAGAIN      # no more data from CDN TLS connection (fd 6)
[pid  3986] epoll_pwait(4, [], ...) = 0    # no events on any fd
[pid  3986] futex(FUTEX_WAIT, ...)         # goroutine parked by Go runtime

Download progress at stall

Metric	Value
Expected blob size	2,759,859 bytes
Bytes received from CDN (ss bytes_received)	2,124,175 bytes
Bytes written to pipe (summed from strace write(8,...))	~2,107,617 bytes
Completion	76.4%

Why This Only Affects the Proxy Path

This deadlock does not occur with direct podman pull or skopeo copy because:

1. Direct pulls use the caller's context (which can be canceled via ctrl-C, systemd timeout, etc.). When the context is canceled, Go's net/http closes the underlying TCP connection, and the Read() returns an error. The stall is recoverable.

2. The proxy path passes context.Background() to the handler — no deadline, no cancellation. The io.Copy goroutine has no context at all. The only thing that can unblock it is the TCP connection actually dying (via TCP keepalive, which can take hours with the OS defaults).

3. The mutex in FinishPipe amplifies the impact: a stalled blob download doesn't just block that one operation — it deadlocks the entire proxy, preventing any other request from being processed including potential cleanup/shutdown.

Suggested Fixes

Fix 1 (proxy — high priority): Don't hold mutex during wg.Wait()

In handler.go, FinishPipe should release the mutex before waiting:

func (h *handler) FinishPipe(ctx context.Context, args []any) (replyBuf, error) {
    h.lock.Lock()
    // ... validate pipeid, get f ...
    h.lock.Unlock()  // release before blocking

    f.wg.Wait()      // now other requests can proceed while we wait

    h.lock.Lock()    // re-acquire to clean up
    delete(h.activePipes, pipeid)
    h.lock.Unlock()

    f.w.Close()
    return ret, f.err
}

Fix 2 (proxy — high priority): Wire context through to the io.Copy goroutine

The GetBlob goroutine should respect context cancellation:

go func() {
    defer blobr.Close()
    defer f.wg.Done()
    verifier := d.Verifier()
    tr := io.TeeReader(blobr, verifier)

    // Use a context-aware copy
    done := ctx.Done()
    buf := make([]byte, 32*1024)
    for {
        select {
        case <-done:
            f.err = ctx.Err()
            return
        default:
        }
        n, err := tr.Read(buf)
        if n > 0 {
            if _, werr := f.w.Write(buf[:n]); werr != nil {
                f.err = werr
                return
            }
        }
        if err != nil {
            if err != io.EOF {
                f.err = err
            }
            return
        }
    }
}()

Fix 3 (containers/image — medium priority): Add idle timeout to bodyReader

The bodyReader in docker/body_reader.go already tracks lastSuccessTime. It should use this to enforce an idle timeout, e.g.:

func (br *bodyReader) Read(p []byte) (int, error) {
    // Set a per-read deadline on the underlying connection
    if br.idleTimeout > 0 && !br.lastSuccessTime.IsZero() {
        if time.Since(br.lastSuccessTime) > br.idleTimeout {
            return 0, fmt.Errorf("read idle timeout after %v with no data", br.idleTimeout)
        }
    }
    // ... existing Read logic ...
}

Or better, wrap the response body with a deadline-enforcing reader at the http.Transport level.

This would fix the issue for all consumers of containers/image, not just the proxy.

Workaround

Kill the skopeo process to unblock rpm-ostree:

sudo kill $(pgrep -f 'skopeo experimental-image-proxy')

rpm-ostree/zincati will detect the child exit and can retry the upgrade.

Related

• containers/image issue #1145 — RFE for per-layer retry on blob download failures
• containers/image PR #1469 — proposed reducing TCP KeepAlive from 30s to 15s for faster dead connection detection
• containers/image docker/body_reader.go — reconnection logic handles ECONNRESET/ErrUnexpectedEOF but not stalls
• containers/container-libs common/pkg/json-proxy/handler.go — proxy handler with the mutex/wg.Wait deadlock

[dustymabe]

Note I am able to reproduce this on latest rawhide Fedora CoreOS 45.20260518.91.1 (qemu):

Software:

$ rpm -q rpm-ostree ostree skopeo bootc
rpm-ostree-2025.6-6.fc42.x86_64
ostree-2025.2-2.fc42.x86_64
skopeo-1.18.0-1.fc42.x86_64
bootc-1.1.6-3.fc42.x86_64

Reproducer:

sudo mount -o remount,rw /sysroot
sudo env RUST_LOG=debug ostree container image pull /ostree/repo ostree-unverified-registry:quay.io/fedora/fedora-coreos:42.20250929.2.0 

It may be hard to reproduce so it might take a loop:

sudo env RUST_LOG=debug ostree container image remove --repo /ostree/repo docker://quay.io/fedora/fedora-coreos:42.20250929.2.0 && \
sudo env RUST_LOG=debug ostree container image pull /ostree/repo ostree-unverified-registry:quay.io/fedora/fedora-coreos:42.20250929.2.0      

Output:

$ sudo env RUST_LOG=debug ostree container image pull /ostree/repo ostree-unverified-registry:quay.io/fedora/fedora-coreos:42.20250929.2.0 
DEBUG argv0="ostree-container"
DEBUG new_with_config: Spawned skopeo pid=4241 config=ImageProxyConfig { authfile: None, auth_data: None, auth_anonymous: true, certificate_directory: None, decryption_keys: None, insecure_skip_tls_verification: Some(false), user_agent_prefix: None, debug: false, skopeo_cmd: Some("skopeo") }
DEBUG new_with_config: Remote protocol version: 0.2.8 config=ImageProxyConfig { authfile: None, auth_data: None, auth_anonymous: true, certificate_directory: None, decryption_keys: None, insecure_skip_tls_verification: Some(false), user_agent_prefix: None, debug: false, skopeo_cmd: Some("skopeo") }
DEBUG Wrote merge commit 22eb7a4afe9e59fc78215756214265d7a95a4ed0cab245edaaca4742f8532450
DEBUG open_image: opening image self=ImageProxy imgref="docker://quay.io/fedora/fedora-coreos:42.20250929.2.0"
DEBUG finish_pipe: closing pipe self=ImageProxy pipeid=PipeId(7)
DEBUG finish_pipe: closing pipe self=ImageProxy pipeid=PipeId(8)
layers already present: 1; layers needed: 50 (945.7 MB)
DEBUG Fetching base
DEBUG get_layer_info: Getting layer info self=ImageProxy img=OpenedImage(1)
DEBUG get_layer_info:finish_pipe: closing pipe self=ImageProxy img=OpenedImage(1) self=ImageProxy pipeid=PipeId(8)
DEBUG fetching sha256:aab5ce09aecad74a10ca3002622fbde68a1fd068fc08b79bd8035aaaf3a6b980
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:aab5ce09aecad74a10ca3002622fbde68a1fd068fc08b79bd8035aaaf3a6b980", split: 6 } size=40581841
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk aab5ce09aecad74a10c (40.6 MB)                                                                                                                                                                                                                       
 36.77 MiB [███████████████████░] (0s) Fetching ostree chunk aab5ce09aecad74a10c (40.6 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_aab5ce09aecad74a10ca3002622fbde68a1fd068fc08b79bd8035aaaf3a6b980 => 7bd1e14c64e45b1d38cf498c54d7f52fbdc3ceeaee0465b7533ebb62ffa02ef0
DEBUG Read extra 13 bytes at end of decompressor stream
DEBUG fetching sha256:192fefea68d06ffbd2ad57402b700d0b293769687d5a07445e35a5079155edc4
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:192fefea68d06ffbd2ad57402b700d0b293769687d5a07445e35a5079155edc4", split: 6 } size=105978439
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 192fefea68d06ffbd2a (106.0 MB)                                                                                                                                                                                                                      
 101.07 MiB [███████████████████░] (0s) Fetching ostree chunk 192fefea68d06ffbd2a (106.0 MB)                                                                                                                                                                                                               
DEBUG Wrote ostree/container/blob/sha256_3A_192fefea68d06ffbd2ad57402b700d0b293769687d5a07445e35a5079155edc4 => c4e7ad1c40b7280075f9904fafd216c63158d5c901055fd07d5c0e710a01b203
DEBUG Read extra 13 bytes at end of decompressor stream
 101.07 MiB [████████████████████] (0s) Fetching ostree chunk 192fefea68d06ffbd2a (106.0 MB)                                                                                                                                                                                                               
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:3b81a3dbd70ecccbf8e0b5c6a592b6e32437320b5c216c630786ef0bf57e4f09", split: 6 } size=37804337
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 3b81a3dbd70ecccbf8e (37.8 MB)                                                                                                                                                                                                                       
 36.05 MiB [███████████████████░] (0s) Fetching ostree chunk 3b81a3dbd70ecccbf8e (37.8 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_3b81a3dbd70ecccbf8e0b5c6a592b6e32437320b5c216c630786ef0bf57e4f09 => 28c6fae82b6082b313cbfe7228ac3de469867b558db849fd10ca0214a8bc313e
DEBUG Read extra 14 bytes at end of decompressor stream
 36.05 MiB [████████████████████] (0s) Fetching ostree chunk 3b81a3dbd70ecccbf8e (37.8 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:8ea5ad3e5189a3ff4908874f0c7cf57eae426272a3cdc44b0f0ede81b6766e99", split: 6 } size=100082590
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 8ea5ad3e5189a3ff490 (100.1 MB)                                                                                                                                                                                                                      
 95.45 MiB [███████████████████░] (0s) Fetching ostree chunk 8ea5ad3e5189a3ff490 (100.1 MB)                                                                                                                                                                                                                
DEBUG Wrote ostree/container/blob/sha256_3A_8ea5ad3e5189a3ff4908874f0c7cf57eae426272a3cdc44b0f0ede81b6766e99 => f9b09e9c5eec1c651470ebc4f9e0ce736ca1e74ee6e2192160683293c7ff5ff8
DEBUG Read extra 14 bytes at end of decompressor stream
 95.45 MiB [████████████████████] (0s) Fetching ostree chunk 8ea5ad3e5189a3ff490 (100.1 MB)                                                                                                                                                                                                                
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:b76ed3b619614796f27eeb8ddd62a5273346bf8be8e2c6d0a7c95594a23d2a83", split: 6 } size=28469492
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk b76ed3b619614796f27 (28.5 MB)                                                                                                                                                                                                                       
 27.15 MiB [███████████████████░] (0s) Fetching ostree chunk b76ed3b619614796f27 (28.5 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_b76ed3b619614796f27eeb8ddd62a5273346bf8be8e2c6d0a7c95594a23d2a83 => 8a2ae6aa0c68cedf2aeadebe57f0aa3ccfb87a27f46a4e7aa95c01aa9e155e17
DEBUG Read extra 13 bytes at end of decompressor stream
 27.15 MiB [████████████████████] (0s) Fetching ostree chunk b76ed3b619614796f27 (28.5 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:046fd3c1057b23733b1baba65f3c5c40cc2e9da42bfe4cbd5dc5c8830a97b664", split: 6 } size=72537703
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 046fd3c1057b23733b1 (72.5 MB)                                                                                                                                                                                                                       
 69.17 MiB [███████████████████░] (0s) Fetching ostree chunk 046fd3c1057b23733b1 (72.5 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_046fd3c1057b23733b1baba65f3c5c40cc2e9da42bfe4cbd5dc5c8830a97b664 => 4f935cb14b61720b9033c0bc3f427a19554b4f0dcb5fca89975b84627f8ace8c
DEBUG Read extra 13 bytes at end of decompressor stream
 69.18 MiB [████████████████████] (0s) Fetching ostree chunk 046fd3c1057b23733b1 (72.5 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:996b57fcff6b7a7622d27f467d64c85218589b5c7307c87328a61210068a49a2", split: 6 } size=19130460
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 996b57fcff6b7a7622d (19.1 MB)                                                                                                                                                                                                                       
 18.24 MiB [███████████████████░] (0s) Fetching ostree chunk 996b57fcff6b7a7622d (19.1 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_996b57fcff6b7a7622d27f467d64c85218589b5c7307c87328a61210068a49a2 => 9e216f6823a7ebb5621b1f2bebbf0c6c1024fae98dfa7e464cee55cfaa0d236c
DEBUG Read extra 14 bytes at end of decompressor stream
 18.24 MiB [████████████████████] (0s) Fetching ostree chunk 996b57fcff6b7a7622d (19.1 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:033db93d0a281e64ef2a2755340ebe5a6d9558521b1f4747d0bef02b61d4d282", split: 6 } size=44274788
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 033db93d0a281e64ef2 (44.3 MB)                                                                                                                                                                                                                       
 42.22 MiB [███████████████████░] (0s) Fetching ostree chunk 033db93d0a281e64ef2 (44.3 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_033db93d0a281e64ef2a2755340ebe5a6d9558521b1f4747d0bef02b61d4d282 => cbaafbdc3be38ddf37dce60c6db95b2c47c9d6934982a11d2faf11adc3df6e38
DEBUG Read extra 14 bytes at end of decompressor stream
 42.22 MiB [████████████████████] (0s) Fetching ostree chunk 033db93d0a281e64ef2 (44.3 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:5623f801e6989a8169aa4cc7eeb447be5a94e33655c65f807348d749648a9c5d", split: 6 } size=13375370
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk 5623f801e6989a8169a (13.4 MB)                                                                                                                                                                                                                       
 12.76 MiB [████████████████████] (0s) Fetching ostree chunk 5623f801e6989a8169a (13.4 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_5623f801e6989a8169aa4cc7eeb447be5a94e33655c65f807348d749648a9c5d => 64854aaa22f0b95255f71327ccce85831f6526aceecec045a836f3f4e65b870b
DEBUG Read extra 13 bytes at end of decompressor stream
 12.76 MiB [████████████████████] (0s) Fetching ostree chunk 5623f801e6989a8169a (13.4 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:f29802b0738633ca380855b417ce0f9cd7a3e0aca386857acd5c73fd04d79fc9", split: 6 } size=15655355
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk f29802b0738633ca380 (15.7 MB)                                                                                                                                                                                                                       
 14.93 MiB [███████████████████░] (0s) Fetching ostree chunk f29802b0738633ca380 (15.7 MB)                                                                                                                                                                                                                 
DEBUG Wrote ostree/container/blob/sha256_3A_f29802b0738633ca380855b417ce0f9cd7a3e0aca386857acd5c73fd04d79fc9 => f8b92961f4ef4e7ff1370f4b5e8220ef17212e5c200f6810ca5ca7ade4e698b0
DEBUG Read extra 14 bytes at end of decompressor stream
 14.93 MiB [████████████████████] (0s) Fetching ostree chunk f29802b0738633ca380 (15.7 MB)                                                                                                                                                                                                                 
DEBUG get_blob: fetching blob self=ImageProxy img=OpenedImage(1) digest=Digest { algorithm: Sha256, value: "sha256:df73c54f907ca7dd0514dc9d7ff62d5d87f0654f5072db11c1809643cd63e678", split: 6 } size=9914307
 0 B [░░░░░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk df73c54f907ca7dd051 (9.9 MB)                                                                                                                                                                                                                        
 2.01 MiB [████░░░░░░░░░░░░░░░░] (0s) Fetching ostree chunk df73c54f907ca7dd051 (9.9 MB)                                                                                                                                                                                                                   

[cgwalters]

Why This Only Affects the Proxy Path ... This deadlock does not occur with direct podman pull or skopeo copy because:

I think it's worth spending more tokens on this, I am a bit skeptical.

3. FinishPipe holds mutex during wg.Wait() — deadlocks entire proxy (skopeo/container-libs)

That said, this issue bit us before and it's one reason we added GetRawBlob, which isn't used yet by bootc or rpm-ostree (ref bootc-dev/containers-image-proxy-rs#114 among other things)

[mtrmac]

Fix 3 (containers/image — medium priority): Add idle timeout to bodyReader

There might be something to this; compare podman-container-tools/container-libs#777 .

I think it’s pretty unexpected to see a connection where keep-alives work but otherwise the progress stalls indefinitely (= a server DoS if it happens at scale), and I’d much prefer seeing a server-side diagnosis+fix.

But if you had/have a semi-reliable reproducer for such a situation, that would be a strong reason to do something on the client side as well.

---

*grumble* https://github.com/containers/container-libs/blob/main/CONTRIBUTING.md#llm-ai-policy

Why This Only Affects the Proxy Path

1. Direct pulls use the caller's context (which can be canceled via ctrl-C, systemd timeout, etc.)

AFAIK that’s not happening.

Suggested Fixes

Fix 1 (proxy — high priority): Don't hold mutex during wg.Wait()

In handler.go, FinishPipe should release the mutex before waiting:

Makes no difference at all, the server will not be processing any request until FinishPipe returns anyway.

Fix 2 (proxy — high priority): Wire context through to the io.Copy goroutine

Makes no difference at all, (the LLM already knew) nothing cancels that context.

[dustymabe]

Sorry @mtrmac. Thank you for sharing a link to the policy. I'll try to adhere to the policy in the future.

There are two details I think are most significant:

1. When this happens the process never makes any more progess. Which could have ramifications for our downstreams one day if they find themselves in a similar situation (I'm still not sure if it's the CDN or a particular network environment that triggers this corner case).
2. There is the reproducer and for the time being I seem to have an environment where I can reproduce this.

On point 2. if someone wants to share an RPM (can build against rawhide) or probe it further, let me know!

[mtrmac]

@dustymabe if you have the time, testing #777 would 1) ~prove the hypothesis and 2) validate that kind of fix. Now, it does nothing to explain why the server can get into such a state… worth filing a Quay support ticket?

[dustymabe]

You mean podman-container-tools/container-libs#777 ?

Is there an RPM that exists somewhere for that? Would this require re-compiling the various pieces (the reproducer is initiated through the ostree command) or is it dynamically linked?

[cgwalters]

Regarding the AI policy - what I personally like is a flow of:

• File issue with (generally) human-written text without excessive detail
• Edit the issue to include a <details> section and dump more LLM-generated content there

Doing things this way makes it easy to follow the LLM content (which often has some useful information) but e.g. avoids people getting email notifications seeing a big dump.

Worth proposing a policy extension of this form?

[dustymabe]

Regarding the AI policy - what I personally like is a flow of:

Yeah. I tried to do the "human introduction" up front in the issue and then paste in the AI stuff later. I could have done this in a <details> or just attached a markdown or HTML file with it I guess.

[cgwalters]

Is there an RPM that exists somewhere for that? Would this require re-compiling the various pieces (the reproducer is initiated through the ostree command) or is it dynamically linked?

It's Go so there's little dynamic linking. Testing that PR or similar code is updating the vendoring of container-libs in this repo, and installing a new /usr/bin/skopeo binary.

I think at this point we should probably deduplicate the reports though - it's not immediately clear to me that FinishPipe is involved here - it seems by far more likely that we really do want a container-libs wide fix.

[dustymabe]

installing a new /usr/bin/skopeo binary.

ahh yes. that's the critical piece. I don't need to rebuild anything in rpm-ostree/ostree/bootc land because it shells out to skopeo.

[mtrmac]

Regarding the AI policy

It’s more “no-one has time to be refuting nonsensical hypotheses” than any styling aspect. (Now, OTOH, the details pointing at specific socket statistics as the smoking gun are valuable and would not always be a part of human-written report… assuming those are not hallucinated as well.)

[mtrmac]

You mean containers/container-libs#777 ?

Yes, my mistake.

[dustymabe]

I can try to compile with podman-container-tools/container-libs#777 and give it a try, but it will have to wait until tomorrow (or possibly Wednesday).