See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/856/changes
Changes: [ddas] HADOOP-5746. Fixes a corner case problem in Streaming, where if an exception happens in MROutputThread after the last call to the map/reduce method, the exception goes undetected. Contributed by Amar Kamat. [ddas] HADOOP-5170. Allows jobs to set max maps/reduces per-node and per-cluster. Contributed by Matei Zaharia. [szetszwo] HADOOP-5762. Fix a problem that DistCp does not copy empty directory. Contributed by Rodrigo Schmidt ------------------------------------------ [...truncated 406383 lines...] [junit] Generating host names for tasktrackers [junit] 2009-06-04 17:42:20,576 INFO mapred.JobTracker (JobTracker.java:<init>(1558)) - Starting jobtracker with owner as hudson and supergroup as supergroup [junit] 2009-06-04 17:42:20,577 INFO mapred.JobTracker (JobTracker.java:initializeTaskMemoryRelatedConfig(3855)) - Scheduler configured with (memSizeForMapSlotOnJT, memSizeForReduceSlotOnJT, limitMaxMemForMapTasks, limitMaxMemForReduceTasks) (-1, -1, -1, -1) [junit] 2009-06-04 17:42:20,577 INFO util.HostsFileReader (HostsFileReader.java:refresh(76)) - Refreshing hosts (include/exclude) list [junit] 2009-06-04 17:42:20,647 INFO metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=JobTracker, port=50857 [junit] 2009-06-04 17:42:20,662 INFO http.HttpServer (HttpServer.java:start(425)) - Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener on 0 [junit] 2009-06-04 17:42:20,662 INFO http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 37226 webServer.getConnectors()[0].getLocalPort() returned 37226 [junit] 2009-06-04 17:42:20,662 INFO http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 37226 [junit] 2009-06-04 17:42:20,663 INFO mortbay.log (?:invoke0(?)) - jetty-6.1.14 [junit] 2009-06-04 17:42:20,846 INFO mortbay.log (?:invoke0(?)) - Started selectchannelconnec...@localhost:37226 [junit] 2009-06-04 17:42:20,848 INFO jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized [junit] 2009-06-04 17:42:20,848 INFO mapred.JobTracker (JobTracker.java:<init>(1671)) - JobTracker up at: 50857 [junit] 2009-06-04 17:42:20,849 INFO mapred.JobTracker (JobTracker.java:<init>(1675)) - JobTracker webserver: 37226 [junit] 2009-06-04 17:42:20,857 INFO mapred.JobTracker (JobTracker.java:<init>(1713)) - Cleaning up the system directory [junit] 2009-06-04 17:42:21,068 INFO mapred.JobTracker (JobTracker.java:refreshHosts(3688)) - Refreshing hosts information [junit] 2009-06-04 17:42:21,091 INFO util.HostsFileReader (HostsFileReader.java:setIncludesFile(100)) - Setting the includes file to [junit] 2009-06-04 17:42:21,092 INFO util.HostsFileReader (HostsFileReader.java:setExcludesFile(105)) - Setting the excludes file to hosts.exclude [junit] 2009-06-04 17:42:21,092 INFO util.HostsFileReader (HostsFileReader.java:refresh(76)) - Refreshing hosts (include/exclude) list [junit] 2009-06-04 17:42:21,092 INFO mapred.JobTracker (JobTracker.java:decommissionNodes(3710)) - Decommissioning 0 nodes [junit] 2009-06-04 17:42:21,093 INFO ipc.Server (Server.java:run(474)) - IPC Server Responder: starting [junit] 2009-06-04 17:42:21,093 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 50857: starting [junit] 2009-06-04 17:42:21,093 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 50857: starting [junit] 2009-06-04 17:42:21,093 INFO ipc.Server (Server.java:run(313)) - IPC Server listener on 50857: starting [junit] 2009-06-04 17:42:21,104 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 7 on 50857: starting [junit] 2009-06-04 17:42:21,104 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 6 on 50857: starting [junit] 2009-06-04 17:42:21,103 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 5 on 50857: starting [junit] 2009-06-04 17:42:21,103 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 4 on 50857: starting [junit] 2009-06-04 17:42:21,103 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 50857: starting [junit] 2009-06-04 17:42:21,093 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 50857: starting [junit] 2009-06-04 17:42:21,105 INFO mapred.JobTracker (JobTracker.java:offerService(1894)) - Starting RUNNING [junit] 2009-06-04 17:42:21,105 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 9 on 50857: starting [junit] 2009-06-04 17:42:21,104 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 8 on 50857: starting [junit] 2009-06-04 17:42:21,525 INFO mapred.MiniMRCluster (MiniMRCluster.java:<init>(176)) - mapred.local.dir is http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/0_0 [junit] 2009-06-04 17:42:26,549 INFO http.HttpServer (HttpServer.java:start(425)) - Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener on 0 [junit] 2009-06-04 17:42:26,549 INFO http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 42904 webServer.getConnectors()[0].getLocalPort() returned 42904 [junit] 2009-06-04 17:42:26,550 INFO http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 42904 [junit] 2009-06-04 17:42:26,550 INFO mortbay.log (?:invoke0(?)) - jetty-6.1.14 [junit] 2009-06-04 17:42:26,611 INFO mortbay.log (?:invoke0(?)) - Started selectchannelconnec...@0.0.0.0:42904 [junit] 2009-06-04 17:42:26,616 INFO jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=TaskTracker, sessionId= - already initialized [junit] 2009-06-04 17:42:26,619 INFO metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=TaskTracker, port=55565 [junit] 2009-06-04 17:42:26,620 INFO ipc.Server (Server.java:run(474)) - IPC Server Responder: starting [junit] 2009-06-04 17:42:26,620 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 55565: starting [junit] 2009-06-04 17:42:26,622 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 55565: starting [junit] 2009-06-04 17:42:26,620 INFO ipc.Server (Server.java:run(313)) - IPC Server listener on 55565: starting [junit] 2009-06-04 17:42:26,623 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 55565: starting [junit] 2009-06-04 17:42:26,623 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 55565: starting [junit] 2009-06-04 17:42:26,696 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(51)) - setsid exited with exit code 0 [junit] 2009-06-04 17:42:26,699 INFO mapred.IndexCache (IndexCache.java:<init>(46)) - IndexCache created with max memory = 10485760 [junit] 2009-06-04 17:42:26,738 INFO net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/host0.foo.com [junit] 2009-06-04 17:42:26,739 INFO mapred.JobTracker (JobTracker.java:addNewTracker(2426)) - Adding tracker tracker_host0.foo.com:localhost/127.0.0.1:55565 to host host0.foo.com [junit] 2009-06-04 17:42:26,740 INFO mapred.MiniMRCluster (MiniMRCluster.java:<init>(176)) - mapred.local.dir is http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0 [junit] 2009-06-04 17:42:31,757 INFO http.HttpServer (HttpServer.java:start(425)) - Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener on 0 [junit] 2009-06-04 17:42:31,758 INFO http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 39974 webServer.getConnectors()[0].getLocalPort() returned 39974 [junit] 2009-06-04 17:42:31,758 INFO http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 39974 [junit] 2009-06-04 17:42:31,758 INFO mortbay.log (?:invoke0(?)) - jetty-6.1.14 [junit] 2009-06-04 17:42:31,832 INFO mortbay.log (?:invoke0(?)) - Started selectchannelconnec...@0.0.0.0:39974 [junit] 2009-06-04 17:42:31,836 INFO jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=TaskTracker, sessionId= - already initialized [junit] 2009-06-04 17:42:31,837 INFO metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=TaskTracker, port=33206 [junit] 2009-06-04 17:42:31,838 INFO ipc.Server (Server.java:run(474)) - IPC Server Responder: starting [junit] 2009-06-04 17:42:31,838 INFO ipc.Server (Server.java:run(313)) - IPC Server listener on 33206: starting [junit] 2009-06-04 17:42:31,843 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 33206: starting [junit] 2009-06-04 17:42:31,843 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 33206: starting [junit] 2009-06-04 17:42:31,846 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 33206: starting [junit] 2009-06-04 17:42:31,846 INFO ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 33206: starting [junit] 2009-06-04 17:42:31,851 INFO mapred.IndexCache (IndexCache.java:<init>(46)) - IndexCache created with max memory = 10485760 [junit] 2009-06-04 17:42:31,877 INFO net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/host1.foo.com [junit] 2009-06-04 17:42:31,878 INFO mapred.JobTracker (JobTracker.java:addNewTracker(2426)) - Adding tracker tracker_host1.foo.com:localhost/127.0.0.1:33206 to host host1.foo.com [junit] rootdir = /test/testDistCh [junit] root=/test/testDistCh, returnvalue=0 [junit] results: [junit] -rw-r--r-- 2 hudson supergroup 38 2009-06-04 17:42 /test/testDistCh/f1 [junit] -rw-r--r-- 2 hudson supergroup 38 2009-06-04 17:42 /test/testDistCh/f2 [junit] -rw-r--r-- 2 hudson supergroup 38 2009-06-04 17:42 /test/testDistCh/f3 [junit] drwxr-xr-x - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub0 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub0/f4 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub0/f5 [junit] drwxr-xr-x - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub1 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub1/f6 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub1/f7 [junit] drwxr-xr-x - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub2 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub2/f8 [junit] drwxr-xr-x - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub3 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub3/f9 [junit] drwxr-xr-x - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub4 [junit] [junit] args=[/test/testDistCh/sub4:::027, [junit] /test/testDistCh/sub3::sub3:754, [junit] /test/testDistCh/sub0:sub0:sub0:236, [junit] /test/testDistCh/sub2:::414] [junit] newstatus=[sub0:sub0:-w--wxrw-, [junit] hudson:supergroup:rwxr-xr-x, [junit] hudson:supergroup:r----xr--, [junit] hudson:sub3:rwxr-xr--, [junit] hudson:supergroup:----w-rwx] [junit] 2009-06-04 17:42:32,544 INFO tools.DistTool (DistCh.java:run(376)) - ops=[/test/testDistCh/sub4:null:null:----w-rwx, /test/testDistCh/sub3:null:sub3:rwxr-xr--, /test/testDistCh/sub0:sub0:sub0:-w--wxrw-, /test/testDistCh/sub2:null:null:r----xr--] [junit] 2009-06-04 17:42:32,546 INFO tools.DistTool (DistCh.java:run(377)) - isIgnoreFailures=false [junit] 2009-06-04 17:42:32,568 INFO tools.DistTool (DistCh.java:setup(427)) - distch.job.dir=hdfs://localhost:47628/user/hudson/build/test/mapred/system/distch_olp7e [junit] 2009-06-04 17:42:32,571 INFO tools.DistTool (DistCh.java:setup(433)) - log=hdfs://localhost:47628/user/hudson/build/test/mapred/system/distch_olp7e/_logs [junit] 2009-06-04 17:42:32,935 INFO tools.DistTool (DistCh.java:setup(476)) - distch.op.count=8 [junit] 2009-06-04 17:42:32,941 WARN mapred.JobClient (JobClient.java:configureCommandLineOptions(551)) - Use GenericOptionsParser for parsing the arguments. Applications should implement Tool for the same. [junit] 2009-06-04 17:42:32,978 WARN mapred.JobClient (JobClient.java:configureCommandLineOptions(673)) - No job jar file set. User classes may not be found. See JobConf(Class) or JobConf#setJar(String). [junit] 2009-06-04 17:42:32,991 INFO tools.DistTool (DistCh.java:getSplits(261)) - numSplits=1, splits.size()=1 [junit] 2009-06-04 17:42:33,227 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/jobTracker/job_200906041742_0001.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] 2009-06-04 17:42:33,235 INFO mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(80)) - Initializing job_200906041742_0001 [junit] 2009-06-04 17:42:33,236 INFO mapred.JobInProgress (JobInProgress.java:initTasks(395)) - Initializing job_200906041742_0001 [junit] 2009-06-04 17:42:33,238 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1287)) - Running job: job_200906041742_0001 [junit] 2009-06-04 17:42:33,388 INFO mapred.JobInProgress (JobInProgress.java:initTasks(439)) - Input size for job job_200906041742_0001 = 793. Number of splits = 1 [junit] 2009-06-04 17:42:34,243 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1300)) - map 0% reduce 0% [junit] 2009-06-04 17:42:34,903 INFO mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906041742_0001_m_000002_0' to tip task_200906041742_0001_m_000002, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:33206' [junit] 2009-06-04 17:42:34,986 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] 2009-06-04 17:42:35,049 INFO mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906041742_0001_m_-1339660424 [junit] 2009-06-04 17:42:35,050 INFO mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906041742_0001_m_-1339660424 spawned. [junit] 2009-06-04 17:42:36,231 WARN util.ProcessTree (ProcessTree.java:destroyProcessGroup(166)) - Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 2009-06-04 17:42:36,231 INFO util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 32450 with SIGTERM. Exit code 1 [junit] 2009-06-04 17:42:37,915 INFO mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906041742_0001_m_000002_0' has completed task_200906041742_0001_m_000002 successfully. [junit] 2009-06-04 17:42:37,920 INFO mapred.JobInProgress (JobInProgress.java:findNewMapTask(1815)) - Choosing a non-local task task_200906041742_0001_m_000000 [junit] 2009-06-04 17:42:37,920 INFO mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906041742_0001_m_000000_0' to tip task_200906041742_0001_m_000000, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:33206' [junit] 2009-06-04 17:42:37,925 INFO mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906041742_0001_m_000002_0 done; removing files. [junit] 2009-06-04 17:42:37,926 INFO mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906041742_0001_m_000002_0 not found in cache [junit] 2009-06-04 17:42:38,007 INFO mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906041742_0001_m_-1403246462 [junit] 2009-06-04 17:42:38,008 INFO mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906041742_0001_m_-1403246462 spawned. [junit] 2009-06-04 17:42:38,256 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906041742_0001_m_000002_0, Status : SUCCEEDED [junit] attempt_200906041742_0001_m_000002_0: 2009-06-04 17:42:35,849 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/attempt_200906041742_0001_m_000002_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] attempt_200906041742_0001_m_000002_0: 2009-06-04 17:42:35,866 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId= [junit] attempt_200906041742_0001_m_000002_0: 2009-06-04 17:42:35,959 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/attempt_200906041742_0001_m_000002_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] attempt_200906041742_0001_m_000002_0: 2009-06-04 17:42:36,030 INFO mapred.Task (Task.java:done(620)) - Task:attempt_200906041742_0001_m_000002_0 is done. And is in the process of commiting [junit] attempt_200906041742_0001_m_000002_0: 2009-06-04 17:42:36,036 INFO mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906041742_0001_m_000002_0' done. [junit] 2009-06-04 17:42:41,245 WARN util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(91)) - Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 2009-06-04 17:42:41,245 INFO util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(94)) - Killing process group32450 with SIGKILL. Exit code 1 [junit] 2009-06-04 17:42:41,246 INFO mapred.DefaultTaskController (DefaultTaskController.java:killTaskJVM(87)) - Process exited with exit code:0 [junit] 2009-06-04 17:42:41,246 INFO mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200906041742_0001_m_-1339660424 exited. Number of tasks it ran: 1 [junit] 2009-06-04 17:42:41,544 WARN util.ProcessTree (ProcessTree.java:destroyProcessGroup(166)) - Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 2009-06-04 17:42:41,545 INFO util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 32499 with SIGTERM. Exit code 1 [junit] 2009-06-04 17:42:43,930 INFO mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906041742_0001_m_000000_0' has completed task_200906041742_0001_m_000000 successfully. [junit] 2009-06-04 17:42:43,934 INFO mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906041742_0001_m_000001_0' to tip task_200906041742_0001_m_000001, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:33206' [junit] 2009-06-04 17:42:43,964 INFO mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906041742_0001_m_-1078325986 [junit] 2009-06-04 17:42:43,964 INFO mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906041742_0001_m_-1078325986 spawned. [junit] 2009-06-04 17:42:44,333 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906041742_0001_m_000000_0, Status : SUCCEEDED [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:38,723 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/attempt_200906041742_0001_m_000000_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:38,740 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId= [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:38,837 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/attempt_200906041742_0001_m_000000_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:38,930 INFO mapred.MapTask (MapTask.java:runOldMapper(352)) - numReduceTasks: 0 [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:39,260 INFO mapred.Task (Task.java:done(620)) - Task:attempt_200906041742_0001_m_000000_0 is done. And is in the process of commiting [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:41,269 INFO mapred.Task (Task.java:commit(720)) - Task attempt_200906041742_0001_m_000000_0 is allowed to commit now [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:41,321 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(92)) - Saved output of task 'attempt_200906041742_0001_m_000000_0' to hdfs://localhost:47628/user/hudson/build/test/mapred/system/distch_olp7e/_logs [junit] attempt_200906041742_0001_m_000000_0: 2009-06-04 17:42:41,330 INFO mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906041742_0001_m_000000_0' done. [junit] 2009-06-04 17:42:45,184 WARN util.ProcessTree (ProcessTree.java:destroyProcessGroup(166)) - Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 2009-06-04 17:42:45,184 INFO util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 32554 with SIGTERM. Exit code 1 [junit] 2009-06-04 17:42:45,342 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1300)) - map 100% reduce 0% [junit] 2009-06-04 17:42:46,558 WARN util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(91)) - Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 2009-06-04 17:42:46,558 INFO util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(94)) - Killing process group32499 with SIGKILL. Exit code 1 [junit] 2009-06-04 17:42:46,558 INFO mapred.DefaultTaskController (DefaultTaskController.java:killTaskJVM(87)) - Process exited with exit code:0 [junit] 2009-06-04 17:42:46,559 INFO mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200906041742_0001_m_-1403246462 exited. Number of tasks it ran: 1 [junit] 2009-06-04 17:42:46,939 INFO mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906041742_0001_m_000001_0' has completed task_200906041742_0001_m_000001 successfully. [junit] 2009-06-04 17:42:46,940 INFO mapred.JobInProgress (JobInProgress.java:jobComplete(2146)) - Job job_200906041742_0001 has completed successfully. [junit] 2009-06-04 17:42:46,977 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906041742_0001_m_000000_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:33206' [junit] 2009-06-04 17:42:46,977 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906041742_0001_m_000001_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:33206' [junit] 2009-06-04 17:42:46,977 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906041742_0001_m_000002_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:33206' [junit] 2009-06-04 17:42:46,978 INFO mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906041742_0001_m_000000_0 done; removing files. [junit] 2009-06-04 17:42:46,979 INFO mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906041742_0001_m_000000_0 not found in cache [junit] 2009-06-04 17:42:46,979 INFO mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906041742_0001_m_000001_0 done; removing files. [junit] 2009-06-04 17:42:46,980 INFO mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906041742_0001_m_000001_0 not found in cache [junit] 2009-06-04 17:42:47,347 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906041742_0001_m_000001_0, Status : SUCCEEDED [junit] attempt_200906041742_0001_m_000001_0: 2009-06-04 17:42:44,769 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/attempt_200906041742_0001_m_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] attempt_200906041742_0001_m_000001_0: 2009-06-04 17:42:44,786 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId= [junit] attempt_200906041742_0001_m_000001_0: 2009-06-04 17:42:44,880 WARN conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200906041742_0001/attempt_200906041742_0001_m_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] attempt_200906041742_0001_m_000001_0: 2009-06-04 17:42:44,991 INFO mapred.Task (Task.java:done(620)) - Task:attempt_200906041742_0001_m_000001_0 is done. And is in the process of commiting [junit] attempt_200906041742_0001_m_000001_0: 2009-06-04 17:42:44,997 INFO mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906041742_0001_m_000001_0' done. [junit] 2009-06-04 17:42:47,351 INFO mapred.JobClient (JobClient.java:monitorAndPrintJob(1355)) - Job complete: job_200906041742_0001 [junit] 2009-06-04 17:42:47,354 INFO mapred.JobClient (Counters.java:log(534)) - Counters: 7 [junit] 2009-06-04 17:42:47,354 INFO mapred.JobClient (Counters.java:log(536)) - Job Counters [junit] 2009-06-04 17:42:47,355 INFO mapred.JobClient (Counters.java:log(538)) - Launched map tasks=1 [junit] 2009-06-04 17:42:47,355 INFO mapred.JobClient (Counters.java:log(536)) - FileInputFormatCounters [junit] 2009-06-04 17:42:47,355 INFO mapred.JobClient (Counters.java:log(538)) - BYTES_READ=696 [junit] 2009-06-04 17:42:47,355 INFO mapred.JobClient (Counters.java:log(536)) - org.apache.hadoop.tools.DistCh$Counter [junit] 2009-06-04 17:42:47,356 INFO mapred.JobClient (Counters.java:log(538)) - SUCCEED=8 [junit] 2009-06-04 17:42:47,356 INFO mapred.JobClient (Counters.java:log(536)) - FileSystemCounters [junit] 2009-06-04 17:42:47,357 INFO mapred.JobClient (Counters.java:log(538)) - HDFS_BYTES_READ=793 [junit] 2009-06-04 17:42:47,357 INFO mapred.JobClient (Counters.java:log(536)) - Map-Reduce Framework [junit] 2009-06-04 17:42:47,358 INFO mapred.JobClient (Counters.java:log(538)) - Map input records=8 [junit] 2009-06-04 17:42:47,358 INFO mapred.JobClient (Counters.java:log(538)) - Spilled Records=0 [junit] 2009-06-04 17:42:47,359 INFO mapred.JobClient (Counters.java:log(538)) - Map output records=0 [junit] root=/test/testDistCh, returnvalue=0 [junit] results: [junit] -rw-r--r-- 2 hudson supergroup 38 2009-06-04 17:42 /test/testDistCh/f1 [junit] -rw-r--r-- 2 hudson supergroup 38 2009-06-04 17:42 /test/testDistCh/f2 [junit] -rw-r--r-- 2 hudson supergroup 38 2009-06-04 17:42 /test/testDistCh/f3 [junit] d-w--wxrw- - sub0 sub0 0 2009-06-04 17:42 /test/testDistCh/sub0 [junit] --w--w-rw- 2 sub0 sub0 43 2009-06-04 17:42 /test/testDistCh/sub0/f4 [junit] --w--w-rw- 2 sub0 sub0 43 2009-06-04 17:42 /test/testDistCh/sub0/f5 [junit] drwxr-xr-x - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub1 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub1/f6 [junit] -rw-r--r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub1/f7 [junit] dr----xr-- - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub2 [junit] -r-----r-- 2 hudson supergroup 43 2009-06-04 17:42 /test/testDistCh/sub2/f8 [junit] drwxr-xr-- - hudson sub3 0 2009-06-04 17:42 /test/testDistCh/sub3 [junit] -rw-r--r-- 2 hudson sub3 43 2009-06-04 17:42 /test/testDistCh/sub3/f9 [junit] d----w-rwx - hudson supergroup 0 2009-06-04 17:42 /test/testDistCh/sub4 [junit] [junit] Shutting down the Mini HDFS Cluster [junit] Shutting down DataNode 1 [junit] 2009-06-04 17:42:47,525 INFO ipc.Server (Server.java:stop(1103)) - Stopping server on 50228 [junit] 2009-06-04 17:42:47,536 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 50228: exiting [junit] 2009-06-04 17:42:47,536 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 50228: exiting [junit] 2009-06-04 17:42:47,536 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 50228: exiting [junit] 2009-06-04 17:42:47,537 INFO ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder [junit] 2009-06-04 17:42:47,536 INFO ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 50228 [junit] 2009-06-04 17:42:47,542 INFO datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread. [junit] 2009-06-04 17:42:47,542 INFO ipc.Server (Server.java:stop(1103)) - Stopping server on 50228 [junit] Shutting down DataNode 0 [junit] 2009-06-04 17:42:47,577 INFO ipc.Server (Server.java:stop(1103)) - Stopping server on 46409 [junit] 2009-06-04 17:42:47,578 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 46409: exiting [junit] 2009-06-04 17:42:47,578 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 46409: exiting [junit] 2009-06-04 17:42:47,578 INFO ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 46409 [junit] 2009-06-04 17:42:47,578 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 46409: exiting [junit] 2009-06-04 17:42:47,578 INFO ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder [junit] 2009-06-04 17:42:47,580 INFO datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread. [junit] 2009-06-04 17:42:47,580 INFO ipc.Server (Server.java:stop(1103)) - Stopping server on 46409 [junit] 2009-06-04 17:42:47,582 WARN namenode.DecommissionManager (DecommissionManager.java:run(67)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted [junit] 2009-06-04 17:42:47,616 INFO ipc.Server (Server.java:stop(1103)) - Stopping server on 47628 [junit] 2009-06-04 17:42:47,616 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 5 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 47628 [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 7 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 4 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder [junit] 2009-06-04 17:42:47,616 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 47628: exiting [junit] 2009-06-04 17:42:47,616 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 3 on 47628: exiting [junit] 2009-06-04 17:42:47,618 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 9 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 8 on 47628: exiting [junit] 2009-06-04 17:42:47,617 INFO ipc.Server (Server.java:run(997)) - IPC Server handler 6 on 47628: exiting [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 29.87 sec checkfailure: BUILD FAILED http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1043: Tests failed! Total time: 220 minutes 26 seconds Publishing Javadoc Recording test results Recording fingerprints Publishing Clover coverage report...