Skip to content

Reduce CI log verbosity from per-worker/per-message amber engine logs #6796

Description

@aglinxinyuan

Problem

CI logs — especially the amber integration specs (e.g. LoopIntegrationSpec) — are flooded with per-worker / per-message engine logs at INFO. A single loop run emits thousands of lines: two full ChannelIdentity dumps per embedded control message (ECM), plus per-worker lifecycle and per-region lines, repeated on every loop iteration because workers are recreated each iteration. This bloats log storage and scroll, slows the run, and buries genuine failures.

Root cause

AmberLogging names each logger "<actorId>] [<ClassName>" so the logback pattern [%logger] can render both the actor id and the class in one field. The side effect: these logger names start with the actor id (e.g. WF6-…, COORDINATOR), not org.apache…, so the

<logger name="org.apache" level="WARN"/>

rule in amber/src/main/resources/logback.xml never matches the engine classes. They all fall through to the root logger (${TEXERA_SERVICE_LOG_LEVEL:-INFO}) and emit at INFO. Lowering the org.apache level does nothing for them.

Noise categories

Volume Message Level Source
Huge (3×/ECM, full URI dump) receive / process / send ECM INFO DataProcessor.scala, main_loop.py
High register <id> -> Actor[…] INFO PekkoActorRefMappingService.scala
High (misleading) …is not reachable anymore, it might have crashed — fires on normal teardown WARN PekkoActorRefMappingService.scala
High (race noise) unknown identifier WARN PekkoActorRefMappingService.scala
Per worker worker replay log writing conf, DP thread started/exits, Starting the worker. INFO WorkflowActor, DPThread, StartHandler
Per region Region N successfully terminated. INFO RegionExecutionManager.scala
Per operator …completed, # of input ports… INFO DataProcessor.scala
Per client msg client actor cannot handle … WARN ClientActor.scala

Fix (this task)

  1. Demote the chatty per-message / per-worker-lifecycle / per-region logs to DEBUG so they no longer print at the default INFO level (CI, local, and prod). This includes the three misleading WARNs that fire on normal operation (might have crashed on graceful teardown, unknown identifier registration race, client actor cannot handle fallthrough). Genuine fault paths are left untouched (DP Thread exists unexpectedly ERROR, Failed to fetch actorRef WARN, Error when terminating region WARN).
  2. CI backstop: pin TEXERA_SERVICE_LOG_LEVEL=WARN and UDF_PYTHON_LOG_STREAMHANDLER_LEVEL=WARN on the amber unit and integration test steps in build.yml.

Follow-up candidates (not in the first PR)

An engine-wide sweep surfaced these additional hot-path logs that could be demoted in a later pass:

Location Level Why noisy
AsyncRPCClient.scala (receive reply: null …) INFO Per control-reply; inconsistent sibling of the debug branch a few lines above
range_based_shuffle_partitioner.py (got {partitioning}) INFO Per-worker partition setup; outlier — no other partitioner logs at INFO in its constructor
tuple.py (out-of-range / cast warnings) WARNING Data-conditional per-tuple/per-field; can flood on a single bad column. Genuinely useful, so consider once-per-column dedupe rather than demotion
ClientActor.scala (Amber Client received: …) INFO Per-message fallback; low confidence it's a real flood

Latent test note: PekkoConfigSpec asserts pekko.stdout-loglevel == "INFO" unguarded. It is safe today only because stdout-loglevel is hardcoded in cluster.conf. If a ${?TEXERA_SERVICE_LOG_LEVEL} override is ever added to that key, the assertion will start failing in the CI step that now sets WARN — either move it inside the sys.env/sys.props guard or add a comment noting the dependency.

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions