df says the disk is 100% full but du finds only a third: deleted files still held open

At 03:40 the ledger worker on one of our batch hosts started failing every job with:

java.io.IOException: No space left on device
    at java.base/java.io.FileOutputStream.writeBytes(Native Method)

The disk alert agreed. /var was full:

$ df -h /var
Filesystem      Size  Used Avail Use% Mounted on
/dev/nvme1n1     98G   93G     0 100% /var

The on-call engineer went looking for the big directory and found nothing big:

$ sudo du -xsh /var
31G     /var
$ sudo du -xh --max-depth=1 /var | sort -h | tail -4
2.1G    /var/cache
4.6G    /var/lib
24G     /var/log
31G     /var

So df said 93 GB were used and du could find 31 GB. Roughly 62 GB were in use but not visible in any directory.

Reproducing it

On a scratch VM the same picture takes four commands:

python3 -c 'import time; f=open("/tmp/big.log","w"); [f.write("x"*1_000_000) or f.flush() for _ in range(2000)]; time.sleep(600)' &
sleep 5; rm /tmp/big.log
df -h /tmp; du -sh /tmp
lsof +L1 | grep big.log

df keeps counting the file's blocks, du no longer sees it, and lsof lists it as (deleted) until the process exits.

What we ruled out

• Reserved blocks. ext4 reserves 5% of blocks for root by default, which makes Avail smaller than Size - Used. That accounts for about 5 GB on this volume, not 62. tune2fs -l /dev/nvme1n1 | grep -i 'reserved block count' confirmed the default.
• Files hidden under a mount point. Data written to a directory before something was mounted over it is invisible to du but still counts in df. We bind-mounted the filesystem elsewhere and measured it without the overlays: mount --bind /var /mnt/var-raw && du -xsh /mnt/var-raw. Still 31 GB.
• Inode exhaustion. df -i /var showed 3% of inodes used, so this was really about blocks.
• Container layers. This host does not run Docker, so the overlay2 class of problem did not apply.

Root cause

lsof +L1 lists open files with a link count below one, which means files that have been deleted but are still open:

$ sudo lsof -nP +L1 /var
COMMAND   PID   USER   FD   TYPE DEVICE    SIZE/OFF NLINK    NODE NAME
java    48211 ledger    7w   REG  259,1 66571993088     0 1310722 /var/log/ledger/app.log.1 (deleted)

One file, 62 GB, deleted, and still open for writing by the ledger JVM on file descriptor 7. The worker had been writing its log into a file that no longer had a name.

The logrotate config for this application explained how it got there:

