Failure lab — unbounded logs fill the disk · Docker & Containers

The scenario is real and it is the one you will actually meet: somebody deploys a service with the log level left at DEBUG, including request bodies. Twenty-four hours later /var/lib/docker is at 100% and every workload on the host is failing for reasons that look unrelated to logging.

This lab reproduces it deliberately. Every stage ends in a check whose output tells you whether the stage worked, rather than whether the command ran.

Stage 0 — establish the baseline

You cannot detect growth without a starting point. Record one.

Read-only / Safebaseline— Free space and existing log consumption before anything is created.

df -h /var/lib/docker | tee /var/tmp/loglab-baseline.txt

sudo du -sh /var/lib/docker/containers 2>/dev/null | tee -a /var/tmp/loglab-baseline.txt

docker info --format 'driver={{.LoggingDriver}}'

If docker info already reports something other than json-file, or if you have log-opts in daemon.json, move them aside first — otherwise Stage 1 will not reproduce the fault, and a lab that cannot fail teaches nothing.

Stage 1 — reproduce

Start a container that logs continuously with no rotation configured. Note that no --log-opt is given: this is the stock configuration, and that is the finding.

Service impact possiblethe log bomb— A container emitting realistic-looking DEBUG lines as fast as it can. Consumes disk until stopped.

docker run -d --name logbomb --log-driver json-file alpine:3.20 sh -c '
i=0
while :; do
i=$((i+1))
echo "$(date -Iseconds) level=debug seq=$i msg=request_completed path=/api/v1/orders status=200 duration_ms=42 body=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA"
done'

docker ps --filter name=logbomb --format 'table {{.Names}}\t{{.Status}}'

Stage 2 — measure, do not guess

The instinct at this point is to watch df -h until something happens. That wastes the most useful thirty seconds of the incident. Measure the rate instead, and turn it into a time-to-full figure you can act on.

Read-only / Safegrowth rate— Sample the log file twice, thirty seconds apart, and derive bytes per second.

CONTAINER=logbomb
CID=$(docker inspect --format '{{.Id}}' "$CONTAINER")
LOGFILE="/var/lib/docker/containers/$CID/$CID-json.log"

A=$(sudo stat -c %s "$LOGFILE")
sleep 30
B=$(sudo stat -c %s "$LOGFILE")

RATE=$(( (B - A) / 30 ))
echo "growth: $RATE bytes/sec  ($(( RATE * 86400 / 1024 / 1024 )) MB/day)"

FREE=$(df --output=avail -B1 /var/lib/docker | tail -1)
echo "free: $((FREE / 1024 / 1024)) MB"
echo "time to full: $(( FREE / (RATE > 0 ? RATE : 1) / 3600 )) hours"

Read-only / Safeexpected shape— Numbers vary with host speed; the shape does not.

$ bash /var/tmp/loglab-rate.sh

growth: 412719 bytes/sec  (33966 MB/day)
free: 38402 MB
time to full: 25 hours

Illustrative output

That single number — hours to full — is what turns a vague “the disk is filling” into a decision about whether you have time to find the root cause or must reclaim space right now.

Why the obvious diagnosis is wrong

Somebody hits a full disk on a Docker host and runs docker system df. It reports the four categories Docker accounts for, and the Containers row — which counts writable layers only — shows a few hundred kilobytes.

Log files live in /var/lib/docker/containers/<id>/, outside the writable layer. They appear in no column of docker system df. So the tool purpose-built for “where did my Docker disk go” reports that Docker is not using the disk, while a container log quietly holds 37 GB.

The next move is usually docker system prune -a, which reclaims a couple of gigabytes of unreferenced images, buys twenty minutes, deletes the image you needed to roll back to, and leaves the actual consumer untouched and still growing. Confirm with du before you delete anything:

Read-only / Safefind the real consumer— The command docker system df cannot substitute for.

