hive-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Neil Guo <guomaof...@gmail.com>
Subject Re: hive jobs pending so long
Date Fri, 21 Dec 2012 06:22:03 GMT
Hi Mark,

I've reboot the server today,  but the problem is still there.  The hive
job is the only job on the machine.

:(


On Fri, Dec 21, 2012 at 1:29 AM, Mark Grover <grover.markgrover@gmail.com>wrote:

> 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 <guomaofeng@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 <guomaofeng@gmail.com> wrote:
> >>
> >> No, there's no failure in jobtracker ui, seems that all of them are
> >> success.
> >>
> >> Attachent is hadoop log files.
> >>
> >> Thanks.
> >
> >
>

Mime
View raw message