buildctl du undercounts snapshots, causing GC to severely underestimate real disk usage

[ZRHann]

Symptom

BuildKit's buildctl du output systematically undercounts disk usage: a layer's extracted snapshot remains on disk, but the active cache record's Size does not include this snapshot.

As a result, GC's space decisions are based on underestimated totalSize:

• maxUsedSpace / reservedSpace are compared against buildctl du's totalSize, so real usage appears smaller than it actually is;
• minFreeSpace uses real df.Free to decide whether to trigger, but when < reservedSpace, it cannot trigger GC;
• In practice, on a 3TB disk with reservedSpace=1.5T, GC never fires because when real usage reaches 3TB, buildctl du still reports < 1.5T.

Root cause overview

BuildKit uses a "whoever extracts owns the accounting" rule for snapshots:

• A record that has run unlazyLayer sets blobOnly=false, and its size() includes the snapshot;
• A lazy record that shares an already-existing snapshot stays blobOnly=true, and its size() skips the snapshot and only counts its blob.

The problem:

1. GC first deletes/marks-dead one or more records via BuildKit prune;
2. There is a window between record deletion and containerd's physical mark-sweep (GarbageCollect);
3. Within this window, a new build FROMing the same image creates a new lazy record B;
4. B's snapshotID is recomputed from chainID and happens to equal the snapshot that already exists on disk;
5. B adds a lease on that snapshot (AddResource tolerates AlreadyExists), so at mark-sweep time the snapshot is preserved;
6. But B never flips blobOnly=false, so size() never accounts for the snapshot.

Final state: the snapshot truly exists on disk, is kept alive by B's lease, and will not be reclaimed by containerd GC; but in buildctl du the size only counts the blob, not the snapshot.

Minimal reproduction

The full flow:

1. First build FROM repro2:gz + RUN, extracting the base snapshot to disk. At this point the decompressor record accounts normally: snapshot + blob ≈ 6.84MB.
2. GC is configured with two policies. auto-GC's policy 1 uses an aggressive threshold and deletes the whole decompressor chain. At this moment containerd's physical GarbageCollect has not yet run, so the base snapshot is still on disk.
3. The patch widens this "record already deleted, GarbageCollect not yet running" window to an observable duration, simulating the prune time cost in a real scenario.
4. Within the window, submit a bare FROM repro2:gz build. It recomputes the same snapshotID from chainID, creates a new lazy record, and leases the base snapshot that already exists on disk.
5. GarbageCollect then runs: because the new lazy record holds a lease, the snapshot is not mark-swept; but that record is still blobOnly=true, so buildctl du only counts the blob and misses the snapshot.
6. After the first GarbageCollect completes, submit another FROM repro2:gz build to trigger the next auto-GC, and find that it still undercounts.

The final state of the two modes:

Mode	FROM submission timing	Final buildctl du	Final on-disk snapshot & blob
in	inside the window where records are deleted but GarbageCollect has not run	2.24MB	snapshot 4472KB remains; blob 2176KB remains
after	after GarbageCollect has completed	12.29kB	snapshot 4472KB and blob 2176KB are both swept

Reproduction materials

Final materials:

1. control/control.go diff       # debug GC throttle override
2. cache/manager.go diff         # prune pass delay + GC/pass markers
3. buildkitd-auto-gc.toml        # two GC policies
4. oneshot.sh                    # reproduction script
5. docker run command
6. base image Dockerfile

1) Set up a local registry and base image

base/Dockerfile:

FROM busybox:latest

Start a local registry and push the base image:

docker rm -f bkrepro-reg
docker run -d --name bkrepro-reg -p 127.0.0.1:5100:5000 registry:2

docker build -t 127.0.0.1:5100/repro2:gz -f base/Dockerfile base
docker push 127.0.0.1:5100/repro2:gz

2) BuildKit source patch (debug harness)

The two diffs below are based on upstream moby/buildkit tag v0.31.1 (commit 673b7e0196de0cac83308274b88aaed97a91af74). They are only a reproduction debug harness, not the proposed fix.

