Production incident

The export that timed out at 50,000 rows

45 minjunior16 yrs

A real incident: symptom first, cause hidden, tradeoff at the end.

The incident

A reporting endpoint exports transactions as CSV. It has worked for two years. Finance now asks for a full-year export instead of a month, and the request dies on the gateway's 60-second timeout. Every retry dies too. What the team observed: 1. A 500-row export returns in milliseconds. 5,000 rows takes about a second. 50,000 rows never finishes inside the timeout. 2. One CPU core is pinned at 100% for the whole request. No database activity after the first second — the query finished immediately. 3. Heap usage climbs steeply and the GC log fills with young-generation collections, but there is no OutOfMemoryError. 4. Someone raised the gateway timeout to 300 seconds. The full-year export then took 240 seconds and the fix was declared done. Find the root cause, fix it, and answer the design question: is building the whole CSV in memory the right approach at all?

What this teaches

  • Concatenating in a loop is O(n^2) in the length of the output
  • Ten times the rows is a hundred times the copying, which is why it looked fine at 500
  • Constant CPU with no I/O and heavy young-gen GC is the signature
  • Raising a timeout hides a complexity bug instead of fixing it
  • Streaming beats building the whole payload in memory for exports

Starter

Starter.java
import java.util.*;

/**
 * Incident reproduction: the CSV export.
 *
 * The measurement counts CHARACTERS COPIED rather than milliseconds, so the
 * result is identical on a laptop and on a build agent. The counter mirrors
 * exactly what the JDK does: `out += row` allocates a new String holding
 * everything accumulated so far plus the new row, and copies both in.
 *
 * Row count is kept small enough to finish quickly. The real endpoint used
 * 50,000 — put that number into the formula and see what you get.
 */
public class Starter {

    record Txn(String id, String account, int paise) {}

    static final int ROWS = 5_000;

    static List<Txn> load(int n) {
        List<Txn> out = new ArrayList<>(n);
        for (int i = 0; i < n; i++) {
            out.add(new Txn("TXN" + i, "ACC" + (i % 900), 1000 + i));
        }
        return out;
    }

    /** How many characters the export copied in total. */
    static long charsCopied;

    /**
     * The export as shipped. One `+=` per row.
     */
    static String toCsv(List<Txn> rows) {
        charsCopied = 0;
        String out = "id,account,paise\n";
        for (Txn t : rows) {
            String row = t.id() + "," + t.account() + "," + t.paise() + "\n";
            // Every += copies the accumulated result AND the new row into a
            // brand-new String. This is the line that is O(n^2).
            charsCopied += out.length() + row.length();
            out += row;
        }
        return out;
    }

    public static void main(String[] args) {
        List<Txn> rows = load(ROWS);

        long start = System.nanoTime();
        String csv = toCsv(rows);
        long millis = (System.nanoTime() - start) / 1_000_000;

        long outputChars = csv.length();

        System.out.println("rows exported     = " + ROWS);
        System.out.println("output size       = " + outputChars + " chars");
        System.out.println("characters copied = " + charsCopied);
        System.out.println("copies per char   = " + (charsCopied / outputChars) + "x");
        System.out.println("wall clock        = " + millis + "ms");
        System.out.println();
        System.out.println("at 50,000 rows this copies roughly "
            + (charsCopied / 1_000_000) * 100 + " million characters");

        // A linear export copies each character a small constant number of
        // times. Allow generous slack — we are separating O(n) from O(n^2).
        long linearBudget = outputChars * 4;
        System.out.println("linear budget     = " + linearBudget);

        boolean linear = charsCopied <= linearBudget;
        boolean correct = csv.startsWith("id,account,paise\n")
            && csv.contains("TXN0,ACC0,1000\n")
            && csv.contains("TXN" + (ROWS - 1) + ",")
            && csv.endsWith("\n");

        System.out.println("output correct    : " + correct);
        System.out.println("copying is linear : " + linear);
        System.out.println(correct && linear ? "PASS" : "FAIL");
    }
}

Run it locally:

cd exercises/java/strings/string-vs-stringbuilder/03-production
javac Starter.java -d /tmp/out && java -cp /tmp/out Starter

Hints

  1. Hint 1

    The query finished in the first second. Everything after that is your code copying characters.

  2. Hint 2

    Work out how many characters are copied in total for n rows. Write the formula, then put n = 500 and n = 50000 into it.

  3. Hint 3

    Young-gen GC churn with no leak means huge numbers of short-lived objects. What is allocating one object per iteration?

  4. Hint 4

    Once it is linear, ask why the whole file is in memory at all. What would you hand back to the client instead?

Done when

  • Characters copied grows linearly with the row count, not quadratically
  • The CSV output is byte-for-byte identical to before
  • A comment explains why raising the timeout was the wrong response
  • A comment describes what streaming the response would change

