omeryanbas.com

Ömer Yanbaş

General Manager, Ticofab Yazılım

OperationsData

Log rotation, retention and the silent cost of a full disk

A disk creeping towards full is a slow outage: writes get refused, builds fail, backups truncate. How to find what grew and stop it growing back.

A disk does not fill up all at once, and it rarely announces itself as a disk problem. The symptoms arrive separately: a database that refuses a write, a deploy that fails halfway through the build step, a nightly backup that finished in four seconds instead of four minutes. On one platform I maintain, the root volume sat above 90 per cent for weeks before anything visible broke, and when it did break, three people were debugging three unrelated bugs that had one cause.

What a full disk actually breaks

Free space is not a single number that every service reads and respects. Each one hits a different wall at a different moment, which is why the failures look unrelated.

  • Most filesystems reserve a slice for the superuser, five per cent by default on ext4. Ordinary services are refused first while root can still write, so you can log in comfortably to a machine where the application has been dead for an hour.
  • A database needs space for far more than rows. Write ahead logs, temporary files for sorts and joins that do not fit in memory, and the full copy it makes when it rewrites a table all live on the same volume. A rebuild of a large table can need as much free space again as the table occupies.
  • A build writes the new output before it removes the old one, so peak usage during a deploy is roughly double the size of the artifact. That is why a deploy fails on a disk that looked fine an hour earlier.
  • A dump written to the same volume produces a truncated file rather than an error anyone notices. If the backup script pipes into a compressor and never checks the status of the whole pipeline, it reports success on a file that cannot be restored.
  • Inodes run out independently of bytes. Millions of small session or cache files exhaust the inode table while df still shows free gigabytes, and every create then fails with a message about no space left that makes no sense next to the free space number.

How to see what grew

Start with both numbers, because they fail separately:

df -h /
df -i /

Then walk down the tree one level at a time. Sorting by human readable size and reading the tail is faster than reading a whole listing:

du -x -h -d1 / 2>/dev/null | sort -h | tail -15
du -x -h -d1 /var 2>/dev/null | sort -h | tail -15

The -x flag keeps du on one filesystem, so a mounted backup volume does not distort the picture. Repeat on whatever sits at the top of the list until the answer stops being a directory and becomes a file.

For the single large files that usually hold the surprise:

find / -xdev -type f -size +200M -printf '%10s %p\n' 2>/dev/null | sort -rn | head -20

In my experience the result falls into the same four categories almost every time: an application log that nothing rotates, old build artifacts and released versions that were never pruned, container images and layers from every deploy since the machine was built, and a backup directory somebody created by hand and then forgot.

