Search code examples
hadoophadoop-yarn

How to find the failed log in mapreduce.Job


I want to import csv to hbase by org.apache.hadoop.hbase.mapreduce.ImportTsv.

2019-12-31 06:02:10,611 INFO  [main] mapreduce.JobSubmitter: Submitting tokens for job: job_1577781650355_0001
2019-12-31 06:02:10,611 INFO  [main] mapreduce.JobSubmitter: Executing with tokens: []
2019-12-31 06:02:10,982 INFO  [main] conf.Configuration: found resource resource-types.xml at file:/etc/hadoop/3.1.4.0-315/0/resource-types.xml
2019-12-31 06:02:11,532 INFO  [main] impl.YarnClientImpl: Submitted application application_1577781650355_0001
2019-12-31 06:02:11,668 INFO  [main] mapreduce.Job: The url to track the job: http://node1:8088/proxy/application_1577781650355_0001/
2019-12-31 06:02:11,670 INFO  [main] mapreduce.Job: Running job: job_1577781650355_0001
2019-12-31 06:02:34,983 INFO  [main] mapreduce.Job: Job job_1577781650355_0001 running in uber mode : false
2019-12-31 06:02:34,985 INFO  [main] mapreduce.Job:  map 0% reduce 0%
2019-12-31 06:02:47,134 INFO  [main] mapreduce.Job:  map 4% reduce 0%
2019-12-31 06:02:50,161 INFO  [main] mapreduce.Job:  map 7% reduce 0%
2019-12-31 06:02:53,184 INFO  [main] mapreduce.Job:  map 10% reduce 0%
2019-12-31 06:02:56,212 INFO  [main] mapreduce.Job:  map 14% reduce 0%
2019-12-31 06:02:59,247 INFO  [main] mapreduce.Job:  map 17% reduce 0%
2019-12-31 06:03:02,275 INFO  [main] mapreduce.Job:  map 20% reduce 0%
2019-12-31 06:03:05,296 INFO  [main] mapreduce.Job:  map 24% reduce 0%
2019-12-31 06:03:08,323 INFO  [main] mapreduce.Job:  map 27% reduce 0%
2019-12-31 06:03:11,349 INFO  [main] mapreduce.Job:  map 29% reduce 0%
2019-12-31 06:03:14,370 INFO  [main] mapreduce.Job:  map 33% reduce 0%
2019-12-31 06:03:18,402 INFO  [main] mapreduce.Job:  map 35% reduce 0%
2019-12-31 06:03:21,427 INFO  [main] mapreduce.Job:  map 39% reduce 0%
2019-12-31 06:03:24,455 INFO  [main] mapreduce.Job:  map 42% reduce 0%
2019-12-31 06:03:27,480 INFO  [main] mapreduce.Job:  map 45% reduce 0%
2019-12-31 06:03:30,502 INFO  [main] mapreduce.Job:  map 48% reduce 0%
2019-12-31 06:03:30,542 INFO  [main] mapreduce.Job: Task Id : attempt_1577781650355_0001_m_000000_0, Status : FAILED
2019-12-31 06:03:32,651 INFO  [main] mapreduce.Job:  map 50% reduce 0%
2019-12-31 06:04:25,000 INFO  [main] mapreduce.Job: Task Id : attempt_1577781650355_0001_m_000000_1, Status : FAILED
2019-12-31 06:05:18,339 INFO  [main] mapreduce.Job: Task Id : attempt_1577781650355_0001_m_000000_2, Status : FAILED
2019-12-31 06:05:31,481 INFO  [main] mapreduce.Job:  map 52% reduce 0%
2019-12-31 06:05:34,495 INFO  [main] mapreduce.Job:  map 54% reduce 0%
2019-12-31 06:05:37,515 INFO  [main] mapreduce.Job:  map 56% reduce 0%
2019-12-31 06:05:40,559 INFO  [main] mapreduce.Job:  map 57% reduce 0%
2019-12-31 06:05:43,580 INFO  [main] mapreduce.Job:  map 58% reduce 0%
2019-12-31 06:05:46,626 INFO  [main] mapreduce.Job:  map 59% reduce 0%
2019-12-31 06:05:49,657 INFO  [main] mapreduce.Job:  map 60% reduce 0%
2019-12-31 06:05:52,703 INFO  [main] mapreduce.Job:  map 62% reduce 0%
2019-12-31 06:05:55,732 INFO  [main] mapreduce.Job:  map 63% reduce 0%
2019-12-31 06:05:58,763 INFO  [main] mapreduce.Job:  map 65% reduce 0%
2019-12-31 06:06:01,783 INFO  [main] mapreduce.Job:  map 67% reduce 0%
2019-12-31 06:06:04,804 INFO  [main] mapreduce.Job:  map 68% reduce 0%
2019-12-31 06:06:07,827 INFO  [main] mapreduce.Job:  map 70% reduce 0%
2019-12-31 06:06:10,843 INFO  [main] mapreduce.Job:  map 71% reduce 0%
2019-12-31 06:06:13,861 INFO  [main] mapreduce.Job:  map 73% reduce 0%
2019-12-31 06:06:16,892 INFO  [main] mapreduce.Job:  map 74% reduce 0%
2019-12-31 06:06:25,977 INFO  [main] mapreduce.Job:  map 76% reduce 0%
2019-12-31 06:06:28,994 INFO  [main] mapreduce.Job:  map 77% reduce 0%
2019-12-31 06:06:32,027 INFO  [main] mapreduce.Job:  map 78% reduce 0%
2019-12-31 06:06:35,045 INFO  [main] mapreduce.Job:  map 79% reduce 0%
2019-12-31 06:06:38,071 INFO  [main] mapreduce.Job:  map 81% reduce 0%
2019-12-31 06:06:41,088 INFO  [main] mapreduce.Job:  map 82% reduce 0%
2019-12-31 06:06:44,112 INFO  [main] mapreduce.Job:  map 84% reduce 0%
2019-12-31 06:06:47,130 INFO  [main] mapreduce.Job:  map 86% reduce 0%
2019-12-31 06:06:50,147 INFO  [main] mapreduce.Job:  map 87% reduce 0%
2019-12-31 06:06:53,181 INFO  [main] mapreduce.Job:  map 89% reduce 0%
2019-12-31 06:06:56,201 INFO  [main] mapreduce.Job:  map 91% reduce 0%
2019-12-31 06:06:59,215 INFO  [main] mapreduce.Job:  map 93% reduce 0%
2019-12-31 06:07:02,230 INFO  [main] mapreduce.Job:  map 95% reduce 0%
2019-12-31 06:07:05,246 INFO  [main] mapreduce.Job:  map 97% reduce 0%
2019-12-31 06:07:08,267 INFO  [main] mapreduce.Job:  map 98% reduce 0%
2019-12-31 06:07:11,296 INFO  [main] mapreduce.Job:  map 100% reduce 0%
2019-12-31 06:07:11,306 INFO  [main] mapreduce.Job: Job job_1577781650355_0001 completed successfully
2019-12-31 06:07:11,565 INFO  [main] mapreduce.Job: Counters: 35
    File System Counters
        FILE: Number of bytes read=0
        FILE: Number of bytes written=550894
        FILE: Number of read operations=0
        FILE: Number of large read operations=0
        FILE: Number of write operations=0
        HDFS: Number of bytes read=209845961
        HDFS: Number of bytes written=0
        HDFS: Number of read operations=4
        HDFS: Number of large read operations=0
        HDFS: Number of write operations=0
    Job Counters
        Failed map tasks=3
        Launched map tasks=5
        Other local map tasks=3
        Data-local map tasks=2
        Total time spent by all maps in occupied slots (ms)=965166
        Total time spent by all reduces in occupied slots (ms)=0
        Total time spent by all map tasks (ms)=321722
        Total vcore-milliseconds taken by all map tasks=321722
        Total megabyte-milliseconds taken by all map tasks=988329984
    Map-Reduce Framework
        Map input records=1047386
        Map output records=1027529
        Input split bytes=206
        Spilled Records=0
        Failed Shuffles=0
        Merged Map outputs=0
        GC time elapsed (ms)=665
        CPU time spent (ms)=47420
        Physical memory (bytes) snapshot=944381952
        Virtual memory (bytes) snapshot=8920907776
        Total committed heap usage (bytes)=627572736
        Peak Map Physical memory (bytes)=478003200
        Peak Map Virtual memory (bytes)=4466188288
    ImportTsv
        Bad Lines=19857
    File Input Format Counters
        Bytes Read=209845755
    File Output Format Counters
        Bytes Written=0

I want to know why the task fail but don't know where to find. The log not throws error.


Solution

  • In the fifth line of the provided log, there is a Job Tracking url link to check the status attempts and logs of the job.

    The url to track the job: http://node1:8088/proxy/application_1577781650355_0001/

    As per the logs above only a particular task attempts got failed before it is finally successful(Job job_1577781650355_0001 completed successfully).

    Refer : mapred-default.xml

    mapreduce.map.maxattempts and mapreduce.reduce.maxattempts both will be set to 4 by default.

    There is also a concept called as speculative execution. You may want to check it out as well.

    Refer :

    hadoop-speculative-task-execution

    what-is-speculative-execution