The 404 That Led to a Fix: Debugging Write Performance in a Distributed S3 System
In a coding session focused on the Filecoin Gateway's distributed S3 storage system, a seemingly trivial moment—a failed HTTP request returning a 404—became a crucial diagnostic pivot. The message in question, message 2859, captures the assistant's initial attempt to profile goroutine behavior on a live node after the user reported that writes were failing. The message reads:
[assistant] Goroutine counts look reasonable (~850-900). Let me check the pprof for any blocked goroutines: [bash] curl -s "http://10.1.232.83:2112/debug/pprof/goroutine?debug=1" 2>&1 | head -100 404 page not found
At first glance, this looks like a dead end—a failed curl command, a 404, nothing gained. But this message sits at a critical inflection point in a debugging chain that ultimately uncovered a subtle performance bottleneck. To understand why this message matters, we need to reconstruct the reasoning, assumptions, and context that led to it, and trace how the 404 redirected the investigation toward the real culprit.
The Context: A System Under Suspicion
Moments before this message, the user had enabled parallel writes in the QA environment—a feature that allows multiple groups to receive writes concurrently instead of serializing all writes through a single group. The assistant had deployed this change across two Kuri nodes (kuri_01 at 10.1.232.83 and kuri_02 at 10.1.232.84), each configured with RIBS_ENABLE_PARALLEL_WRITES=true and RIBS_MAX_PARALLEL_GROUPS=2. The initial deployment had a hiccup—the assistant mistakenly appended the configuration to /opt/fgw/config/settings.env when the systemd service was actually reading from /data/fgw/config/settings.env—but this was quickly corrected, and both nodes confirmed parallel writes were enabled.
Then the user reported: "Writes failing now, investigate."
The assistant's first response was to check the journal logs on kuri_01. The logs showed PUT requests flowing through, but no obvious error messages beyond expected noise (CIDGravity API token not configured, Bitswap network errors). The assistant then attempted a direct S3 write using rclone, but that failed with a URI parsing error unrelated to the system itself—a client-side configuration issue. At this point, the user suggested: "Probably check goroutines seems like some timeout?"
This suggestion shifted the investigation from log inspection to runtime profiling. The assistant checked the goroutine metrics exposed via Prometheus on port 2112, finding approximately 893 goroutines on kuri_01 and 858 on kuri_02. These numbers were within normal range for a Go service handling network I/O, bitswap, and database connections—not indicative of a goroutine leak or runaway spawning.
The Subject Message: A Reasonable Assumption Meets Reality
The subject message represents the assistant's next logical step: having confirmed that the raw goroutine count is unremarkable, the next diagnostic move is to inspect what those goroutines are doing. The Go runtime's pprof goroutine profile, when requested with ?debug=1, provides a full stack trace dump of every goroutine, making it possible to identify goroutines stuck on locks, waiting on channels, or blocked in system calls.
The assistant's assumption was that the pprof endpoint would be available on port 2112—the same port used for Prometheus metrics. This is a reasonable assumption: many Go services expose both metrics and debug profiling on the same HTTP server, or at least on adjacent ports. The go_goroutines metric had just been successfully fetched from port 2112, so it was natural to try the pprof endpoint there as well.
But the assumption was incorrect. The 404 response revealed that port 2112 was exclusively for Prometheus metrics scraping—it did not serve the /debug/pprof/ paths. The pprof endpoints were instead served on port 9010, the JSON-RPC port used for administrative and diagnostic RPC calls. This is an architectural choice: separating the metrics exposition (intended for monitoring systems like Prometheus) from the debug profiling (intended for interactive debugging) onto different ports and HTTP handlers.
The Mistake: A Wrong Port, But a Productive One
The 404 was a mistake—or rather, an incorrect assumption about the service's HTTP routing topology. But it was a productive mistake. It forced the assistant to reconsider where the pprof endpoints lived. In the very next message (message 2860), the assistant tried port 9010 instead and successfully retrieved the full goroutine profile, showing 879 goroutines with stack traces.
More importantly, the 404 created a natural pause in the diagnostic flow. Instead of immediately diving into the goroutine dump and potentially getting lost in hundreds of stack traces, the assistant had to re-orient. This brief recalibration may have contributed to the methodical approach that followed: rather than scanning the goroutine dump for anomalies, the assistant systematically checked the parallel write stats, which revealed that writes were actually succeeding—2,481 total writes, 2,481 parallel writes, zero errors, and 2 GB written. The "writes failing" report turned out to be about performance (slow and bursty), not outright failure.
Input Knowledge Required
To understand this message, one needs familiarity with several concepts:
- Go pprof: The Go runtime's built-in profiling infrastructure, accessible via HTTP at
/debug/pprof/. The goroutine profile with?debug=1produces a text dump of all goroutine stack traces, essential for diagnosing deadlocks, contention, and goroutine leaks. - Prometheus metrics exposition: Go services commonly expose metrics on a separate HTTP endpoint (often port 2112 or similar) for Prometheus scraping, distinct from the application's main API port.
- Distributed S3 architecture: The system under debug uses Kuri storage nodes that serve S3-compatible APIs, with separate ports for metrics (2112), health checks (8079), and RPC/diagnostics (9010).
- Parallel write mechanics: The recently enabled feature allows concurrent writes to multiple groups, which could theoretically introduce new contention patterns or goroutine behavior.
Output Knowledge Created
This message produced several pieces of actionable knowledge:
- Goroutine counts are normal: ~850-900 goroutines is not pathological for this service, ruling out a goroutine leak as the cause of write slowness.
- The pprof endpoint is not on port 2112: This is a concrete piece of operational knowledge about the service's HTTP routing—debug endpoints live on port 9010, not the metrics port.
- The diagnostic path needs to continue: The 404 is a signal to try alternative approaches, which led to checking parallel write stats directly and discovering that writes were actually succeeding.
The Deeper Discovery
The investigation didn't end with the goroutine profile. After confirming writes were working (message 2863), the user clarified that the issue was "pretty slow and bursty writes." The assistant then took a CPU profile, finding only 6.2% utilization over 5 seconds—the system was not CPU-bound. Block and mutex contention profiles were empty. The system was not under load or contention.
The breakthrough came when the assistant inspected the journal logs more carefully and noticed a recurring message: "syncing group 201" appearing on every write. A grep of the source code revealed the culprit—a debug fmt.Println("syncing group", m.id) statement at line 264 of group.go, placed inside the sync() method that was called on every flush. This fmt.Println was writing to stdout on every single write operation, an I/O call that, while individually fast, could subtly degrade throughput under sustained write loads and, more importantly, was cluttering the logs with useless debug output.
The assistant removed the debug print statement in message 2875, applying a one-line edit that eliminated the unnecessary I/O bottleneck. The fix was trivial in code terms, but the diagnostic journey to find it—spanning log inspection, goroutine counting, pprof profiling (via the wrong port first), CPU profiling, contention analysis, and finally source code grep—was anything but.
The Thinking Process
The subject message reveals a methodical diagnostic mindset. The assistant is working through a mental checklist:
- Check the obvious: Logs show no errors, so the problem isn't a crash or exception.
- Follow the user's lead: The user suggested goroutines, so check goroutine counts.
- Quantify before diving: The raw count (~850-900) is noted as "reasonable"—a qualitative judgment based on experience with Go services of similar complexity.
- Escalate to deeper inspection: If the count is reasonable but the system is slow, the next step is to see what those goroutines are doing—hence the pprof request.
- Adapt when blocked: The 404 is not a dead end; it's a signal to try a different approach. The assistant immediately tries the RPC port in the next message. This pattern—observe, quantify, escalate, adapt—is characteristic of effective debugging. The assistant doesn't panic at the 404, doesn't assume the system is broken, and doesn't give up. It simply notes the failure and moves to the next diagnostic technique.
Conclusion
Message 2859 is, on its surface, a failed HTTP request. But in the context of the broader debugging session, it represents a crucial decision point: the moment when the assistant confirmed that goroutine counts were not pathological and needed to look deeper. The 404 was not a bug in the system—it was a gap in the assistant's mental model of the service's port topology, quickly corrected. And the diagnostic path that followed—checking parallel write stats, taking CPU profiles, and eventually grepping for the debug print—led to a real performance improvement: the removal of an unnecessary fmt.Println that was being called on every write.
In distributed systems debugging, the most valuable insights often come not from the tools that work perfectly, but from the ones that fail in informative ways. A 404 on port 2112 told the assistant exactly where not to look, narrowing the search space and ultimately leading to the right fix.