Solution

Show the solution — try it yourself first
Solution.java
import java.util.*;

/**
 * Root cause: `out += row` inside the loop.
 *
 * String is immutable, so `+=` cannot extend anything. Each iteration allocates
 * a brand-new String holding every character accumulated so far plus the new
 * row, and copies both in. Over n rows the copying is O(n^2) in the length of
 * the output.
 *
 * That explains every observation:
 *
 *   - 500 rows fine, 50,000 rows never finishes. Ten times the rows is a
 *     HUNDRED times the copying. The endpoint was never fast; it was small.
 *   - One core at 100% with no database activity. After the query returned,
 *     every remaining second was System.arraycopy inside String concatenation.
 *   - Heavy young-generation GC with no leak. Each iteration produces two
 *     short-lived Strings (the row, and the new accumulated result), so at
 *     50,000 rows that is 100,000 objects, the largest of them megabytes.
 *     Nothing leaks — it is all garbage immediately, which is exactly why the
 *     young collector was busy and the heap never overflowed.
 *
 * Why raising the timeout was the wrong response: it converted a 60-second
 * failure into a 240-second success and left the complexity unchanged. The next
 * doubling of data — two years instead of one — makes it roughly 960 seconds
 * and the timeout has to be raised again. A quadratic algorithm cannot be
 * configured away.
 *
 * The fix is one buffer instead of n copies. Each character is written once.
 *
 * Pre-sizing: the final length is predictable from the row count, so the
 * builder is constructed with capacity up front and never resizes. That is a
 * smaller win than the algorithmic one and worth it here only because the size
 * is genuinely known.
 *
 * The design question — should the whole CSV be in memory at all? No. Even
 * linear, a 50,000-row export is a multi-megabyte String held entirely on the
 * heap, and concurrent requests multiply that. Writing each row to the response
 * OutputStream as it is produced would:
 *
 *   - make memory constant regardless of row count
 *   - cut time-to-first-byte from "after the last row" to "after the first"
 *   - stop one large export from pressuring the heap for every other request
 *
 * The cost: once you have started writing a 200 response you cannot change your
 * mind and send a 500 if row 40,000 fails. That trade is usually worth taking
 * for exports, and it is the actual senior-level answer to this incident.
 */
public class Solution {

    record Txn(String id, String account, int paise) {}

    static final int ROWS = 5_000;

    static List<Txn> load(int n) {
        List<Txn> out = new ArrayList<>(n);
        for (int i = 0; i < n; i++) {
            out.add(new Txn("TXN" + i, "ACC" + (i % 900), 1000 + i));
        }
        return out;
    }

    static long charsCopied;

    /** Roughly 30 characters per row; enough to avoid every resize. */
    private static final int CHARS_PER_ROW = 32;

    static String toCsv(List<Txn> rows) {
        charsCopied = 0;

        StringBuilder out = new StringBuilder(rows.size() * CHARS_PER_ROW + 32);
        out.append("id,account,paise\n");

        for (Txn t : rows) {
            // Each character is written into the buffer exactly once. Nothing
            // already in the buffer is touched again.
            int before = out.length();
            out.append(t.id()).append(',')
               .append(t.account()).append(',')
               .append(t.paise()).append('\n');
            charsCopied += out.length() - before;
        }

        // toString() copies the buffer once, which is the one unavoidable copy.
        charsCopied += out.length();
        return out.toString();
    }

    public static void main(String[] args) {
        List<Txn> rows = load(ROWS);

        long start = System.nanoTime();
        String csv = toCsv(rows);
        long millis = (System.nanoTime() - start) / 1_000_000;

        long outputChars = csv.length();

        System.out.println("rows exported     = " + ROWS);
        System.out.println("output size        = " + outputChars + " chars");
        System.out.println("characters copied = " + charsCopied);
        System.out.println("copies per char   = " + (charsCopied / outputChars) + "x");
        System.out.println("wall clock        = " + millis + "ms");

        long linearBudget = outputChars * 4;
        System.out.println("linear budget     = " + linearBudget);

        boolean linear = charsCopied <= linearBudget;
        boolean correct = csv.startsWith("id,account,paise\n")
            && csv.contains("TXN0,ACC0,1000\n")
            && csv.contains("TXN" + (ROWS - 1) + ",")
            && csv.endsWith("\n");

        System.out.println("output correct    : " + correct);
        System.out.println("copying is linear : " + linear);
        System.out.println(correct && linear ? "PASS" : "FAIL");
    }
}

Stretch

Rewrite the export so it writes each row to an OutputStream (or a Writer) as it is produced, instead of returning one String. Then say what that changes about memory, about time-to-first-byte, and about your ability to report an error halfway through the export.

← Back to What is the difference between String, StringBuilder and StringBuffer?