Neil, It might be a transient problem with your single-node cluster. Was something else running on the machine when you ran the long running job. Can you monitor the usage of the machine when the hive query is running. Have you tried rebooting the machine? Does the query remain slow even after reboot?
Mark On Wed, Dec 19, 2012 at 11:21 PM, Neil Guo <guomaof...@gmail.com> wrote: > another log, > > cd $HADOOP_LOG_DIR && tail -n 0 -f *.log |tee log_merge.log > > > ==> hadoop-neil-datanode-Ct-bj108.log <== > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > > ==> hadoop-neil-namenode-Ct-bj108.log <== > > ==> hadoop-neil-secondarynamenode-Ct-bj108.log <== > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:10,425 INFO > org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification > succeeded for blk_7549818753225420678_5717 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:10:15,265 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: > 1 Total time for transactions(ms): 0Number of transactions batched in Syncs: > 0 Number of syncs: 0 SyncTimes(ms): 0 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:16,415 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-6072279734308701530_134821 src: /127.0.0.1:34080 dest: /127.0.0.1:50010 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:10:16,393 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7. > blk_-6072279734308701530_134821 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:16,564 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34080, dest: /127.0.0.1:50010, bytes: 57401, op: HDFS_WRITE, > cliID: DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-6072279734308701530_134821, duration: 84788000 > 2012-12-20 15:10:16,565 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-6072279734308701530_134821 terminating > 2012-12-20 15:10:16,911 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_5272124058034081804_134822 src: /127.0.0.1:34082 dest: /127.0.0.1:50010 > 2012-12-20 15:10:17,003 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34082, dest: /127.0.0.1:50010, bytes: 3915, op: HDFS_WRITE, > cliID: DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_5272124058034081804_134822, duration: 56734000 > 2012-12-20 15:10:17,003 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_5272124058034081804_134822 terminating > 2012-12-20 15:10:17,122 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-5406425112482671769_134823 src: /127.0.0.1:34083 dest: /127.0.0.1:50010 > 2012-12-20 15:10:17,313 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34083, dest: /127.0.0.1:50010, bytes: 449818, op: HDFS_WRITE, > cliID: DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-5406425112482671769_134823, duration: 152658000 > 2012-12-20 15:10:17,313 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-5406425112482671769_134823 terminating > 2012-12-20 15:10:17,474 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-6418269071912761245_134824 src: /127.0.0.1:34084 dest: /127.0.0.1:50010 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:10:16,565 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-6072279734308701530_134821 size 57401 > 2012-12-20 15:10:16,567 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7 > is closed by DFSClient_-1778955690 > 2012-12-20 15:10:16,603 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication > for file > /tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7. > New replication is 10 > 2012-12-20 15:10:16,910 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar. > blk_5272124058034081804_134822 > 2012-12-20 15:10:17,003 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_5272124058034081804_134822 size 3915 > 2012-12-20 15:10:17,005 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar > is closed by DFSClient_-1778955690 > 2012-12-20 15:10:17,043 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication > for file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar. > New replication is 10 > 2012-12-20 15:10:17,121 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar. > blk_-5406425112482671769_134823 > 2012-12-20 15:10:17,313 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-5406425112482671769_134823 size 449818 > 2012-12-20 15:10:17,315 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar > is closed by DFSClient_-1778955690 > 2012-12-20 15:10:17,355 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication > for file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar. > New replication is 10 > 2012-12-20 15:10:17,472 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.jar. > blk_-6418269071912761245_134824 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:17,801 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34084, dest: /127.0.0.1:50010, bytes: 3461228, op: HDFS_WRITE, > cliID: DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-6418269071912761245_134824, duration: 265447000 > 2012-12-20 15:10:17,801 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-6418269071912761245_134824 terminating > 2012-12-20 15:10:18,043 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-6063479553986664026_134825 src: /127.0.0.1:34085 dest: /127.0.0.1:50010 > 2012-12-20 15:10:18,151 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34085, dest: /127.0.0.1:50010, bytes: 242, op: HDFS_WRITE, cliID: > DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-6063479553986664026_134825, duration: 49252000 > 2012-12-20 15:10:18,151 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-6063479553986664026_134825 terminating > 2012-12-20 15:10:18,229 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-8321979998668805180_134826 src: /127.0.0.1:34086 dest: /127.0.0.1:50010 > 2012-12-20 15:10:18,351 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34086, dest: /127.0.0.1:50010, bytes: 28, op: HDFS_WRITE, cliID: > DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-8321979998668805180_134826, duration: 74262000 > 2012-12-20 15:10:18,351 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-8321979998668805180_134826 terminating > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:10:17,802 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-6418269071912761245_134824 size 3461228 > 2012-12-20 15:10:17,803 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.jar > is closed by DFSClient_-1778955690 > 2012-12-20 15:10:17,825 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication > for file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.jar. > New replication is 10 > 2012-12-20 15:10:18,007 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication > for file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.split. > New replication is 10 > 2012-12-20 15:10:18,041 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.split. > blk_-6063479553986664026_134825 > 2012-12-20 15:10:18,151 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-6063479553986664026_134825 size 242 > 2012-12-20 15:10:18,153 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.split > is closed by DFSClient_-1778955690 > 2012-12-20 15:10:18,228 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.splitmetainfo. > blk_-8321979998668805180_134826 > 2012-12-20 15:10:18,351 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-8321979998668805180_134826 size 28 > 2012-12-20 15:10:18,353 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.splitmetainfo > is closed by DFSClient_-1778955690 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:18,537 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-4169651595582041742_134827 src: /127.0.0.1:34087 dest: /127.0.0.1:50010 > 2012-12-20 15:10:18,725 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34087, dest: /127.0.0.1:50010, bytes: 41235, op: HDFS_WRITE, > cliID: DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-4169651595582041742_134827, duration: 107084000 > 2012-12-20 15:10:18,725 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-4169651595582041742_134827 terminating > 2012-12-20 15:10:18,941 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34089, bytes: 41559, op: HDFS_READ, > cliID: DFSClient_-1581977158, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-4169651595582041742_134827, duration: 1806000 > 2012-12-20 15:10:19,338 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-7272939761936583747_134828 src: /127.0.0.1:34090 dest: /127.0.0.1:50010 > 2012-12-20 15:10:19,453 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34090, dest: /127.0.0.1:50010, bytes: 106, op: HDFS_WRITE, cliID: > DFSClient_-2004864441, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-7272939761936583747_134828, duration: 81486000 > 2012-12-20 15:10:19,454 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-7272939761936583747_134828 terminating > 2012-12-20 15:10:19,485 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34091, bytes: 32, op: HDFS_READ, cliID: > DFSClient_-1581977158, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-8321979998668805180_134826, duration: 339000 > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > 2012-12-20 15:10:19,091 INFO org.apache.hadoop.mapred.JobInProgress: > job_201212201444_0001: nMaps=1 nReduces=1 max=-1 > 2012-12-20 15:10:19,094 INFO org.apache.hadoop.mapred.JobTracker: Job > job_201212201444_0001 added successfully for user 'neil' to queue 'default' > 2012-12-20 15:10:19,095 INFO org.apache.hadoop.mapred.JobTracker: > Initializing job_201212201444_0001 > 2012-12-20 15:10:19,096 INFO org.apache.hadoop.mapred.JobInProgress: > Initializing job_201212201444_0001 > 2012-12-20 15:10:19,097 INFO org.apache.hadoop.mapred.AuditLogger: USER=neil > IP=127.0.0.1 OPERATION=SUBMIT_JOB TARGET=job_201212201444_0001 > RESULT=SUCCESS > 2012-12-20 15:10:19,477 INFO org.apache.hadoop.mapred.JobInProgress: > jobToken generated and stored with users keys in > /data/disk/hadoop/mapred/system/job_201212201444_0001/jobToken > 2012-12-20 15:10:19,495 INFO org.apache.hadoop.mapred.JobInProgress: Input > size for job job_201212201444_0001 = 21896. Number of splits = 1 > 2012-12-20 15:10:19,496 INFO org.apache.hadoop.mapred.JobInProgress: > tip:task_201212201444_0001_m_000000 has split on > node:/default-rack/dms.example.com > 2012-12-20 15:10:19,496 INFO org.apache.hadoop.mapred.JobInProgress: > job_201212201444_0001 LOCALITY_WAIT_FACTOR=1.0 > 2012-12-20 15:10:19,497 INFO org.apache.hadoop.mapred.JobInProgress: Job > job_201212201444_0001 initialized successfully with 1 map tasks and 1 reduce > tasks. > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:10:18,536 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.xml. > blk_-4169651595582041742_134827 > 2012-12-20 15:10:18,725 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-4169651595582041742_134827 size 41235 > 2012-12-20 15:10:18,727 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/job.xml > is closed by DFSClient_-1778955690 > 2012-12-20 15:10:19,337 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /data/disk/hadoop/mapred/system/job_201212201444_0001/jobToken. > blk_-7272939761936583747_134828 > 2012-12-20 15:10:19,454 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-7272939761936583747_134828 size 106 > 2012-12-20 15:10:19,455 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /data/disk/hadoop/mapred/system/job_201212201444_0001/jobToken is closed by > DFSClient_-2004864441 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:20,250 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34093, bytes: 110, op: HDFS_READ, cliID: > DFSClient_-1631073440, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-7272939761936583747_134828, duration: 400000 > 2012-12-20 15:10:20,404 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34095, bytes: 41559, op: HDFS_READ, > cliID: DFSClient_1731936872, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-4169651595582041742_134827, duration: 317000 > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > 2012-12-20 15:10:19,997 INFO org.apache.hadoop.mapred.JobTracker: Adding > task (JOB_SETUP) 'attempt_201212201444_0001_m_000002_0' to tip > task_201212201444_0001_m_000002, for tracker > 'tracker_dms.example.com:dms.example.com/127.0.0.1:46543' > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:10:20,037 INFO org.apache.hadoop.mapred.TaskTracker: > LaunchTaskAction (registerTask): attempt_201212201444_0001_m_000002_0 task's > state:UNASSIGNED > 2012-12-20 15:10:20,041 INFO org.apache.hadoop.mapred.TaskTracker: Trying to > launch : attempt_201212201444_0001_m_000002_0 which needs 1 slots > 2012-12-20 15:10:20,041 INFO org.apache.hadoop.mapred.TaskTracker: In > TaskLauncher, current free slots : 16 and trying to launch > attempt_201212201444_0001_m_000002_0 which needs 1 slots > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:20,867 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34096, bytes: 57853, op: HDFS_READ, > cliID: DFSClient_1731936872, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-6072279734308701530_134821, duration: 493000 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:10:20,716 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Creating > 418d928d-6cd4-485b-99b6-0355e9a20fd7 in > /data/disk/hadoop/mapred/local/taskTracker/distcache/6421471112967063702_-513718697_925234720/localhost/tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003-work-4922778804279647881 > with rwxr-xr-x > 2012-12-20 15:10:21,023 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Cached > hdfs://localhost:9000/tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7#HIVE_PLAN418d928d-6cd4-485b-99b6-0355e9a20fd7 > as > /data/disk/hadoop/mapred/local/taskTracker/distcache/6421471112967063702_-513718697_925234720/localhost/tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7 > 2012-12-20 15:10:21,025 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Cached > hdfs://localhost:9000/tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7#HIVE_PLAN418d928d-6cd4-485b-99b6-0355e9a20fd7 > as > /data/disk/hadoop/mapred/local/taskTracker/distcache/6421471112967063702_-513718697_925234720/localhost/tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/-mr-10003/418d928d-6cd4-485b-99b6-0355e9a20fd7 > 2012-12-20 15:10:21,410 INFO org.apache.hadoop.mapred.JobLocalizer: > Initializing user neil on this TT. > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:10:22,446 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34097, bytes: 3488272, op: HDFS_READ, > cliID: DFSClient_1731936872, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-6418269071912761245_134824, duration: 126510000 > 2012-12-20 15:11:11,624 INFO > org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification > succeeded for blk_-9131161345248274165_47715 > 2012-12-20 15:12:13,025 INFO > org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification > succeeded for blk_-8619676883356146541_5718 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:18,558 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Creating > hive-builtins-0.8.1.jar in > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-5673828160848660706_522549067_925235614/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar-work--3174612500938353524 > with rwxr-xr-x > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:12:18,894 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34100, bytes: 3947, op: HDFS_READ, cliID: > DFSClient_1731936872, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_5272124058034081804_134822, duration: 286000 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:19,081 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Extracting > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-5673828160848660706_522549067_925235614/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar-work--3174612500938353524/hive-builtins-0.8.1.jar > to > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-5673828160848660706_522549067_925235614/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar-work--3174612500938353524 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:12:20,331 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34101, bytes: 453334, op: HDFS_READ, > cliID: DFSClient_1731936872, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-5406425112482671769_134823, duration: 16852000 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:19,857 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Cached > hdfs://localhost:9000/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar > as > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-5673828160848660706_522549067_925235614/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/hive-builtins-0.8.1.jar > 2012-12-20 15:12:19,865 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Creating > protobuf-java-2.4.0a.jar in > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-6084675189877492673_-1521931690_925235825/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar-work-215528142457418648 > with rwxr-xr-x > 2012-12-20 15:12:20,549 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Extracting > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-6084675189877492673_-1521931690_925235825/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar-work-215528142457418648/protobuf-java-2.4.0a.jar > to > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-6084675189877492673_-1521931690_925235825/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar-work-215528142457418648 > 2012-12-20 15:12:33,215 INFO > org.apache.hadoop.filecache.TrackerDistributedCacheManager: Cached > hdfs://localhost:9000/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar > as > /data/disk/hadoop/mapred/local/taskTracker/neil/distcache/-6084675189877492673_-1521931690_925235825/localhost/data/disk/hadoop/mapred/staging/neil/.staging/job_201212201444_0001/libjars/protobuf-java-2.4.0a.jar > 2012-12-20 15:12:33,532 INFO org.apache.hadoop.mapred.JvmManager: In > JvmRunner constructed JVM ID: jvm_201212201444_0001_m_103787484 > 2012-12-20 15:12:33,533 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner > jvm_201212201444_0001_m_103787484 spawned. > 2012-12-20 15:12:33,573 INFO org.apache.hadoop.mapred.TaskController: > Writing commands to > /data/disk/hadoop/mapred/local/ttprivate/taskTracker/neil/jobcache/job_201212201444_0001/attempt_201212201444_0001_m_000002_0/taskjvm.sh > 2012-12-20 15:12:34,812 INFO org.apache.hadoop.mapred.TaskTracker: JVM with > ID: jvm_201212201444_0001_m_103787484 given task: > attempt_201212201444_0001_m_000002_0 > 2012-12-20 15:12:38,837 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_m_000002_0 0.0% setup > 2012-12-20 15:12:38,839 INFO org.apache.hadoop.mapred.TaskTracker: Task > attempt_201212201444_0001_m_000002_0 is done. > 2012-12-20 15:12:38,840 INFO org.apache.hadoop.mapred.TaskTracker: reported > output size for attempt_201212201444_0001_m_000002_0 was -1 > 2012-12-20 15:12:38,841 INFO org.apache.hadoop.mapred.TaskTracker: > addFreeSlot : current free slots : 16 > 2012-12-20 15:12:39,080 INFO org.apache.hadoop.mapred.JvmManager: JVM : > jvm_201212201444_0001_m_103787484 exited with exit code 0. Number of tasks > it ran: 1 > 2012-12-20 15:12:39,115 INFO org.apache.hadoop.util.NativeCodeLoader: Loaded > the native-hadoop library > 2012-12-20 15:12:39,147 INFO org.apache.hadoop.io.nativeio.NativeIO: > Initialized cache for UID to User mapping with a cache timeout of 14400 > seconds. > 2012-12-20 15:12:39,147 INFO org.apache.hadoop.io.nativeio.NativeIO: Got > UserName neil for UID 502 from the native implementation > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > 2012-12-20 15:12:41,247 INFO org.apache.hadoop.mapred.JobInProgress: Task > 'attempt_201212201444_0001_m_000002_0' has completed > task_201212201444_0001_m_000002 successfully. > 2012-12-20 15:12:41,251 INFO org.apache.hadoop.mapred.JobTracker: Adding > task (MAP) 'attempt_201212201444_0001_m_000000_0' to tip > task_201212201444_0001_m_000000, for tracker > 'tracker_dms.example.com:dms.example.com/127.0.0.1:46543' > 2012-12-20 15:12:41,252 INFO org.apache.hadoop.mapred.JobInProgress: > Choosing data-local task task_201212201444_0001_m_000000 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:41,254 INFO org.apache.hadoop.mapred.TaskTracker: > LaunchTaskAction (registerTask): attempt_201212201444_0001_m_000000_0 task's > state:UNASSIGNED > 2012-12-20 15:12:41,255 INFO org.apache.hadoop.mapred.TaskTracker: Trying to > launch : attempt_201212201444_0001_m_000000_0 which needs 1 slots > 2012-12-20 15:12:41,255 INFO org.apache.hadoop.mapred.TaskTracker: In > TaskLauncher, current free slots : 16 and trying to launch > attempt_201212201444_0001_m_000000_0 which needs 1 slots > 2012-12-20 15:12:41,255 INFO org.apache.hadoop.mapred.TaskTracker: Received > KillTaskAction for task: attempt_201212201444_0001_m_000002_0 > 2012-12-20 15:12:41,255 INFO org.apache.hadoop.mapred.TaskTracker: About to > purge task: attempt_201212201444_0001_m_000002_0 > 2012-12-20 15:12:41,255 INFO org.apache.hadoop.mapred.IndexCache: Map ID > attempt_201212201444_0001_m_000002_0 not found in cache > 2012-12-20 15:12:41,258 INFO org.apache.hadoop.mapred.JvmManager: In > JvmRunner constructed JVM ID: jvm_201212201444_0001_m_-1051107442 > 2012-12-20 15:12:41,258 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner > jvm_201212201444_0001_m_-1051107442 spawned. > 2012-12-20 15:12:41,308 INFO org.apache.hadoop.mapred.TaskController: > Writing commands to > /data/disk/hadoop/mapred/local/ttprivate/taskTracker/neil/jobcache/job_201212201444_0001/attempt_201212201444_0001_m_000000_0/taskjvm.sh > 2012-12-20 15:12:42,769 INFO org.apache.hadoop.mapred.TaskTracker: JVM with > ID: jvm_201212201444_0001_m_-1051107442 given task: > attempt_201212201444_0001_m_000000_0 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:12:43,797 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34108, bytes: 246, op: HDFS_READ, cliID: > DFSClient_attempt_201212201444_0001_m_000000_0, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-6063479553986664026_134825, duration: 346000 > 2012-12-20 15:12:44,575 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34109, bytes: 22068, op: HDFS_READ, > cliID: DFSClient_attempt_201212201444_0001_m_000000_0, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_5550712265940538900_53660, duration: 340000 > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > 2012-12-20 15:12:47,268 INFO org.apache.hadoop.mapred.JobInProgress: Task > 'attempt_201212201444_0001_m_000000_0' has completed > task_201212201444_0001_m_000000 successfully. > 2012-12-20 15:12:47,280 INFO org.apache.hadoop.mapred.JobTracker: Adding > task (REDUCE) 'attempt_201212201444_0001_r_000000_0' to tip > task_201212201444_0001_r_000000, for tracker > 'tracker_dms.example.com:dms.example.com/127.0.0.1:46543' > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:46,788 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_m_000000_0 0.0% > hdfs://localhost:9000/user/hive/neiltest/dt=2012-12-04/halfhour=21%3A30/input.log:0+21896 > 2012-12-20 15:12:46,790 INFO org.apache.hadoop.mapred.TaskTracker: Task > attempt_201212201444_0001_m_000000_0 is done. > 2012-12-20 15:12:46,790 INFO org.apache.hadoop.mapred.TaskTracker: reported > output size for attempt_201212201444_0001_m_000000_0 was 19 > 2012-12-20 15:12:46,791 INFO org.apache.hadoop.mapred.TaskTracker: > addFreeSlot : current free slots : 16 > 2012-12-20 15:12:47,016 INFO org.apache.hadoop.mapred.JvmManager: JVM : > jvm_201212201444_0001_m_-1051107442 exited with exit code 0. Number of tasks > it ran: 1 > 2012-12-20 15:12:47,288 INFO org.apache.hadoop.mapred.TaskTracker: > LaunchTaskAction (registerTask): attempt_201212201444_0001_r_000000_0 task's > state:UNASSIGNED > 2012-12-20 15:12:47,288 INFO org.apache.hadoop.mapred.TaskTracker: Trying to > launch : attempt_201212201444_0001_r_000000_0 which needs 1 slots > 2012-12-20 15:12:47,288 INFO org.apache.hadoop.mapred.TaskTracker: In > TaskLauncher, current free slots : 16 and trying to launch > attempt_201212201444_0001_r_000000_0 which needs 1 slots > 2012-12-20 15:12:47,292 INFO org.apache.hadoop.mapred.JvmManager: In > JvmRunner constructed JVM ID: jvm_201212201444_0001_r_103787484 > 2012-12-20 15:12:47,293 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner > jvm_201212201444_0001_r_103787484 spawned. > 2012-12-20 15:12:47,327 INFO org.apache.hadoop.mapred.TaskController: > Writing commands to > /data/disk/hadoop/mapred/local/ttprivate/taskTracker/neil/jobcache/job_201212201444_0001/attempt_201212201444_0001_r_000000_0/taskjvm.sh > 2012-12-20 15:12:48,590 INFO org.apache.hadoop.mapred.TaskTracker: JVM with > ID: jvm_201212201444_0001_r_103787484 given task: > attempt_201212201444_0001_r_000000_0 > 2012-12-20 15:12:54,842 INFO > org.apache.hadoop.mapred.TaskTracker.clienttrace: src: 127.0.0.1:50060, > dest: 127.0.0.1:51570, bytes: 19, op: MAPRED_SHUFFLE, cliID: > attempt_201212201444_0001_m_000000_0, duration: 16156000 > 2012-12-20 15:12:55,653 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_r_000000_0 0.0% reduce > copy > > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:12:56,522 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block > blk_-5131011905768025520_134829 src: /127.0.0.1:34114 dest: /127.0.0.1:50010 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:12:56,392 INFO > org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: > 45 Total time for transactions(ms): 0Number of transactions batched in > Syncs: 0 Number of syncs: 32 SyncTimes(ms): 1213 > 2012-12-20 15:12:56,485 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.allocateBlock: > /tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/_task_tmp.-ext-10001/_tmp.000000_0. > blk_-5131011905768025520_134829 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:55,700 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_r_000000_0 0.0% reduce > copy > > 2012-12-20 15:12:55,786 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_r_000000_0 0.0% reduce > copy > > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:12:56,682 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:34114, dest: /127.0.0.1:50010, bytes: 4, op: HDFS_WRITE, cliID: > DFSClient_attempt_201212201444_0001_r_000000_0, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-5131011905768025520_134829, duration: 78187000 > 2012-12-20 15:12:56,682 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 0 for block > blk_-5131011905768025520_134829 terminating > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:12:56,682 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50010 is added to > blk_-5131011905768025520_134829 size 4 > 2012-12-20 15:12:56,684 INFO org.apache.hadoop.hdfs.StateChange: DIR* > NameSystem.completeFile: file > /tmp/hive-neil/hive_2012-12-20_15-10-12_982_9050806798858515370/_task_tmp.-ext-10001/_tmp.000000_0 > is closed by DFSClient_attempt_201212201444_0001_r_000000_0 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:58,661 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_r_000000_0 1.0% reduce > reduce > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > 2012-12-20 15:12:59,312 INFO org.apache.hadoop.mapred.JobInProgress: Task > 'attempt_201212201444_0001_r_000000_0' has completed > task_201212201444_0001_r_000000 successfully. > 2012-12-20 15:12:59,318 INFO org.apache.hadoop.mapred.JobTracker: Adding > task (JOB_CLEANUP) 'attempt_201212201444_0001_m_000001_0' to tip > task_201212201444_0001_m_000001, for tracker > 'tracker_dms.example.com:dms.example.com/127.0.0.1:46543' > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:12:58,666 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_r_000000_0 1.0% reduce > reduce > 2012-12-20 15:12:58,667 INFO org.apache.hadoop.mapred.TaskTracker: Task > attempt_201212201444_0001_r_000000_0 is done. > 2012-12-20 15:12:58,668 INFO org.apache.hadoop.mapred.TaskTracker: reported > output size for attempt_201212201444_0001_r_000000_0 was -1 > 2012-12-20 15:12:58,668 INFO org.apache.hadoop.mapred.TaskTracker: > addFreeSlot : current free slots : 16 > 2012-12-20 15:12:58,889 INFO org.apache.hadoop.mapred.JvmManager: JVM : > jvm_201212201444_0001_r_103787484 exited with exit code 0. Number of tasks > it ran: 1 > 2012-12-20 15:12:59,320 INFO org.apache.hadoop.mapred.TaskTracker: > LaunchTaskAction (registerTask): attempt_201212201444_0001_m_000001_0 task's > state:UNASSIGNED > 2012-12-20 15:12:59,320 INFO org.apache.hadoop.mapred.TaskTracker: Trying to > launch : attempt_201212201444_0001_m_000001_0 which needs 1 slots > 2012-12-20 15:12:59,320 INFO org.apache.hadoop.mapred.TaskTracker: Received > KillTaskAction for task: attempt_201212201444_0001_r_000000_0 > 2012-12-20 15:12:59,320 INFO org.apache.hadoop.mapred.TaskTracker: In > TaskLauncher, current free slots : 16 and trying to launch > attempt_201212201444_0001_m_000001_0 which needs 1 slots > 2012-12-20 15:12:59,321 INFO org.apache.hadoop.mapred.TaskTracker: About to > purge task: attempt_201212201444_0001_r_000000_0 > 2012-12-20 15:12:59,324 INFO org.apache.hadoop.mapred.JvmManager: In > JvmRunner constructed JVM ID: jvm_201212201444_0001_m_869411230 > 2012-12-20 15:12:59,324 INFO org.apache.hadoop.mapred.JvmManager: JVM Runner > jvm_201212201444_0001_m_869411230 spawned. > 2012-12-20 15:12:59,377 INFO org.apache.hadoop.mapred.TaskController: > Writing commands to > /data/disk/hadoop/mapred/local/ttprivate/taskTracker/neil/jobcache/job_201212201444_0001/attempt_201212201444_0001_m_000001_0/taskjvm.sh > 2012-12-20 15:13:00,424 INFO org.apache.hadoop.mapred.TaskTracker: JVM with > ID: jvm_201212201444_0001_m_869411230 given task: > attempt_201212201444_0001_m_000001_0 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:13:01,399 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-6418269071912761245 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:01,399 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-6063479553986664026 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:01,399 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-8321979998668805180 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:01,399 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-4169651595582041742 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:01,399 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_5272124058034081804 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:01,399 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-5406425112482671769 is added to invalidSet > of 127.0.0.1:50010 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:13:01,396 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_m_000001_0 0.0% > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:13:02,556 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask > 127.0.0.1:50010 to delete blk_-6063479553986664026_134825 > blk_-4169651595582041742_134827 blk_-6418269071912761245_134824 > blk_-5406425112482671769_134823 blk_5272124058034081804_134822 > blk_-8321979998668805180_134826 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:13:04,416 INFO org.apache.hadoop.mapred.TaskTracker: > attempt_201212201444_0001_m_000001_0 0.0% cleanup > 2012-12-20 15:13:04,420 INFO org.apache.hadoop.mapred.TaskTracker: Task > attempt_201212201444_0001_m_000001_0 is done. > 2012-12-20 15:13:04,421 INFO org.apache.hadoop.mapred.TaskTracker: reported > output size for attempt_201212201444_0001_m_000001_0 was -1 > 2012-12-20 15:13:04,421 INFO org.apache.hadoop.mapred.TaskTracker: > addFreeSlot : current free slots : 16 > 2012-12-20 15:13:04,632 INFO org.apache.hadoop.mapred.JvmManager: JVM : > jvm_201212201444_0001_m_869411230 exited with exit code 0. Number of tasks > it ran: 1 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:13:05,045 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-8321979998668805180_134826 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-8321979998668805180 > 2012-12-20 15:13:05,048 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-6418269071912761245_134824 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-6418269071912761245 > 2012-12-20 15:13:05,049 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-6063479553986664026_134825 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-6063479553986664026 > 2012-12-20 15:13:05,050 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-5406425112482671769_134823 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-5406425112482671769 > 2012-12-20 15:13:05,051 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-4169651595582041742_134827 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-4169651595582041742 > 2012-12-20 15:13:05,052 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_5272124058034081804_134822 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_5272124058034081804 > > ==> hadoop-neil-jobtracker-Ct-bj108.log <== > 2012-12-20 15:13:05,330 INFO org.apache.hadoop.mapred.JobInProgress: Task > 'attempt_201212201444_0001_m_000001_0' has completed > task_201212201444_0001_m_000001 successfully. > 2012-12-20 15:13:05,331 INFO org.apache.hadoop.mapred.JobInProgress: Job > job_201212201444_0001 has completed successfully. > 2012-12-20 15:13:05,335 INFO > org.apache.hadoop.mapred.JobInProgress$JobSummary: > jobId=job_201212201444_0001,submitTime=1355987418797,launchTime=1355987419496,firstMapTaskLaunchTime=1355987561251,firstReduceTaskLaunchTime=1355987567274,firstJobSetupTaskLaunchTime=1355987419969,firstJobCleanupTaskLaunchTime=1355987579318,finishTime=1355987585331,numMaps=1,numSlotsPerMap=1,numReduces=1,numSlotsPerReduce=1,user=neil,queue=default,status=SUCCEEDED,mapSlotSeconds=15,reduceSlotsSeconds=11,clusterMapCapacity=16,clusterReduceCapacity=16 > 2012-12-20 15:13:05,343 INFO org.apache.hadoop.mapred.JobHistory: Creating > DONE subfolder at > file:/opt/hadoop/hadoop/logs/history/done/version-1/localhost_1355985857105_/2012/12/20/000000 > 2012-12-20 15:13:05,344 INFO org.apache.hadoop.mapred.JobHistory: Moving > file:/opt/hadoop/hadoop/logs/history/job_201212201444_0001_1355987418797_neil_select+count%28*%29+from+neiltest%28Stage-1%29 > to > file:/opt/hadoop/hadoop/logs/history/done/version-1/localhost_1355985857105_/2012/12/20/000000 > 2012-12-20 15:13:05,347 INFO org.apache.hadoop.mapred.JobTracker: Removing > task 'attempt_201212201444_0001_m_000000_0' > 2012-12-20 15:13:05,347 INFO org.apache.hadoop.mapred.JobTracker: Removing > task 'attempt_201212201444_0001_m_000001_0' > 2012-12-20 15:13:05,347 INFO org.apache.hadoop.mapred.JobTracker: Removing > task 'attempt_201212201444_0001_m_000002_0' > 2012-12-20 15:13:05,348 INFO org.apache.hadoop.mapred.JobTracker: Removing > task 'attempt_201212201444_0001_r_000000_0' > 2012-12-20 15:13:05,352 INFO org.apache.hadoop.mapred.JobHistory: Moving > file:/opt/hadoop/hadoop/logs/history/job_201212201444_0001_conf.xml to > file:/opt/hadoop/hadoop/logs/history/done/version-1/localhost_1355985857105_/2012/12/20/000000 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:13:05,349 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-7272939761936583747 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:05,558 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask > 127.0.0.1:50010 to delete blk_-7272939761936583747_134828 > > ==> hadoop-neil-tasktracker-Ct-bj108.log <== > 2012-12-20 15:13:05,349 INFO org.apache.hadoop.mapred.TaskTracker: Received > 'KillJobAction' for job: job_201212201444_0001 > 2012-12-20 15:13:05,350 INFO org.apache.hadoop.mapred.IndexCache: Map ID > attempt_201212201444_0001_m_000001_0 not found in cache > 2012-12-20 15:13:05,351 INFO org.apache.hadoop.mapred.UserLogCleaner: Adding > job_201212201444_0001 for user-log deletion with > retainTimeStamp:1356073985351 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:13:06,136 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode.clienttrace: src: > /127.0.0.1:50010, dest: /127.0.0.1:34119, bytes: 8, op: HDFS_READ, cliID: > DFSClient_-1778955690, offset: 0, srvID: > DS-1688600142-127.0.0.1-50010-1318579377533, blockid: > blk_-5131011905768025520_134829, duration: 788000 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:13:05,861 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-6072279734308701530 is added to invalidSet > of 127.0.0.1:50010 > 2012-12-20 15:13:06,140 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* > NameSystem.addToInvalidates: blk_-5131011905768025520 is added to invalidSet > of 127.0.0.1:50010 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:13:08,048 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-7272939761936583747_134828 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-7272939761936583747 > > ==> hadoop-neil-namenode-Ct-bj108.log <== > 2012-12-20 15:13:08,560 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask > 127.0.0.1:50010 to delete blk_-6072279734308701530_134821 > blk_-5131011905768025520_134829 > > ==> hadoop-neil-datanode-Ct-bj108.log <== > 2012-12-20 15:13:11,050 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-6072279734308701530_134821 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-6072279734308701530 > 2012-12-20 15:13:11,051 INFO > org.apache.hadoop.hdfs.server.datanode.DataNode: Deleting block > blk_-5131011905768025520_134829 file > /data/disk/hadoop/dfs/data/current/subdir6/blk_-5131011905768025520 > 2012-12-20 15:13:14,425 INFO > org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: Verification > succeeded for blk_-8887324286910430426_17010 > > > > > On Thu, Dec 20, 2012 at 12:40 PM, Neil Guo <guomaof...@gmail.com> wrote: >> >> No, there's no failure in jobtracker ui, seems that all of them are >> success. >> >> Attachent is hadoop log files. >> >> Thanks. > >
