Reading the Spark UI to Diagnose a Slow Job

explain() shows the plan. The UI shows what happened. When a job is slow, the UI answers the question in about ninety seconds if you know which number to read.

Getting to it

While a job runs, the driver serves the UI on port 4040:

Spark context Web UI available at http://192.168.1.24:4040

After it exits, the UI is gone. Keep the data:

mkdir -p /tmp/spark-events

spark-submit \
  --conf spark.eventLog.enabled=true \
  --conf spark.eventLog.dir=file:///tmp/spark-events \
  app.py

$SPARK_HOME/sbin/start-history-server.sh

starting org.apache.spark.deploy.history.HistoryServer, logging to
  /opt/spark/logs/spark-history-server.out

The history server reads those logs at http://localhost:18080. Turn event logging on everywhere — a job you cannot inspect after the fact is a job you cannot debug.

A deliberately slow job

from pyspark.sql import SparkSession, functions as F

spark = (SparkSession.builder.appName("slow-job").master("local[4]")
         .config("spark.eventLog.enabled", "true")
         .config("spark.eventLog.dir", "file:///tmp/spark-events")
         .getOrCreate())

# 85% of rows share one key.
facts = spark.range(20_000_000).select(
    F.when(F.rand(seed=1) < 0.85, F.lit(7))
     .otherwise((F.rand(seed=2) * 5000).cast("int")).alias("key"),
    F.rand(seed=3).alias("value"),
)
dim = spark.range(5000).select(
    F.col("id").alias("key"),
    F.concat(F.lit("label-"), F.col("id")).alias("label"),
)

spark.conf.set("spark.sql.autoBroadcastJoinThreshold", -1)   # force a shuffle join
spark.conf.set("spark.sql.adaptive.enabled", False)          # and disable the safety net

result = facts.join(dim, "key").groupBy("label").agg(F.avg("value").alias("avg_v"))
print("rows:", result.count())

rows: 5000

It finished — in 94 seconds. The UI explains why.

Jobs tab: which action was slow

Job Id  Description                              Submitted            Duration  Stages  Tasks
2       count at slow_job.py:24                  2026/02/15 13:02:11  1.6 min   4/4     617/617
1       count at slow_job.py:18                  2026/02/15 13:02:04  2 s       1/1     8/8
0       range at slow_job.py:12                  2026/02/15 13:02:02  0.4 s     1/1     8/8

Job 2 is the whole problem. This tab tells you that and nothing more — it maps actions to durations. Click into it.

Stages tab: where the time went

Stage  Description                 Duration  Tasks      Input     Shuffle Read  Shuffle Write
5      HashAggregate               3 s       200/200    —         41.2 MB       —
4      Exchange (dim side)         1 s       8/8        —         —             182.4 KB
3      Exchange (facts side)       18 s      8/8        —         —             487.3 MB
2      SortMergeJoin               74 s      200/200    —         487.5 MB      41.2 MB

Stage 2 is 79% of the runtime. One dominant stage means a targeted problem — skew, spill, or a bad join strategy. Many uniformly slow stages would instead mean under-provisioning.

Task distribution: the skew tell

Open stage 2 and read the summary metrics:

Metric                  Min      25th     Median   75th     Max
Duration                0.1 s    0.2 s    0.3 s    0.4 s    71 s
GC Time                 0 ms     0 ms     0 ms     10 ms    4.1 s
Shuffle Read Size       11 KB    38 KB    52 KB    71 KB    414.8 MB
Shuffle Read Records    412      1,203    1,588    2,104    17,001,204
Spill (Memory)          0 B      0 B      0 B      0 B      2.9 GB
Spill (Disk)            0 B      0 B      0 B      0 B      834 MB

This is the diagnostic. Median task: 0.3 seconds, 52 KB. Max task: 71 seconds, 415 MB, 17 million records. One task did essentially all the work while 199 finished instantly.

The rule of thumb: max more than about 5× the median means skew. Here it is 236×.

The Event Timeline makes the same point visually — 199 bars of a few pixels and one bar spanning the whole stage.

SQL tab: the plan that actually ran

The SQL tab shows the executed plan annotated with real row counts:

== Physical Plan ==
SortMergeJoin [key#2], [key#8], Inner
   number of output rows: 20,000,000
:- Sort [key#2 ASC NULLS FIRST]
:  +- Exchange hashpartitioning(key#2, 200)
:       shuffle records written: 20,000,000
:       shuffle write time: 14.2 s
+- Sort [key#8 ASC NULLS FIRST]
   +- Exchange hashpartitioning(key#8, 200)
        shuffle records written: 5,000

Twenty million records shuffled to join against five thousand. Those annotated counts are what explain() cannot give you — estimates before the run, actuals after.

Executors tab: is the cluster even busy

Executor ID  Address           Active Tasks  Failed  Complete  Task Time  GC Time  Input   Shuffle Read
driver       192.168.1.24      1             0       616       94 s       6 s      1.2 GB  487 MB

One executor with one active task for most of the stage. On a real cluster you would see the same shape — 19 idle executors and one working. That confirms the problem is distribution, not capacity, and that adding executors will not help.

The fixes, measured

Broadcast the small side — removes the shuffle entirely:

spark.conf.set("spark.sql.autoBroadcastJoinThreshold", 10 * 1024 * 1024)

Stage  Description        Duration  Max Task  Median Task  Spill (Disk)
2      BroadcastHashJoin  7 s       0.9 s     0.6 s        0 B

94 seconds to 11 seconds overall. No Exchange on the fact side, so the skew stops mattering.

Or enable AQE — splits the skewed partition:

spark.conf.set("spark.sql.adaptive.enabled", True)
spark.conf.set("spark.sql.adaptive.skewJoin.enabled", True)

Stage  Description                        Duration  Max Task  Median Task
2      SortMergeJoin (AQEShuffleRead       22 s      4.2 s     1.8 s
       coalesced and skewed)

The stage detail now says coalesced and skewed, and max task duration dropped from 71s to 4.2s. Median rose because work was redistributed — which is the point. A stage takes as long as its slowest task.

Storage tab

RDD Name              Storage Level                  Cached Partitions  Fraction Cached  Size in Memory  Size on Disk
*(1) Scan parquet     Disk Memory Deserialized 1x    124/200            62%              1.4 GB          0.9 GB

Fraction Cached below 100% means execution memory evicted storage blocks. The job still works — MEMORY_AND_DISK re-reads from disk — but a cache you thought was in memory is partly not.

A reading order

1. Jobs — which action was slow?
2. Stages — one dominant stage, or many?
3. Stage detail, summary metrics — max vs median duration. Skewed or uniform?
4. Spill columns — non-zero disk spill means partitions too large.
5. GC Time vs Duration — over ~10% means heap pressure.
6. SQL tab — how many rows actually crossed each exchange?
7. Executors — are they all busy, or is one carrying the job?

Practice

max 71 s / median 0.3 s = 236x

$ ls /tmp/spark-events
local-1771158131842

before: 100%, 1.4 GB in memory, 0 B on disk
after:   62%, 0.9 GB in memory, 0.5 GB on disk

Next: the memory model behind spill, eviction, and the out-of-memory errors above.