You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-dev@hadoop.apache.org by Apache Hudson Server <hu...@hudson.zones.apache.org> on 2009/06/04 19:24:27 UTC

Build failed in Hudson: Hadoop-trunk #856

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 SelectChannelConnector@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 SelectChannelConnector@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 SelectChannelConnector@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...


Build failed in Hudson: Hadoop-trunk #862

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/862/changes

Changes:

[gkesavan] HADOOP-5989. Fix streaming test failure.  (gkesavan)

[stevel] HADOOP-4768 Dynamic Priority Scheduler that allows queue shares to be controlled dynamically by a currency

------------------------------------------
[...truncated 458957 lines...]
    [junit] 09/06/11 11:33:13 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:13 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:13 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000003_0 0.0% map > map
    [junit] 09/06/11 11:33:13 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:14 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:14 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:14 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:14 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:14 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:14 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:15 INFO mapred.TaskTracker: attempt_200906111123_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:15 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:15 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:16 INFO mapred.TaskTracker: attempt_200906111123_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:16 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:16 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:16 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000003_0 0.0% map > map
    [junit] 09/06/11 11:33:16 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:17 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:17 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:17 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:17 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:17 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:17 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:18 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:18 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:18 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:19 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:19 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:19 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000003_0 0.0% map > map
    [junit] 09/06/11 11:33:19 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:20 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:20 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:20 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:20 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:20 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:20 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:21 INFO mapred.TaskTracker: attempt_200906111123_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:21 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:21 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:22 INFO mapred.TaskTracker: attempt_200906111123_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:22 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:22 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:22 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000003_0 0.0% map > map
    [junit] 09/06/11 11:33:22 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:23 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:24 INFO mapred.TaskTracker: attempt_200906111123_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:24 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:24 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:24 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:25 INFO mapred.TaskTracker: attempt_200906111123_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:25 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:25 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:25 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:25 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000003_0 0.0% map > map
    [junit] 09/06/11 11:33:25 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:26 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:26 INFO mapred.TaskTracker: attempt_200906111123_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:26 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:26 INFO mapred.TaskTracker: attempt_200906111123_0003_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:26 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:26 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:27 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000000_0 0.0% map > map
    [junit] 09/06/11 11:33:27 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/11 11:33:27 INFO mapred.TaskTracker: attempt_200906111123_0005_m_000002_0 0.0% map > map
    [junit] 09/06/11 11:33:28 INFO mapred.TaskTracker: attempt_200906111123_0004_m_000001_0 0.0% map > map
    [junit] 09/06/11 11:33:28 INFO mapred.TaskTracker: attempt_200906111123_0005_r_000003_0 0.0% reduce > copy > 
    [junit] Running org.apache.hadoop.mapred.TestQueueCapacities
    [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec
    [junit] Test org.apache.hadoop.mapred.TestQueueCapacities FAILED (timeout)

checkfailure:
    [touch] Creating http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/testsfailed 

check-contrib:

init:
     [echo] contrib: mrunit

init-contrib:

ivy-download:
      [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar
      [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar 
      [get] Not modified - so not downloaded

ivy-probe-antlib:

ivy-init-antlib:

ivy-init:
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

ivy-resolve-common:
[ivy:resolve] :: resolving dependencies :: org.apache.hadoop#mrunit;working@vesta.apache.org
[ivy:resolve] 	confs: [common]
[ivy:resolve] 	found commons-logging#commons-logging;1.0.4 in maven2
[ivy:resolve] 	found log4j#log4j;1.2.15 in maven2
[ivy:resolve] 	found junit#junit;4.5 in maven2
[ivy:resolve] :: resolution report :: resolve 19ms :: artifacts dl 2ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      common      |   3   |   0   |   0   |   0   ||   3   |   0   |
	---------------------------------------------------------------------

ivy-retrieve-common:
[ivy:retrieve] :: retrieving :: org.apache.hadoop#mrunit [sync]
[ivy:retrieve] 	confs: [common]
[ivy:retrieve] 	0 artifacts copied, 3 already retrieved (0kB/2ms)
No ivy:settings found for the default reference 'ivy.instance'.  A default instance will be used
DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

compile:
     [echo] contrib: mrunit

compile-examples:

compile-test:
     [echo] contrib: mrunit
    [javac] Compiling 9 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test 
    [javac] Note: Some input files use or override a deprecated API.
    [javac] Note: Recompile with -Xlint:deprecation for details.

test:
     [echo] contrib: mrunit
   [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [junit] Running org.apache.hadoop.mrunit.TestExample
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.203 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapDriver
    [junit] 09/06/11 11:33:30 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/11 11:33:30 ERROR mrunit.TestDriver: Received unexpected output (null, null)
    [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.206 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapReduceDriver
    [junit] 09/06/11 11:33:30 ERROR mrunit.TestDriver: Missing expected output (foo, 52) at position 0
    [junit] Tests run: 8, Failures: 0, Errors: 0, Time elapsed: 0.211 sec
    [junit] Running org.apache.hadoop.mrunit.TestReduceDriver
    [junit] 09/06/11 11:33:31 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/11 11:33:31 ERROR mrunit.TestDriver: Received unexpected output (null, 0)
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.203 sec
    [junit] Running org.apache.hadoop.mrunit.TestTestDriver
    [junit] Tests run: 19, Failures: 0, Errors: 0, Time elapsed: 0.202 sec
    [junit] Running org.apache.hadoop.mrunit.mock.TestMockReporter
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.105 sec
    [junit] Running org.apache.hadoop.mrunit.types.TestPair
    [junit] Tests run: 20, Failures: 0, Errors: 0, Time elapsed: 0.066 sec

checkfailure:

check-contrib:

init:
     [echo] contrib: dynamic-priority

init-contrib:

ivy-download:
      [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar
      [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar 
      [get] Not modified - so not downloaded

ivy-probe-antlib:

ivy-init-antlib:

ivy-init:
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

ivy-resolve-common:
[ivy:resolve] :: resolving dependencies :: org.apache.hadoop#dynamic-priority;working@vesta.apache.org
[ivy:resolve] 	confs: [common]
[ivy:resolve] 	found commons-logging#commons-logging;1.0.4 in maven2
[ivy:resolve] 	found log4j#log4j;1.2.15 in maven2
[ivy:resolve] 	found commons-httpclient#commons-httpclient;3.0.1 in maven2
[ivy:resolve] 	found commons-codec#commons-codec;1.3 in maven2
[ivy:resolve] 	found xmlenc#xmlenc;0.52 in maven2
[ivy:resolve] 	found net.java.dev.jets3t#jets3t;0.6.1 in maven2
[ivy:resolve] 	found commons-net#commons-net;1.4.1 in maven2
[ivy:resolve] 	found org.mortbay.jetty#servlet-api-2.5;6.1.14 in maven2
[ivy:resolve] 	found oro#oro;2.0.8 in maven2
[ivy:resolve] 	found org.mortbay.jetty#jetty;6.1.14 in maven2
[ivy:resolve] 	found org.mortbay.jetty#jetty-util;6.1.14 in maven2
[ivy:resolve] 	found tomcat#jasper-runtime;5.5.12 in maven2
[ivy:resolve] 	found tomcat#jasper-compiler;5.5.12 in maven2
[ivy:resolve] 	found commons-el#commons-el;1.0 in maven2
[ivy:resolve] 	found junit#junit;4.5 in maven2
[ivy:resolve] 	found commons-logging#commons-logging-api;1.0.4 in maven2
[ivy:resolve] 	found org.slf4j#slf4j-api;1.4.3 in maven2
[ivy:resolve] 	found org.slf4j#slf4j-log4j12;1.4.3 in maven2
[ivy:resolve] :: resolution report :: resolve 116ms :: artifacts dl 7ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      common      |   18  |   0   |   0   |   0   ||   18  |   0   |
	---------------------------------------------------------------------

ivy-retrieve-common:
[ivy:retrieve] :: retrieving :: org.apache.hadoop#dynamic-priority [sync]
[ivy:retrieve] 	confs: [common]
[ivy:retrieve] 	0 artifacts copied, 18 already retrieved (0kB/5ms)
No ivy:settings found for the default reference 'ivy.instance'.  A default instance will be used
DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

compile:
     [echo] contrib: dynamic-priority

compile-examples:

compile-test:
     [echo] contrib: dynamic-priority
    [javac] Compiling 4 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/dynamic-priority/test 
    [javac] Note: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/dynamic-scheduler/src/test/org/apache/hadoop/mapred/BaseSchedulerTest.java  uses or overrides a deprecated API.
    [javac] Note: Recompile with -Xlint:deprecation for details.

test:
     [echo] contrib: dynamic-priority
   [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/dynamic-priority/test/logs 
    [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/dynamic-priority/test/logs 
    [junit] 09/06/11 11:33:33 WARN conf.Configuration: DEPRECATED: hadoop-site.xml found in the classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml, mapred-site.xml and hdfs-site.xml to override properties of core-default.xml, mapred-default.xml and hdfs-default.xml respectively
    [junit] Running org.apache.hadoop.mapred.TestDynamicScheduler
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.177 sec
    [junit] 09/06/11 11:33:34 WARN conf.Configuration: DEPRECATED: hadoop-site.xml found in the classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml, mapred-site.xml and hdfs-site.xml to override properties of core-default.xml, mapred-default.xml and hdfs-default.xml respectively
    [junit] Running org.apache.hadoop.mapred.TestPriorityScheduler
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.161 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1047: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1028: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :61: Tests failed!

Total time: 281 minutes 46 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Build failed in Hudson: Hadoop-trunk #861

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/861/changes

Changes:

[sharad] HADOOP-5694. Change org.apache.hadoop.examples.dancing to use new mapreduce api. Contributed by Amareshwari Sriramadasu.

[szetszwo] HADOOP-5963. Remove an unnecessary exception catch in NNBench.  Contributed by Boris Shkolnik

------------------------------------------
[...truncated 439840 lines...]
    [junit] Generating rack names for tasktrackers
    [junit] Generating host names for tasktrackers
    [junit] 2009-06-09 18:46:24,973 INFO  mapred.JobTracker (JobTracker.java:<init>(1558)) - Starting jobtracker with owner as hudson and supergroup as supergroup
    [junit] 2009-06-09 18:46:24,974 INFO  mapred.JobTracker (JobTracker.java:initializeTaskMemoryRelatedConfig(3855)) - Scheduler configured with (memSizeForMapSlotOnJT, memSizeForReduceSlotOnJT, limitMaxMemForMapTasks, limitMaxMemForReduceTasks) (-1, -1, -1, -1)
    [junit] 2009-06-09 18:46:24,974 INFO  util.HostsFileReader (HostsFileReader.java:refresh(76)) - Refreshing hosts (include/exclude) list
    [junit] 2009-06-09 18:46:25,025 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=JobTracker, port=37582
    [junit] 2009-06-09 18:46:25,039 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-09 18:46:25,039 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 48005 webServer.getConnectors()[0].getLocalPort() returned 48005
    [junit] 2009-06-09 18:46:25,040 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 48005
    [junit] 2009-06-09 18:46:25,040 INFO  mortbay.log (?:invoke0(?)) - jetty-6.1.14
    [junit] 2009-06-09 18:46:25,123 INFO  mortbay.log (?:invoke0(?)) - Started SelectChannelConnector@localhost:48005
    [junit] 2009-06-09 18:46:25,127 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
    [junit] 2009-06-09 18:46:25,128 INFO  mapred.JobTracker (JobTracker.java:<init>(1671)) - JobTracker up at: 37582
    [junit] 2009-06-09 18:46:25,128 INFO  mapred.JobTracker (JobTracker.java:<init>(1675)) - JobTracker webserver: 48005
    [junit] 2009-06-09 18:46:25,139 INFO  mapred.JobTracker (JobTracker.java:<init>(1713)) - Cleaning up the system directory
    [junit] 2009-06-09 18:46:25,386 INFO  mapred.JobTracker (JobTracker.java:refreshHosts(3688)) - Refreshing hosts information
    [junit] 2009-06-09 18:46:25,410 INFO  util.HostsFileReader (HostsFileReader.java:setIncludesFile(100)) - Setting the includes file to 
    [junit] 2009-06-09 18:46:25,410 INFO  util.HostsFileReader (HostsFileReader.java:setExcludesFile(105)) - Setting the excludes file to hosts.exclude
    [junit] 2009-06-09 18:46:25,410 INFO  util.HostsFileReader (HostsFileReader.java:refresh(76)) - Refreshing hosts (include/exclude) list
    [junit] 2009-06-09 18:46:25,411 INFO  mapred.JobTracker (JobTracker.java:decommissionNodes(3710)) - Decommissioning 0 nodes
    [junit] 2009-06-09 18:46:25,411 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-06-09 18:46:25,412 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 37582: starting
    [junit] 2009-06-09 18:46:25,413 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 37582: starting
    [junit] 2009-06-09 18:46:25,412 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 37582: starting
    [junit] 2009-06-09 18:46:25,411 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 37582: starting
    [junit] 2009-06-09 18:46:25,458 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 9 on 37582: starting
    [junit] 2009-06-09 18:46:25,458 INFO  mapred.JobTracker (JobTracker.java:offerService(1894)) - Starting RUNNING
    [junit] 2009-06-09 18:46:25,457 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 7 on 37582: starting
    [junit] 2009-06-09 18:46:25,457 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 6 on 37582: starting
    [junit] 2009-06-09 18:46:25,456 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 5 on 37582: starting
    [junit] 2009-06-09 18:46:25,422 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 4 on 37582: starting
    [junit] 2009-06-09 18:46:25,422 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 37582: starting
    [junit] 2009-06-09 18:46:25,459 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 8 on 37582: starting
    [junit] 2009-06-09 18:46:25,923 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-09 18:46:30,939 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-09 18:46:30,940 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 34095 webServer.getConnectors()[0].getLocalPort() returned 34095
    [junit] 2009-06-09 18:46:30,940 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 34095
    [junit] 2009-06-09 18:46:30,940 INFO  mortbay.log (?:invoke0(?)) - jetty-6.1.14
    [junit] 2009-06-09 18:46:31,003 INFO  mortbay.log (?:invoke0(?)) - Started SelectChannelConnector@0.0.0.0:34095
    [junit] 2009-06-09 18:46:31,005 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=TaskTracker, sessionId= - already initialized
    [junit] 2009-06-09 18:46:31,008 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=TaskTracker, port=49599
    [junit] 2009-06-09 18:46:31,009 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-06-09 18:46:31,009 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 49599: starting
    [junit] 2009-06-09 18:46:31,010 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 49599: starting
    [junit] 2009-06-09 18:46:31,010 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 49599: starting
    [junit] 2009-06-09 18:46:31,010 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 49599: starting
    [junit] 2009-06-09 18:46:31,009 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 49599: starting
    [junit] 2009-06-09 18:46:31,070 INFO  util.ProcessTree (ProcessTree.java:isSetsidSupported(51)) - setsid exited with exit code 0
    [junit] 2009-06-09 18:46:31,073 INFO  mapred.IndexCache (IndexCache.java:<init>(46)) - IndexCache created with max memory = 10485760
    [junit] 2009-06-09 18:46:31,107 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/host0.foo.com
    [junit] 2009-06-09 18:46:31,109 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-09 18:46:31,109 INFO  mapred.JobTracker (JobTracker.java:addNewTracker(2426)) - Adding tracker tracker_host0.foo.com:localhost/127.0.0.1:49599 to host host0.foo.com
    [junit] 2009-06-09 18:46:36,127 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-09 18:46:36,128 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 44569 webServer.getConnectors()[0].getLocalPort() returned 44569
    [junit] 2009-06-09 18:46:36,128 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 44569
    [junit] 2009-06-09 18:46:36,128 INFO  mortbay.log (?:invoke0(?)) - jetty-6.1.14
    [junit] 2009-06-09 18:46:36,229 INFO  mortbay.log (?:invoke0(?)) - Started SelectChannelConnector@0.0.0.0:44569
    [junit] 2009-06-09 18:46:36,231 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=TaskTracker, sessionId= - already initialized
    [junit] 2009-06-09 18:46:36,232 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=TaskTracker, port=60626
    [junit] 2009-06-09 18:46:36,233 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-06-09 18:46:36,233 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 60626: starting
    [junit] 2009-06-09 18:46:36,233 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 60626: starting
    [junit] 2009-06-09 18:46:36,235 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 60626: starting
    [junit] 2009-06-09 18:46:36,235 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 60626: starting
    [junit] 2009-06-09 18:46:36,233 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 60626: starting
    [junit] 2009-06-09 18:46:36,250 INFO  mapred.IndexCache (IndexCache.java:<init>(46)) - IndexCache created with max memory = 10485760
    [junit] 2009-06-09 18:46:36,362 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/host1.foo.com
    [junit] 2009-06-09 18:46:36,363 INFO  mapred.JobTracker (JobTracker.java:addNewTracker(2426)) - Adding tracker tracker_host1.foo.com:localhost/127.0.0.1:60626 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-09 18:46 /test/testDistCh/f1
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-09 18:46 /test/testDistCh/f2
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-09 18:46 /test/testDistCh/f3
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub0
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub0/f4
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub1
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub1/f5
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub1/f6
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub2
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub2/f7
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub2/f8
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub3
    [junit] -rw-r--r--   2 hudson supergroup         44 2009-06-09 18:46 /test/testDistCh/sub3/f10
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub3/f9
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub4
    [junit] 
    [junit] args=[/test/testDistCh/sub2:::030]
    [junit] newstatus=[hudson:supergroup:rwxr-xr-x,
    [junit]    hudson:supergroup:rwxr-xr-x,
    [junit]    hudson:supergroup:----wx---,
    [junit]    hudson:supergroup:rwxr-xr-x,
    [junit]    hudson:supergroup:rwxr-xr-x]
    [junit] 2009-06-09 18:46:37,111 INFO  tools.DistTool (DistCh.java:run(376)) - ops=[/test/testDistCh/sub2:null:null:----wx---]
    [junit] 2009-06-09 18:46:37,112 INFO  tools.DistTool (DistCh.java:run(377)) - isIgnoreFailures=false
    [junit] 2009-06-09 18:46:37,156 INFO  tools.DistTool (DistCh.java:setup(427)) - distch.job.dir=hdfs://localhost:43516/user/hudson/build/test/mapred/system/distch_gehcbr
    [junit] 2009-06-09 18:46:37,159 INFO  tools.DistTool (DistCh.java:setup(433)) - log=hdfs://localhost:43516/user/hudson/build/test/mapred/system/distch_gehcbr/_logs
    [junit] 2009-06-09 18:46:37,419 INFO  tools.DistTool (DistCh.java:setup(476)) - distch.op.count=3
    [junit] 2009-06-09 18:46:37,425 WARN  mapred.JobClient (JobClient.java:configureCommandLineOptions(551)) - Use GenericOptionsParser for parsing the arguments. Applications should implement Tool for the same.
    [junit] 2009-06-09 18:46:37,471 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-09 18:46:37,483 INFO  tools.DistTool (DistCh.java:getSplits(261)) - numSplits=1, splits.size()=1
    [junit] 2009-06-09 18:46:37,689 WARN  conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/jobTracker/job_200906091846_0001.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] 2009-06-09 18:46:37,700 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1287)) - Running job: job_200906091846_0001
    [junit] 2009-06-09 18:46:37,700 INFO  mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(80)) - Initializing job_200906091846_0001
    [junit] 2009-06-09 18:46:37,701 INFO  mapred.JobInProgress (JobInProgress.java:initTasks(395)) - Initializing job_200906091846_0001
    [junit] 2009-06-09 18:46:37,868 INFO  mapred.JobInProgress (JobInProgress.java:initTasks(439)) - Input size for job job_200906091846_0001 = 368. Number of splits = 1
    [junit] 2009-06-09 18:46:38,706 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1300)) -  map 0% reduce 0%
    [junit] 2009-06-09 18:46:39,389 INFO  mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906091846_0001_m_000002_0' to tip task_200906091846_0001_m_000002, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:60626'
    [junit] 2009-06-09 18:46:39,468 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_200906091846_0001/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] 2009-06-09 18:46:39,533 INFO  mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906091846_0001_m_864244286
    [junit] 2009-06-09 18:46:39,534 INFO  mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906091846_0001_m_864244286 spawned.
    [junit] 2009-06-09 18:46:40,649 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-09 18:46:40,650 INFO  util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 3810 with SIGTERM. Exit code 1
    [junit] 2009-06-09 18:46:42,398 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906091846_0001_m_000002_0' has completed task_200906091846_0001_m_000002 successfully.
    [junit] 2009-06-09 18:46:42,403 INFO  mapred.JobInProgress (JobInProgress.java:findNewMapTask(1815)) - Choosing a non-local task task_200906091846_0001_m_000000
    [junit] 2009-06-09 18:46:42,404 INFO  mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906091846_0001_m_000000_0' to tip task_200906091846_0001_m_000000, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:60626'
    [junit] 2009-06-09 18:46:42,409 INFO  mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906091846_0001_m_000002_0 done; removing files.
    [junit] 2009-06-09 18:46:42,410 INFO  mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906091846_0001_m_000002_0 not found in cache
    [junit] 2009-06-09 18:46:42,458 INFO  mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906091846_0001_m_789000441
    [junit] 2009-06-09 18:46:42,460 INFO  mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906091846_0001_m_789000441 spawned.
    [junit] 2009-06-09 18:46:42,720 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906091846_0001_m_000002_0, Status : SUCCEEDED
    [junit] attempt_200906091846_0001_m_000002_0: 2009-06-09 18:46:40,239 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_200906091846_0001/attempt_200906091846_0001_m_000002_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906091846_0001_m_000002_0: 2009-06-09 18:46:40,256 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_200906091846_0001_m_000002_0: 2009-06-09 18:46:40,366 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_200906091846_0001/attempt_200906091846_0001_m_000002_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906091846_0001_m_000002_0: 2009-06-09 18:46:40,431 INFO  mapred.Task (Task.java:done(620)) - Task:attempt_200906091846_0001_m_000002_0 is done. And is in the process of commiting
    [junit] attempt_200906091846_0001_m_000002_0: 2009-06-09 18:46:40,447 INFO  mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906091846_0001_m_000002_0' done.
    [junit] 2009-06-09 18:46:45,661 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-09 18:46:45,662 INFO  util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(94)) - Killing process group3810 with SIGKILL. Exit code 1
    [junit] 2009-06-09 18:46:45,662 INFO  mapred.DefaultTaskController (DefaultTaskController.java:killTaskJVM(87)) - Process exited with exit code:0
    [junit] 2009-06-09 18:46:45,662 INFO  mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200906091846_0001_m_864244286 exited. Number of tasks it ran: 1
    [junit] 2009-06-09 18:46:45,795 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-09 18:46:45,795 INFO  util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 3859 with SIGTERM. Exit code 1
    [junit] 2009-06-09 18:46:48,415 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906091846_0001_m_000000_0' has completed task_200906091846_0001_m_000000 successfully.
    [junit] 2009-06-09 18:46:48,419 INFO  mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906091846_0001_m_000001_0' to tip task_200906091846_0001_m_000001, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:60626'
    [junit] 2009-06-09 18:46:48,447 INFO  mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906091846_0001_m_-1309676680
    [junit] 2009-06-09 18:46:48,448 INFO  mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906091846_0001_m_-1309676680 spawned.
    [junit] 2009-06-09 18:46:48,795 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906091846_0001_m_000000_0, Status : SUCCEEDED
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:43,166 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_200906091846_0001/attempt_200906091846_0001_m_000000_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:43,183 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:43,277 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_200906091846_0001/attempt_200906091846_0001_m_000000_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:43,369 INFO  mapred.MapTask (MapTask.java:runOldMapper(352)) - numReduceTasks: 0
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:43,499 INFO  mapred.Task (Task.java:done(620)) - Task:attempt_200906091846_0001_m_000000_0 is done. And is in the process of commiting
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:45,508 INFO  mapred.Task (Task.java:commit(720)) - Task attempt_200906091846_0001_m_000000_0 is allowed to commit now
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:45,593 INFO  mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(92)) - Saved output of task 'attempt_200906091846_0001_m_000000_0' to hdfs://localhost:43516/user/hudson/build/test/mapred/system/distch_gehcbr/_logs
    [junit] attempt_200906091846_0001_m_000000_0: 2009-06-09 18:46:45,600 INFO  mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906091846_0001_m_000000_0' done.
    [junit] 2009-06-09 18:46:49,578 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-09 18:46:49,578 INFO  util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 3914 with SIGTERM. Exit code 1
    [junit] 2009-06-09 18:46:49,805 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1300)) -  map 100% reduce 0%
    [junit] 2009-06-09 18:46:50,813 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-09 18:46:50,813 INFO  util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(94)) - Killing process group3859 with SIGKILL. Exit code 1
    [junit] 2009-06-09 18:46:50,813 INFO  mapred.DefaultTaskController (DefaultTaskController.java:killTaskJVM(87)) - Process exited with exit code:0
    [junit] 2009-06-09 18:46:50,813 INFO  mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200906091846_0001_m_789000441 exited. Number of tasks it ran: 1
    [junit] 2009-06-09 18:46:51,424 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906091846_0001_m_000001_0' has completed task_200906091846_0001_m_000001 successfully.
    [junit] 2009-06-09 18:46:51,425 INFO  mapred.JobInProgress (JobInProgress.java:jobComplete(2146)) - Job job_200906091846_0001 has completed successfully.
    [junit] 2009-06-09 18:46:51,463 INFO  mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906091846_0001_m_000000_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:60626'
    [junit] 2009-06-09 18:46:51,463 INFO  mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906091846_0001_m_000001_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:60626'
    [junit] 2009-06-09 18:46:51,464 INFO  mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906091846_0001_m_000002_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:60626'
    [junit] 2009-06-09 18:46:51,464 INFO  mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906091846_0001_m_000001_0 done; removing files.
    [junit] 2009-06-09 18:46:51,465 INFO  mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906091846_0001_m_000001_0 not found in cache
    [junit] 2009-06-09 18:46:51,466 INFO  mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906091846_0001_m_000000_0 done; removing files.
    [junit] 2009-06-09 18:46:51,466 INFO  mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906091846_0001_m_000000_0 not found in cache
    [junit] 2009-06-09 18:46:51,812 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906091846_0001_m_000001_0, Status : SUCCEEDED
    [junit] attempt_200906091846_0001_m_000001_0: 2009-06-09 18:46:49,150 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_200906091846_0001/attempt_200906091846_0001_m_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906091846_0001_m_000001_0: 2009-06-09 18:46:49,167 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_200906091846_0001_m_000001_0: 2009-06-09 18:46:49,264 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_200906091846_0001/attempt_200906091846_0001_m_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906091846_0001_m_000001_0: 2009-06-09 18:46:49,373 INFO  mapred.Task (Task.java:done(620)) - Task:attempt_200906091846_0001_m_000001_0 is done. And is in the process of commiting
    [junit] attempt_200906091846_0001_m_000001_0: 2009-06-09 18:46:49,380 INFO  mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906091846_0001_m_000001_0' done.
    [junit] 2009-06-09 18:46:51,816 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1355)) - Job complete: job_200906091846_0001
    [junit] 2009-06-09 18:46:51,819 INFO  mapred.JobClient (Counters.java:log(534)) - Counters: 7
    [junit] 2009-06-09 18:46:51,819 INFO  mapred.JobClient (Counters.java:log(536)) -   Job Counters 
    [junit] 2009-06-09 18:46:51,820 INFO  mapred.JobClient (Counters.java:log(538)) -     Launched map tasks=1
    [junit] 2009-06-09 18:46:51,820 INFO  mapred.JobClient (Counters.java:log(536)) -   FileInputFormatCounters
    [junit] 2009-06-09 18:46:51,820 INFO  mapred.JobClient (Counters.java:log(538)) -     BYTES_READ=271
    [junit] 2009-06-09 18:46:51,821 INFO  mapred.JobClient (Counters.java:log(536)) -   org.apache.hadoop.tools.DistCh$Counter
    [junit] 2009-06-09 18:46:51,821 INFO  mapred.JobClient (Counters.java:log(538)) -     SUCCEED=3
    [junit] 2009-06-09 18:46:51,821 INFO  mapred.JobClient (Counters.java:log(536)) -   FileSystemCounters
    [junit] 2009-06-09 18:46:51,822 INFO  mapred.JobClient (Counters.java:log(538)) -     HDFS_BYTES_READ=368
    [junit] 2009-06-09 18:46:51,822 INFO  mapred.JobClient (Counters.java:log(536)) -   Map-Reduce Framework
    [junit] 2009-06-09 18:46:51,822 INFO  mapred.JobClient (Counters.java:log(538)) -     Map input records=3
    [junit] 2009-06-09 18:46:51,823 INFO  mapred.JobClient (Counters.java:log(538)) -     Spilled Records=0
    [junit] 2009-06-09 18:46:51,823 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-09 18:46 /test/testDistCh/f1
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-09 18:46 /test/testDistCh/f2
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-09 18:46 /test/testDistCh/f3
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub0
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub0/f4
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub1
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub1/f5
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub1/f6
    [junit] d----wx---   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub2
    [junit] -----w----   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub2/f7
    [junit] -----w----   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub2/f8
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub3
    [junit] -rw-r--r--   2 hudson supergroup         44 2009-06-09 18:46 /test/testDistCh/sub3/f10
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-09 18:46 /test/testDistCh/sub3/f9
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-09 18:46 /test/testDistCh/sub4
    [junit] 
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 1
    [junit] 2009-06-09 18:46:51,866 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 34117
    [junit] 2009-06-09 18:46:51,866 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 34117: exiting
    [junit] 2009-06-09 18:46:51,867 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 34117: exiting
    [junit] 2009-06-09 18:46:51,867 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 34117: exiting
    [junit] 2009-06-09 18:46:51,868 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-06-09 18:46:51,868 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 34117
    [junit] 2009-06-09 18:46:51,869 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-09 18:46:51,870 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 34117
    [junit] Shutting down DataNode 0
    [junit] 2009-06-09 18:46:51,908 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 44291
    [junit] 2009-06-09 18:46:51,908 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 44291: exiting
    [junit] 2009-06-09 18:46:51,909 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 44291
    [junit] 2009-06-09 18:46:51,909 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-06-09 18:46:51,909 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 44291: exiting
    [junit] 2009-06-09 18:46:51,909 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 44291: exiting
    [junit] 2009-06-09 18:46:51,910 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-09 18:46:51,910 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 44291
    [junit] 2009-06-09 18:46:52,063 WARN  namenode.DecommissionManager (DecommissionManager.java:run(67)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
    [junit] 2009-06-09 18:46:52,075 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 43516
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 4 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 9 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 43516
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 8 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 7 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 3 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 5 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 43516: exiting
    [junit] 2009-06-09 18:46:52,076 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 6 on 43516: exiting
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 58.948 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1043: Tests failed!

Total time: 217 minutes 1 second
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Build failed in Hudson: Hadoop-trunk #860

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/860/

------------------------------------------
[...truncated 411016 lines...]
    [junit] 09/06/08 18:18:59 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:18:59 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:18:59 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:18:59 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:18:59 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:18:59 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:00 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:00 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:01 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:01 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:01 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:01 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:01 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:01 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:02 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:02 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:02 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:02 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:02 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:02 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:03 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:03 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:04 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:04 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:04 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:04 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:04 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:05 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:05 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:05 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:05 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:05 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:05 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:06 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:06 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:07 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:08 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:09 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:09 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:09 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:10 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:10 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:10 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:10 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:10 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:10 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:11 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:11 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:11 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:11 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:11 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:11 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:12 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:12 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:13 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:13 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:13 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:13 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:13 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:14 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:14 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:14 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:14 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:14 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:14 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:15 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:15 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:16 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:16 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:16 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:16 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:16 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:16 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:17 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:17 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:17 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:17 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:17 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:17 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:18 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:18 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:19 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:19 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:19 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:19 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:19 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:20 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:20 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:20 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:20 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:20 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:20 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:21 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:21 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:22 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:23 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:24 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:24 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:24 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:25 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:25 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:25 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:25 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:25 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:25 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:26 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:26 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:26 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:26 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:26 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:26 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:27 INFO mapred.TaskTracker: attempt_200906081809_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:27 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:28 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:28 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:28 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:28 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:28 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:29 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:29 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:29 INFO mapred.TaskTracker: attempt_200906081809_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:29 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000001_0 0.0% map > map
    [junit] 09/06/08 18:19:29 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:29 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000002_0 0.0% map > map
    [junit] 09/06/08 18:19:30 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:30 INFO mapred.TaskTracker: attempt_200906081809_0005_m_000003_0 0.0% map > map
    [junit] 09/06/08 18:19:31 INFO mapred.TaskTracker: attempt_200906081809_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/08 18:19:31 INFO mapred.TaskTracker: attempt_200906081809_0003_m_000000_0 0.0% map > map
    [junit] 09/06/08 18:19:31 INFO mapred.TaskTracker: attempt_200906081809_0004_m_000000_0 0.0% map > map
    [junit] Running org.apache.hadoop.mapred.TestQueueCapacities
    [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec
    [junit] Test org.apache.hadoop.mapred.TestQueueCapacities FAILED (timeout)

checkfailure:

check-contrib:

init:
     [echo] contrib: mrunit

init-contrib:

ivy-download:
      [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar
      [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar 
      [get] Not modified - so not downloaded

ivy-probe-antlib:

ivy-init-antlib:

ivy-init:
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

ivy-resolve-common:
[ivy:resolve] :: resolving dependencies :: org.apache.hadoop#mrunit;working@vesta.apache.org
[ivy:resolve] 	confs: [common]
[ivy:resolve] 	found commons-logging#commons-logging;1.0.4 in maven2
[ivy:resolve] 	found log4j#log4j;1.2.15 in maven2
[ivy:resolve] 	found junit#junit;4.5 in maven2
[ivy:resolve] :: resolution report :: resolve 18ms :: artifacts dl 1ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      common      |   3   |   0   |   0   |   0   ||   3   |   0   |
	---------------------------------------------------------------------

ivy-retrieve-common:
[ivy:retrieve] :: retrieving :: org.apache.hadoop#mrunit [sync]
[ivy:retrieve] 	confs: [common]
[ivy:retrieve] 	0 artifacts copied, 3 already retrieved (0kB/1ms)
No ivy:settings found for the default reference 'ivy.instance'.  A default instance will be used
DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

compile:
     [echo] contrib: mrunit

compile-examples:

compile-test:
     [echo] contrib: mrunit
    [javac] Compiling 9 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test 
    [javac] Note: Some input files use or override a deprecated API.
    [javac] Note: Recompile with -Xlint:deprecation for details.

test:
     [echo] contrib: mrunit
   [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [junit] Running org.apache.hadoop.mrunit.TestExample
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.2 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapDriver
    [junit] 09/06/08 18:19:33 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/08 18:19:33 ERROR mrunit.TestDriver: Received unexpected output (null, null)
    [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.211 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapReduceDriver
    [junit] 09/06/08 18:19:33 ERROR mrunit.TestDriver: Missing expected output (foo, 52) at position 0
    [junit] Tests run: 8, Failures: 0, Errors: 0, Time elapsed: 0.213 sec
    [junit] Running org.apache.hadoop.mrunit.TestReduceDriver
    [junit] 09/06/08 18:19:34 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/08 18:19:34 ERROR mrunit.TestDriver: Received unexpected output (null, 0)
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.212 sec
    [junit] Running org.apache.hadoop.mrunit.TestTestDriver
    [junit] Tests run: 19, Failures: 0, Errors: 0, Time elapsed: 0.196 sec
    [junit] Running org.apache.hadoop.mrunit.mock.TestMockReporter
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.107 sec
    [junit] Running org.apache.hadoop.mrunit.types.TestPair
    [junit] Tests run: 20, Failures: 0, Errors: 0, Time elapsed: 0.069 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1047: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1028: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :60: Tests failed!

Total time: 243 minutes 9 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Build failed in Hudson: Hadoop-trunk #859

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/859/

------------------------------------------
[...truncated 493650 lines...]
    [junit] 09/06/07 16:39:10 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:10 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:10 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:10 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:11 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:11 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:12 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:12 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:12 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:13 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:13 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:13 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:13 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:14 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:14 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:15 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:15 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:15 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:16 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:16 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:16 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:16 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:17 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:17 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:18 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:18 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:18 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:19 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:19 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:19 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:19 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:20 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:20 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:21 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:21 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:21 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:22 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:22 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:22 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:22 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:23 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:23 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:24 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:24 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:24 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:25 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:25 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:25 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:25 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:26 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:26 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:27 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:27 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:27 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:28 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:28 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:28 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:28 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:29 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:29 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:30 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:30 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:30 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:31 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:31 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:31 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:31 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:32 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:32 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:33 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:33 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:33 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:34 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:34 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:34 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:34 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:35 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:35 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:36 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:36 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:36 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:37 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:37 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:37 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:37 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000013_0 0.0% map > map
    [junit] 09/06/07 16:39:38 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000000_0 0.0% map > map
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000002_0 0.0% map > map
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000012_0 0.0% map > map
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000014_0 0.0% map > map
    [junit] 09/06/07 16:39:38 INFO mapred.TaskTracker: attempt_200906071626_0002_m_000001_0 0.0% map > map
    [junit] 09/06/07 16:39:39 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:39 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000006_0 0.0% map > map
    [junit] 09/06/07 16:39:39 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000010_0 0.0% map > map
    [junit] 09/06/07 16:39:40 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000011_0 0.0% map > map
    [junit] 09/06/07 16:39:40 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000007_0 0.0% map > map
    [junit] 09/06/07 16:39:40 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000015_0 0.0% map > map
    [junit] 09/06/07 16:39:40 INFO mapred.MiniMRCluster: Waiting for task tracker tracker_host0.foo.com:localhost/127.0.0.1:37159 to be idle.
    [junit] 09/06/07 16:39:41 INFO mapred.TaskTracker: attempt_200906071626_0001_m_000008_0 0.0% map > map
    [junit] Running org.apache.hadoop.mapred.TestQueueCapacities
    [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec
    [junit] Test org.apache.hadoop.mapred.TestQueueCapacities FAILED (timeout)

checkfailure:

check-contrib:

init:
     [echo] contrib: mrunit

init-contrib:

ivy-download:
      [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar
      [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar 
      [get] Not modified - so not downloaded

ivy-probe-antlib:

ivy-init-antlib:

ivy-init:
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

ivy-resolve-common:
[ivy:resolve] :: resolving dependencies :: org.apache.hadoop#mrunit;working@vesta.apache.org
[ivy:resolve] 	confs: [common]
[ivy:resolve] 	found commons-logging#commons-logging;1.0.4 in maven2
[ivy:resolve] 	found log4j#log4j;1.2.15 in maven2
[ivy:resolve] 	found junit#junit;4.5 in maven2
[ivy:resolve] :: resolution report :: resolve 17ms :: artifacts dl 1ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      common      |   3   |   0   |   0   |   0   ||   3   |   0   |
	---------------------------------------------------------------------

ivy-retrieve-common:
[ivy:retrieve] :: retrieving :: org.apache.hadoop#mrunit [sync]
[ivy:retrieve] 	confs: [common]
[ivy:retrieve] 	0 artifacts copied, 3 already retrieved (0kB/1ms)
No ivy:settings found for the default reference 'ivy.instance'.  A default instance will be used
DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

compile:
     [echo] contrib: mrunit

compile-examples:

compile-test:
     [echo] contrib: mrunit
    [javac] Compiling 9 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test 
    [javac] Note: Some input files use or override a deprecated API.
    [javac] Note: Recompile with -Xlint:deprecation for details.

test:
     [echo] contrib: mrunit
   [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [junit] Running org.apache.hadoop.mrunit.TestExample
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.202 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapDriver
    [junit] 09/06/07 16:39:43 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/07 16:39:43 ERROR mrunit.TestDriver: Received unexpected output (null, null)
    [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.203 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapReduceDriver
    [junit] 09/06/07 16:39:43 ERROR mrunit.TestDriver: Missing expected output (foo, 52) at position 0
    [junit] Tests run: 8, Failures: 0, Errors: 0, Time elapsed: 0.218 sec
    [junit] Running org.apache.hadoop.mrunit.TestReduceDriver
    [junit] 09/06/07 16:39:44 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/07 16:39:44 ERROR mrunit.TestDriver: Received unexpected output (null, 0)
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.203 sec
    [junit] Running org.apache.hadoop.mrunit.TestTestDriver
    [junit] Tests run: 19, Failures: 0, Errors: 0, Time elapsed: 0.201 sec
    [junit] Running org.apache.hadoop.mrunit.mock.TestMockReporter
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.104 sec
    [junit] Running org.apache.hadoop.mrunit.types.TestPair
    [junit] Tests run: 20, Failures: 0, Errors: 0, Time elapsed: 0.067 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1047: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1028: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :60: Tests failed!

Total time: 252 minutes 31 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Build failed in Hudson: Hadoop-trunk #858

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/858/changes

Changes:

[rangadi] HADOOP-5961. DataNode process understand generic hadoop command line
options (like -Ddfs.property=value). (Raghu Angadi)

------------------------------------------
[...truncated 417119 lines...]
    [junit] 09/06/06 19:21:33 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:33 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:33 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:34 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:34 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:34 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:35 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:35 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:35 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:35 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:35 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:36 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:37 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:37 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:37 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:37 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:38 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:38 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:38 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:38 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:38 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:38 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:39 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:39 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:39 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:39 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:39 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:39 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:40 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:40 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:40 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:41 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:41 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:41 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:41 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:42 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:42 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:42 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:42 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:42 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:42 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:43 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:43 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:43 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:44 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:44 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:44 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:44 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:44 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:45 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:45 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:45 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:45 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:45 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:45 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:46 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:46 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:46 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:47 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:47 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:47 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:47 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:48 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:48 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:48 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:48 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:48 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:48 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:49 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:49 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:49 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:50 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:50 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:50 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:50 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:50 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:51 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:52 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:52 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:52 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:52 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:53 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:53 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:53 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:53 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:53 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:53 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:54 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:54 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:54 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:54 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:54 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:54 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:55 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:55 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:55 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:56 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:56 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:56 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:56 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:21:57 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:57 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:57 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:57 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:57 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:57 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:58 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:58 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:21:58 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:59 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:59 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:21:59 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:21:59 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:21:59 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:22:00 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:22:00 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:22:00 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:00 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:22:00 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:00 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:22:01 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000002_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:01 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:22:01 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:22:02 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:22:02 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000003_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:02 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:22:02 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] 09/06/06 19:22:03 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:22:03 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:03 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:22:03 INFO mapred.TaskTracker: attempt_200906061910_0003_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:22:03 INFO mapred.TaskTracker: attempt_200906061910_0004_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:03 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:22:04 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:04 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000000_0 0.0% map > map
    [junit] 09/06/06 19:22:04 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:22:05 INFO mapred.TaskTracker: attempt_200906061910_0003_r_000001_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:05 INFO mapred.TaskTracker: attempt_200906061910_0005_r_000000_0 0.0% reduce > copy > 
    [junit] 09/06/06 19:22:05 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000001_0 0.0% map > map
    [junit] 09/06/06 19:22:05 INFO mapred.TaskTracker: attempt_200906061910_0004_m_000002_0 0.0% map > map
    [junit] 09/06/06 19:22:05 INFO mapred.TaskTracker: attempt_200906061910_0005_m_000003_0 0.0% map > map
    [junit] Running org.apache.hadoop.mapred.TestQueueCapacities
    [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec
    [junit] Test org.apache.hadoop.mapred.TestQueueCapacities FAILED (timeout)

checkfailure:

check-contrib:

init:
     [echo] contrib: mrunit

init-contrib:

ivy-download:
      [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar
      [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar 
      [get] Not modified - so not downloaded

ivy-probe-antlib:

ivy-init-antlib:

ivy-init:
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

ivy-resolve-common:
[ivy:resolve] :: resolving dependencies :: org.apache.hadoop#mrunit;working@vesta.apache.org
[ivy:resolve] 	confs: [common]
[ivy:resolve] 	found commons-logging#commons-logging;1.0.4 in maven2
[ivy:resolve] 	found log4j#log4j;1.2.15 in maven2
[ivy:resolve] 	found junit#junit;4.5 in maven2
[ivy:resolve] :: resolution report :: resolve 21ms :: artifacts dl 1ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      common      |   3   |   0   |   0   |   0   ||   3   |   0   |
	---------------------------------------------------------------------

ivy-retrieve-common:
[ivy:retrieve] :: retrieving :: org.apache.hadoop#mrunit [sync]
[ivy:retrieve] 	confs: [common]
[ivy:retrieve] 	0 artifacts copied, 3 already retrieved (0kB/2ms)
No ivy:settings found for the default reference 'ivy.instance'.  A default instance will be used
DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead
:: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml 

compile:
     [echo] contrib: mrunit

compile-examples:

compile-test:
     [echo] contrib: mrunit
    [javac] Compiling 9 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test 
    [javac] Note: Some input files use or override a deprecated API.
    [javac] Note: Recompile with -Xlint:deprecation for details.

test:
     [echo] contrib: mrunit
   [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs 
    [junit] Running org.apache.hadoop.mrunit.TestExample
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.2 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapDriver
    [junit] 09/06/06 19:22:07 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/06 19:22:07 ERROR mrunit.TestDriver: Received unexpected output (null, null)
    [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.206 sec
    [junit] Running org.apache.hadoop.mrunit.TestMapReduceDriver
    [junit] 09/06/06 19:22:08 ERROR mrunit.TestDriver: Missing expected output (foo, 52) at position 0
    [junit] Tests run: 8, Failures: 0, Errors: 0, Time elapsed: 0.216 sec
    [junit] Running org.apache.hadoop.mrunit.TestReduceDriver
    [junit] 09/06/06 19:22:08 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs.
    [junit] 09/06/06 19:22:08 ERROR mrunit.TestDriver: Received unexpected output (null, 0)
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.204 sec
    [junit] Running org.apache.hadoop.mrunit.TestTestDriver
    [junit] Tests run: 19, Failures: 0, Errors: 0, Time elapsed: 0.197 sec
    [junit] Running org.apache.hadoop.mrunit.mock.TestMockReporter
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.106 sec
    [junit] Running org.apache.hadoop.mrunit.types.TestPair
    [junit] Tests run: 20, Failures: 0, Errors: 0, Time elapsed: 0.069 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1047: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1028: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :60: Tests failed!

Total time: 245 minutes 39 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Build failed in Hudson: Hadoop-trunk #857

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/857/changes

Changes:

[gkesavan] HADOOP-5457. Fix to continue to run builds even if contrib test fails.

[yhemanth] HADOOP-5884. Fixes accounting in capacity scheduler so that high RAM jobs take more slots. Contributed by Vinod Kumar Vavilapalli.

[szetszwo] HADOOP-5859. Fix "wait() or sleep() with locks held" findbugs warnings in DFSClient.  Contributed by Kan Zhang

[sharad] HADOOP-2838. Add mapred.child.env to pass environment variables to tasktracker's child processes. Contributed by Amar Kamat.

------------------------------------------
[...truncated 436549 lines...]
    [junit] 2009-06-05 18:00:32,208 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 49203: starting
    [junit] 2009-06-05 18:00:32,208 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 49203: starting
    [junit] 2009-06-05 18:00:32,208 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 49203: starting
    [junit] 2009-06-05 18:00:32,210 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/127.0.0.1:38974
    [junit] Generating rack names for tasktrackers
    [junit] Generating host names for tasktrackers
    [junit] 2009-06-05 18:00:32,385 INFO  mapred.JobTracker (JobTracker.java:<init>(1558)) - Starting jobtracker with owner as hudson and supergroup as supergroup
    [junit] 2009-06-05 18:00:32,386 INFO  mapred.JobTracker (JobTracker.java:initializeTaskMemoryRelatedConfig(3855)) - Scheduler configured with (memSizeForMapSlotOnJT, memSizeForReduceSlotOnJT, limitMaxMemForMapTasks, limitMaxMemForReduceTasks) (-1, -1, -1, -1)
    [junit] 2009-06-05 18:00:32,386 INFO  util.HostsFileReader (HostsFileReader.java:refresh(76)) - Refreshing hosts (include/exclude) list
    [junit] 2009-06-05 18:00:32,437 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=JobTracker, port=48057
    [junit] 2009-06-05 18:00:32,450 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-05 18:00:32,450 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 41222 webServer.getConnectors()[0].getLocalPort() returned 41222
    [junit] 2009-06-05 18:00:32,450 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 41222
    [junit] 2009-06-05 18:00:32,450 INFO  mortbay.log (?:invoke0(?)) - jetty-6.1.14
    [junit] 2009-06-05 18:00:32,538 INFO  mortbay.log (?:invoke0(?)) - Started SelectChannelConnector@localhost:41222
    [junit] 2009-06-05 18:00:32,540 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
    [junit] 2009-06-05 18:00:32,540 INFO  mapred.JobTracker (JobTracker.java:<init>(1671)) - JobTracker up at: 48057
    [junit] 2009-06-05 18:00:32,541 INFO  mapred.JobTracker (JobTracker.java:<init>(1675)) - JobTracker webserver: 41222
    [junit] 2009-06-05 18:00:32,549 INFO  mapred.JobTracker (JobTracker.java:<init>(1713)) - Cleaning up the system directory
    [junit] 2009-06-05 18:00:32,766 INFO  mapred.JobTracker (JobTracker.java:refreshHosts(3688)) - Refreshing hosts information
    [junit] 2009-06-05 18:00:32,790 INFO  util.HostsFileReader (HostsFileReader.java:setIncludesFile(100)) - Setting the includes file to 
    [junit] 2009-06-05 18:00:32,790 INFO  util.HostsFileReader (HostsFileReader.java:setExcludesFile(105)) - Setting the excludes file to hosts.exclude
    [junit] 2009-06-05 18:00:32,790 INFO  util.HostsFileReader (HostsFileReader.java:refresh(76)) - Refreshing hosts (include/exclude) list
    [junit] 2009-06-05 18:00:32,790 INFO  mapred.JobTracker (JobTracker.java:decommissionNodes(3710)) - Decommissioning 0 nodes
    [junit] 2009-06-05 18:00:32,791 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-06-05 18:00:32,791 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 48057: starting
    [junit] 2009-06-05 18:00:32,791 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 48057: starting
    [junit] 2009-06-05 18:00:32,792 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 48057: starting
    [junit] 2009-06-05 18:00:32,791 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 48057: starting
    [junit] 2009-06-05 18:00:32,791 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 48057: starting
    [junit] 2009-06-05 18:00:32,792 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 5 on 48057: starting
    [junit] 2009-06-05 18:00:32,792 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 4 on 48057: starting
    [junit] 2009-06-05 18:00:32,793 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 7 on 48057: starting
    [junit] 2009-06-05 18:00:32,793 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 8 on 48057: starting
    [junit] 2009-06-05 18:00:32,792 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 6 on 48057: starting
    [junit] 2009-06-05 18:00:32,793 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 9 on 48057: starting
    [junit] 2009-06-05 18:00:32,793 INFO  mapred.JobTracker (JobTracker.java:offerService(1894)) - Starting RUNNING
    [junit] 2009-06-05 18:00:33,347 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-05 18:00:38,369 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-05 18:00:38,369 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 60169 webServer.getConnectors()[0].getLocalPort() returned 60169
    [junit] 2009-06-05 18:00:38,370 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 60169
    [junit] 2009-06-05 18:00:38,370 INFO  mortbay.log (?:invoke0(?)) - jetty-6.1.14
    [junit] 2009-06-05 18:00:38,479 INFO  mortbay.log (?:invoke0(?)) - Started SelectChannelConnector@0.0.0.0:60169
    [junit] 2009-06-05 18:00:38,482 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=TaskTracker, sessionId= - already initialized
    [junit] 2009-06-05 18:00:38,485 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=TaskTracker, port=42117
    [junit] 2009-06-05 18:00:38,485 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-06-05 18:00:38,486 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 42117: starting
    [junit] 2009-06-05 18:00:38,490 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 42117: starting
    [junit] 2009-06-05 18:00:38,486 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 42117: starting
    [junit] 2009-06-05 18:00:38,486 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 42117: starting
    [junit] 2009-06-05 18:00:38,486 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 42117: starting
    [junit] 2009-06-05 18:00:38,525 INFO  util.ProcessTree (ProcessTree.java:isSetsidSupported(51)) - setsid exited with exit code 0
    [junit] 2009-06-05 18:00:38,528 INFO  mapred.IndexCache (IndexCache.java:<init>(46)) - IndexCache created with max memory = 10485760
    [junit] 2009-06-05 18:00:38,564 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/host0.foo.com
    [junit] 2009-06-05 18:00:38,565 INFO  mapred.JobTracker (JobTracker.java:addNewTracker(2426)) - Adding tracker tracker_host0.foo.com:localhost/127.0.0.1:42117 to host host0.foo.com
    [junit] 2009-06-05 18:00:38,567 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-05 18:00:43,587 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-05 18:00:43,588 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 58456 webServer.getConnectors()[0].getLocalPort() returned 58456
    [junit] 2009-06-05 18:00:43,588 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 58456
    [junit] 2009-06-05 18:00:43,588 INFO  mortbay.log (?:invoke0(?)) - jetty-6.1.14
    [junit] 2009-06-05 18:00:43,650 INFO  mortbay.log (?:invoke0(?)) - Started SelectChannelConnector@0.0.0.0:58456
    [junit] 2009-06-05 18:00:43,654 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=TaskTracker, sessionId= - already initialized
    [junit] 2009-06-05 18:00:43,656 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=TaskTracker, port=39536
    [junit] 2009-06-05 18:00:43,656 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-06-05 18:00:43,657 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 39536: starting
    [junit] 2009-06-05 18:00:43,659 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 39536: starting
    [junit] 2009-06-05 18:00:43,659 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 39536: starting
    [junit] 2009-06-05 18:00:43,656 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 39536: starting
    [junit] 2009-06-05 18:00:43,659 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 3 on 39536: starting
    [junit] 2009-06-05 18:00:43,666 INFO  mapred.IndexCache (IndexCache.java:<init>(46)) - IndexCache created with max memory = 10485760
    [junit] 2009-06-05 18:00:43,729 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/host1.foo.com
    [junit] 2009-06-05 18:00:43,729 INFO  mapred.JobTracker (JobTracker.java:addNewTracker(2426)) - Adding tracker tracker_host1.foo.com:localhost/127.0.0.1:39536 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-05 18:00 /test/testDistCh/f1
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-05 18:00 /test/testDistCh/f2
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-05 18:00 /test/testDistCh/f3
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub0
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub1
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub1/f4
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub1/f5
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub2
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub3
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub3/f6
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub4
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub4/f7
    [junit] 
    [junit] args=[/test/testDistCh/sub4:sub4:sub4:,
    [junit]    /test/testDistCh/sub2::sub2:,
    [junit]    /test/testDistCh/sub0::sub0:074]
    [junit] newstatus=[hudson:sub0:---rwxr--,
    [junit]    hudson:supergroup:rwxr-xr-x,
    [junit]    hudson:sub2:rwxr-xr-x,
    [junit]    hudson:supergroup:rwxr-xr-x,
    [junit]    sub4:sub4:rwxr-xr-x]
    [junit] 2009-06-05 18:00:44,287 INFO  tools.DistTool (DistCh.java:run(376)) - ops=[/test/testDistCh/sub4:sub4:sub4:null, /test/testDistCh/sub2:null:sub2:null, /test/testDistCh/sub0:null:sub0:---rwxr--]
    [junit] 2009-06-05 18:00:44,288 INFO  tools.DistTool (DistCh.java:run(377)) - isIgnoreFailures=false
    [junit] 2009-06-05 18:00:44,305 INFO  tools.DistTool (DistCh.java:setup(427)) - distch.job.dir=hdfs://localhost:42333/user/hudson/build/test/mapred/system/distch_bzp1to
    [junit] 2009-06-05 18:00:44,320 INFO  tools.DistTool (DistCh.java:setup(433)) - log=hdfs://localhost:42333/user/hudson/build/test/mapred/system/distch_bzp1to/_logs
    [junit] 2009-06-05 18:00:44,572 INFO  tools.DistTool (DistCh.java:setup(476)) - distch.op.count=4
    [junit] 2009-06-05 18:00:44,578 WARN  mapred.JobClient (JobClient.java:configureCommandLineOptions(551)) - Use GenericOptionsParser for parsing the arguments. Applications should implement Tool for the same.
    [junit] 2009-06-05 18:00:44,607 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-05 18:00:44,620 INFO  tools.DistTool (DistCh.java:getSplits(261)) - numSplits=1, splits.size()=1
    [junit] 2009-06-05 18:00:44,965 WARN  conf.Configuration (Configuration.java:loadResource(1179)) - http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/mapred/local/jobTracker/job_200906051800_0001.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] 2009-06-05 18:00:44,974 INFO  mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(80)) - Initializing job_200906051800_0001
    [junit] 2009-06-05 18:00:44,975 INFO  mapred.JobInProgress (JobInProgress.java:initTasks(395)) - Initializing job_200906051800_0001
    [junit] 2009-06-05 18:00:44,975 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1287)) - Running job: job_200906051800_0001
    [junit] 2009-06-05 18:00:45,123 INFO  mapred.JobInProgress (JobInProgress.java:initTasks(439)) - Input size for job job_200906051800_0001 = 399. Number of splits = 1
    [junit] 2009-06-05 18:00:45,980 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1300)) -  map 0% reduce 0%
    [junit] 2009-06-05 18:00:46,755 INFO  mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906051800_0001_m_000002_0' to tip task_200906051800_0001_m_000002, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:39536'
    [junit] 2009-06-05 18:00:46,835 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_200906051800_0001/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] 2009-06-05 18:00:46,900 INFO  mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906051800_0001_m_888394226
    [junit] 2009-06-05 18:00:46,900 INFO  mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906051800_0001_m_888394226 spawned.
    [junit] 2009-06-05 18:00:48,012 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-05 18:00:48,012 INFO  util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 20504 with SIGTERM. Exit code 1
    [junit] 2009-06-05 18:00:49,764 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906051800_0001_m_000002_0' has completed task_200906051800_0001_m_000002 successfully.
    [junit] 2009-06-05 18:00:49,769 INFO  mapred.JobInProgress (JobInProgress.java:findNewMapTask(1815)) - Choosing a non-local task task_200906051800_0001_m_000000
    [junit] 2009-06-05 18:00:49,771 INFO  mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906051800_0001_m_000000_0' to tip task_200906051800_0001_m_000000, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:39536'
    [junit] 2009-06-05 18:00:49,776 INFO  mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906051800_0001_m_000002_0 done; removing files.
    [junit] 2009-06-05 18:00:49,777 INFO  mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906051800_0001_m_000002_0 not found in cache
    [junit] 2009-06-05 18:00:49,831 INFO  mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906051800_0001_m_-1644609087
    [junit] 2009-06-05 18:00:49,831 INFO  mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906051800_0001_m_-1644609087 spawned.
    [junit] 2009-06-05 18:00:49,994 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906051800_0001_m_000002_0, Status : SUCCEEDED
    [junit] attempt_200906051800_0001_m_000002_0: 2009-06-05 18:00:47,663 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_200906051800_0001/attempt_200906051800_0001_m_000002_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906051800_0001_m_000002_0: 2009-06-05 18:00:47,680 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_200906051800_0001_m_000002_0: 2009-06-05 18:00:47,779 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_200906051800_0001/attempt_200906051800_0001_m_000002_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906051800_0001_m_000002_0: 2009-06-05 18:00:47,839 INFO  mapred.Task (Task.java:done(620)) - Task:attempt_200906051800_0001_m_000002_0 is done. And is in the process of commiting
    [junit] attempt_200906051800_0001_m_000002_0: 2009-06-05 18:00:47,845 INFO  mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906051800_0001_m_000002_0' done.
    [junit] 2009-06-05 18:00:53,032 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-05 18:00:53,033 INFO  util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(94)) - Killing process group20504 with SIGKILL. Exit code 1
    [junit] 2009-06-05 18:00:53,033 INFO  mapred.DefaultTaskController (DefaultTaskController.java:killTaskJVM(87)) - Process exited with exit code:0
    [junit] 2009-06-05 18:00:53,033 INFO  mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200906051800_0001_m_888394226 exited. Number of tasks it ran: 1
    [junit] 2009-06-05 18:00:53,189 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-05 18:00:53,190 INFO  util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 20553 with SIGTERM. Exit code 1
    [junit] 2009-06-05 18:00:55,782 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906051800_0001_m_000000_0' has completed task_200906051800_0001_m_000000 successfully.
    [junit] 2009-06-05 18:00:55,786 INFO  mapred.JobTracker (JobTracker.java:createTaskEntry(1962)) - Adding task 'attempt_200906051800_0001_m_000001_0' to tip task_200906051800_0001_m_000001, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:39536'
    [junit] 2009-06-05 18:00:55,819 INFO  mapred.JvmManager (JvmManager.java:<init>(383)) - In JvmRunner constructed JVM ID: jvm_200906051800_0001_m_-1036348605
    [junit] 2009-06-05 18:00:55,819 INFO  mapred.JvmManager (JvmManager.java:spawnNewJvm(351)) - JVM Runner jvm_200906051800_0001_m_-1036348605 spawned.
    [junit] 2009-06-05 18:00:56,068 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906051800_0001_m_000000_0, Status : SUCCEEDED
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:50,561 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_200906051800_0001/attempt_200906051800_0001_m_000000_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:50,578 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:50,674 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_200906051800_0001/attempt_200906051800_0001_m_000000_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:50,767 INFO  mapred.MapTask (MapTask.java:runOldMapper(352)) - numReduceTasks: 0
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:50,913 INFO  mapred.Task (Task.java:done(620)) - Task:attempt_200906051800_0001_m_000000_0 is done. And is in the process of commiting
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:52,921 INFO  mapred.Task (Task.java:commit(720)) - Task attempt_200906051800_0001_m_000000_0 is allowed to commit now
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:52,960 INFO  mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(92)) - Saved output of task 'attempt_200906051800_0001_m_000000_0' to hdfs://localhost:42333/user/hudson/build/test/mapred/system/distch_bzp1to/_logs
    [junit] attempt_200906051800_0001_m_000000_0: 2009-06-05 18:00:52,967 INFO  mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906051800_0001_m_000000_0' done.
    [junit] 2009-06-05 18:00:56,894 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-05 18:00:56,895 INFO  util.ProcessTree (ProcessTree.java:destroyProcessGroup(168)) - Killing all processes in the process group 20608 with SIGTERM. Exit code 1
    [junit] 2009-06-05 18:00:57,078 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1300)) -  map 100% reduce 0%
    [junit] 2009-06-05 18:00:58,205 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-05 18:00:58,205 INFO  util.ProcessTree (ProcessTree.java:sigKillInCurrentThread(94)) - Killing process group20553 with SIGKILL. Exit code 1
    [junit] 2009-06-05 18:00:58,205 INFO  mapred.DefaultTaskController (DefaultTaskController.java:killTaskJVM(87)) - Process exited with exit code:0
    [junit] 2009-06-05 18:00:58,206 INFO  mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200906051800_0001_m_-1644609087 exited. Number of tasks it ran: 1
    [junit] 2009-06-05 18:00:58,789 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2022)) - Task 'attempt_200906051800_0001_m_000001_0' has completed task_200906051800_0001_m_000001 successfully.
    [junit] 2009-06-05 18:00:58,790 INFO  mapred.JobInProgress (JobInProgress.java:jobComplete(2146)) - Job job_200906051800_0001 has completed successfully.
    [junit] 2009-06-05 18:00:58,865 INFO  mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906051800_0001_m_000000_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:39536'
    [junit] 2009-06-05 18:00:58,865 INFO  mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906051800_0001_m_000001_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:39536'
    [junit] 2009-06-05 18:00:58,866 INFO  mapred.JobTracker (JobTracker.java:removeMarkedTasks(2077)) - Removed completed task 'attempt_200906051800_0001_m_000002_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:39536'
    [junit] 2009-06-05 18:00:58,867 INFO  mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906051800_0001_m_000001_0 done; removing files.
    [junit] 2009-06-05 18:00:58,868 INFO  mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906051800_0001_m_000001_0 not found in cache
    [junit] 2009-06-05 18:00:58,868 INFO  mapred.TaskRunner (MapTaskRunner.java:close(43)) - attempt_200906051800_0001_m_000000_0 done; removing files.
    [junit] 2009-06-05 18:00:58,869 INFO  mapred.IndexCache (IndexCache.java:removeMap(140)) - Map ID attempt_200906051800_0001_m_000000_0 not found in cache
    [junit] 2009-06-05 18:00:59,083 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1349)) - Task Id : attempt_200906051800_0001_m_000001_0, Status : SUCCEEDED
    [junit] attempt_200906051800_0001_m_000001_0: 2009-06-05 18:00:56,527 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_200906051800_0001/attempt_200906051800_0001_m_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906051800_0001_m_000001_0: 2009-06-05 18:00:56,544 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_200906051800_0001_m_000001_0: 2009-06-05 18:00:56,640 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_200906051800_0001/attempt_200906051800_0001_m_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir;  Ignoring.
    [junit] attempt_200906051800_0001_m_000001_0: 2009-06-05 18:00:56,702 INFO  mapred.Task (Task.java:done(620)) - Task:attempt_200906051800_0001_m_000001_0 is done. And is in the process of commiting
    [junit] attempt_200906051800_0001_m_000001_0: 2009-06-05 18:00:56,707 INFO  mapred.Task (Task.java:sendDone(691)) - Task 'attempt_200906051800_0001_m_000001_0' done.
    [junit] 2009-06-05 18:00:59,087 INFO  mapred.JobClient (JobClient.java:monitorAndPrintJob(1355)) - Job complete: job_200906051800_0001
    [junit] 2009-06-05 18:00:59,090 INFO  mapred.JobClient (Counters.java:log(534)) - Counters: 7
    [junit] 2009-06-05 18:00:59,090 INFO  mapred.JobClient (Counters.java:log(536)) -   Job Counters 
    [junit] 2009-06-05 18:00:59,091 INFO  mapred.JobClient (Counters.java:log(538)) -     Launched map tasks=1
    [junit] 2009-06-05 18:00:59,091 INFO  mapred.JobClient (Counters.java:log(536)) -   FileInputFormatCounters
    [junit] 2009-06-05 18:00:59,091 INFO  mapred.JobClient (Counters.java:log(538)) -     BYTES_READ=302
    [junit] 2009-06-05 18:00:59,092 INFO  mapred.JobClient (Counters.java:log(536)) -   org.apache.hadoop.tools.DistCh$Counter
    [junit] 2009-06-05 18:00:59,092 INFO  mapred.JobClient (Counters.java:log(538)) -     SUCCEED=4
    [junit] 2009-06-05 18:00:59,092 INFO  mapred.JobClient (Counters.java:log(536)) -   FileSystemCounters
    [junit] 2009-06-05 18:00:59,093 INFO  mapred.JobClient (Counters.java:log(538)) -     HDFS_BYTES_READ=399
    [junit] 2009-06-05 18:00:59,093 INFO  mapred.JobClient (Counters.java:log(536)) -   Map-Reduce Framework
    [junit] 2009-06-05 18:00:59,093 INFO  mapred.JobClient (Counters.java:log(538)) -     Map input records=4
    [junit] 2009-06-05 18:00:59,094 INFO  mapred.JobClient (Counters.java:log(538)) -     Spilled Records=0
    [junit] 2009-06-05 18:00:59,094 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-05 18:00 /test/testDistCh/f1
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-05 18:00 /test/testDistCh/f2
    [junit] -rw-r--r--   2 hudson supergroup         38 2009-06-05 18:00 /test/testDistCh/f3
    [junit] d---rwxr--   - hudson sub0                0 2009-06-05 18:00 /test/testDistCh/sub0
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub1
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub1/f4
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub1/f5
    [junit] drwxr-xr-x   - hudson sub2                0 2009-06-05 18:00 /test/testDistCh/sub2
    [junit] drwxr-xr-x   - hudson supergroup          0 2009-06-05 18:00 /test/testDistCh/sub3
    [junit] -rw-r--r--   2 hudson supergroup         43 2009-06-05 18:00 /test/testDistCh/sub3/f6
    [junit] drwxr-xr-x   - sub4   sub4                0 2009-06-05 18:00 /test/testDistCh/sub4
    [junit] -rw-r--r--   2 sub4 sub4         43 2009-06-05 18:00 /test/testDistCh/sub4/f7
    [junit] 
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 1
    [junit] 2009-06-05 18:00:59,232 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 49203
    [junit] 2009-06-05 18:00:59,233 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 49203: exiting
    [junit] 2009-06-05 18:00:59,233 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 49203: exiting
    [junit] 2009-06-05 18:00:59,233 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-06-05 18:00:59,233 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 49203: exiting
    [junit] 2009-06-05 18:00:59,233 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 49203
    [junit] 2009-06-05 18:00:59,235 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-05 18:00:59,236 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 49203
    [junit] Shutting down DataNode 0
    [junit] 2009-06-05 18:00:59,337 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 45669
    [junit] 2009-06-05 18:00:59,338 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 45669: exiting
    [junit] 2009-06-05 18:00:59,338 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-06-05 18:00:59,338 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 45669
    [junit] 2009-06-05 18:00:59,338 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 45669: exiting
    [junit] 2009-06-05 18:00:59,338 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 45669: exiting
    [junit] 2009-06-05 18:00:59,340 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-05 18:00:59,340 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 45669
    [junit] 2009-06-05 18:00:59,442 WARN  namenode.DecommissionManager (DecommissionManager.java:run(67)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 42333
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 42333: exiting
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 42333: exiting
    [junit] 2009-06-05 18:00:59,456 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 8 on 42333: exiting
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 4 on 42333: exiting
    [junit] 2009-06-05 18:00:59,456 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 9 on 42333: exiting
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 3 on 42333: exiting
    [junit] 2009-06-05 18:00:59,456 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 5 on 42333: exiting
    [junit] 2009-06-05 18:00:59,456 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 42333: exiting
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 6 on 42333: exiting
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 7 on 42333: exiting
    [junit] 2009-06-05 18:00:59,455 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 42333
    [junit] 2009-06-05 18:00:59,458 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 29.939 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1043: Tests failed!

Total time: 230 minutes 23 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...