Log Troubleshooting SOP: 6-Step Pipeline from Alert to Root Cause with 10 Exercises

Scenario: 2 AM Alert on 800MB Log

An engineer is woken by a Prometheus alert: order-service error rate spiked from 0.1% to 8% in five minutes. Facing an 800MB order-service.log, the engineer tries vim (hangs 30 seconds) and tail -f (blindly watches). The article argues that log troubleshooting is not about knowing individual commands but having a repeatable investigation chain: locate → context → quantify → track.

Six-Step Investigation Pipeline

① Locate keyword      grep "ERROR" app.log
② View context        grep -C 5 "ERROR" app.log
③ Extract fields      awk -F'|' '{print $4}'
④ Quantify distribution  awk ... | sort | uniq -c | sort -rn
⑤ Real-time track     tail -f app.log | grep --line-buffered "ERROR"
⑥ System-level logs   journalctl -u order-service -f

Each step adds a "buff" to the previous one; the core chain remains fixed.

Q1–Q10: Problem → Command → Output Interpretation → Pitfalls

Q1: Open huge log without freezing

Command: less app.log Why not vim/cat: vim loads entire file into memory (800MB freezes); cat dumps all content to terminal. less uses paged on-demand loading — opens 1GB instantly.

Key less keys: G (jump to end, where new logs append), g (jump to start), /keyword (search down), ?keyword (search up), n / N (next/prev match), F (follow like tail -f, Ctrl+C to exit follow but stay in less), q (quit). less -N shows line numbers.

Pitfall: Use less for large files, not vim.

Q2: Find error lines by keyword

Commands:

grep "ERROR" app.log
grep -i "error" app.log          # case-insensitive
grep -n "ERROR" app.log          # with line numbers
grep -c "ERROR" app.log          # count matching lines only

Output example:

12345:2026-07-29 02:03:11 ERROR OrderService - 下单失败: 库存不足, orderId=998

(line number from -n helps jump in less).

Critical distinction: grep -c counts lines containing the pattern, not total occurrences. A line with three "ERROR" still counts as 1. For true occurrence count: grep -o "ERROR" app.log | wc -l.

Regex: grep -E "ERROR|WARN" (extended regex for alternation), grep -E "orderId=[0-9]+", grep "^ERROR" (lines starting with ERROR). Default grep treats | literally; need -E or egrep. Escape special chars: grep "orderId=998\.".

Q3: View context around error lines

Commands: grep -A 5 "ERROR" (after), grep -B 2 (before), grep -C 3 (context, both sides). -C 3 is most common.

Output example:

2026-07-29 02:03:10 INFO  OrderService - 开始下单 orderId=998
2026-07-29 02:03:11 ERROR OrderService - 下单失败: 库存不足
2026-07-29 02:03:11 DEBUG StockService - 查库存 sku=123, remain=0
2026-07-29 02:03:11 ERROR GlobalExceptionHandler - 捕获异常: BizException

Immediately reveals: stock=0 caused order failure.

Pitfalls: Long stack traces may need -A 20. Use grep --color=auto for highlighting.

Q4: Real-time follow only new errors

Commands:

tail -f app.log                          # follow all new lines
tail -f app.log | grep "ERROR"           # may not refresh (buffering)
tail -f app.log | grep --line-buffered "ERROR"  # correct
tail -F app.log                          # -F follows file name across rotation

Why --line-buffered : grep defaults to block buffering in pipes, batching output. --line-buffered forces line-by-line flush for real-time visibility.

Why -F not -f : Logrotate renames app.log → app.log.1; -f tracks old file descriptor, misses new file. -F reopens by name after rotation.

Combo: tail -F app.log | grep --line-buffered -E "ERROR|/api/order" (real-time filter for ERROR or specific API).

Q5: Extract specific field from a log line

Sample format (pipe-delimited):

2026-07-29 02:03:11|INFO|OrderService|/api/order/create|120ms|orderId=998

