Spark and Hudi logging: making a write explain itself

• Why is none of this Hudi-specific configuration?
• Architecture: where the config goes and who reads it
• Which Hudi loggers actually fire?
• What does the signal look like?
• The config that keeps the signal
• Which side do Hudi logs come out of?
• Sending Hudi to its own file
• Turning up one subsystem at a time
• Production tips
• Frequently asked questions
• Conclusion
• References
• Trademarks

TL;DR

• Hudi logs through slf4j with class-name loggers, so every knob is an org.apache.hudi.* package in your Log4j 2 config. Nothing Hudi-specific is needed to capture them.
• On a two-commit Merge-on-Read write, HoodieTableConfig alone produced 101 lines saying it loaded the same properties file. It is the first thing to silence.
• The five loggers worth keeping print the instant lifecycle: requested, inflight, committed, and what a reader reconciled. That is the same timeline your table is built on.
• A tuned config took the same job from 899 lines to 204 without losing a single lifecycle line.
• additivity = false is what sends Hudi to its own file instead of duplicating it into the console.

A Hudi write goes wrong in a way Spark’s own logs cannot explain. The stage succeeded, the job did not fail, and the table is somehow missing the update you just wrote. Or the write took far longer than the one before it and nothing in the Spark UI says why, because the time went somewhere the UI does not model: index lookup, log file reads, a metadata table commit.

The answers are in Hudi’s logs. The problem is that a small write emits hundreds of lines and most of them repeat that a properties file was loaded.

This post is the filter. It covers which Hudi loggers actually fire, which to keep, and how to read what survives. The generic mechanism, how a Log4j 2 file reaches the driver and the executors, is in the Spark JVM playbook; this is the Hudi-specific layer on top.

Written against the latest Hudi release, 1.2.0 as of now, on Spark 4.x. The logger names and line counts below were measured on a real Merge-on-Read write rather than recalled.

Why is none of this Hudi-specific configuration?

Because Hudi does not have a logging system of its own. HoodieTableMetaClient and every other class does this:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

private static final Logger LOG = LoggerFactory.getLogger(HoodieTableMetaClient.class);

slf4j with a class-name logger. The consequence is the useful part: every logger name is a fully qualified class name, so you can address any subsystem by its package. org.apache.hudi.client.transaction is the locking code, org.apache.hudi.common.table.log is the log file reader, and so on.

One version note that catches people moving from older guides. Spark 3.3.0 switched to Log4j 2, and at v4.2.0 the only template shipped is conf/log4j2.properties.template; the Log4j 1 template is gone. If a guide tells you to edit log4j.properties with log4j.rootLogger=, it predates that change and the file will be ignored.

Architecture: where the config goes and who reads it

One file reaches two kinds of JVM, and each hosts different Hudi classes.

log4j2-hudi.properties
        |
        |  --files ships it into every container's working directory
        |
        +--> driver JVM      -Dlog4j.configurationFile=log4j2-hudi.properties
        |      BaseHoodieWriteClient, ActiveTimelineV2,
        |      HoodieBackedTableMetadataWriter, TransactionManager
        |
        +--> executor JVMs   -Dlog4j.configurationFile=log4j2-hudi.properties
               HoodieMergeHandle, HoodieAppendHandle, HoodieCreateHandle,
               index classes, log record readers

Log4j 2 reads the file once per JVM at startup, so the same config governs both sides and there is no Hudi-side reload. What differs is only which classes are loaded in each JVM, which is why the two logs answer different questions.

Which Hudi loggers actually fire?

Rather than guess, run a write with every org.apache.hudi logger at INFO, print the logger name in the pattern, and count. On a Merge-on-Read table with one insert and one update, two commits in total:

The shape is the point. The four noisiest loggers describe plumbing that is working correctly, and the three in bold are the ones that answer questions. HoodieTableConfig produced more lines than the commit lifecycle, the timeline and the log reader combined.

What does the signal look like?

Three loggers carry almost all the diagnostic value.

BaseHoodieWriteClient gives you the commit, by instant:

INFO BaseHoodieWriteClient - Committing 20260917105313836 action deltacommit
INFO BaseHoodieWriteClient - Committed 20260917105313836

Two lines, and the second one is the one that matters. Committing without a matching Committed is a write that did not land, which is exactly the case where the Spark job looks successful and the table disagrees.

