Skip to content
Data Engineering

The bottleneck was never the network

The bottleneck was never the network

How a 200-column ERP table exposed a false assumption in our ingestion sizer

The ticket said the ingestion pipeline was hanging.

It certainly looked that way. Two tables in the batch had been sitting at the same status for the better part of an hour. The run record showed no progress. The monitoring UI showed no rows read. At the sixty-minute mark the watchdog gave up, marked them TIMED_OUT, and moved on. The next scheduled run did exactly the same thing. And the one after that.

Everyone’s first instinct mine included was that something was stuck. A connection had gone stale, a lock was being held somewhere upstream, the driver was blocked on a socket that would never return.

None of that was true. The tables were making progress the entire time. They were reading rows steadily, one after another, at roughly twenty rows per second. They just weren’t going to finish before the watchdog killed them, and they weren’t going to finish before the next hourly run started either.

They weren’t hung. They were crawling.

Working out the difference between those two things and then working out why took apart an assumption that the entire pipeline’s resource sizing was built on. This post is that investigation. The fix itself is the subject of the next post; this one is about the diagnosis, because in this case the diagnosis was the hard part and the more transferable one.


1. The setup

The pipeline ingests from Infor LN through the Infor Data Lake, reached over the Infor Compass JDBC driver, into a medallion architecture on cloud object storage.

Layer Technology
Source Infor LN → Infor Data Lake (Compass), ~1,500 tables available
Transport Compass JDBC driver (Java)
Landing (Bronze) Snappy Parquet on ADLS Gen2

There is a single sentence in that table that contains the entire problem: a Java driver, in a Python application.

That is not unusual. Plenty of teams run JDBC from Python over JPype is a well-worn path, and for most workloads it is completely fine. It was fine for us too, right up until the shape of the data changed.

Because the other thing you need to know about Infor LN is that its tables are pathologically wide. Two hundred columns is normal. Some go past three hundred. This is not a design flaw so much as a consequence of what LN is: a deeply configurable ERP with decades of accumulated functional surface area, where a single financial transaction table carries every field any customer in any industry might have needed since the nineties.

Width is the villain of this story. Hold on to it.

The target we were building toward: 350-plus registered Bronze tables, roughly ten million rows on a full refresh, running on an hourly incremental schedule. Nothing about those numbers is extreme by modern standards. A ten-million-row full refresh is a small warehouse. The hourly cadence is unremarkable.

We could not get anywhere near it.


2. The code that looked fine

Here is the extractor, reduced to its essentials:

while True:
    rows = cursor.fetchmany(10_000)
    if not rows:
        break
    col_arrays = [
        pa.array([converters[i](row[i]) for row in rows], type=col_arrow_types[i])
        for i in range(n_cols)
    ]
    yield pa.table(dict(zip(columns, col_arrays)), schema=batch_schema)

Fetch a batch. Convert it column by column. Yield an Arrow table. It is a textbook JDBC-to-columnar bridge and there is nothing obviously wrong with it.

It is also worth saying clearly that this was not first-draft code. It had already been through three rounds of optimisation, each of which was a real improvement:

  • Thread-local connection caching, so the pool wasn’t paying handshake costs repeatedly.
  • Schema-driven type converters, pulled once from information_schema rather than inferred from the first row which removed both a correctness hazard and a per-batch cost.
  • Column-major batch construction in a single pass, rather than building row dicts and transposing.

Each of those was the right call. Each of them made things measurably better. And the result was still catastrophically slow.

That combination code that has been thoughtfully optimised and is still an order of magnitude off target is usually a signal. It means you are optimising within the wrong structure. You can shave constants off a loop indefinitely; you cannot shave your way out of the loop being the wrong shape.

We didn’t know that yet. What we had was a suspicion and no numbers.


3. Getting numbers

The first useful thing we did was stop reasoning about the pipeline in aggregate and measure a single table in isolation, with nothing else running.

Scenario Throughput
Single isolated extractor thread (215-column table) 12,810 rows/min
In-batch, 18–32 tables extracting concurrently 1,100–1,320 rows/min per table

Two real tables from a production-shaped run, for concreteness:

  • ln_tdpur406 45,104 rows in 41 minutes = 1,098 rows/min
  • ln_cisli305 11,697 rows in 9 minutes = 1,318 rows/min

Read that table again, because it contains the whole story in two rows.

The same code, on the same hardware, against the same source, ran roughly ten times slower when run in parallel. Not slower per unit of total work slower per table, which is to say the parallelism was buying us nothing at all and costing us a great deal.

At 12,810 rows/min in isolation, a 45,000-row table takes about three and a half minutes. At 1,100 rows/min in a batch, the same table takes forty-one. And the arithmetic that actually mattered to users: at in-batch throughput, any table above roughly 65,000–70,000 rows could not finish inside the 60-minute watchdog. Ever. Not slowly never. It would be killed and retried and killed again on every schedule, forever, and would appear in the UI as a permanently broken table.

The tables in the opening ticket were both in that range. Neither had ever completed. Neither ever would have.


4. Proving they weren’t stuck

Before chasing throughput we had to eliminate the obvious explanation, because “the query is blocked upstream” and “the query is slow” call for completely different investigations.

The probe was deliberately crude. For every table that looked stuck, run two trivial queries against the same connection path:

SELECT COUNT(*) FROM <table>;
SELECT * FROM <table> FETCH FIRST 1 ROW ONLY;

Both returned on every single “stuck” table, in 5 to 31 seconds. The source was healthy. The driver was healthy. The connection was healthy. The query planner was answering. There was no lock, no dead socket, no upstream contention.

Which left only one possibility: the data was moving, just very slowly, and something in our own process was the limiting factor.

That was the moment the investigation turned around. Up to then we had been looking outward at Infor, at the network, at the tenant. Everything after that point was looking inward.


5. The observability failure that hid all of this

There is a sub-plot here that is worth pulling out, because it is the most portable lesson in the post and it has nothing to do with JDBC.

rows_read was written to the run record on completion.

Not periodically. Not on a heartbeat. Not every N batches. On completion which meant that for the entire duration of an extraction, the recorded progress was zero, and at the end it jumped to the final count.

The consequence: a table moving at twenty rows per second and a table that was genuinely dead were byte-for-byte identical in the UI. Both showed no progress. Both eventually timed out. There was no signal anywhere in the system that could distinguish “slow” from “stopped,” which is why the initial diagnosis was wrong and why it stayed wrong for as long as it did.

We had built a pipeline that could tell us whether work had finished, and could not tell us whether work was happening.

If you take one thing from this post and you don’t run JDBC from Python, take this: emit progress on a cadence, not on completion. A counter flushed every few batches would have collapsed this entire investigation into about ten minutes. It is a trivially cheap write and it is the difference between a performance problem and a mystery.


6. The root cause: nine million boundary crossings

So where was the time going?

Consider what actually happens for a single batch in that innocent-looking loop.

The JDBC driver, running inside the JVM, produces a ResultSet. JayDeBeApi materialises each row as a Python tuple of converted Java objects which means every individual cell is converted from a Java type into a Python object, one at a time, and crosses the JNI boundary to get there. Then our converter loop walks the batch again and touches every cell a second time to build the Arrow arrays.

That is O(rows × columns) of Python-level work, and this is the part that matters all of it holds the GIL.

Put the numbers in:

A 45,000-row × 200-column table is nine million individual boundary crossings for what is, physically, a bulk memory copy.

Nine million. For one mid-sized table. In a batch of 350.

And now the width of LN tables stops being background colour and becomes the mechanism. On a ten-column table, this design is fine the per-row overhead dominates and there are not many rows-times-columns to speak of. On a 215-column table, the cell count is twenty times higher for the same row count, and you have driven straight off a performance cliff that a narrower schema would have hidden completely.

This is why the three previous rounds of optimisation didn’t rescue it. Every one of them made the per-cell work cheaper. None of them made there be fewer cells.


7. The parallelism paradox

Here is where it gets genuinely counter-intuitive, and where a comment in our own codebase turns out to have been quietly wrong for a long time.

The resource sizer contained this:

_IO_THREAD_RATIO = 4    # threads per CPU  safe for I/O-bound
                        # (GIL released on JDBC waits)