(time|level|service|API|latency|business).

Commands:

awk -F'|' '{print $4}' app.log                    # extract 4th field (API)
awk -F'|' '{print $4, $5}' app.log                # API + latency
awk -F'|' '$5 > "500ms" {print $0}' app.log       # string compare (flawed)
awk -F'|' '{gsub(/ms/,"",$5)} $5+0 > 500 {print $0}' app.log  # numeric compare

Awk basics: -F'|' sets delimiter; $1.. $n are fields (1-indexed), $0 is whole line. It runs a mini-script per line, enabling conditionals.

Regex alternative: grep -oE "orderId=[0-9]+" app.log ( -o outputs only matched portion).

Pitfalls: Field index starts at 1 ( $0 is whole line, no $00). String comparison of "1200ms" vs "500ms" uses lexicographic order (wrong); must strip unit with gsub then coerce to number with +0.

Q6: Count per-API occurrences, sort for Top N

Classic pipeline:

grep "ERROR" app.log |
awk -F'|' '{print $4}' |
sort |
uniq -c |
sort -rn |
head -10

Step-by-step: grep "ERROR" — filter error lines awk -F'|' '{print $4}' — extract API field sort — required before uniq (uniq only merges adjacent identical lines) uniq -c — count adjacent duplicates sort -rn — numeric reverse sort ( -n crucial: without it "9" > "100" lexicographically) head -10 — top 10

Output: 342 /api/order/create, 128 /api/order/pay, 56 /api/order/cancel — create is hotspot.

Advanced — hourly distribution:

grep "ERROR" app.log | awk -F'|' '{print substr($1,1,13)}' | sort | uniq -c

(extracts "2026-07-29 02" to see which hour had most errors).

Q7: Batch replace or delete fields (e.g., mask phone numbers)

Commands:

sed 's/138[0-9]\{8\}/138********/g' app.log > app.mask.log          # write to new file
sed -i.bak 's/DEBUG//g' app.log                                        # in-place with backup
sed '5,10s/ERROR/WARN/g' app.log                                       # only lines 5-10

Syntax: s/old/new/g — s =substitute, g =global (all occurrences per line).

Pitfalls: sed -i is irreversible — always use -i.bak to create backup. For replacement strings containing / or &, change delimiter: sed 's#/api/order#/api/v2/order#g'.

Q8: systemd service logs via journalctl

Applications started via systemctl start order-service log to journald, not application log files.

Commands:

journalctl -u order-service                    # all logs for service
journalctl -u order-service -f                 # follow (like tail -f)
journalctl -u order-service --since "1 hour ago"
journalctl -u order-service --since "2026-07-29 02:00" --until "2026-07-29 03:00"
journalctl -u order-service -p err             # only error priority
journalctl -u order-service -b                 # since current boot
journalctl -u order-service -b -1              # previous boot

Pitfalls: journalctl -f without -u floods with all services. Journald defaults to volatile storage (lost on reboot); persist with Storage=persistent in /etc/systemd/journald.conf.

Q9: Search across multiple log files

Commands:

grep "ERROR" app.log.2026-07-28 app.log.2026-07-29
grep "ERROR" app.log.2026-07-*
grep -rn "ERROR" /var/log/myapp/                    # recursive with file:line
grep -rn --include="*.log" "ERROR" /var/log/        # only .log files

Output: /var/log/myapp/app.log.2026-07-28:123:ERROR ... (file:line:content from -rn).

Pitfall: grep -r follows symlinks; use --include to limit file types.

Q10: Save investigation results for sharing

Commands:

grep "ERROR" app.log > error.txt              # overwrite
grep "WARN" app.log >> error.txt              # append
tail -f app.log | grep "ERROR" | tee error.txt  # watch and save simultaneously
grep --color=always "ERROR" app.log | tee error.txt  # WRONG: ANSI codes pollute file
grep "ERROR" app.log | tee error.txt          # correct: clean file

