Enable Debug Logging for YARN Application in Hive
Cloudera

Enable Debug Logging for YARN Application in Hive

Cloudera
When troubleshooting Hadoop related issues, we constantly need to enable DEBUG level logging so that we can see more what Hadoop is doing when running jobs. This blog post in particular shows how you can enable DEBUG logging for YARN application jobs when you run them through Hive. To do so, it is simple. Just add below three lines before you run your query in Hive session: 
SET mapreduce.map.log.level=DEBUG;
SET mapreduce.reduce.log.level=DEBUG;
SET yarn.app.mapreduce.am.log.level=DEBUG;
This will turn on Mapper, Reducer and Application Master log to DEBUG level. If you just need one of them, then simply remove the other ones. Then you can just run your query as normal: 
SELECT COUNT(*) FROM tablename;
Before enabling the DEBUG in Mapper log: 
2018-05-22 21:06:30,267 WARN [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Metrics system not started: org.apache.commons.configuration.ConfigurationException: Unable to load the configuration from the URL file:/run/cloudera-scm-agent/process/1370-yarn-NODEMANAGER/hadoop-metrics2.properties
2018-05-22 21:06:30,338 INFO [main] org.apache.hadoop.mapred.YarnChild: Executing with tokens:
2018-05-22 21:06:30,339 INFO [main] org.apache.hadoop.mapred.YarnChild: Kind: mapreduce.job, Service: job_1526873868324_0001, Ident: (org.apache.hadoop.mapreduce.security.token.JobTokenIdentifier@54b83d10)
2018-05-22 21:06:30,686 INFO [main] org.apache.hadoop.mapred.YarnChild: Kind: HDFS_DELEGATION_TOKEN, Service: 10.17.100.142:8020, Ident: (token for hive: HDFS_DELEGATION_TOKEN owner=hive/host-10-17-100-142.coe.cloudera.com@CDH511.COM, renewer=yarn, realUser=, issueDate=1527048353000, maxDate=1527653153000, sequenceNumber=787, masterKeyId=173)
2018-05-22 21:06:31,556 INFO [main] org.apache.hadoop.mapred.YarnChild: Sleeping for 0ms before retrying again. Got null now.
2018-05-22 21:06:32,194 INFO [main] org.apache.hadoop.mapred.YarnChild: mapreduce.cluster.local.dir for child: /yarn/nm2/usercache/hive/appcache/application_1526873868324_0001
2018-05-22 21:06:33,738 INFO [main] org.apache.hadoop.conf.Configuration.deprecation: session.id is deprecated. Instead, use dfs.metrics.session-id
2018-05-22 21:06:34,271 INFO [main] org.apache.hadoop.mapred.Task:  Using ResourceCalculatorProcessTree : [ ]
After DEBUG is enabled: 
2018-05-22 21:08:00,607 DEBUG [main] org.apache.hadoop.mapred.YarnChild: Child starting
2018-05-22 21:08:01,936 DEBUG [main] org.apache.hadoop.metrics2.lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginSuccess with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Rate of successful kerberos logins and latency (milliseconds)], always=false, type=DEFAULT, sampleName=Ops)
2018-05-22 21:08:01,968 DEBUG [main] org.apache.hadoop.metrics2.lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginFailure with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Rate of failed kerberos logins and latency (milliseconds)], always=false, type=DEFAULT, sampleName=Ops)
2018-05-22 21:08:01,968 DEBUG [main] org.apache.hadoop.metrics2.lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.getGroups with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[GetGroups], always=false, type=DEFAULT, sampleName=Ops)
2018-05-22 21:08:01,969 DEBUG [main] org.apache.hadoop.metrics2.lib.MutableMetricsFactory: field private org.apache.hadoop.metrics2.lib.MutableGaugeLong org.apache.hadoop.security.UserGroupInformation$UgiMetrics.renewalFailuresTotal with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Renewal failures since startup], always=false, type=DEFAULT, sampleName=Ops)
2018-05-22 21:08:01,969 DEBUG [main] org.apache.hadoop.metrics2.lib.MutableMetricsFactory: field private org.apache.hadoop.metrics2.lib.MutableGaugeInt org.apache.hadoop.security.UserGroupInformation$UgiMetrics.renewalFailures with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Renewal failures since last successful login], always=false, type=DEFAULT, sampleName=Ops)
2018-05-22 21:08:01,970 DEBUG [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: UgiMetrics, User and group related metrics
2018-05-22 21:08:02,125 DEBUG [main] org.apache.hadoop.security.SecurityUtil: Setting hadoop.security.token.service.use_ip to true
2018-05-22 21:08:02,169 DEBUG [main] org.apache.hadoop.security.Groups:  Creating new Groups object
2018-05-22 21:08:02,211 DEBUG [main] org.apache.hadoop.util.Shell: Failed to detect a valid hadoop home directory
java.io.IOException: HADOOP_HOME or hadoop.home.dir are not set.
	at org.apache.hadoop.util.Shell.checkHadoopHome(Shell.java:351)
	at org.apache.hadoop.util.Shell.(Shell.java:376)
	at org.apache.hadoop.util.StringUtils.(StringUtils.java:79)
	at org.apache.hadoop.security.Groups.parseStaticMapping(Groups.java:168)
	at org.apache.hadoop.security.Groups.(Groups.java:132)
	at org.apache.hadoop.security.Groups.(Groups.java:100)
	at org.apache.hadoop.security.Groups.getUserToGroupsMappingService(Groups.java:435)
	at org.apache.hadoop.security.UserGroupInformation.initialize(UserGroupInformation.java:337)
	at org.apache.hadoop.security.UserGroupInformation.setConfiguration(UserGroupInformation.java:374)
	at org.apache.hadoop.mapred.YarnChild.main(YarnChild.java:78)
2018-05-22 21:08:02,425 DEBUG [main] org.apache.hadoop.util.Shell: setsid exited with exit code 0
2018-05-22 21:08:02,521 DEBUG [main] org.apache.hadoop.security.Groups: Group mapping impl=org.apache.hadoop.security.ShellBasedUnixGroupsMapping; cacheTimeout=300000; warningDeltaMs=5000
2018-05-22 21:08:02,548 DEBUG [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: from system property: null
2018-05-22 21:08:02,549 DEBUG [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: from environment variable: null
2018-05-22 21:08:02,614 DEBUG [main] org.apache.commons.configuration.ConfigurationUtils: ConfigurationUtils.locate(): base is null, name is hadoop-metrics2-maptask.properties
2018-05-22 21:08:02,616 DEBUG [main] org.apache.commons.configuration.ConfigurationUtils: ConfigurationUtils.locate(): base is null, name is hadoop-metrics2.properties
2018-05-22 21:08:02,617 DEBUG [main] org.apache.commons.configuration.ConfigurationUtils: Loading configuration from the context classpath (hadoop-metrics2.properties)
2018-05-22 21:08:02,620 WARN [main] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Metrics system not started: org.apache.commons.configuration.ConfigurationException: Unable to load the configuration from the URL file:/run/cloudera-scm-agent/process/1370-yarn-NODEMANAGER/hadoop-metrics2.properties
Hope above helps!

Other posts that you might also be interested:

  1. Enabling Kerberos Debug for Hive
  2. Available options to connect to Hive and Impala from .NET application
  3. Yarn Job Failed with Error: “Split metadata size exceeded 10000000”
  4. Hive unable to read Snappy files generated by Hive and Flume together
  5. Application log shows container “is running beyond physical memory limits” error
  6. Enable Snappy Compression For Flume

Powered by YARPP.

Leave a Reply

Your email address will not be published.

✕

My new Snowflake Blog is now live. I will not be updating this blog anymore but will continue with new contents in the Snowflake world!