Hi, I am running a normal map-reduce job. The map phases finishes but the reduce phases does not start. However, the job is still running but seems it is just halting at the reduce phase.
Note: I am running hadoop 1.2 pseudo-dsitributed on a single node. below is a snap of the log file for 2014-04-17 11:58:54,939 INFO org.apache.hadoop.mapred.TaskTracker: TaskTracker up at: localhost/127.0.0.1:50584 2014-04-17 11:58:54,940 INFO org.apache.hadoop.mapred.TaskTracker: Starting tracker tracker_kw2261.rc.kaust.edu.sa:localhost/127.0.0.1:50584 2014-04-17 11:58:54,980 INFO org.apache.hadoop.mapred.TaskTracker: Starting thread: Map-events fetcher for all reduce tasks on tracker_kw2261.rc.kaust.edu.sa:localhost/127.0.0.1:50584 2014-04-17 11:58:54,988 INFO org.apache.hadoop.util.ProcessTree: setsid exited with exit code 0 2014-04-17 11:58:54,992 INFO org.apache.hadoop.mapred.TaskTracker: Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@1ce3570c 2014-04-17 11:58:54,994 WARN org.apache.hadoop.mapred.TaskTracker: TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled. 2014-04-17 11:58:54,997 INFO org.apache.hadoop.mapred.IndexCache: IndexCache created with max memory = 10485760 2014-04-17 11:58:55,003 INFO org.apache.hadoop.metrics2.impl.MetricsSourceAdapter: MBean for source ShuffleServerMetrics registered. 2014-04-17 11:58:55,005 INFO org.apache.hadoop.http.HttpServer: Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener on 50060 2014-04-17 11:58:55,005 INFO org.apache.hadoop.http.HttpServer: listener.getLocalPort() returned 50060 webServer.getConnectors()[0].getLocalPort() returned 50060 2014-04-17 11:58:55,005 INFO org.apache.hadoop.http.HttpServer: Jetty bound to port 50060 2014-04-17 11:58:55,006 INFO org.mortbay.log: jetty-6.1.26 2014-04-17 11:58:55,189 INFO org.mortbay.log: Started SelectChannelConnector@0.0.0.0:50060 2014-04-17 11:58:55,189 INFO org.apache.hadoop.mapred.TaskTracker: FILE_CACHE_SIZE for mapOutputServlet set to : 2000 2014-04-17 12:01:40,711 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_201404171158_0001_m_000003_0 task's state:UNASSIGNED 2014-04-17 12:01:40,714 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_201404171158_0001_m_000003_0 which needs 1 slots 2014-04-17 12:01:40,714 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_201404171158_0001_m_000003_0 which needs 1 slots 2014-04-17 12:01:40,921 INFO org.apache.hadoop.mapred.JobLocalizer: Initializing user awaraka on this TT. 2014-04-17 12:01:41,103 INFO org.apache.hadoop.mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_201404171158_0001_m_-2007628880 2014-04-17 12:01:41,104 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner jvm_201404171158_0001_m_-2007628880 spawned. 2014-04-17 12:01:41,106 INFO org.apache.hadoop.mapred.TaskController: Writing commands to /home/awaraka/data/hadoop-1.2.1_data/hadoop_local-awaraka/ttprivate/taskTracker/awaraka/jobcache/job_201404171158 _0001/attempt_201404171158_0001_m_000003_0/taskjvm.sh 2014-04-17 12:01:41,564 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_201404171158_0001_m_-2007628880 given task: attempt_201404171158_0001_m_000003_0 2014-04-17 12:01:42,046 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000003_0 0.0% setup 2014-04-17 12:01:42,047 INFO org.apache.hadoop.mapred.TaskTracker: Task attempt_201404171158_0001_m_000003_0 is done. 2014-04-17 12:01:42,047 INFO org.apache.hadoop.mapred.TaskTracker: reported output size for attempt_201404171158_0001_m_000003_0 was -1 2014-04-17 12:01:42,048 INFO org.apache.hadoop.mapred.TaskTracker: addFreeSlot : current free slots : 2 2014-04-17 12:01:42,212 INFO org.apache.hadoop.mapred.JvmManager: JVM : jvm_201404171158_0001_m_-2007628880 exited with exit code 0. Number of tasks it ran: 1 2014-04-17 12:01:42,250 INFO org.apache.hadoop.io.nativeio.NativeIO: Initialized cache for UID to User mapping with a cache timeout of 14400 seconds. 2014-04-17 12:01:42,251 INFO org.apache.hadoop.io.nativeio.NativeIO: Got UserName awaraka for UID 100000 from the native implementation 2014-04-17 12:01:42,271 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_201404171158_0001_m_000000_0 task's state:UNASSIGNED 2014-04-17 12:01:42,271 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_201404171158_0001_m_000001_0 task's state:UNASSIGNED 2014-04-17 12:01:42,273 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_201404171158_0001_m_000000_0 which needs 1 slots 2014-04-17 12:01:42,273 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_201404171158_0001_m_000000_0 which needs 1 slots 2014-04-17 12:01:42,274 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_201404171158_0001_m_000001_0 which needs 1 slots 2014-04-17 12:01:42,274 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 1 and trying to launch attempt_201404171158_0001_m_000001_0 which needs 1 slots 2014-04-17 12:01:42,279 INFO org.apache.hadoop.mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_201404171158_0001_m_298746358 2014-04-17 12:01:42,279 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner jvm_201404171158_0001_m_298746358 spawned. 2014-04-17 12:01:42,282 INFO org.apache.hadoop.mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_201404171158_0001_m_-1495095563 2014-04-17 12:01:42,282 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner jvm_201404171158_0001_m_-1495095563 spawned. 2014-04-17 12:01:42,282 INFO org.apache.hadoop.mapred.TaskController: Writing commands to /home/awaraka/data/hadoop-1.2.1_data/hadoop_local-awaraka/ttprivate/taskTracker/awaraka/jobcache/job_201404171158 _0001/attempt_201404171158_0001_m_000001_0/taskjvm.sh 2014-04-17 12:01:42,284 INFO org.apache.hadoop.mapred.TaskController: Writing commands to /home/awaraka/data/hadoop-1.2.1_data/hadoop_local-awaraka/ttprivate/taskTracker/awaraka/jobcache/job_201404171158 _0001/attempt_201404171158_0001_m_000000_0/taskjvm.sh 2014-04-17 12:01:42,770 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_201404171158_0001_m_-1495095563 given task: attempt_201404171158_0001_m_000000_0 2014-04-17 12:01:42,773 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_201404171158_0001_m_298746358 given task: attempt_201404171158_0001_m_000001_0 2014-04-17 12:01:43,206 INFO org.apache.hadoop.mapred.TaskTracker: Received KillTaskAction for task: attempt_201404171158_0001_m_000003_0 2014-04-17 12:01:43,206 INFO org.apache.hadoop.mapred.TaskTracker: About to purge task: attempt_201404171158_0001_m_000003_0 2014-04-17 12:01:43,206 INFO org.apache.hadoop.mapred.IndexCache: Map ID attempt_201404171158_0001_m_000003_0 not found in cache 2014-04-17 12:01:49,222 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000001_0 1.0% 2014-04-17 12:01:49,225 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.1479132% 2014-04-17 12:01:50,455 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000001_0 1.0% 2014-04-17 12:01:50,457 INFO org.apache.hadoop.mapred.TaskTracker: Task attempt_201404171158_0001_m_000001_0 is done. 2014-04-17 12:01:50,457 INFO org.apache.hadoop.mapred.TaskTracker: reported output size for attempt_201404171158_0001_m_000001_0 was 15476534 2014-04-17 12:01:50,457 INFO org.apache.hadoop.mapred.TaskTracker: addFreeSlot : current free slots : 1 2014-04-17 12:01:50,516 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_201404171158_0001_r_000000_0 task's state:UNASSIGNED 2014-04-17 12:01:50,516 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_201404171158_0001_r_000000_0 which needs 1 slots 2014-04-17 12:01:50,516 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_201404171158_0001_r_000000_0 which needs 1 slots 2014-04-17 12:01:50,520 INFO org.apache.hadoop.mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_201404171158_0001_r_-2007628880 2014-04-17 12:01:50,520 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner jvm_201404171158_0001_r_-2007628880 spawned. 2014-04-17 12:01:50,522 INFO org.apache.hadoop.mapred.TaskController: Writing commands to /home/awaraka/data/hadoop-1.2.1_data/hadoop_local-awaraka/ttprivate/taskTracker/awaraka/jobcache/job_201404171158 _0001/attempt_201404171158_0001_r_000000_0/taskjvm.sh 2014-04-17 12:01:50,656 INFO org.apache.hadoop.mapred.JvmManager: JVM : jvm_201404171158_0001_m_298746358 exited with exit code 0. Number of tasks it ran: 1 2014-04-17 12:01:51,007 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_201404171158_0001_r_-2007628880 given task: attempt_201404171158_0001_r_000000_0 2014-04-17 12:01:52,261 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.20643327% 2014-04-17 12:01:55,295 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.2850715% 2014-04-17 12:01:57,404 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:01:58,428 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.34942606% 2014-04-17 12:02:00,449 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:01,463 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.43121892% 2014-04-17 12:02:04,494 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.4922323% 2014-04-17 12:02:06,492 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:07,526 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.57880783% 2014-04-17 12:02:10,561 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.6370768% 2014-04-17 12:02:12,553 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:13,598 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.70603764% 2014-04-17 12:02:15,596 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:16,628 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.782714% 2014-04-17 12:02:19,658 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.840947% 2014-04-17 12:02:21,634 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:22,687 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.91763073% 2014-04-17 12:02:24,670 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:25,715 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 0.98650074% 2014-04-17 12:02:28,743 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 1.0% 2014-04-17 12:02:30,707 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:31,771 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 1.0% 2014-04-17 12:02:34,798 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 1.0% 2014-04-17 12:02:35,315 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_m_000000_0 1.0% 2014-04-17 12:02:35,316 INFO org.apache.hadoop.mapred.TaskTracker: Task attempt_201404171158_0001_m_000000_0 is done. 2014-04-17 12:02:35,316 INFO org.apache.hadoop.mapred.TaskTracker: reported output size for attempt_201404171158_0001_m_000000_0 was 126033710 2014-04-17 12:02:35,316 INFO org.apache.hadoop.mapred.TaskTracker: addFreeSlot : current free slots : 2 2014-04-17 12:02:35,489 INFO org.apache.hadoop.mapred.JvmManager: JVM : jvm_201404171158_0001_m_-1495095563 exited with exit code 0. Number of tasks it ran: 1 2014-04-17 12:02:36,768 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:39,805 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:45,840 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:51,877 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:02:54,909 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > 2014-04-17 12:03:00,941 INFO org.apache.hadoop.mapred.TaskTracker: attempt_201404171158_0001_r_000000_0 0.0% reduce > copy > .... *That last line gets repeated forever. * -- Best Regards, Karim Ahmed Awara -- ------------------------------ This message and its contents, including attachments are intended solely for the original recipient. If you are not the intended recipient or have received this message in error, please notify me immediately and delete this message from your computer system. Any unauthorized use or distribution is prohibited. Please consider the environment before printing this email.