ActiveTimelineV2 gives you the state machine described in the Hudi architecture post, printed as it happens:

INFO ActiveTimelineV2 - Creating a new instant [==>20260917105313836__deltacommit__REQUESTED]
INFO ActiveTimelineV2 - Marking instant complete [==>20260917105313836__deltacommit__INFLIGHT]
INFO ActiveTimelineV2 - Created new file for toInstant: .hoodie/timeline/20260917105313836_20260917105315303.deltacommit
INFO ActiveTimelineV2 - Completed [==>20260917105313836__deltacommit__INFLIGHT]

Read the filename on the third line. 20260917105313836_20260917105315303 is the start time and the completion time, which is the naming the timeline uses for a finished instant. If your logs stop after REQUESTED or INFLIGHT, you have found where the write stopped, and the instant time tells you exactly which files to look at under .hoodie/.

BaseHoodieLogRecordReader tells you what a Merge-on-Read reader had to reconcile:

INFO BaseHoodieLogRecordReader - Ordered instant times seen [20260917105313836]
INFO BaseHoodieLogRecordReader - Targeted instants that are rolled back are []
INFO BaseHoodieLogRecordReader - Total valid instants found are 1

That count is read-side merge work made visible. When snapshot queries slow down on a Merge-on-Read table, this number climbing across runs is compaction falling behind, and it moves before any query gets slow enough to notice.

The config that keeps the signal

Everything above in one file. Save it as log4j2-hudi.properties:

status = warn
rootLogger.level = warn
rootLogger.appenderRef.stdout.ref = console

appender.console.type = Console
appender.console.name = console
appender.console.target = SYSTEM_OUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{HH:mm:ss} %-5level %logger{1} - %msg%n

# the write lifecycle: which instant, and whether it committed
logger.hudiclient.name = org.apache.hudi.client.BaseHoodieWriteClient
logger.hudiclient.level = info

# instant state transitions: requested -> inflight -> completed
logger.huditimeline.name = org.apache.hudi.common.table.timeline
logger.huditimeline.level = info

# what a Merge-on-Read reader reconciled
logger.hudilog.name = org.apache.hudi.common.table.log
logger.hudilog.level = info

# noise: repeats the same property load on every access
logger.huditableconfig.name = org.apache.hudi.common.table.HoodieTableConfig
logger.huditableconfig.level = warn
logger.hudifsview.name = org.apache.hudi.common.table.view
logger.hudifsview.level = warn
logger.hudilock.name = org.apache.hudi.client.transaction
logger.hudilock.level = warn

On the same two-commit job that produced 899 lines, this produces 204, with every lifecycle line intact. HoodieTableConfig drops from 101 lines to 4 and the locking chatter to none.

Ship it the same way as any Spark logging config:

spark-submit \
  --files /etc/spark/conf/log4j2-hudi.properties \
  --conf "spark.driver.extraJavaOptions=-Dlog4j.configurationFile=log4j2-hudi.properties" \
  --conf "spark.executor.extraJavaOptions=-Dlog4j.configurationFile=log4j2-hudi.properties" \
  --class com.example.TripsIngest \
  trips-ingest.jar

--files puts the file in each container’s working directory, which is why the value of -Dlog4j.configurationFile is a bare filename rather than a path. In client mode the driver JVM already exists by the time your code runs, so use --driver-java-options for the driver side instead.

Which side do Hudi logs come out of?

Both, and they say different things. It is worth knowing which log to open.

The split follows the architecture: the driver owns the timeline and the commit, the executors do the record-level work. So a question about whether a write committed is a driver-log question, and a question about why one partition was slow is an executor-log question. Setting spark.executor.extraJavaOptions and forgetting the driver, or the reverse, is why half the expected lines never appear.

Sending Hudi to its own file

On a busy job Hudi’s output is interleaved with Spark’s. A dedicated appender separates them:

appender.hudifile.type = RollingFile
appender.hudifile.name = hudifile
appender.hudifile.fileName = /var/log/spark/hudi.log
appender.hudifile.filePattern = /var/log/spark/hudi-%d{yyyy-MM-dd}-%i.log.gz
appender.hudifile.layout.type = PatternLayout
appender.hudifile.layout.pattern = %d{ISO8601} %-5level %logger - %msg%n
appender.hudifile.policies.type = Policies
appender.hudifile.policies.size.type = SizeBasedTriggeringPolicy
appender.hudifile.policies.size.size = 50MB
appender.hudifile.strategy.type = DefaultRolloverStrategy
appender.hudifile.strategy.max = 5

