AnsweredAssumed Answered

Troubleshooting slow merge phase

Question asked by heathbar on Feb 13, 2013
Latest reply on Feb 13, 2013 by gera
After my mappers complete their computation, the mapper's merge phase takes a very long time (about as long as the mapper spent running the actual computation ~ 2 hrs).  The logs show the same "Down to the last merge-pass" message repeatedly, which seems suspicious.  Is this the expected behavior?  What makes the merge so slow?

    2013-02-13 13:52:56,319 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3427434307 bytes
    2013-02-13 14:02:54,170 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 14:03:38,370 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 14:08:40,987 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3364663582 bytes
    2013-02-13 14:18:14,674 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 14:18:55,404 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 14:24:10,119 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3409790736 bytes
    2013-02-13 14:33:51,374 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 14:34:27,709 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 14:40:01,760 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3401252596 bytes
    2013-02-13 14:49:52,595 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 14:50:26,713 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 14:55:35,137 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3390113839 bytes
    2013-02-13 15:05:21,418 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 15:05:53,411 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 15:11:28,064 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3404205015 bytes
    2013-02-13 15:21:29,578 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 15:22:03,916 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 15:27:23,019 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3403487058 bytes
    2013-02-13 15:37:24,634 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 15:37:54,156 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 15:43:06,958 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3363344926 bytes
    2013-02-13 15:52:58,993 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 15:53:38,704 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 15:58:47,659 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3372042552 bytes
    2013-02-13 16:08:38,473 INFO org.apache.hadoop.mapred.Merger: Merging 453 sorted segments
    2013-02-13 16:09:34,054 INFO org.apache.hadoop.mapred.Merger: Merging 198 intermediate segments out of a total of 453
    2013-02-13 16:14:43,305 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 256 segments left of total size: 3375369651 bytes
    2013-02-13 16:24:57,469 INFO org.apache.hadoop.mapred.Task: Task:attempt_201302131112_0001_m_000019_0 is done. And is in the process of commiting
    2013-02-13 16:24:57,541 INFO org.apache.hadoop.mapred.Task: Task 'attempt_201302131112_0001_m_000019_0' done.
    2013-02-13 16:24:57,566 INFO org.apache.hadoop.mapred.TaskLogsTruncater: Initializing logs' truncater with mapRetainSize=-1 and reduceRetainSize=-1

Outcomes