andygrove opened a new pull request, #6356:
URL: https://github.com/apache/datafusion-comet/pull/6356
## Which issue does this PR close?
No issue. This comes from an audit of how the Scala code logs.
## Rationale for this change
The Scala code logs through Spark's `Logging` trait. Its methods take the
message by name and check the level before building it, so Scala call sites
don't need an `isDebugEnabled` guard, and none of them have one. What varied
from file to file was how a caught exception gets logged and which level a
given kind of event uses.
Most of `IcebergReflection` logged a caught exception by interpolating
`${e.getMessage}` into the message and dropping the exception. For a reflective
call that prints nothing useful. `Method.invoke` wraps whatever the Iceberg
method throws in an `InvocationTargetException`, whose `getMessage` is `null`.
So when an Iceberg method failed, the log said, for example, `Iceberg
reflection failure: Failed to get table from SparkScan: null`, with no stack
trace and no cause. `resolveFileIOClass` already unwrapped the cause for this
reason, but the other call sites didn't.
The level for the same event varied too. When a reflective lookup fails,
Comet declines the scan or write and Spark runs it. 31 of these call sites
logged at ERROR, while others in the same file logged the same kind of failure
at WARN. Comet's other fallbacks log at WARN, including the fallback reasons
that `spark.comet.explain.fallback.log.enabled` logs and a native library that
fails to load. A query that falls back still succeeds, so it shouldn't leave
ERROR lines in the log.
## What changes are included in this PR?
Two rules, applied across `spark/src/main`:
- A log call that reports a caught exception passes it as the throwable
(`logWarning(msg, e)`) instead of interpolating its message. 35 calls change.
Two of them are log-then-throw sites in `CometIcebergNativeScan`, which now
pass the cause as the third one there already did. 4 more calls drop a
`${e.getMessage}` that repeated the exception they already passed.
- ERROR is for failures that propagate, where the task, job or query fails.
WARN is for failures Comet recovers from by falling back.
Level changes:
- ERROR to WARN: 31 reflection failures in `IcebergReflection`, 2 in
`CometScanRule` (catalog property extraction and the partition type check), and
2 for the build info properties file, where a missing file was already a
warning.
- WARN to ERROR: a task abort in `CometNativeWriteExec`.
`CometWriteFilesExec` and Spark's `FileFormatWriter` log the same event at
ERROR.
- INFO to DEBUG: the two DPP conversions in `CometExecRule`. The rest of the
DPP rule tracing, in `CometPlanAdaptiveDynamicPruningFilters` and
`CometSpark34AqeDppFallbackRule`, is already at DEBUG.
Cleanups:
- Removes `Logging` from seven objects that never log:
`CometConfigProvider`, `CometLiteral`, `CometArrowConverters`,
`PlanDataInjector`, and the companion objects of `CometScanRule`,
`CometShuffleManager` and `CometIcebergNativeScanMetadata`.
- Removes `with Logging` from four classes whose parent already mixes it in:
three `Rule`s and `IcebergCommitExec`.
- Drops the `CometBatchKernelCodegen:` and `CometScalaUDFCodegen:` message
prefixes. They repeat the logger name, which Spark's log layout already prints.
Left as they are:
- Three calls log only the exception's message on purpose. These are an
invalid `spark.comet.memory.logInterval`, the test-only Iceberg write report
listener, and the `CometNativeWriteExec` task abort, whose exception is
rethrown and logged by Spark.
- `CometPlugin` mixes in `Logging` without using it, but it is `@Public`, so
its type is unchanged.
- The Iceberg scan serialization summary in `CometIcebergNativeScan` is the
one place that computes values only to log them. It logs at INFO, which is on
by default, so a level check would not save anything.
## How are these changes tested?
The change only touches logging, so it adds no tests. I checked that no
test, and no diff under `dev/diffs/`, asserts on a message or level this PR
changes. `CometIcebergNativeScanSuite` asserts on the exception that
`serializeResidual` throws, which is unchanged.
`test-compile` passes on Spark 3.4 with Scala 2.12 and on the default Spark
4.1 with Scala 2.13, which covers both the 3.x and 4.x versions of the
`Logging` trait. scalafix (on 3.4), scalastyle and spotless are clean. I didn't
run any suites.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
