Nine Commands, In Order

Phase 0 was mental models. Phase 1 puts your hands on a box.

Nine commands will diagnose the overwhelming majority of "the server is being weird" — and the skill is not the nine commands. It is the order. One sequence gives you the cause in twenty seconds; another gives it to you in forty minutes, having restarted things in between.

Three support tickets in six minutes: the shop loads, the basket loads, placing the order takes nine seconds or fails. Nothing was deployed today. The dashboard is green — it checks that the homepage returns 200, and it does.

Nine plausible causes and no obvious order: the app crashed, it is leaking memory, the CPU is pinned, the disk is full, the database is slow, the network to the database is slow, a cron job is hogging the box, something is listening on the wrong port, or somebody’s change is simply bad.

In Lesson 01 the team read the application log first. It is the most natural move and the most expensive one: the log is where the symptom lives, so it always shows you something, which feels like progress. What it will not do is eliminate anything. Diagnosis is not a search for the answer; it is the fastest possible destruction of wrong answers.

Tier 1 — eliminating. Cheap, broad, run all three before forming any theory.

Nine causes to one in twenty seconds.

Tier 2 — narrowing. Precise, slow, and worthless until Tier 1 has said where to look. du (which directory, 40 s) → tail (which file, 20 s) → grep/uniq -c (which line, 45 s) → systemctl + journalctl (why it restarted, 65 s) → ss (is it serving again — the proof, 5 s).

Tier 2 costs three minutes and removes no causes. It only says where. Reading the log first is starting at the bottom row.

1. ps (3 s) — ps -eo pid,etimes,rss,comm --sort=-rss | head. Pid 811, etimes 259 200 (three days — nothing restarted it), RSS 213 MB of 3.8 GB. Kills "it crashed", "it’s leaking", "somebody deployed". Use etimes (seconds) not etime: it sorts and it does not lie about days.
2. top (15 s) — read the third line, not the process list: 4.0 us, 55.1 id, 38.0 wa. Over a third of the machine is waiting on disk and the app is in state D. Nothing is compute-bound, nothing is swapping. Four causes gone and a direction: storage.
3. df -h (2 s) — / at 100 %, 0 bytes available. Twenty seconds in, the fog is gone. Two habits: run df -h reflexively, before you have a theory; and run df -i straight after — a filesystem can be 4 % full and still refuse writes because it is out of inodes.
4. du (40 s) — du -xh --max-depth=1 / | sort -h, then walk the biggest branch. /var 31 G → /var/log 31 G → /var/log/shop/app.log, one file, 28 GB. -x matters: it stops du wandering into network mounts and /proc.
5. tail (20 s) — tail -n 50 app.log: fifty identical DEBUG cart.serialize lines, hundreds per second. Note it is fifth. Run first, the same flood looks like noise rather than a cause.
6. grep (45 s) — grep -c 'DEBUG cart.serialize' app.log → 4.1 M of 4.4 M lines this hour. Better when you don’t know what to grep for yet: awk '{print $3, $4}' app.log | sort | uniq -c | sort -rn | head — the frequency table tells you what the file is made of. A debug line left on in Tuesday’s deploy writes 1.4 GB a day.
7. systemctl (5 s) — systemctl status shop says active (running) since 13:59, but the process is three days old. Those two facts conflict, and the conflict is the finding: three restarts in fifteen minutes. "Active" is not "fine". Read the since and the restart count, never the green dot.
8. journalctl (60 s) — journalctl -u shop --since '15 min ago' --no-pager → OSError: [Errno 28] No space left on device, three times, each followed by a restart into the same full disk. Keep -p err (errors only) and -b (this boot). The one Tier 2 command that gives a causal story rather than a location.
9. ss (5 s) — after the fix, ss -tlnp | grep 8080. The closing command, not a hunting one: proof that what you fixed is bound to the port a user reaches. It also catches the classic self-inflicted outage — an app listening on 127.0.0.1 instead of 0.0.0.0, which works perfectly over ssh and is unreachable from the load balancer.

Reading a top screen (Fig. 2)

• [1] load 3.84 on 2 cores is a queue — but load counts tasks blocked on disk as well as tasks wanting CPU, so on its own it never means "the CPU is the problem".
• [2] 55.1 id and 38.0 wa — over half the CPU idle, so nothing is compute-bound and there is no point reading code. The 38 % is time waiting for a disk. This line chose the next command.
• [3] read avail Mem, never free — 412 MB free looks alarming and is not; Linux spends spare RAM on cache and hands it back on demand. 1782 MB available, swap 0 used = no memory pressure.
• [4] state D — the most useful character on the screen. R running, S sleeping, Z zombie, D = uninterruptible sleep: blocked in the kernel, nearly always on storage. A task in D is not busy, it is stuck, and SIGTERM will not move it. Checkout was slow because every order blocked writing its log line.
• [5] VIRT vs RES — VIRT is address space (files mapped and never read), RES is memory actually held. Alert on RES and on swap, never on VIRT.

The habit: almost everyone reads the process list first and the %Cpu(s) line never. It is the wrong way round — that line tells you which kind of problem you have, and therefore which command to run next. (1 splits it per core, M sorts by memory.)

A server can only run out of four things. Learn the normal numbers for your box — values below are a small production VM: 2 vCPU, 4 GB, 40 GB disk.

The fourth row is the one nobody checks. And note df -i: inode exhaustion presents as "no space left on device" on a disk df -h says is 4 % full.

One line of ss -tlnp, field by field (Fig. 3)

• LISTEN — the socket is open and accepting. No LISTEN row means nothing is serving that port, whatever systemctl says.
• Recv-Q — on a listening socket this is the current backlog: connections the kernel accepted that the app has not picked up. Zero is healthy. Persistently non-zero means the app is slower than its arrival rate — an overload signal that moves minutes before any latency graph.
• Send-Q — on a listening socket this is the maximum backlog, the listen() queue. When Recv-Q reaches it, new connections are dropped rather than queued, silently, with nothing in the application’s own log. (Python’s http.server asks for 5.)
• 0.0.0.0:8080 — every interface. 127.0.0.1:8080 would answer perfectly over ssh and be invisible to the load balancer. [::]:8080 is the IPv6 spelling.
• users:(()) — who owns the port; how you discover yesterday’s process never exited.

$ rm /var/log/shop/app.log $ df -h / /dev/vda1 40G 40G 0 100% / <– still full. 28 GB deleted, nothing returned.

On Linux a file is not gone when its name is gone. The data survives while any process holds the file open — and the app has had that log open since Tuesday. One command shows it:

$ lsof +L1
COMMAND  PID  USER  FD  TYPE  DEVICE  SIZE/OFF   NLINK  NODE  NAME
python3  811  shop  3w  REG   253,1   30064771072    0     4  /var/log/shop/app.log (deleted)

NLINK 0 and (deleted): 28 GB held by pid 811, returned only when that descriptor closes — i.e. a restart, at the moment you least want one. Instead, truncate in place:

$ : > /var/log/shop/app.log        # or: truncate -s 0 /var/log/shop/app.log
$ df -h / | tail -1
/dev/vda1        40G  9.1G   29G  24% /

Runbook entry: never rm a log a running process holds. Truncate it — : > file — then fix the thing writing to it, then install logrotate. The real fix is the rotation rule and an alert at 80 %: a filling disk is one of about five failures you can see coming days ahead with a single threshold, and it is the cheapest monitoring any team ever installs.

Same person, same box, same bug. The difference is which command ran first. The restart at 04:00 is the expensive part: it worked, for four minutes, and turned a diagnosis into a second outage. Restarting is a legitimate mitigation once you know what you are mitigating. It is never step one.

Footnote to Lesson 05: everything here is responsibility 5 — carrying the pager — and the shop’s compensating control was the runbook Kai was told to write before he needed it. This lesson is its first page. Its value is not that Kai knows it; it is that Ana, who has never debugged a Linux box, can run the first four and paste the output into the channel at 03:14. That is what "three names on the rota" actually requires to be true.

Every step below was executed on a plain Linux box before publishing. No Docker. If something is missing: apt-get install -y iproute2 lsof procps.

1. Start something that serves a port

mkdir -p ~/lab && cd ~/lab
python3 -m http.server 8080 --directory ~/lab > server.out 2>&1 &
SHOP=$!; echo "shop pid: $SHOP"

2. ps — is it running, since when, how big

ps -eo pid,etimes,rss,stat,comm --sort=-rss | head -5
ps -o pid,etimes,rss,stat,args -p $SHOP

3. top — read the third line, not the list

top -b -n1 | head -8          # -b = batch/scriptable; drop it for the live screen
grep -E '^cpu ' /proc/stat    # the same counters top reads: user nice system idle iowait ...

4. Build a 20 MB disk you are allowed to destroy

mkdir -p ~/lab/mnt
sudo mount -t tmpfs -o size=20M tmpfs ~/lab/mnt
mkdir -p ~/lab/mnt/log/shop
df -h ~/lab/mnt               # 20M total, 0% used

5. Let the app flood its own log — one INFO line per order, forty DEBUG lines behind it:

cat > ~/lab/flood.py <<'PY'
import time, os
path = os.path.expanduser("~/lab/mnt/log/shop/app.log")
f, i = open(path, "a", buffering=1), 0
while True:
    i += 1
    try:
        f.write(f"14:0{i%10}:00 INFO  checkout order_id={i} ok in 241ms\n")
        for _ in range(40):
            f.write(f"14:0{i%10}:00 DEBUG cart.serialize items=3 bytes=1841 "
                    + "payload=" + "x"*180 + "\n")
    except OSError as e:
        print("app: write failed:", e, flush=True)   # what the app sees
    time.sleep(0.01)
PY
python3 ~/lab/flood.py > ~/lab/app.err 2>&1 &
FLOOD=$!; sleep 30            # ~700 KB/s; 20 MB takes about half a minute

6. df then du

df -h ~/lab/mnt               # 20M 20M 0 100%  <- two seconds to the cause
df -i ~/lab/mnt               # the inode view
du -xh --max-depth=1 ~/lab/mnt | sort -h
ls -lh ~/lab/mnt/log/shop/
head -2 ~/lab/app.err         # app: write failed: [Errno 28] No space left on device

7. tail, then grep for proportion

tail -n 5 ~/lab/mnt/log/shop/app.log
grep -c 'DEBUG cart.serialize' ~/lab/mnt/log/shop/app.log
wc -l ~/lab/mnt/log/shop/app.log
awk '{print $2, $3}' ~/lab/mnt/log/shop/app.log | sort | uniq -c | sort -rn | head -5

Roughly forty DEBUG lines per real order. That is a one-line change to ask for, not a vague "logging is too verbose".

8. Spring the trap on purpose

rm ~/lab/mnt/log/shop/app.log
df -h ~/lab/mnt               # STILL 100% - 20 MB deleted, 0 bytes returned
sudo lsof +L1 | grep app.log  # NLINK 0, "(deleted)", held open by the flood pid

kill $FLOOD; sleep 1          # space returns when the descriptor closes, not on delete
df -h ~/lab/mnt               # 0% again
python3 ~/lab/flood.py > ~/lab/app.err 2>&1 & FLOOD=$!; sleep 30
: > ~/lab/mnt/log/shop/app.log   # truncate in place; handle stays valid
df -h ~/lab/mnt                  # space back at once, nothing restarted

9. ss, and the localhost mistake

ss -tlnp | grep 8080
python3 -m http.server 8081 --bind 127.0.0.1 --directory ~/lab > /dev/null 2>&1 &
sleep 1; ss -tlnp | grep -E '808[01]'
curl -s -o /dev/null -w '%{http_code}\n' http://127.0.0.1:8081/   # 200 for you, nothing for the LB

Two rows, one difference: the address. Look at Send-Q too — Python reports 5. That is Fig. 3’s cliff, in the default configuration of a tool people put in front of real traffic.

10. systemctl and journalctl — need a real systemd host (any cloud VM, or WSL2 with systemd); they do not work inside most containers, which is itself worth knowing:

systemctl status nginx
systemctl list-units --failed          # first command on an unfamiliar box
journalctl -u nginx --since '30 min ago' --no-pager | tail -20
journalctl -p err -b --no-pager | tail -20
journalctl --disk-usage                # would have caught our incident days early

11. Clean up

kill $FLOOD $SHOP 2>/dev/null; pkill -f 'http.server 8081'
sudo umount ~/lab/mnt && rm -rf ~/lab

Turn it into the runbook page

Four lines at the top of RUNBOOK.md, today: ps -eo pid,etimes,rss,stat,comm --sort=-rss | head · top -b -n1 | head -8 · df -h; df -i · ss -tlnp. Then the rule that makes it real: whoever is paged runs all four and pastes the output into the channel before proposing anything. Twenty seconds, the same twenty seconds every time, and the second person to arrive starts from evidence instead of from a ten-minute-old theory.

• "If our main server is slow at 03:14 and I am the one awake — what are the first four commands, and where are they written down?" Lesson 05’s R2 made testable. A rota of three names only works if three people can produce evidence. If the answer is "ask Kai", the rota is decorative, and the fix is a twenty-line file, not a hire. Follow-up: when did someone who is not Kai last run them?
• "What is the disk usage on our production box right now, and would we know at 80 %?" A filling disk is one of the very few failures that announces itself days in advance, and the alert costs one line. No answer to the first half means no monitoring; no answer to the second means no useful monitoring. Same question for inodes, which no dashboard has by default.
• "Last time we restarted something to fix an incident — did we know what we were fixing before we restarted it?" Restarting destroys the evidence and can buy a false all-clear that turns one incident into two. You are not asking people to stop restarting; you are asking for the ps / top / df / ss paste to exist before the restart.

Next: Lesson 07 — Where a Linux service lives: systemd units, logs, restarts.