logger.hudi.name = org.apache.hudi
logger.hudi.level = info
logger.hudi.additivity = false
logger.hudi.appenderRef.hudifile.ref = hudifile

additivity = false is the line that does the work. Without it a logger sends its output to its own appender and to the root appender, so everything lands in both the file and the console. With it, the same run put 871 Hudi lines in hudi.log and left 4 on the console.

Two cautions. On YARN and Kubernetes an absolute path writes inside the container, so use a mounted path or let log aggregation collect it. And the rolling policy is not optional at INFO on a busy writer: without SizeBasedTriggeringPolicy and a max, the file grows until the disk is the problem you are debugging.

Turning up one subsystem at a time

Once the baseline is quiet, raise exactly one package for the question you have.

The first row is the one to reach for most often, because an unset hoodie.index.type resolves to SIMPLE on Spark, whose cost scales with the table rather than the batch. The Hudi cheat sheet has the index options and the rest of the config surface.

Production tips

• Keep the tuned config as the default, not something you switch on during an incident. The lifecycle lines are what let you answer questions after the fact.
• Set both driver and executor options. Each answers different questions, and a missing one looks like a missing feature.
• Never leave org.apache.hudi at DEBUG in production. Raise one package for one investigation, then put it back.
• Give Hudi its own file with additivity = false, and always pair it with a size policy and a max.
• Alert on Committing without Committed. That pair, matched by instant time, is the cheapest write-succeeded check you can build.
• Log the instant time into your own job output. It is the join key between your scheduler, the Spark UI and everything under .hoodie/.

Frequently asked questions

Why does log4j.properties no longer work? Spark moved to Log4j 2 in 3.3.0. The file is log4j2.properties, the flag is -Dlog4j.configurationFile=, and the syntax is logger.<key>.name rather than log4j.logger.<name>. Spark 4.x ships only the Log4j 2 template.

Do I need a Hudi-specific logging dependency? No. Hudi logs through slf4j, and the Spark bundle already brings a binding. Configuring Log4j 2 is enough.

My executor logs are empty even though the driver’s are fine. spark.executor.extraJavaOptions is probably unset, or the file was not shipped with --files, so the path resolves on the submitting machine only.

Can I change levels without restarting? Add monitorInterval to the config and Log4j 2 re-reads it periodically. It is useful on a long streaming job, and pointless on a batch job that will finish before the interval elapses.

Why is the same properties file loaded so many times? HoodieTableConfig logs on each access rather than caching the message. It is harmless, and it is the single biggest source of noise, which is why the config above pins it to WARN.

Conclusion

The reason Hudi logs feel useless by default is not that they lack information. It is that the lines carrying the state machine are outnumbered roughly four to one by lines confirming that plumbing worked. Silence the plumbing and what remains is a readable account of the write: an instant created, moved to inflight, and completed with a filename that carries both its start and completion time.

That account is worth keeping on by default. Hudi’s failure modes are quiet ones, a write that never committed or a Merge-on-Read table whose logs are outgrowing compaction, and neither raises an exception in the Spark job. The lifecycle lines are the record that lets you answer, afterwards, which instant did what.

The general mechanism is not Hudi’s at all, which is the useful part. Once you can address any subsystem by its package name, the same file tunes Spark, Hudi and whatever else is on the classpath, and the only decision left is which question you are asking today.

References

• Hudi configuration reference for every hoodie.* key mentioned here
• Log4j 2 properties configuration for appenders, additivity and rollover
• HoodieTableMetaClient.java at release-1.2.0, showing the slf4j logger every Hudi class uses
• A Spark JVM playbook for how a Log4j 2 file reaches the driver and the executors
• Apache Hudi architecture for the timeline and instant states these logs narrate

Trademarks

Apache Hudi, Apache Spark, Apache Log4j, Apache Hadoop, Apache Parquet, Apache Avro and Apache are either registered trademarks or trademarks of The Apache Software Foundation in the United States and other countries.