Operations 19 min read

A Complete Walkthrough of Investigating High Server Load in Production

This article narrates a step‑by‑step investigation of a sudden CPU load spike on a 24‑core e‑commerce web server, revealing an I/O bottleneck caused by misconfigured log rotation and excessive debug logging, and outlines the diagnostic commands, root‑cause analysis, immediate remediation, and long‑term fixes.

Raymond Ops
Raymond Ops
Raymond Ops
A Complete Walkthrough of Investigating High Server Load in Production

Problem Background

During a mid‑year promotion in June 2025, a 24‑core, 32 GB RAM web server triggered a CPU load alarm at 14:30. Load average jumped from the normal 5‑8 to over 42, and the P99 response time rose from 200 ms to 3800 ms, causing timeouts and 502 errors.

1. Alert Received – First Reaction

$ uptime
14:31:45 up 15 days, 6:12, 3 users, load average: 42.35, 28.17, 15.42

The three numbers are the 1‑, 5‑, and 15‑minute averages. On a 24‑core machine, 42.35 means ~1.76 tasks per core, indicating CPU saturation. However, high load does not always equal high CPU utilization; further investigation is required.

2. Global Scan – Qualitative Bottleneck Identification

2.1 top – CPU Time Distribution

$ top
%Cpu(s): 8.5 us, 5.2 sy, 0.0 ni, 32.1 id, 53.8 wa, 0.0 hi, 0.4 si, 0.0 st

Key observation: wa = 53.8 % (I/O wait) while id = 32.1 % . CPU usage (us+sy) is only 13.7 %, so the high load is caused by I/O blocking.

2.2 vmstat – Confirm Blocking

$ vmstat 1 5
... b 38 (blocked processes) ... r 3 (run queue)

38 processes are blocked on I/O, confirming an I/O subsystem bottleneck.

2.3 free – Memory and Swap Check

$ free -h -w
Mem: 31G total, 14G used, 13G available
Swap: 4.0G total, 3.0G used

Memory is sufficient, but swap usage indicates some pressure.

2.4 First‑Stage Summary

Bottleneck Type: I/O (wa=53.8 %, b=38)

Resource Situation: CPU has idle capacity, memory is adequate, swap modestly used

Next Step: Identify which process generates the heavy I/O.

3. Pinpointing the I/O Source

3.1 iostat – Disk Activity

$ iostat -xdm 1 3
Device  r/s   w/s   rkB/s   wkB/s  r_await  w_await  aqu-sz  %util
vda    120.5 4500.3 3840.0 360000.0 2.1   112.3   248.5  98.7

Key metrics: w/s = 4500 writes/sec, w_await = 112 ms (far above SSD normal <2 ms), aqu‑sz = 248 (large queue), %util = 98.7 % (disk near saturation).

3.2 iotop – Process‑Level I/O

$ iotop -o
Total DISK READ: 3.84 M/s | Total DISK WRITE: 360.00 M/s
 TID PRIO USER   DISK READ DISK WRITE SWAPIN IO% COMMAND
3456 be/4 root   0.00 B/s   320.00 M/s 0.00 % 95.2 % java
5678 be/4 www    3.84 M/s   0.00 B/s 0.00 % 2.1 % nginx

The Java process writes 320 MB/s, accounting for almost all disk I/O, and spends 95 % of its time waiting on I/O.

3.3 pidstat -d – Per‑Process I/O Confirmation

$ pidstat -d 1 3
 PID   kB_rd/s   kB_wr/s  kB_ccwr/s  Command
3456   0.00    320000.00   0.00    java

3.4 File‑Level Write Verification

$ ls -la /proc/3456/fd/ | grep -E 'REG.*W' | sort -k7 -rn | head -5
lrwx------ 1 root root 64 Jun 15 14:33 23 -> /var/log/app/app.log
lrwx------ 1 root root 64 Jun 15 14:33 24 -> /var/log/app/app.log.1
lrwx------ 1 root root 64 Jun 15 14:33 25 -> /var/log/app/error.log

The Java process still holds a file descriptor to app.log.1, the rotated log file, meaning it continues writing to the old file after rotation.

4. Root Cause Confirmation

4.1 Findings

Debug‑level logging was enabled during the promotion, inflating log volume from ~20 MB/min to ~20 GB/min.