sudo du -sh /var/lib/docker/containers/* | sort -h | tail -5

Stage 3 — confirm the diagnosis before acting

Two questions, two commands. Both answers must be consistent before you touch anything.

Read-only / Safeconfirm— Is this container uncapped, and is its log the largest thing in the tree?

CONTAINER=logbomb

# Q1: what log configuration is this container actually running with?
docker inspect --format \
'{{.Name}} driver={{.HostConfig.LogConfig.Type}} opts={{.HostConfig.LogConfig.Config}}' \
"$CONTAINER"

# Q2: does the file size match the consumption you measured?
CID=$(docker inspect --format '{{.Id}}' "$CONTAINER")
sudo ls -lh /var/lib/docker/containers/"$CID"/"$CID"-json.log*

An opts=map[] in the first answer is the diagnosis: the container has no rotation whatsoever. If the map is populated and the file is still enormous, you have a different problem — a single log line larger than max-size, or a different consumer entirely — and the remedy below is the wrong one.

Stage 4 — the recovery that does not work, and the one that does

This stage exists because the intuitive command is the wrong one, and the reason is not obvious from anything Docker prints.

Destructivedemonstrate why rm fails— Deletes the log file and shows that no space is returned. Lab hosts only.

CONTAINER=logbomb
CID=$(docker inspect --format '{{.Id}}' "$CONTAINER")
LOGFILE="/var/lib/docker/containers/$CID/$CID-json.log"

BEFORE=$(df --output=avail -B1 /var/lib/docker | tail -1)
sudo rm -f "$LOGFILE"
sleep 5
AFTER=$(df --output=avail -B1 /var/lib/docker | tail -1)

echo "freed by rm: $(( (AFTER - BEFORE) / 1024 / 1024 )) MB"

# The inode is gone from the directory but not from the filesystem.
DOCKERD=$(pgrep -x dockerd | head -1)
sudo ls -l /proc/"$DOCKERD"/fd 2>/dev/null | grep -F 'json.log' | grep -F '(deleted)'

Read-only / Safewhat rm actually did— No space returned, and the daemon is still writing to an inode with no name.

$ bash /var/tmp/loglab-rm.sh

freed by rm: 0 MB
l-wx------ 1 root root 64 Aug 12 09:41 27 -> /var/lib/docker/containers/9c7e.../9c7e...-json.log (deleted)

Illustrative output

Zero megabytes freed, and the file descriptor is still open on a deleted inode. The container keeps logging into it, the space keeps growing, and you can no longer measure it with du on the path because the path no longer exists. You have made the incident harder to diagnose without making it smaller.

unlink(2) versus truncate(2)

rm calls unlink(2), which removes a directory entry. The inode and its data blocks are released only when both the link count and the open-descriptor count reach zero. The daemon holds a descriptor for the life of the container, so the blocks stay allocated until the container stops or the daemon restarts.

truncate -s 0 calls truncate(2), which sets the file length to zero and releases the data blocks immediately. The inode survives, so every open descriptor stays valid, and the daemon’s next append simply writes into the now-empty file.

One further consequence of rm: the daemon’s rotation logic operates on the path. With the path gone, rotation can no longer rename the active file, so max-size stops being enforced for that container even if you configure it. The container has to be recreated to get back to a sane state.

Now do it correctly. Note the evidence capture first — the log is the only record of whatever caused the incident, and this step destroys it.

Destructivereclaim correctly— Capture evidence, then release the blocks without invalidating the daemon's descriptor.

CONTAINER=logbomb

# The rm above removed the path, so recreate the container to restore a sane
# state before demonstrating the correct recovery.
docker rm -f "$CONTAINER" > /dev/null
docker run -d --name "$CONTAINER" --log-driver json-file alpine:3.20 sh -c '
while :; do echo "$(date -Iseconds) level=debug msg=filler"; done'
sleep 20

CID=$(docker inspect --format '{{.Id}}' "$CONTAINER")
LOGFILE="/var/lib/docker/containers/$CID/$CID-json.log"

sudo tail -c 2M "$LOGFILE" > /var/tmp/loglab-evidence.json

BEFORE=$(df --output=avail -B1 /var/lib/docker | tail -1)
sudo truncate -s 0 "$LOGFILE"
AFTER=$(df --output=avail -B1 /var/lib/docker | tail -1)

echo "freed by truncate: $(( (AFTER - BEFORE) / 1024 / 1024 )) MB"
docker logs --tail 2 "$CONTAINER"

The last line is the assertion that matters: docker logs still returns output after the truncation, which proves the daemon’s descriptor survived and the container is logging normally.

Stage 5 — fix it, and verify the fix

Set rotation at the daemon level. Add log-opts with max-size and max-file to /etc/docker/daemon.json. Every value must be a quoted string.
Validate the JSON before it reaches the daemon. A malformed daemon.json means the daemon will not start, on a host full of running containers.
Reload rather than restart. A reload re-reads the configuration without disturbing running containers.
Observe that the running container is still uncapped. This is the step everyone skips, and it is why the incident recurs.
Recreate the workload. Remove and run again, or use compose with force-recreate. A restart is not sufficient because it reuses the same container object.
Run the audit and confirm every container reports a populated options map.
Fix the application. Rotation bounds the damage; it does not stop a service logging request bodies at DEBUG in production.

Configuration changeapply rotation— Daemon default, validated before it is applied.

sudo tee /etc/docker/daemon.json.new > /dev/null <<'EOF'
{
"log-driver": "json-file",
"log-opts": {
  "max-size": "10m",
  "max-file": "3"
}
}
EOF

sudo python3 -m json.tool /etc/docker/daemon.json.new > /dev/null \
&& sudo mv /etc/docker/daemon.json.new /etc/docker/daemon.json \
&& sudo systemctl reload docker

Now the step that proves the point. The container is still running, the daemon has reloaded, and nothing about this container changed:

Read-only / Safethe half-fix, exposed— After the reload, before the recreation. The options map is still empty.

$ docker inspect --format '{{.HostConfig.LogConfig.Config}}' logbomb

map[]

Illustrative output

Recreate, then assert. This script exits non-zero when the fix has not landed, which is what makes it a verification rather than a demonstration:

Read-only / Safeverification that can fail— Exits 1 if any running container lacks a max-size. Suitable for a nightly check.

docker rm -f logbomb > /dev/null
docker run -d --name logbomb alpine:3.20 sh -c 'while :; do echo filler; done' > /dev/null

FAIL=0
for C in $(docker ps -q); do
NAME=$(docker inspect --format '{{.Name}}' "$C")
OPTS=$(docker inspect --format '{{.HostConfig.LogConfig.Config}}' "$C")
DRIVER=$(docker inspect --format '{{.HostConfig.LogConfig.Type}}' "$C")
case "$DRIVER" in
  journald|local|none) continue ;;
esac
case "$OPTS" in
  *max-size*) echo "ok   $NAME $OPTS" ;;
  *)          echo "FAIL $NAME has no max-size"; FAIL=1 ;;
esac
done
exit "$FAIL"

local and journald are excluded deliberately: local is bounded by its own defaults and journald is bounded by journald.conf, so demanding a max-size on them would produce a false failure. A check that cries wolf gets turned off, and then it protects nothing.

Confirm the ceiling actually holds by letting the container run past it:

Read-only / Safeprove the ceiling— After several minutes, total log size must stay under max-size times max-file.

CID=$(docker inspect --format '{{.Id}}' logbomb)
sleep 300
TOTAL=$(sudo du -cb /var/lib/docker/containers/"$CID"/"$CID"-json.log* | tail -1 | cut -f1)
echo "total log bytes: $TOTAL (ceiling: $((10 * 1024 * 1024 * 3)))"
[ "$TOTAL" -le $((10 * 1024 * 1024 * 3 + 1048576)) ] \
&& echo 'PASS: rotation is bounding the log' \
|| echo 'FAIL: log exceeded the configured ceiling'

Stage 6 — tear down

Destructiveteardown— Removes everything this lab created. Restore your previous daemon.json if you had one.

docker rm -f logbomb 2>/dev/null || true
rm -f /var/tmp/loglab-evidence.json /var/tmp/loglab-baseline.txt

df -h /var/lib/docker

The rm-deleted inode from Stage 4 was released when that container was removed. Confirm with df that free space matches your Stage 0 baseline; if it does not, some descriptor is still open and a daemon restart will release it.

What if the disk is already at 100% when you arrive?

The diagnostic tools stop working, which is what makes this incident disorienting.

Containers get ENOSPC on their next write. Some crash cleanly, some hang in uninterruptible I/O, and databases can corrupt mid-transaction rather than fail. The daemon cannot write container state, so docker ps may hang or return stale rows — and an operator reading a stale docker ps concludes the daemon is wedged rather than that the disk is full. New containers fail with errors about the layer, which reads like a storage-driver fault. The journal stops recording, so the evidence window closes exactly when you need it.

Your own shell degrades too. Redirecting output to a file fails. The editor cannot write its swap file. Command history is not saved.

Buy room before diagnosing. Truncating the single largest container log returns enough space to work in, takes a second, and does not require the daemon to be responsive:

BIGGEST=$(sudo du -a /var/lib/docker/containers/ |
  grep -F -- '-json.log' |
  sort -n | tail -1 | cut -f2)
echo "truncating: $BIGGEST"
sudo truncate -s 0 "$BIGGEST"
df -h /var/lib/docker

Then diagnose properly with the space you just bought. Do not reach for docker system prune -a first: it needs a responsive daemon, it takes minutes, and it deletes the images you may need to bring the host back up.

Knowledge check

Why this matters

Everyone can recite the remedy for this incident. Almost nobody has executed it, and the gap between the two is where the outage lives.

Under pressure, on a host where docker ps is hanging and your redirects are failing with ENOSPC, the difference between an engineer who has run this lab and one who has only read about it is about forty minutes. The one who has run it knows that docker system df will lie by omission, that rm will appear to work and free nothing, that truncate is safe, and that the daemon.json edit they are about to make will not touch a single running container.

Practise it once on a host you are willing to break. The muscle memory is worth more than the theory, and this is one of the very few production failures you can reproduce end to end in half an hour.