The Spark UI: Intermediate
Slow-job investigations tend to start with whichever number looks most alarming. An executor shows red GC time, so someone doubles spark.executor.memory. The cluster bill rises and the ranking job still runs 2.3 hours, because the cause was a single title_id holding 35 times the typical task's rows. The memory change treated a symptom of that key.
The stage chosen in check 1 is the stage that checks 2 to 5 read.
| Check | Where you read it | The number | Reads as healthy |
|---|---|---|---|
| 1. Slow stage | Stages tab, sorted by Duration | Stage duration as a share of the job | Picks the target for the other 4 checks |
| 2. Shuffle volume | Stage page header | Shuffle write over input | Matches the operation's shape |
| 3. Skew | Summary Metrics, Duration row | Max task over median task | Under 2 |
| 4. GC time | Executors tab, Task Time (GC Time) | GC time over task time | Under 10% |
| 5. Spill | Stage page, Spill (Memory) and Spill (Disk) | Any spill at all | Columns absent |
Why this order
Running the checks on the ranking job
| Stage | Description | Duration | Tasks | Input | Output | Shuffle Read | Shuffle Write |
|---|---|---|---|---|---|---|---|
| 3 | scan viewing_events | 7.4 min | 2,800 | 380 GB | 0 B | 0 B | 205 GB |
| 4 | window by title_id, write | 2.1 h | 1,000 | 0 B | 1.6 GB | 205 GB | 0 B |
| Check | Reading on stage 4 | Verdict |
|---|---|---|
| 3. Skew | Max task 2.0 h, median 3.5 min: ratio 34 | Fails |
| 4. GC time | Task 812 spent 38 min of its 2.0 h in GC (32%); executor 41, which ran it, is the only red row | Fails, on 1 executor |
| 5. Spill | 29 GB spilled from memory as 6.4 GB on disk, all by task 812 | Fails, in 1 task |
- ▸Checks 3, 4 and 5 fail, and all 3 trace back to task 812.
- ▸Task 812's GC time and its spill both come from pushing 66 million rows through a single core.
- ▸Raising memory would shorten that GC and spill and leave the 66 million rows exactly where they are.
- ▸Salting or isolating the hot title_id fixes check 3, and checks 4 and 5 clear with it.
A stage holds 80% of a job's runtime. Its code explodes an array column before a groupBy, and its shuffle write is 3.2 times its input. Its max task runs 6 times the median, and 2 executors show red GC time. Where does the diagnosis start?
| Operation | Expected write over input | Why |
|---|---|---|
| groupBy on a low-cardinality key | Well under 0.01 | Each map task combines its rows to one per key before writing |
| groupBy on a near-unique key | Close to 1 | Combining finds almost no repeated keys inside a map task |
| Shuffle join or window | About 0.5 to 1.5 | Every kept row crosses; columnar input and shuffle blocks compress differently |
| Broadcast join | 0 for the large side | The small side ships whole and the large side stays put |
| After an explode or a duplicate-key join | Above 1.5 | Rows multiplied before the write |
Count records, then bytes
views.groupBy("country").sum("minutes").collect()
Same scan, 3 verdicts
| Operation | Shuffle write | Ratio | Verdict |
|---|---|---|---|
| groupBy country, sum minutes | 15 MB | 0.00004 | Healthy: combining collapsed each task to 190 rows at most |
| groupBy profile_id, collect_list of titles | 361 GB | 0.95 | Expected for the key: profiles barely repeat inside a task |
| window by title_id after a join to device_history on device_id | 1.9 TB | 5.0 | Excessive: device_id repeats on both sides, so the join multiplied rows before the window's exchange |
Where an excessive shuffle comes from
- Rows multiplied before the write: an explode shows Shuffle Write records above Input records in its own stage. A join on a key that repeats on both sides shows it one stage later: the join's map stages write their input rows, and the stage taking the join's output into the next exchange writes far more records than the scan read.
- A broadcast that did not happen: the small side's estimated size sat above spark.sql.autoBroadcastJoinThreshold, so the large side crossed the network too. The plan shows SortMergeJoin where you expected BroadcastHashJoin.
- The same data shuffled twice on one key: 2 Exchange nodes with identical hash partitioning in a single plan, where the first shuffle's output could have been reused.
Input counts bytes read after Parquet column pruning, so a query touching 4 of 60 columns shows only those 4 columns' bytes. Measuring shuffle write against the full table size on disk makes every shuffle look healthier than it is.
A stage scans 120 GB and runs a sum of revenue grouped by store_id, with 1,000 map tasks over 500 stores. Its Shuffle Write reads 96 GB. What is the verdict?
| Metric | Min | 25th | Median | 75th | Max |
|---|---|---|---|---|---|
| Duration | 48 s | 2.9 min | 3.5 min | 4.1 min | 2.0 h |
| GC Time | 1 s | 4 s | 5 s | 7 s | 38 min |
| Shuffle Read Size / Records | 160 MB / 1.6M | 182 MB / 1.8M | 190 MB / 1.9M | 199 MB / 2.0M | 6.6 GB / 66M |
| Spill (Disk) | 0 B | 0 B | 0 B | 0 B | 6.4 GB |
| Max over median | What it means |
|---|---|
| Under 2 | Ordinary variation between tasks |
| 2 to 5 | Open the task table and read the slowest 10 tasks |
| Above 5 | Skew or a sick node: decide which before changing code |
These bands are a working heuristic from practice; Spark itself flags none of them.
Data skew or a slow node
- Records ratio close to the duration ratio
- The slow tasks read far more shuffle records
- Several slow tasks sit on different executors
- A rerun is slow at the same task index, wherever it lands
- Records ratio near 1
- The slow tasks read an ordinary share of records
- The slow tasks share one Executor ID and Host
- A rerun whose tasks land elsewhere runs at normal speed
| Row | Task | Executor ID | Host | Duration | Shuffle Read Records |
|---|---|---|---|---|---|
| 1 | 1311 | 17 | 10.0.3.21 | 2.4 min | 1.2M |
| 2 | 1290 | 17 | 10.0.3.21 | 2.3 min | 1.1M |
| 3 | 1347 | 17 | 10.0.3.21 | 2.3 min | 1.1M |
| 41 | 1318 | 6 | 10.0.1.9 | 12 s | 1.1M |
A stage's Summary Metrics show a median Duration of 20 s and a max of 4.0 min. Shuffle Read Records show a median of 800K and a max of 840K. The 6 slowest tasks all ran on executor 9. What do you conclude?
spark.conf.set("spark.sql.autoBroadcastJoinThreshold", -1)plays.join(titles, "title_id").count()
per_user = (
spark.table("user_events")
.where("user_id IS NOT NULL")
.groupBy("user_id")
.count()
.withColumnRenamed("count", "events")
)
per_user.groupBy("events").count().orderBy("events").show()| Executor | Cores | Task Time (GC Time) | GC share | Storage Memory |
|---|---|---|---|---|
| 1 | 5 | 3.2 h (1.0 h) | 31% | 9.6 GB / 10.1 GB |
| 2 | 5 | 3.4 h (58 min) | 28% | 9.9 GB / 10.1 GB |
| 3 | 5 | 3.1 h (55 min) | 30% | 9.7 GB / 10.1 GB |
3 GC patterns and what causes each
| Pattern on the Executors tab | Likely cause | First lever |
|---|---|---|
| One executor red, the rest clean | It ran the skewed task | Go back to the skew tell |
| All red, Storage Memory near full | Cached data crowding the heap | Call `unpersist()` on caches no longer read |
| All red, Storage Memory low, spill present | Each task holds too much data | More, smaller partitions |
Levers before the heap knob
Raising spark.executor.memory is the last lever, and the order of the others follows from where the pressure comes from:
- Shrink the taskFirstMore shuffle partitions, or smaller input splits, mean each task builds smaller hash tables and sort buffers, so fewer objects churn through the heap.
- Free the heapSecondA cache the job no longer reads keeps its memory until you call unpersist(); releasing it hands that space back to running tasks.
- Give each task more of the executorThirdDropping from 5 cores to 4 on the same heap raises each task's share by a quarter, at the cost of a task slot per executor.
- Raise the heapLastEvery executor pays for a larger heap for the whole run, and the oversized tasks or idle cache that caused the pressure grow into it.
Where the ratio misleads
An executor's Task Time (GC Time) reads 2.5 h (50 min). Storage Memory shows 0.4 GB of 10 GB used, and the stage it ran shows spill on every task. What is the first change?
Why spill means the task is too big
A worked fix
A daily aggregation reads 400 GB of shuffle data with spark.sql.shuffle.partitions at 200, so each task fetches about 2 GB. Divide the shuffle read by a target of 200 MB per partition to get the new count: 400 GB over 200 MB is 2,000.
| Metric | Value |
|---|---|
| Shuffle read per task | 2 GB |
| Spill (Memory) | 1.6 TB |
| Spill (Disk) | 310 GB |
| Stage duration | 48 min |
| Metric | Value |
|---|---|
| Shuffle read per task | 200 MB |
| Spill (Memory) | column absent |
| Spill (Disk) | column absent |
| Stage duration | 14 min |
Which lever, by where the spill sits
| Where the spill sits | First lever |
|---|---|
| Every task in a shuffle stage, about evenly | Raise `spark.sql.shuffle.partitions` toward 100 to 200 MB per partition |
| A few tasks; the rest show 0 B | Skew: run the skew tell and fix the hot key |
| Tasks of a scan stage | Lower `spark.sql.files.maxPartitionBytes` from its 128 MB default |
| Every task, even at 100 MB partitions | Fewer cores per executor, then a larger heap |
- Treat any spill figure as a finding, whatever its size
- Size shuffle partitions as shuffle read over 100 to 200 MB
- Compare the Median and Max spill to see whether spill is even
- Re-read the stage page after a change; the spill columns should vanish
- Raise executor memory before trying more partitions
- Add partitions when a single task holds all the spill
- Call 310 GB of disk spill small because the stage still finished
- Tune a scan stage's spill with the shuffle partition setting
A stage shows Spill (Disk) with Min 0 B, Median 0 B and Max 14 GB. Shuffle read per task has a median of 120 MB. Which lever comes first?
> Two weeks after the hot-title fix, the same Netflix ranking job slips to 1.6 hours. A change joined device details onto every viewing row ahead of the window, and the on-call engineer works the 5 checks on the new slow stage.
Five checks, in a fixed order, that turn a slow Spark job into a named cause and the first lever to pull.
- Category
- Spark
- Difficulty
- intermediate
- Duration
- 14 minutes
- Challenges
- 14 hands-on challenges
Topics covered: The Five Checks, in Order, Reading Shuffle Volume, The Skew Tell, The GC Tell, The Spill Tell
Lesson Sections
- The Five Checks, in Order
A fixed order prevents that. Each check reads one number from one place in the UI, and each narrows where the next looks. Checks 2, 3 and 5 live on the stage detail page, which opens when you click a stage's description in the Stages tab. Check 4 has a tab of its own because the JVM records garbage collection per executor; the stage page also carries a GC Time row, useful once you know which executor to blame. Why this order The order runs from the widest view to the narrowest. Shuffle volume is
- Reading Shuffle Volume
Check 2 asks one question of the slow stage: does the amount it shuffles match what its operation needs? The stage page header gives 3 totals. Input is what the stage read from storage. Shuffle Write is what its map tasks wrote for the next stage, and Shuffle Read is what its reduce tasks fetched from the stage before. The ratio to compute is a map stage's shuffle write over its input, or for a reduce stage, its shuffle read over the input of the stages feeding it. That ratio has no single healt
- The Skew Tell
The stage page's Summary Metrics table gives each metric's spread across the stage's tasks: Min, 25th percentile, Median, 75th percentile and Max. The skew tell is a single division, the Max of the Duration row over its Median. The median is the right baseline because one straggler drags a mean upward while barely moving the middle task. For stage 4 of the ranking job, 2.0 hours over 3.5 minutes gives 34. Duration alone cannot say why the task was slow, so divide a second row the same way: 66 mi
- The GC Tell
Garbage collection is the JVM pausing an executor's task threads to reclaim heap from objects nothing references anymore. Every task records how long it was paused, and the UI sums those pauses in 2 places: the GC Time row of a stage's Summary Metrics, and the Executors tab's Task Time (GC Time) column, which shows an executor's total task time with its GC time in brackets. The tell is GC time over task time. The Executors tab draws an executor's cell in red once GC passes 10% of its task time,
- The Spill Tell
Spill is a task writing part of its sort or aggregation buffer to local disk because execution memory ran out, then reading it back to finish. The stage page gives it 2 columns, Spill (Memory) and Spill (Disk), and shows them only when some task in the stage spilled. If the columns are absent, no task spilled; if they appear at any size, that is a finding. Spill (Memory) is how large the spilled data was in its in-memory form; Spill (Disk) is the same data serialized and compressed on disk, so t