/var/log/ledger/*.log {
    daily
    rotate 7
    compress
    missingok
    notifempty
    create 0640 ledger ledger
}

Logrotate renamed app.log to app.log.1 and created a fresh app.log. Because compress is set without delaycompress, it then gzipped app.log.1 into app.log.1.gz straight away and deleted the uncompressed file. The JVM kept its file descriptor, which still pointed at that renamed and now deleted inode, and carried on writing into it. The blocks stayed allocated and kept growing for days, while the compressed copy on disk looked like a normal, small rotated log. The empty app.log sitting next to it was the giveaway we had all overlooked.

What is happening under the hood

On Linux, a file is an inode; a name in a directory is just a link to it. rm removes the link. The kernel frees the inode and its blocks only when the link count is zero and no process has the file open. Until then, the data is intact and reachable through /proc/<pid>/fd/<n>.

du walks directory trees and sums sizes of files it can find by name, so a deleted file is invisible to it. df asks the filesystem how many blocks are allocated, which includes deleted-but-open files. A large gap between the two almost always means one of: deleted open files, data hidden under a mount, or reserved blocks.

Logrotate's create mode assumes the application reopens its log file after rotation, either on its own or because a postrotate script tells it to (for example with a signal). Our application did neither. Logback, which it used, never reopens a FileAppender on its own; it expects to do rotation itself with a RollingFileAppender.

Environment

Minimal reproduction

# Simulate an app that never reopens its log
mkdir -p /tmp/rot && cd /tmp/rot
( exec 3>>app.log; while true; do head -c 1048576 /dev/zero >&3; sleep 0.2; done ) &
cat > rot.conf <<'EOF'
/tmp/rot/app.log {
    rotate 2
    compress
    create
}
EOF
logrotate -f -s state rot.conf   # app.log -> app.log.1 -> app.log.1.gz, writer still on the old inode
lsof -nP +L1 | grep /tmp/rot

Who is affected

Any long-running process that writes to a file it opened once: JVM apps with plain file appenders, Python apps using logging.FileHandler, custom daemons. Also common: someone runs rm on a huge log during an incident to "free space", which frees nothing while the writer is alive.

The fix

Step 1, free the space now without restarting. The ledger worker was mid-way through a month-end batch, so a restart was the last thing we wanted. Truncating the deleted file through the process's descriptor releases the blocks immediately, and the process keeps writing at its current offset into what becomes a sparse file:

sudo ls -l /proc/48211/fd/7
# l-wx------ 1 ledger ledger 64 Feb 23 03:52 /proc/48211/fd/7 -> /var/log/ledger/app.log.1 (deleted)
sudo truncate -s 0 /proc/48211/fd/7
df -h /var
# /dev/nvme1n1     98G   31G   63G  33% /var

Only do this to log files whose contents you do not need. If you do need them, copy first: cp /proc/48211/fd/7 /data/recovered-app.log.

Step 2, stop it recurring. We moved rotation into Logback, which rotates and reopens correctly, and removed the logrotate rule for this app:

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
  <file>/var/log/ledger/app.log</file>
  <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
    <fileNamePattern>/var/log/ledger/app.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
    <maxFileSize>1GB</maxFileSize>
    <maxHistory>7</maxHistory>
    <totalSizeCap>20GB</totalSizeCap>
  </rollingPolicy>
  <encoder>
    <pattern>%d{ISO8601} %-5level [%thread] %logger{36} - %msg%n</pattern>
  </encoder>
</appender>

totalSizeCap is the important line: it bounds disk use even if someone leaves DEBUG on again.

Alternatives and trade-offs

• copytruncate in logrotate. Copies the file then truncates it in place, so the app keeps writing to the same inode. Works for apps that cannot reopen, but lines written between the copy and the truncate are lost, and the copy temporarily doubles disk use.
• postrotate with a reopen signal. Ideal when the app supports it (nginx reopens on USR1). Our app had no such hook.
• Log to stdout and let journald or the container runtime handle it. Removes the problem class entirely; journald enforces its own size limits.
• Restart the process. Closes the descriptor and frees the space. Simple, but it was not acceptable mid-batch.

How to test the fix

# Force several rollovers in staging by lowering maxFileSize to 10MB, then:
ls -l /var/log/ledger/
sudo lsof -nP +L1 /var | grep -c ledger || true   # expected: 0
df -h /var; sudo du -xsh /var                     # values within a few percent

Confirming in production

After the deploy, we compared df and du daily for a week; the gap stayed under 1 GB (reserved blocks plus journal). We also checked fleet-wide for any other process holding deleted files:

sudo find /proc/[0-9]*/fd -lname '*(deleted)' -printf '%p -> %l\n' 2>/dev/null \
  | grep -v -e memfd: -e /dev/shm

Two other services on other hosts turned up with small deleted logs. Both got the same treatment.

Regression guard

Our node exporter alerts now include one for a sustained gap between allocated and visible space. Since du is too expensive to run often, the exporter's textfile collector runs a small script every 15 minutes that writes the total size of deleted-but-open files as a metric:

#!/usr/bin/env bash
set -euo pipefail
total=$(lsof -nP +L1 2>/dev/null | awk 'NR>1 && $5=="REG" {s+=$7} END {print s+0}')
echo "node_deleted_open_bytes ${total}" > /var/lib/node_exporter/textfile/deleted_open.prom.$$
mv /var/lib/node_exporter/textfile/deleted_open.prom.$$ /var/lib/node_exporter/textfile/deleted_open.prom

The alert fires when it exceeds 5 GB for 30 minutes. We also alert on disk usage growth rate, not only on a fixed percentage, so a 9 GB-per-day log gets attention days before it fills the volume.

Security implications

Deleting a file does not delete its data while a process holds it open. Logs that contain personal data or tokens, which someone "removed" for compliance reasons, remain readable to root and to the owning user through /proc/<pid>/fd until the process closes them. If a deletion is meant to remove sensitive data, the writing process must be stopped or made to reopen, and the storage-level retention (snapshots, backups) must be handled too. On the availability side, a full /var also breaks package installs, journald and anything writing state there, so the log runaway was effectively a denial of service against the whole host. The truncate through /proc requires root; we documented it in the runbook with the warning to only use it on logs.

Prevention checklist

• Let the application rotate its own logs, or use copytruncate or a reopen signal knowingly.
• Bound log disk use with size caps, not only age-based retention.
• When df and du disagree, run lsof +L1 before deleting anything else.
• Never rm a log that a running process is writing; truncate it instead.
• Alert on disk growth rate and on deleted-but-open bytes.

References

• lsof project and manual: https://github.com/lsof-org/lsof
• proc filesystem, /proc/pid/fd: https://man7.org/linux/man-pages/man5/proc_pid_fd.5.html
• logrotate manual page: https://man7.org/linux/man-pages/man8/logrotate.8.html
• Logback manual, appenders: https://logback.qos.ch/manual/appenders.html
• unlink(2) manual page: https://man7.org/linux/man-pages/man2/unlink.2.html