Pitfalls: tee in long pipelines may buffer; use stdbuf -oL to force line buffering. Never use --color=always when writing to file — ANSI escape codes become garbage in editors/ less.

Combo Move: End-to-End Pipeline

Scenario: Find today's top 3 error APIs and save report.

grep "$(date +%Y-%m-%d)" app.log |
  grep "ERROR" |
  awk -F'|' '{print $4}' |
  sort | uniq -c | sort -rn |
  head -3 |
  tee top3-error-$(date +%Y%m%d).txt

One command extracts conclusion from 800MB log — demonstrates power of simple composable parts.

Pitfall Checklist (Anti-pattern vs Correct)

Anti-pattern: vim 800MB.log → Correct: less 800MB.log — Reason: vim loads entire file

Anti-pattern: grep "ERROR|WARN" x → Correct: grep -E "ERROR|WARN" x — Reason: | literal without -E

Anti-pattern: tail -f | grep ERR → Correct: tail -f | grep --line-buffered ERR — Reason: block buffering delays output

Anti-pattern: tail -f app.log → Correct: tail -F app.log — Reason: rotation breaks -f

Anti-pattern: uniq -c without sort → Correct: sort | uniq -c — Reason: uniq only merges adjacent

Anti-pattern: sort numbers → Correct: sort -rn — Reason: lexicographic without -n

Anti-pattern: sed -i 's/a/b/g' x → Correct: sed -i.bak 's/a/b/g' x — Reason: in-place irreversible

Anti-pattern: grep -c for occurrences → Correct: grep -o ERR | wc -l — Reason: -c counts lines, not matches

Anti-pattern: awk '$5>500' on ms strings → Correct: gsub(/ms/,"",$5); $5+0>500 — Reason: "1200ms" < "500ms" lexicographically

Methodology Summary

Locate: Keyword search ( grep) for ERROR/exception/API path → get line numbers.

Context: grep -C or less jump to line → examine before/after causality.

Quantify: awk extract fields + sort | uniq -c | sort -rn → find Top, see distribution patterns.

Track: tail -F | grep --line-buffered → real-time confirm if errors persist or fix works.

Mnemonic: Locate → Context → Quantify → Track . Forget commands? Remember four steps; look up syntax here.

Hands-On Exercises (with Mock Log Generator)

Generate 1000-line simulated log (fields: time|level|service|API|latency|business):

for i in $(seq 1 1000); do
  lvl=$(echo -e "INFO
INFO
INFO
WARN
ERROR" | shuf -n 1)
  api=$(echo -e "/api/order/create
/api/order/pay
/api/order/cancel
/api/order/query" | shuf -n 1)
  ms=$((RANDOM % 1500))
  echo "2026-07-29 02:0$((RANDOM%9)):$((RANDOM%59))|$lvl|OrderService|$api|${ms}ms|orderId=$((RANDOM%1000))"
done >> app.log

Exercises (Q1–Q10) map directly to the ten questions above. Reference answers provided for each:

Q1: less app.log → G → /ERROR → n → q Q2: grep -c "ERROR" app.log (line count)

Q3: grep -o "ERROR" app.log | wc -l (occurrence count)

Q4: grep -A 3 "ERROR" app.log Q5: awk -F'|' '{print $4}' app.log Q6: awk -F'|' '{gsub(/ms/,"",$5)} $5+0 > 800 {print $0}' app.log Q7:

grep "ERROR" app.log | awk -F'|' '{print $4}' | sort | uniq -c | sort -rn

Q8: sed -i.bak 's/13[0-9]\{8\}/13*********/g' app.log (verify with diff and grep)

Q9:

tail -F app.log | grep --line-buffered -E "ERROR|/api/order/pay"

Q10: Full pipeline with tee top3.txt (no --color)

References

Linux运维全解析与案例实战 — 原理深挖（/proc、strace 等） man grep / man awk / man sed / man journalctl — primary manuals

grep official documentation

awk tutorial — GNU Awk

systemd journalctl documentation