Spark Token Debug

Luke Hebert

- 2 minutes read - 292 words

When Spark authentication is misbehaving and the default logs do not tell you enough, you need verbose token and Kerberos tracing on both the driver and the executors. The steps below walk through creating two log4j property files and wiring them into your spark-submit command so you can capture the full picture.

Step 1: Create the log4j property files

Create two files, one for the driver and one for the executors.

log4j-driver.properties

log4j.appender.rolling=org.apache.log4j.RollingFileAppender
log4j.appender.rolling.encoding=UTF-8
log4j.appender.rolling.layout=org.apache.log4j.PatternLayout
log4j.appender.rolling.layout.conversionPattern=[%d] %p %m (%c)%n
log4j.appender.rolling.maxBackupIndex=5
log4j.appender.rolling.maxFileSize=50MB
log4j.logger.org.apache.spark=DEBUG
log4j.logger.org.eclipse.jetty=WARN
log4j.rootLogger=DEBUG, rolling
log4j.appender.rolling.file=${spark.yarn.app.container.log.dir}/driver.log
log4j.logger.org.apache.hadoop.crypto.key.kms=TRACE, rolling
log4j.logger.org.apache.hadoop.security.token.delegation.web=TRACE, rolling
log4j.logger.org.apache.hadoop.security.authentication.client=TRACE, rolling
log4j.logger.org.apache.spark.deploy.yarn.Client=DEBUG, rolling

log4j-executor.properties

log4j.appender.rolling=org.apache.log4j.RollingFileAppender
log4j.appender.rolling.encoding=UTF-8
log4j.appender.rolling.layout=org.apache.log4j.PatternLayout
log4j.appender.rolling.layout.conversionPattern=[%d] %p %m (%c)%n
log4j.appender.rolling.maxBackupIndex=5
log4j.appender.rolling.maxFileSize=50MB
log4j.logger.org.apache.spark=DEBUG
log4j.logger.org.eclipse.jetty=DEBUG
log4j.rootLogger=DEBUG, rolling
log4j.appender.rolling.file=${spark.yarn.app.container.log.dir}/executor.log
log4j.logger.org.apache.hadoop.crypto.key.kms=TRACE, rolling
log4j.logger.org.apache.hadoop.security.token.delegation.web=TRACE, rolling
log4j.logger.org.apache.hadoop.security.authentication.client=TRACE, rolling
log4j.logger.org.apache.spark.deploy.yarn.Client=DEBUG, rolling

Step 2: Add the debug flags to spark-submit

Append the following --conf and --files arguments to your spark-submit command. Make sure they appear before the Spark jar path.

--conf 'spark.yarn.am.extraJavaOptions=-Dsun.security.krb5.debug=true -Dsun.security.spnego.debug=true' \
--conf 'spark.yarn.appMasterEnv.HADOOP_JAAS_DEBUG=true' \
--keytab /opt/path/to/.keytab \
--principal <principal> \
--files /path/to/log4j-driver.properties,/path/to/log4j-executor.properties \
--conf "spark.driver.extraJavaOptions=-Dlog4j.configuration=log4j-driver.properties" \
--conf "spark.executor.extraJavaOptions=-Dlog4j.configuration=log4j-executor.properties"

Full example command

spark-submit \
  --class org.apache.spark.examples.SparkPi \
  --master yarn \
  --deploy-mode client \
  /opt/cloudera/parcels/CDH/lib/spark/examples/lib/spark-examples-1.6.0-cdh5.15.2-hadoop2.6.0-cdh5.15.2.jar \
  --conf 'spark.yarn.am.extraJavaOptions=-Dsun.security.krb5.debug=true -Dsun.security.spnego.debug=true' \
  --conf 'spark.yarn.appMasterEnv.HADOOP_JAAS_DEBUG=true' \
  --keytab /opt/path/to/.keytab \
  --principal <principal> \
  --files /path/to/log4j-driver.properties,/path/to/log4j-executor.properties \
  --conf "spark.driver.extraJavaOptions=-Dlog4j.configuration=log4j-driver.properties" \
  --conf "spark.executor.extraJavaOptions=-Dlog4j.configuration=log4j-executor.properties" \
  $SPARK_JAR \
  $SPARK_INPUT_RM_HDFS/${RM_RUNNING}_${ENV}_${WORK}.${JSON}
Important

The --files flag is what ships both property files into the container. Double-check that the paths you supply match where you actually created the files, and that the keytab and principal values point to the correct application credentials.

Step 3: Collect the logs

Run the application with the parameters above. Once it completes (or fails), upload the driver and executor logs for review. The TRACE-level entries under org.apache.hadoop.security.token.delegation.web and org.apache.hadoop.security.authentication.client will show exactly where the token exchange is breaking down.