Read that comment on its own and it is textbook-correct. JDBC is network I/O. JPype does release the GIL while the JVM is waiting on a socket. Therefore Python threads are the right concurrency primitive, and oversubscribing four-to-one against cores is a sensible, conservative ratio for an I/O-bound workload.

Every clause in that reasoning is true. The conclusion is still wrong, and it is wrong for a reason that is easy to miss: the GIL was released during the wait, and reacquired for the conversion after it. The wait was never the expensive part. The nine million cell conversions that happened after the data arrived were the expensive part, and those are pure Python, and they are serialised.

The workload was not I/O-bound. It was CPU-bound, wearing an I/O-bound costume.

Now watch what the sizer does with that assumption on an 8-core host:

max_jobs = min(8 * 4, mem_based, 32) = 32

Thirty-two concurrent extractions. Thirty-two threads, all doing Python-level cell conversion, all contending for one GIL. Each one making progress at roughly one thirty-second of a single core’s worth of throughput.

That is the ten-times slowdown from section 3. It was not mysterious contention or driver weirdness or tenant throttling. We had explicitly configured it. The sizer was working exactly as designed; the design was based on a premise that a single measurement disproved.

When we assembled a ranked list of fixes, the item at the top was this:

Reduce extraction parallelism. Running at concurrency 4 instead of 32 would make each table three to four times faster, with zero code changes.

That is a strange sentence to write in a performance review. The first recommendation for making the ingestion faster was to make it do fewer things at once. No new code, no new infrastructure, no bigger box just stop asking thirty-two threads to share one interpreter lock and pretending that constitutes parallelism.

The first thing we did to speed up ingestion was run fewer things at once.

It also would not have been enough. Three to four times faster than 1,100 rows/min is still only around 4,000 rows/min, which still leaves large tables missing the watchdog and still leaves a ten-million-row full refresh comfortably outside an hourly window. Turning the concurrency down was a tourniquet, not a treatment. It bought headroom while we did the structural work.


8. What the fix actually had to be

By this point the shape of the real solution was forced by the diagnosis.

If the cost is O(rows × columns) of Python work under the GIL, then there are exactly three things you can do about it:

  1. Make each unit of that work cheaper. Already tried, three times. Diminishing and insufficient.
  2. Do more of it in parallel. Impossible the GIL is the thing being contended, so adding threads makes it worse, which is precisely what we had measured.
  3. Have less of it to do. Which means not converting cells individually at all.

Only the third one is a real answer, and it implies something specific: the data has to cross the Java/Python boundary in bulk, in a format both sides already understand, without being touched cell by cell on the way. That is a wire format problem, not a tuning problem and it is why no amount of instance sizing was going to fix this either. A bigger machine gives you more cores for a workload that is bottlenecked on a lock, not on cores.

That solution Apache Arrow as the transfer format, with the entire ResultSet converted inside the JVM and handed to Python as a single serialised blob per batch is the subject of the next post in this series, along with the four production traps we hit implementing it.


9. Two lessons before we get there

“I/O-bound” is an assumption, not a fact. A comment in our resource sizer asserted that the GIL was released during JDBC waits. It was. That was never the question. The question was what happened in the microseconds after the wait, and nobody had checked. One isolated measurement overturned a sizing formula the entire pipeline had been built on. If your concurrency model rests on a claim about where time is spent, go and measure where time is actually spent the claim is probably in a comment, written by someone who was reasoning rather than profiling.

More threads can be strictly worse. Not “diminishing returns.” Not “no further improvement.” Ten times slower, same code, same data. If your workload is secretly CPU-bound in Python, every additional thread is a tax paid by every other thread. Concurrency is not free and it is not always positive, and the only way to know which side of that line you are on is to measure one worker in isolation and compare it to one worker in a crowd.

The gap between those two numbers 12,810 and 1,100 was the most informative measurement in the whole project. It cost about twenty minutes to obtain. We should have taken it months earlier.


Next in this series: Arrow as the wire format between Java and Python turning O(rows × columns) into O(batches), and the four traps in the way.

Related reading

Comments 00

Leave a Reply

Discover more from Data On The Move

Subscribe now to keep reading and get access to the full archive.

Continue reading