control/control.go

diff --git a/control/control.go b/control/control.go
index de0f4c931..46f83fce2 100644
--- a/control/control.go
+++ b/control/control.go
@@ -4,6 +4,7 @@ import (
 	"context"
 	stderrors "errors"
 	"fmt"
+	"os"
 	"runtime/trace"
 	"strconv"
 	"sync"
@@ -139,7 +140,11 @@ func NewController(opt Opt) (*Controller, error) {
 		cache:            opt.CacheManager,
 		gatewayForwarder: gatewayForwarder,
 	}
-	c.throttledGC = throttle.After(time.Minute, c.gc)
+	gcThrottle := time.Minute
+	if d, err := time.ParseDuration(os.Getenv("BUILDKITD_DEBUG_GC_THROTTLE")); err == nil && d > 0 {
+		gcThrottle = d
+	}
+	c.throttledGC = throttle.After(gcThrottle, c.gc)
 	// use longer interval for releaseUnreferencedCache deleting links quickly is less important
 	c.throttledReleaseUnreferenced = throttle.After(5*time.Minute, func() { c.releaseUnreferencedCache(context.TODO()) })

cache/manager.go

diff --git a/cache/manager.go b/cache/manager.go
index 7cb408115..cf0d7a67d 100644
--- a/cache/manager.go
+++ b/cache/manager.go
@@ -5,6 +5,7 @@ import (
 	"context"
 	"fmt"
 	"maps"
+	"os"
 	"slices"
 	"strings"
 	"sync"
@@ -1015,11 +1016,14 @@ func (cm *cacheManager) createDiffRef(ctx context.Context, parents parentRefs, d
 func (cm *cacheManager) Prune(ctx context.Context, ch chan client.UsageInfo, opts ...client.PruneInfo) error {
 	cm.muPrune.Lock()
 
-	for _, opt := range opts {
+	for idx, opt := range opts {
 		if err := cm.prune(ctx, ch, opt); err != nil {
 			cm.muPrune.Unlock()
 			return err
 		}
+		if os.Getenv("BUILDKITD_DEBUG_PRUNE_GC_DELAY") != "" {
+			bklog.G(ctx).Warnf("debug: prune pass idx=%d finished", idx)
+		}
 	}
 
 	cm.muPrune.Unlock()
@@ -1028,6 +1032,9 @@ func (cm *cacheManager) Prune(ctx context.Context, ch chan client.UsageInfo, opt
 		if _, err := cm.GarbageCollect(ctx); err != nil {
 			return err
 		}
+		if os.Getenv("BUILDKITD_DEBUG_PRUNE_GC_DELAY") != "" {
+			bklog.G(ctx).Warnf("debug: GarbageCollect finished (BUILDKITD_DEBUG_PRUNE_GC_DELAY)")
+		}
 	}
 
 	return nil
@@ -1080,11 +1087,21 @@ func (cm *cacheManager) prune(ctx context.Context, ch chan client.UsageInfo, opt
 	}
 	for {
 		releasedSize, releasedCount, err := cm.pruneOnce(ctx, ch, popt)
-		if err != nil || releasedCount == 0 {
+		if err != nil {
 			return err
 		}
+		if releasedCount == 0 {
+			break
+		}
 		popt.totalSize -= releasedSize
 	}
+	if d, err := time.ParseDuration(os.Getenv("BUILDKITD_DEBUG_PRUNE_GC_DELAY")); err == nil && d > 0 {
+		bklog.G(ctx).Warnf("debug: delaying end of prune pass by %v (BUILDKITD_DEBUG_PRUNE_GC_DELAY)", d)
+		time.Sleep(d)
+	}
+	return nil
 }

Build the patched buildkitd:

CGO_ENABLED=0 go build -o "$HOME/tmp/bktest/buildkitd" ./cmd/buildkitd

3) BuildKitd config: buildkitd-auto-gc.toml

[registry."127.0.0.1:5100"]
  http = true
[worker.oci]
  gc = true
  [[worker.oci.gcpolicy]]
    all = true
    reservedSpace = 0
    maxUsedSpace = "3MB"
  [[worker.oci.gcpolicy]]
    all = true
    maxUsedSpace = "100MB"

4) Reproduction script: oneshot.sh

#!/bin/bash
set -e
ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
MODE="${1:-in}"
SNAP='/var/lib/buildkit/runc-overlayfs/snapshots/snapshots'
CONTENT='/var/lib/buildkit/runc-overlayfs/content/blobs/sha256'
GC_DONE_RE='GarbageCollect finished'
say(){ echo; echo "== $*"; }
du_snap(){ say "snapshots:"; docker exec bkrepro sh -c "du -sk $SNAP/*/fs 2>/dev/null | sort -n"; }
du_blob(){ say "blobs:"; docker exec bkrepro sh -c "du -sk $CONTENT/* 2>/dev/null | sort -n"; }
extractor_present(){ docker exec bkrepro buildctl du -v 2>/dev/null | grep -q 'pulled from 127.0.0.1:5100/repro2:gz'; }
now_ts(){ date -u +%Y-%m-%dT%H:%M:%S.%NZ; }
wait_gc_after(){ # $1 = timestamp; wait for a new GC-finished marker after that time
  local ts="$1"
  echo "   waiting for GarbageCollect to finish..."
  for j in $(seq 1 240); do
    if docker logs --since="$ts" bkrepro 2>&1 | grep -q "$GC_DONE_RE"; then
      echo "   GarbageCollect finished after ${j}x0.5s"
      return 0
    fi
    sleep 0.5
  done
  echo "   no GarbageCollect completion log within 120s, aborting"; exit 1
}
wait_pass_after(){ # $1 = pass idx; $2 = timestamp; wait for that prune pass log
  local idx="$1" ts="$2"
  echo "   waiting for prune pass idx=$idx to finish (window opens during the pass-end debug delay)..."
  for j in $(seq 1 240); do
    if docker logs --since="$ts" bkrepro 2>&1 | grep -q "prune pass idx=$idx finished"; then
      echo "   prune pass idx=$idx finished after ${j}x0.5s"
      return 0
    fi
    sleep 0.5
  done
  echo "   no prune pass idx=$idx log within 120s, aborting"; exit 1
}

CTX="$ROOT/issue-contexts"
mkdir -p "$CTX/decompressor" "$CTX/relay"
cat > "$CTX/decompressor/Dockerfile" <<'EOF'
FROM 127.0.0.1:5100/repro2:gz
RUN echo consumerA > /a
EOF
cat > "$CTX/relay/Dockerfile" <<'EOF'
FROM 127.0.0.1:5100/repro2:gz
EOF

say "[0] mode: $MODE | cleanup"
docker exec bkrepro buildctl prune
docker exec bkrepro buildctl du

say "[1] create the decompressor (should get ~6.8MB chain)"
STEP1_TS=$(now_ts)
docker exec bkrepro buildctl build --frontend dockerfile.v0 \
  --local context=/work/issue-contexts/decompressor --local dockerfile=/work/issue-contexts/decompressor >/dev/null 2>&1
docker exec bkrepro buildctl du -v

say "[2] wait for auto-GC prune pass idx=0 to finish (this opens the post-delete, pre-GarbageCollect window)"
wait_pass_after 0 "$STEP1_TS"
extractor_present && { echo "   pass idx=0 finished but decompressor still exists, aborting"; exit 1; }
WIN_TS=$(now_ts)
docker exec bkrepro buildctl du -v
du_snap
du_blob

if [ "$MODE" = after ]; then
  say "[3] wait for GarbageCollect to finish, then submit FROM"
  wait_gc_after "$WIN_TS"
  echo "   snapshots on disk:"
  du_snap
  du_blob
  say "[3b] submit FROM after GarbageCollect (same image)"
  docker exec bkrepro buildctl build --frontend dockerfile.v0 \
    --local context=/work/issue-contexts/relay --local dockerfile=/work/issue-contexts/relay 2>&1 | grep -E "^#4|DONE"
else
  say "[3] submit FROM inside the window immediately (GarbageCollect has not run yet)"
  docker exec bkrepro buildctl build --frontend dockerfile.v0 \
    --local context=/work/issue-contexts/relay --local dockerfile=/work/issue-contexts/relay 2>&1 | grep -E "^#4|DONE"
  say "[3b] wait for GarbageCollect to finish"
  wait_gc_after "$WIN_TS"
fi

say "[4] ledger after the first GC"
docker exec bkrepro buildctl du -v

say "[5] snapshots and blobs on disk after the first GC"
du_snap
du_blob

if [ "$MODE" = in ]; then
  say "[6] run another build after the first GarbageCollect is done, to trigger another GC"
  POST_TS=$(now_ts)
  docker exec bkrepro buildctl build --frontend dockerfile.v0 \
    --local context=/work/issue-contexts/relay --local dockerfile=/work/issue-contexts/relay 2>&1 | grep -E "^#4|DONE"
  wait_gc_after "$POST_TS"

  say "[7] ledger and disk after the second GarbageCollect"
  docker exec bkrepro buildctl du -v
  du_snap
  du_blob
fi

5) docker run command

Start patched buildkitd:

docker rm -f bkrepro
docker run -d --name bkrepro --privileged --network host \
  -e BUILDKITD_DEBUG_PRUNE_GC_DELAY=10s \
  -e BUILDKITD_DEBUG_GC_THROTTLE=1s \
  -v "$HOME/tmp/bktest/buildkitd:/usr/bin/buildkitd:ro" \
  -v "$HOME/tmp/bktest/buildkitd-auto-gc.toml:/etc/buildkit/buildkitd.toml:ro" \
  -v "$HOME/tmp/bktest:/work" \
  docker.io/moby/buildkit:v0.31.1@sha256:2caaaf9bc673a82d5b0a87824f8375e6b2b36b55001dad611230516c724e9fba

Run the positive case:

"$HOME/tmp/bktest/oneshot.sh" in

Run the control group (recommended to start a fresh container):

docker rm -f bkrepro
docker run -d --name bkrepro --privileged --network host \
  -e BUILDKITD_DEBUG_PRUNE_GC_DELAY=10s \
  -e BUILDKITD_DEBUG_GC_THROTTLE=1s \
  -v "$HOME/tmp/bktest/buildkitd:/usr/bin/buildkitd:ro" \
  -v "$HOME/tmp/bktest/buildkitd-auto-gc.toml:/etc/buildkit/buildkitd.toml:ro" \
  -v "$HOME/tmp/bktest:/work" \
  docker.io/moby/buildkit:v0.31.1@sha256:2caaaf9bc673a82d5b0a87824f8375e6b2b36b55001dad611230516c724e9fba

"$HOME/tmp/bktest/oneshot.sh" after

Expected output summary

in

[1] Total: 6.84MB

[2] pass idx=0 finished
    Total: 0B
    4472KB base snapshot still on disk

[3] FROM inside the deletion/GC window
[3b] GarbageCollect finished

[4] Total: 2.24MB
[5] 4472KB base snapshot survives

[7] after second GC:
    Total: 2.24MB
    4472KB base snapshot survives

after

[1] Total: 6.84MB

[2] pass idx=0 finished
    Total: 0B
    4472KB base snapshot still on disk before GC sweeps it

[3] GarbageCollect finished

[4] Total: 12.29kB
[5] 4472KB base snapshot is gone

Possible fix

When GetByBlob finds that the chainID snapshot already exists and no live record on that chainID is currently accounting for it (no live blobOnly=false holder), make the new record blobOnly=false and queueSize(sizeUnknown).

I’m happy to open a PR for this if the direction sounds reasonable.

[ZRHann]

Update: after checking more production data, I found this lazy-relay phantom case is not the main cause of the GC size undercount on that node. I’m continuing to investigate and will update here once I have a clearer root cause.