Skip to content

[bulk] Report driver-side failures politely too (closes #332) - #339

Merged
hunterhacker merged 8 commits into
mainfrom
driver-side-failures-reported-politely
Sep 1, 2026
Merged

[bulk] Report driver-side failures politely too (closes #332)#339
hunterhacker merged 8 commits into
mainfrom
driver-side-failures-reported-politely

Conversation

@hunterhacker

@hunterhacker hunterhacker commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Closes #332.

A driver-side failure used to reach the user as three copies of the same problem: Glue's exception-analysis blob, Py4J's restatement, and a Java stack with AWS's actual sentence buried on line two. A denied count was 323 lines, closing on Error Category: UNCLASSIFIED_ERROR; ...; An error occurred while calling o304.load — which names nothing anyone can act on.

Workers have been polite since #331. This applies the same model to the driver.

Three parts

1. A net in root.py. Everything out of a verb now goes through shared/driver_errors.py, which classifies it with the same classify_failure workers use and exits instead of re-raising. Re-raising is what summons the blob and the Py4J duplicate.

  • understood (a denial, expired credentials, throttling, or anything a verb already phrased as BulkExecutorError) -> one sentence, no traceback
  • unexpected -> the traceback is printed once, for the user rather than for CloudWatch, then the job exits with a one-line reason

SystemExit passes straight through: a helper that already called exit() has said its piece.

2. get_error_message unwraps a Java/Py4J error. The SDK v1 pattern in there stopped matching when Glue moved to the v2 SDK (software.amazon.awssdk...DynamoDbException rather than com.amazonaws...AmazonDynamoDBException), which is why a denial's "message" was the entire stack. It now takes the innermost cause, because the outer layer is usually Spark boilerplate ("Job aborted due to stage failure") while the cause is the sentence the user needs.

3. Per-site wording where the net's generic sentence would be worse: sql's query errors, load's source read (naming the path and the format the user claimed) and its connector write, and the module named by --transform.

Plus two things the live runs turned up, described below.

Before / after, measured live

Same account, region, table (6 items) and --XNumberOfWorkers 2; before is main at d5dcefa. "noise" counts lines matching Traceback (most recent, py4j, GlueExceptionAnalysis, at org.apache.spark or at software.amazon. Full logs for every row are in ~/Documents/bulk-332-runs/ with an INDEX.md.

scenario before: lines / noise after: lines / noise what the user now reads
count, read denied (connector .load()) 323 / 182 37 / 0 Failure: User: arn:aws:sts::654654401288:assumed-role/AWSGlueServiceRoleBulk332NoRead/GlueJobRunnerSession is not authorized to perform: dynamodb:Scan on resource: arn:aws:dynamodb:us-eas...
find, read denied (connector .load()) 314 / 182 37 / 0 Failure: User: arn:aws:sts::654654401288:assumed-role/AWSGlueServiceRoleBulk332NoRead/GlueJobRunnerSession is not authorized to perform: dynamodb:Scan on resource: arn:aws:dynamodb:us-eas...
sql, read denied (connector .load()) 314 / 182 37 / 0 Failure: User: arn:aws:sts::654654401288:assumed-role/AWSGlueServiceRoleBulk332NoRead/GlueJobRunnerSession is not authorized to perform: dynamodb:Scan on resource: arn:aws:dynamodb:us-eas...
load, write denied (connector write) 848 / 11 794 / 7 BulkExecutorError: Error in writing to table: User: arn:aws:sts::654654401288:assumed-role/AWSGlueServiceRoleBulk332NoWrite/GlueJobRunnerSession is not authorized to perform: dynamodb:Bat...
load --format parquet at a CSV file 1006 / 104 810 / 7 BulkExecutorError: Could not read the source at 's3://aws-glue-bulk-dynamodb-us-east-1-654654401288-zav2b3nfl/b332/csv/data.csv' as 'parquet': s3://aws-glue-bulk-dynamodb-us-east-1-654654...
sql referencing a column that does not exist 148 / 91 37 / 0 BulkExecutorError: SQL query error: [UNRESOLVED_COLUMN.WITH_SUGGESTION] A column, variable, or function parameter with name nosuchcolumn cannot be resolved. Did you mean one of the foll...
fill, generator raises during the driver's size peek 111 / 5 40 / 1 Failure: RuntimeError: faker exploded on every call
load-export --transform naming a missing module 84 / 2 46 / 0 BulkExecutorError: Cannot import transform module 'no_such_transform_module' from 'python_modules.load_export.transform': No module named 'python_modules.load_export.transform.no_such_tra...
load --format json at a non-JSON file (already benign) 25 / 0 25 / 0 Job completed successfully
sql with a query the client rejects (already benign) 55 / 0 55 / 0
count success 36 / 0 36 / 0 Job completed successfully
find --limit 3 success 42 / 0 42 / 0 Job completed successfully
sql success 42 / 0 42 / 0 Job completed successfully
load success (CSV) 48 / 0 48 / 0 Job completed successfully

The fill row's single remaining noise line is the traceback we print on purpose — that failure is a bug in the user's own generator, so the frames are the report. It points at alwaysboom.py", line 5, in generate.

Two things the live runs caught that unit tests had not

A marker has to reach the console every time. The first pass left a denied find printing our clean sentence and then 183 lines of Glue exception analysis anyway, while a denied count in the same batch printed none. Glue emits that blob after a clean sys.exit only sometimes, and the client only suppresses it once the job has identified itself — which previously required the exception to literally be a BulkExecutorError. Understood failures now log behind EXPLAINED_FAILURE_PREFIX, and the drift guard checks all three markers against runner.py rather than one.

A format mismatch fails in two different places. --format parquet at a CSV file raises while the DynamicFrame is created (Parquet reads its footer), not at count() where a JSON or CSV mismatch surfaces — so it fell past the handler I had converted and was reported as unexpected (Py4JJavaError: ... is not a Parquet file). read_data now sits inside that handler: 1006 lines -> 810, noise 104 -> 7.

Known remaining noise, deliberately not suppressed

Two rows are still long, and none of it is our output. Taking 04_load_DENIED_write_connector (794 lines) line by line:

lines what
1-52 normal preamble: cost estimate, job start
53-797 four [Glue Exception Analysis] JSON blobs from Glue's own GlueExceptionAnalysisListener — one per failure level (GlueExceptionAnalysisTaskFailed, StageFailed, JobFailed, then a one-line Root Cause Analysis Result). Each carries a "Failure Reason" and a "Stack Trace" array of Glue connector frames (glue.spark.dynamodb.write.DynamoDBDataWriter.flushBuffer(DynamoDBDataWriter.scala:186) -> .commit(:211)). ~740 lines total
798 our message: BulkExecutorError: Error in writing to table: User: ... is not authorized to perform: dynamodb:BatchWriteItem ...
800 the closing line, same sentence

They are JSON rather than Python tracebacks, which is why the noise counter only scores 7 for this run: it matches at org.apache.spark-style frame lines, and these are "Declaring Class" fields inside a JSON array. The stack trace a reviewer sees in that file is Glue's, four times over, before our code has been told anything.

Why the client cannot suppress it. The client drops Glue-analysis lines only once the job has identified itself, and that happens at line 798 — after all four blobs. The ordering is inherent: the write is distributed, so Glue's listener reacts to the task failing, then the stage, then the job, while the driver only learns of it when Spark finally raises on the write call.

This is also why the three connector read rows collapse to 37 lines while this one does not: a denied .load() fails on the driver before any task exists, so there are no per-task blobs to arrive first. load --format parquet at a CSV file (810 lines) is the same shape as this row.

The fix available, and why it is not here. Suppress GlueExceptionAnalysisListener output unconditionally rather than only after the marker. That is newly defensible: since this PR the driver always explains itself, so those blobs are always redundant. The cost is that for a failure we classify as unexpected — where the Python traceback is thin and Glue's root-cause analysis is the real diagnostic — you would lose it. It is a one-line ignore-list entry plus a test, and I would scope it to the "Event": "GlueExceptionAnalysis...Failed blobs while keeping the single Root Cause Analysis Result line. Wanted a decision on it rather than folding it in.

The other route, pre-flighting the write permission, is ruled out by earlier discussion: whether a write will be permitted is not reliably knowable in advance, so a good failure beats a guess.

Tests

make test: 1682 passed, 48 skipped. Coverage: shared/driver_errors.py 100%, root.py 99%, shared/errors.py 54% -> 73% (its ParseException and .message branches were pre-existing gaps, testable once there was a way to import a module the suite stubs).

Mutation-checked, each failing at least one test: re-raising in root.py (the original bug), not printing the traceback for unexpected failures, treating everything as understood, not collapsing or not bounding the reason, removing the Java unwrapping, taking the outermost cause instead of the innermost, dropping the understood marker, the client not watching it, moving read_data back outside the handler, and both wrong anchors for the Spark-analysis filter.

e2e on this branch: connector 7 passed, commands 12 passed, security 22 passed. The root.py change is global, so the whole suite mattered here.

Also in this PR

Spark logs a query-analysis failure itself, at ERROR, as one 10,850-char JSON event carrying the message we go on to print plus ~90 Java frames and the unresolved query plan — 90 of the 148 lines in the sql mistyped-column run. One event, verified against the raw CloudWatch record, so one ignore-list anchor drops all of it; a guard test covers the tempting alternative of anchoring on the error text, which would have hidden the verb's own sentence.

The lint rule's invariant 2 is rewritten for the new shape, including the two things to check when reading driver-side code: that a marker reaches the console, and that the message survived the Java stack.


Follow-up: the understood-failure marker is now named, not generic

Review question: is 'Failure: ' specific enough for the client to key on? It matches as a substring anywhere in a log line, so no.

Measured first: across every run captured for #332 — thousands of lines — "Failure: " appeared only in our own output (8 occurrences, all ours). The near neighbours were Glue's "Failure Reason" JSON key and lowercase "stage failure:" / "most recent failure:", neither of which matches.

But that is an argument about the shapes we happened to see. Spark emits ExecutorLostFailure: executor 7 exited … and FetchFailure: shuffle block missing, and both contain "Failure: ". A false match makes the client suppress Glue's exception-analysis blob for a failure nobody explained — precisely inverting the marker's purpose, and #302 is an open issue about lost-executor errors, so those lines are not hypothetical here.

The marker is now "Bulk Executor failure: ", with a guard test that runs four real Spark and Glue lines through _pretty_print_log_event and asserts none of them flips the suppression flag. Reverting the marker to the generic form fails three tests.

Re-verified live with a denied count: 31 lines, zero traceback/Py4J/Glue-blob lines, closing on AWS's own sentence, capture in after/01b_count_DENIED_read_marker_recheck.log.

Jason Hunter added 6 commits September 1, 2026 01:46
Workers have surfaced failures politely since #331; the driver had not. A denied
connector read reached the user as ~320 lines: Glue's exception-analysis blob, Py4J's
restatement, and a Java stack with AWS's actual sentence buried on line two, closing on
"An error occurred while calling o304.load".

Three parts.

1. root.py now routes every failure out of a verb through shared/driver_errors.py rather
   than re-raising. Understood -- a denial, expired credentials, throttling, or anything a
   verb already phrased as BulkExecutorError -- exits with one sentence. Unexpected prints
   its traceback once, for the user rather than for CloudWatch, and still exits with a
   one-line reason. Exiting rather than re-raising is the point: a re-raise is what
   summons Glue's blob and Py4J's duplicate.

   It catches BaseException, because a worker that calls exit() arrives as SystemExit
   through Py4J; driver_errors' own sys.exit is let through.

2. get_error_message now unwraps a Java/Py4J error. The SDK v1 pattern stopped matching
   when Glue moved to the v2 SDK (software.amazon.awssdk...DynamoDbException rather than
   com.amazonaws...AmazonDynamoDBException), so a denial's "message" was the whole stack.
   It takes the innermost cause, because the outer layer is usually Spark boilerplate
   ("Job aborted due to stage failure") while the cause is the sentence the user needs.

3. Per-site sentences where the net's generic one would be worse: sql's query errors,
   load's source read (naming the path and the format the user claimed) and its connector
   write, and the transform module named by --transform.

The client suppresses Glue's blob on the driver banner as well as the worker one, and the
drift guard now checks both constants against runner.py.
… every time

Found in the live before/after: a denied `find` printed our clean sentence and then 183
lines of Glue exception analysis anyway, while a denied `count` in the same batch printed
none. Glue emits that blob after a clean sys.exit only sometimes, and the client can only
drop it once the job has identified itself -- which previously happened only when the
exception was literally a BulkExecutorError.

Understood driver failures now log behind EXPLAINED_FAILURE_PREFIX ("Failure: "), the
client watches for it, and the drift guard checks all three markers rather than one.
Asserted client-side as well, since whether the blob shows up in any given live run is
not something a test can rely on.
…notices it

The live before/after caught this: `--format parquet` at a CSV file was reported as an
unexpected failure ("Py4JJavaError: ... is not a Parquet file", with a traceback) rather
than as the user's own mistake. Parquet reads its footer while the DynamicFrame is being
created, so it raises from read_data -- outside the handler that already converted the
count() path, which is where a JSON or CSV mismatch surfaces.

read_data now sits inside that handler, so both report the same way: one sentence naming
the path and the format the user claimed it was.

Also updates the lint rule's invariant 2 for #332: the net exists, a marker has to reach
the console (Glue's blob follows a clean exit only sometimes -- 183 lines after a denied
find, none after a denied count in the same batch), and get_error_message has to unwrap
the Java stack to the innermost cause.
Measured while verifying #332: `sql` with a mistyped column produced 148 lines, 90 of
them Spark logging the AnalysisException itself -- at ERROR, before our handler turns it
into "SQL query error: [UNRESOLVED_COLUMN...]" -- as one 10,850-char JSON event carrying
the message we already print, ~90 Java frames, and the unresolved query plan.

One event, so one ignore-list anchor drops all of it, checked against the raw CloudWatch
event rather than assumed. Anchored on the logger name inside the JSON; a guard test
covers the tempting alternative of anchoring on the error text, which would have hidden
the verb's own sentence too.
…or I committed

fill/alwaysboom.py was a throwaway generator for reproducing a driver-side failure and
should never have been committed -- removed.

Coverage additions, all reachable now that there is a way to import shared/errors.py in a
suite that stubs it: Spark's ParseException branch (message plus the offending SQL), the
.message-attribute branch, and root.py's SystemExit passthrough. The first two were
pre-existing gaps; the third is mine. shared/errors.py goes 54% -> 73%, root.py 96% -> 99%.
@hunterhacker hunterhacker added the bulk_executor All bulk executor tasks label Sep 1, 2026
Jason Hunter added 2 commits September 1, 2026 15:25
…rip it

The client matches markers as substrings anywhere in a log line, so "Failure: " was too
generic: Spark emits shapes like "ExecutorLostFailure: executor 7 exited" and
"FetchFailure: shuffle block missing", either of which contains it. A false match
suppresses Glue's diagnostics for a failure nobody explained -- the opposite of what the
marker is for.

Across every run captured for #332 the string appeared only in our own output, so this is
about the shapes we have not seen rather than one we have. Now "Bulk Executor failure: ",
with a guard test over four real Spark and Glue lines; reverting the marker fails it.

Re-verified live: a denied count is 31 lines, no traceback or Glue blob, closing on AWS's
own sentence.
Reading zero items logged at ERROR and returned, so job.commit() ran, Glue marked the run
SUCCEEDED, and the output read:

  ERROR - No data found, please check your data source
  Job completed successfully. Job duration: 0:01:28

An error and a success about the same run, with exit 0 for anything watching. Now a
warning that says what happened and what to check, naming the path and the format the user
claimed: "Read 0 items from '<path>' as 'json' -- nothing was loaded. If that is
unexpected, check --format and the path."

Deliberately still a success. An empty drop is a legitimate input and the export pipeline
already treats a 0-item export that way. Whether a source that holds bytes but yields no
rows should fail instead -- the wrong-format case -- is a behaviour change with its own
before/after, tracked as #340.
@hunterhacker
hunterhacker merged commit b8ddf29 into main Sep 1, 2026
4 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bulk_executor All bulk executor tasks

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[bulk] Driver-side failures still surface as a Spark traceback, not a polite message

1 participant