logrotate used the default create method, which renames the current log to app.log.1 and creates a new file. The Java process kept the old file handle, so it kept writing to app.log.1.

The massive write volume plus double‑file writes (both app.log and app.log.1) saturated disk I/O, causing the load spike.

4.2 Immediate Recovery Steps

Force the Java process to release the old file descriptor (e.g., send USR1 to trigger log‑framework reload) and verify space reclamation with df -h.

If reload fails, locate the deleted file descriptor via lsof and truncate it: : > /proc/PID/fd/FD_NUMBER.

Reduce log level from DEBUG to WARN/INFO in log4j2.xml or logback.xml and reload.

Validate I/O recovery with iostat -xdm 1 3 and uptime; load returns to normal within ~15 minutes.

4.3 Long‑Term Solutions

Change logrotate to use copytruncate so the original file is not renamed while the process holds it.

Enable asynchronous log appenders (log4j2 AsyncAppender or logback AsyncAppender) to avoid blocking business threads.

Place logs on a dedicated partition to prevent filling the root filesystem.

Formalize a change‑approval workflow for production log‑level adjustments, with automatic rollback.

5. Additional Production Failure Cases

Case A – MySQL Double‑Write Flush

High load (60+) with wa 70‑80 % caused by innodb_flush_log_at_trx_commit=1 and sync_binlog=1. Temporary mitigation: lower flush settings; long‑term: upgrade to higher‑IOPS storage, enable group commit, consider semi‑sync replication.

Case B – TIME_WAIT Exhaustion

Short‑lived connections caused TIME_WAIT to reach 62 000, leading to connection refusals. Immediate fix: enable tcp_tw_reuse and lower tcp_fin_timeout. Long‑term: use persistent connection pools.

Case C – apt‑check I/O Spike on Small Instance

Unattended‑upgrades triggered heavy disk reads on a 2‑core, 4 GB VM, pushing wa > 90 %. Mitigation: stop or disable the apt‑daily.timer services.

6. Netflix 60‑Second Rule in Practice

The investigation follows Netflix’s “60‑second rule”: run a predefined set of commands within the first minute after login to quickly assess load, CPU, memory, I/O, and network.

# 1‑5 s: uptime, dmesg -T | tail -10
# 6‑15 s: vmstat 1 3, mpstat -P ALL 1 3
# 16‑25 s: pidstat -u 1 3, pidstat -d 1 3
# 26‑35 s: iostat -xzm 1 3, free -h -w
# 36‑45 s: sar -n DEV 1 3, sar -n TCP,ETCP 1 3
# 46‑60 s: top -bn1, ss -s

7. Production Troubleshooting Best Practices

Avoid blind restarts during high load; collect data first.

Gather on‑site metrics before any destructive operation (e.g., mkdir /tmp/debug_$(date +%s) and save command outputs).

Base judgments on concrete data (e.g., "wa=53.8 %" rather than "I think it’s I/O").

Perform gray‑scale roll‑outs when multiple nodes are available.

Prepare rollback plans (e.g., backup /etc/logrotate.d/app before editing).

Record every change with who, when, what, and impact.

8. Summary

Investigating high server load is fundamentally about locating the bottleneck resource. Load spikes can stem from I/O, CPU, memory, or network constraints. The case study shows that misconfigured log rotation combined with uncontrolled debug logging can silently fill disks, saturate I/O, and inflate load. Recommended actions include using copytruncate for log rotation, limiting debug logs in production, employing asynchronous logging, and institutionalizing a disciplined change‑management process.

Original Source

Signed-in readers can open the original source through BestHub's protected redirect.

Sign in to view source
Republication Notice

This article has been distilled and summarized from source material, then republished for learning and reference. If you believe it infringes your rights, please contactadmin@besthub.devand we will review it promptly.

monitoringPerformanceOpsLinuxtroubleshootingLoad AveragelogrotateI/O Bottleneck
Raymond Ops
Written by

Raymond Ops

Linux ops automation, cloud-native, Kubernetes, SRE, DevOps, Python, Golang and related tech discussions.

0 followers
Reader feedback

How this landed with the community

Sign in to like

Rate this article

Was this worth your time?

Sign in to rate
Discussion

0 Comments

Thoughtful readers leave field notes, pushback, and hard-won operational detail here.