From 26 minutes to 8 seconds: replicating a legacy export

The file

The media company I work with runs part of its sales on a vendor's legacy system. That system feeds finance with a spreadsheet the team calls "the pipeline": 62 columns, one row per proposal, location and period, the months of the year in columns and a billing block at the end (status, dates, invoice number, payment slip, who handled it). It's generated every night at 01:10 and the team downloads it in the morning. There's a variant with 82 columns, and a full one with 83 columns three times a day.

We were integrating our own sales system with that vendor's system. On 14 August, looking at the table those spreadsheets come from, I asked the obvious thing in the session with the agent: why can't we fill it ourselves? The plan that came out was to replicate it as it is, maybe improve later, and stop depending on them for this.

Step 1: replicate the source table, and prove it

Both spreadsheets come from one table with 189 columns that the legacy system fills. The first job was a replica of whatever fills it, written in our code, reading their database and writing nothing. Then a validation backfill: run the replica for every proposal since May and compare with their table, field by field.

That run took 32 seconds. It compared 1,495 proposals, 4,689 rows, 862,297 fields, and found 0 divergent.

Its headline number was 97.76% OK. Right below it, the report prints the honest number: 95.82%. The difference is 17,484 fields that were never compared, because some groups of rows existed only on one side (45 only ours, 48 only theirs) and the headline only looked at groups that paired. With the wrong grain a validator like this shows 100% without comparing a single row, so both numbers stay in the report.

Every field that didn't match needed a named cause with evidence, or it failed:

In simplified form, the classifier looks like this, and the important part is the default at the end:

// every mismatch needs a named verdict backed by evidence; no verdict, no pass
$verdict = match (true) {
    $ours === $theirs                         => 'OK',
    $this->knownLegacyBug($col, $row)         => 'THEIR_BUG',
    $this->sourceChangedAfter($row, $col)     => 'SOURCE_STALE',
    $this->registryChangedAfter($row, $col)   => $this->hasChangeLog($row, $col)
                                                    ? 'REGISTRY_CHANGED'
                                                    : 'NO_PROOF',
    default                                   => 'DIVERGENT',
};

NO_PROOF is my favorite line of that table. "The registry probably changed" explains almost anything, so without a change log it doesn't count as explained. It goes to a list to investigate, with 37 proposals in it after that run.

Step 2: where 26 minutes came from

With the table proven, the spreadsheets. I read the legacy export code. For the daily file it did about 10 queries per row: transfers, invoice, payment slip, three lookups in logs, the person responsible, and three more for a property filter. 8,232 rows times 10 is about 82,000 queries, and their own generation log said 01:10:03 to 01:36:01. The 82-column variant was worse, 53 queries per row because each of the 24 monthly accounting columns cost two queries, so about 138,000 queries in 43 minutes.

A classic N+1. The replica collects the proposal ids of the cut first, then runs one query per lookup table for each batch of 3,000 ids and keeps the results in arrays by key. The main cursor streams the rows and only reads from those arrays, so the number of queries depends of the number of tables and batches, never of the rows.

private const BATCH = 3000;

/** "1,2,3" lists of int ids, BATCH at a time */
private function batches(array $ids): array
{
    $ids = array_values(array_unique(array_map('intval', $ids)));
    return array_map(fn (array $c) => implode(',', $c), array_chunk($ids, self::BATCH));
}

/** one query per batch, where the legacy did one per row */
private function prefetchFiles(string $table, array $proposals): array
{
    $out = [];
    foreach ($this->batches($proposals) as $in) {
        $rows = $this->db->query(
            "SELECT proposal_id, file FROM {$table} WHERE proposal_id IN ({$in}) ORDER BY id ASC"
        )->getResultArray();

        foreach ($rows as $r) {
            $p = (int) $r['proposal_id'];
            // the legacy builds file & "," & acc, so the list comes out reversed. We keep it.
            $out[$p] = isset($out[$p]) && $out[$p] !== '' ? $r['file'] . ',' . $out[$p] : $r['file'];
        }
    }
    return $out;
}

Ids are cast to int before going in the IN, so the list is safe to build as a string. The full file has 69,783 rows × 83 columns, around 5.8 million cells, so it goes through a streaming XLSX writer with constant memory.

When the agent showed me the first number I wrote back, more or less, "are you serious, it took 26 minutes and now it takes 8 seconds?". I didn't believe it until the diff against their file of 01:10 was green.

Step 3: the same file, cell by cell

Our diff tool reads both XLSX files and aligns rows by key, then compares cell by cell, including type and format. On a weekday it can never be 100%, because their file is from 01:10 and ours from hours later, and billing moves in between. On 4 September the daily file matched 99.95%, and the 247 differences were all billing that was completed or rejected that same day.

Two things only the real file showed. The invoice column appears on every row of a proposal: the legacy code tries to reset the variable on each row, but the check for "proposal changed" doesn't hold, so the value repeats. And the 82-column variant doesn't select one column the others have, because their table doesn't have it. We replicated both. Finance reconciles against this file, so changing what it shows is a business decision, and the bugs go to a separate list to fix with their ok.

A clean test came on Saturday, 5 September, with no billing activity. Their 01:10 file against ours: 8,315 rows, 515,530 cells, 100% identical, 0 rows left on either side. The variant, 214,348 cells, also 100%. The replica is in production since 4 September, and the plan is to keep the legacy jobs running until the diff stays clean for 10 business days in a row, and only then turn theirs off.

What I'd do the same way

Replicate before improving, with the old system running next to it, because the old one is the answer key and also the rollback. Prove with their real output and not with my reading of their code: the two quirks above were in the code, and I only saw them in the file. Put the honest number next to the nice one, and give every mismatch a name. The speed came almost for free once the N+1 was visible; most of the work was in the proof.

Filed under the problem it solves

• n+1 queries
• legacy systems
• data validation
• migration
• php
• mysql
• reporting