docker system df
du -sh /var/log/journal /var/log/*.log 2>/dev/null | sort -h | tail

On the database side, ask the database rather than the filesystem, because a data directory tells you nothing about which table grew:

SELECT table_name,
       ROUND((data_length + index_length) / 1024 / 1024) AS mb
FROM information_schema.tables
WHERE table_schema = DATABASE()
ORDER BY mb DESC
LIMIT 10;

Nine times out of ten the top row is an event or audit table designed to be written and never to be deleted.

The fix, in three parts

Rotate both kinds of log

System logs usually have rotation already. Application logs written by the process manager or by the application itself usually do not, and that is where the gigabytes are:

/srv/app/logs/*.log {
  daily
  rotate 14
  compress
  delaycompress
  missingok
  notifempty
  copytruncate
  su appuser appuser
}

copytruncate exists because the application holds the file open and will keep writing to the old inode if you simply rename it. If your process manager keeps its own log files, give it its own rotation with a maximum size and a retained count. Several of them will happily grow one file forever, and a rotation job has to survive a restart like everything else, which is the same lesson as process managers and boot persistence.

Give every table a retention window

Each table gets a window that matches the reason it exists, and the reasons are different:

  • Request and access logs: a few months. They answer what happened last week, and nobody has ever asked about last year.
  • Delivery and event records: the length of the operational question they answer, typically around six months.
  • Financial and ledger rows: a year at minimum, and usually never deleted, only archived somewhere cheaper.

Then the part that gets skipped. The delete needs an index on the date column. Without it, the nightly cleanup is a full table scan holding locks on the busiest table you have, and you have traded a disk problem for a latency problem:

CREATE INDEX idx_events_created_at ON events (created_at);

Delete in batches with a pause between them rather than in one statement that touches millions of rows:

DELETE FROM events
WHERE created_at < NOW() - INTERVAL 180 DAY
ORDER BY created_at
LIMIT 5000;

Run that in a loop until it affects zero rows, with a short sleep between iterations so replication and the other writers can breathe. Keep the window in configuration rather than in the SQL, so changing it is an edit and not a deploy.

One warning that costs people an evening: on InnoDB, deleting rows returns the space to the table, not to the filesystem. The file keeps its size and reuses the freed pages for new rows. If you need the bytes back today you have to rebuild the table, and the rebuild wants free space of roughly the table's size, which is precisely what you do not have. Start deleting early enough that you never need the rebuild.

Alert at 75 per cent

An alert at 95 per cent is a notification that you are already late. Nearly every remedy needs free space: rebuilding a table, pulling a new image while the old container still runs, writing a dump before you move it off the machine. Seventy five per cent gives you room to fix it as a task instead of an incident.

#!/bin/sh
set -eu
use=$(df -P / | awk 'NR==2 {print $5}' | tr -d '%')
if [ "$use" -ge 75 ]; then
  printf 'root filesystem at %s per cent\n' "$use"
  exit 1
fi

Wire that into whatever already reaches a human. Two thresholds beat one: a warning in a channel at 75 and a page at 90.

How to check it worked

Three checks, in order. The filesystem number moved:

df -h / | awk 'NR==2 {print $5, $4}'
# 60%  74G

Rotation is really configured, without waiting a day to find out:

logrotate -d /etc/logrotate.d/app 2>&1 | grep -i "rotating\|log needs"

And the oldest row is inside the window:

SELECT COUNT(*) AS overdue, MIN(created_at) AS oldest
FROM events
WHERE created_at < NOW() - INTERVAL 180 DAY;

overdue should be zero the morning after the first full run and stay zero. If it climbs during the day and drops overnight, the job is working. If it climbs and never drops, the job is failing quietly, which is the normal failure mode for anything scheduled.

What to watch out for

  • A deleted file that a running process still holds open frees nothing. df stays full while du finds nothing, until lsof +L1 shows the log you deleted this morning still attached to a process nobody restarted.
  • copytruncate can lose the lines written between the copy and the truncate. For an audit log where every line matters, use a reopen signal instead and accept the extra configuration.
  • Time zones make retention windows lie. If rows are stored in one zone and the cleanup compares against another, you delete a few hours too much or too little every night, silently. That is the same trap as a campaign scheduled in the wrong time zone.
  • Pruning images with docker system prune -a also removes the previous version you would have rolled back to. Keep the last known good tag out of the prune, or a way to rebuild it quickly.
  • Retention is not backup. Expiring old rows and holding a restorable copy are different jobs with different failure modes, and a backup that lives on the volume it protects disappears with it.

Growth is a property of the system you built, so it belongs in the design rather than in the incident channel. Every file that is appended to gets a rotation rule, every table that is only ever inserted into gets a window and an index to support it, and the alert fires early enough that the fix is still cheap. The same instinct applies to work that arrives in bulk, which is why a hundred thousand pasted rows belong in a queue rather than in a request. What all of it buys you is the freedom to fix things while they are small.

Questions and answers

Why does my server say no space left when df shows free space?
You have most likely run out of inodes rather than bytes. Check with df -i on the same filesystem. Millions of small session, cache or mail files exhaust the inode table long before they fill the disk, and every attempt to create a file then fails with a message about space.
I deleted a large log file and nothing was freed. What happened?
A process still has the file open, so the filesystem keeps the blocks until that process closes the descriptor or restarts. Run lsof +L1 to list deleted files that are still open. Restart the process, or rotate properly with copytruncate or a reopen signal instead of deleting.
Does deleting old rows give the disk space back?
Not immediately on most engines. InnoDB returns the freed pages to the table, so the file keeps its size and reuses the space for new rows. Getting the bytes back to the filesystem requires rebuilding the table, and the rebuild needs roughly as much free space again as the table occupies. Delete early enough that you never need it.
What retention window should I use?
One window for the whole database is the wrong shape. Pick per table, based on the question that table answers: a few months for request and access logs, the length of the operational question for delivery or event records, and a year or longer for anything financial. Store the window in configuration so changing it is not a deploy.