Beyond 'grep error': How WARN, INFO, and DEBUG Logs Reveal Production Root Causes
This article demonstrates why relying solely on ERROR logs misses critical production issues, using four real cases where WARN storms caused memory overflow, slow SQL queries hid in INFO logs, DEBUG-level serialization spiked CPU, and silent data loss appeared only in business count mismatches — teaching a systematic log-analysis approach for root-cause detection.
Log Levels: Understand the Design Logic
Many engineers only stare at ERROR logs, fundamentally misunderstanding log level priorities. System logs follow a strict hierarchy from low to high: INFO → WARN → ERROR .
INFO : Normal business flow logs — record process, input parameters, execution branches to reconstruct the full business flow.
WARN : Exception warning logs — business hasn't broken, service hasn't crashed, but anomalies, violations, or performance risks have appeared; these are problem precursors .
ERROR : Final failure logs — program termination, interface errors, functional failures; these are problem outcomes .
One-sentence summary : ERROR is the accident conclusion; WARN and INFO are the accident process. Only watching the conclusion never reveals the true cause.
Why This Matters: Developers Don't Always Follow Textbook Logging
The author, a former developer, admits that under deadline pressure, code often returns HTTP 200 with only an INFO line like "No data found for xx, check xxx" instead of proper errors. Some developers omit logs entirely. Therefore, production troubleshooting cannot assume textbook logging; you must read logs line by line from top to bottom — critical clues hide in INFO and WARN, even behind "successful" 200 responses.
Typical Production Log Level Configuration
Online services balance performance and debuggability with level filtering:
Default: print WARN + ERROR , some core services enable key INFO , disable verbose DEBUG.
Thus, searching only for ERROR ignores vast retained WARN and key INFO logs — the very clues that expose problems early.
Troubleshooting rule: Don't just grep error . Scan all levels along the timeline.
SQL Log Configuration
Database faults are the highest-frequency online issues; log analysis depends on SQL log setup:
Enable slow query log : default records SQL exceeding threshold (usually 1–3 seconds), printing duration, SQL statement, scanned rows.
Disable full SQL printing : avoids high-frequency business flooding logs, wasting disk, memory, CPU.
Force-log exceptional SQL : error SQL, parameter anomalies, transaction failures must be retained.
Key point : Many database stalls, spinning pages, interface timeouts have zero ERROR logs — they only appear in slow-query WARN logs. Grepping ERROR will never find them.
Real Case 1: ERROR Is the Result, WARN Is the Cause
User reported: "After importing archive data, page spins forever, then shows service exception." Following the four-step method (capture interface, locate service, match time, tail logs), the author ran: tail -f /data/logs/laotang/am.log Triggering the import produced logs like:
2026-05-20 14:23:15.123 INFO [archive/import] Received import request, file: staff_2026.xlsx, size: 12MB
2026-05-20 14:23:15.456 INFO [archive/import] Parsing Excel, 10,000 rows
2026-05-20 14:24:44.789 WARN [archive/import] Row 6888: phone format error (13800138000), skipped
2026-05-20 14:24:44.790 WARN [archive/import] Row 6889: phone format error (13900139000), skipped
... (hundreds of similar WARN lines omitted)
2026-05-20 14:24:58.001 ERROR [archive/import] Import failed: GC overhead limit exceededIf only grep error were used, only the final GC overhead limit exceeded line appears — leading developers to simply "add memory," treating symptom not root cause. The real culprit hides in the hundreds of WARN logs : code logged every validation failure per row, each triggering string concatenation and disk I/O. Combined with loading the entire Excel into memory for row-by-row processing, the dual pressure exhausted memory.
Root Cause
No rate-limiting on error-data logging (e.g., print only first 10, then count). Business need to know which rows failed is valid, but better implemented via error-file download (write bad rows to CSV, offer download after import) rather than thousands of log lines.
Final Optimization
During validation, only count errors, do not print per-row WARN .
After import, generate error-detail file for user download.
Change import to batch commit every 500 rows to reduce memory footprint.
Optimize Excel parsing logic to limit peak memory consumption.
Takeaways
ERROR is the symptom (service crashed); WARN is the root cause (why it crashed) — WARN often exposes risk early.
Reasonable business requirement ≠ reasonable code implementation .
On-site troubleshooting must combine full log analysis to give developers precise optimization direction, not just throw "OOM" over the wall.
Case 2: Slow Query in INFO — No Error, Page Just Spins
A report page slowed every afternoon ~3 PM, from seconds to tens of seconds, then timed out. Following the process (capture interface, find service, tail logs), not a single ERROR, not even a WARN appeared. The only clue was an INFO line (slow-query logging pre-configured):
2026-05-20 15:02:16.789 INFO [report] Executing SQL: select * from sales where create_time between '2026-05-01' and '2026-05-20' order by amount desc limit 100
2026-05-20 15:02:16.790 INFO [report] SQL duration: 18723 ms18.7 seconds — program didn't crash, but interface timed out, returning empty or "service busy." Developers seeing grep error logs said "no error," leaving ops passive.
Root Cause
SQL missed index, full table scan on tens of millions of rows. Slow-query threshold set at 3 seconds; this SQL triggered INFO log but never ERROR.
Troubleshooting Tips
If logs contain "duration", "cost", "elapsed" fields, sort them:
grep "耗时" /data/logs/app.log | awk -F'耗时: ' '{print $2}' | sort -rn | head -10If no duration printed, ask developers to add it at core interfaces, SQL, RPC calls — it's the lifeline for performance debugging.
Case 3: DEBUG Log's Silent Killer — No Log Output, CPU Explodes First
Service CPU suddenly hits 100%, logs show no ERROR, WARN normal. Using top -H -p <pid> to inspect threads reveals many stuck in toString() or JSON.toJSONString(). Code inspection finds a large loop with:
log.debug("Current processing object: {}", hugeObject);Production log level accidentally set to DEBUG. Each iteration serializes the huge object (containing Lists, Maps, even base64 images) to string. Critical point: even if the log framework ultimately discards it (level check happens after toString() ), CPU is already consumed.
Troubleshooting Tips
CPU spikes but logs quiet → use jstack to capture thread stacks, see which class's toString() or JSON.toJSONString() is blocking.
Check current log level config: grep -i "log level\|root level" /path/to/config Production must never enable DEBUG/TRACE unless temporary debugging; turn off immediately after.
Case 4: Business Logic Black Hole in INFO — Interface Returns Success, Data Lost
Most insidious: no errors, users complain data wrong. Example: Service A calls Service B to sync orders; B returns 200 OK but internally saves only partial fields. Or cron job logs all "finished" yet certain data never processed. Here, ERROR and WARN are absent; clues hide in two INFO lines' business counts .
Real Incident
Sync service logs:
2026-05-20 10:00:01.123 INFO [sync] Read 1000 records from source table
2026-05-20 10:00:02.456 INFO [sync] Target interface call succeededTarget service logs:
2026-05-20 10:00:03.001 INFO [receive] Received 998 records
2026-05-20 10:00:03.500 INFO [receive] Persistence complete, 998 succeededTwo records missing, no error. Cause: sender didn't escape special characters; parser silently dropped them, neither throwing exception nor logging WARN.
Troubleshooting Tips
Cross-service debugging: chain upstream/downstream logs by requestId/traceId , compare counts line by line.
Watch log fields count, success, skip — find where numbers don't match.
If logs lack business counts entirely, that's observability gap — require developers to add at key branches:
log.info("processed {} records, skipped {} due to ...", total, skip)Troubleshooting Mnemonic (Memorize This)
ERROR pins time, WARN finds risks, INFO traces flow, slow SQL needs sorting, jstack cures CPU. Don't believe "no error means no problem" — log's hidden killers never wear red.
Next time a developer asks you to "dig deeper," throw these scenarios at them:
"It's not ERROR — a WARN storm filled memory."
"No error, but INFO has a 20-second slow SQL."
"Logs all green, but jstack shows everything stuck in toString()."
You're one insight away from "root-cause detective": Logs aren't for printing errors; they're for reconstructing the scene.
Signed-in readers can open the original source through BestHub's protected redirect.
This article has been distilled and summarized from source material, then republished for learning and reference. If you believe it infringes your rights, please contactand we will review it promptly.
Engineer Tang's Implementation Study Notes
Old Tang | Pseudo-full-stack tech player: writes code without going bald, manages projects without going crazy, delivers without staying up late. No formal tutorials here, only a "slacking-off" practical manual that cures system pain points. Focuses on Shell, SQL, Java, and delivery, turning complexity into simplicity and making efficiency fun.
How this landed with the community
Was this worth your time?
0 Comments
Thoughtful readers leave field notes, pushback, and hard-won operational detail here.
