본문 바로가기

Hadoop Ecosystem

RHadoop log

Error 발생 


Error in mr(map = map, reduce = reduce, combine = combine, vectorized.reduce,  : 

  hadoop streaming failed with error code 1


2013-06-27 20:18:13,019 INFO org.apache.hadoop.mapred.TaskInProgress: Error from attempt_201306271950_0003_m_000000_0: java.lang.RuntimeException: PipeMapRed.waitOutputThreads(): subprocess failed with code 1


./bin/hadoop jar contrib/streaming/hadoop-streaming-1.0.4.jar \
       -input test_input \
       -output test_out \
       -mapper "sed '1d' | cut -f 3,4 -d , | awk 'NF'" \
       -reducer "uniq" 

2013-06-27 20:48:22,735 INFO org.apache.hadoop.mapred.JobInProgress: Choosing data-local task task_201306271950_0004_m_000002
2013-06-27 20:48:22,736 INFO org.apache.hadoop.mapred.JobTracker: Removing task 'attempt_201306271950_0004_m_000000_0'
2013-06-27 20:48:23,419 INFO org.apache.hadoop.mapred.JobInProgress: Choosing a failed task task_201306271950_0004_m_000000
2013-06-27 20:48:23,426 INFO org.apache.hadoop.mapred.JobTracker: Adding task (MAP) 'attempt_201306271950_0004_m_000000_1' to tip task_201306271950_0004_m_000000, for tracker 'tracker_h002:127.0.0.1/127.0.0.1:46586'
2013-06-27 20:48:23,427 INFO org.apache.hadoop.mapred.JobInProgress: Choosing data-local task task_201306271950_0004_m_000000
2013-06-27 20:48:25,788 INFO org.apache.hadoop.mapred.TaskInProgress: Error from attempt_201306271950_0004_m_000001_0: java.lang.RuntimeException: PipeMapRed.waitOutputThreads(): subprocess failed with code 4


[hadoop@h001 hadoop]$ ./bin/hadoop jar contrib/streaming/hadoop-streaming-1.0.4.jar \
>        -input test_input \
>        -output test_out \
>        -mapper "sed '1d' | cut -f 3,4 -d , | awk 'NF'" \
>        -reducer "uniq" 
Warning: $HADOOP_HOME is deprecated.

packageJobJar: [/home/hadoop/hadoop/hadoop-data/hadoop-unjar7588201407350200593/] [] /tmp/streamjob8691001151864666898.jar tmpDir=null
13/06/27 20:47:23 INFO util.NativeCodeLoader: Loaded the native-hadoop library
13/06/27 20:47:23 WARN snappy.LoadSnappy: Snappy native library not loaded
13/06/27 20:47:23 INFO mapred.FileInputFormat: Total input paths to process : 2
13/06/27 20:47:25 INFO streaming.StreamJob: getLocalDirs(): [/home/hadoop/hadoop/hadoop-data//mapred/local]
13/06/27 20:47:25 INFO streaming.StreamJob: Running job: job_201306271950_0004
13/06/27 20:47:25 INFO streaming.StreamJob: To kill this job, run:
13/06/27 20:47:25 INFO streaming.StreamJob: /home/hadoop/hadoop/libexec/../bin/hadoop job  -Dmapred.job.tracker=h001:9001 -kill job_201306271950_0004
13/06/27 20:47:25 INFO streaming.StreamJob: Tracking URL: http://h001:50030/jobdetails.jsp?jobid=job_201306271950_0004
13/06/27 20:47:26 INFO streaming.StreamJob:  map 0%  reduce 0%
13/06/27 20:50:04 INFO streaming.StreamJob:  map 100%  reduce 100%
13/06/27 20:50:04 INFO streaming.StreamJob: To kill this job, run:
13/06/27 20:50:04 INFO streaming.StreamJob: /home/hadoop/hadoop/libexec/../bin/hadoop job  -Dmapred.job.tracker=h001:9001 -kill job_201306271950_0004
13/06/27 20:50:04 INFO streaming.StreamJob: Tracking URL: http://h001:50030/jobdetails.jsp?jobid=job_201306271950_0004
13/06/27 20:50:04 ERROR streaming.StreamJob: Job not successful. Error: # of failed Map Tasks exceeded allowed limit. FailedCount: 1. LastFailedTask: task_201306271950_0004_m_000000
13/06/27 20:50:04 INFO streaming.StreamJob: killJob...
Streaming Command Failed!
[hadoop@h001 hadoop]$ vi mapper.sh
[hadoop@h001 hadoop]$ vi mapper.sh
[hadoop@h001 hadoop]$ ./bin/hadoop jar contrib/streaming/hadoop-streaming-1.0.4.jar \
>         -file mapper.sh \
>         -input test_input \
>         -output test_output \
>         -mapper mapper.sh \
>         -reducer "uniq" 
Warning: $HADOOP_HOME is deprecated.

packageJobJar: [mapper.sh, /home/hadoop/hadoop/hadoop-data/hadoop-unjar5450442549553978340/] [] /tmp/streamjob4646283169125417488.jar tmpDir=null
13/06/27 20:52:37 INFO util.NativeCodeLoader: Loaded the native-hadoop library
13/06/27 20:52:37 WARN snappy.LoadSnappy: Snappy native library not loaded
13/06/27 20:52:37 INFO mapred.FileInputFormat: Total input paths to process : 2
13/06/27 20:52:38 INFO streaming.StreamJob: getLocalDirs(): [/home/hadoop/hadoop/hadoop-data//mapred/local]
13/06/27 20:52:38 INFO streaming.StreamJob: Running job: job_201306271950_0005
13/06/27 20:52:38 INFO streaming.StreamJob: To kill this job, run:
13/06/27 20:52:38 INFO streaming.StreamJob: /home/hadoop/hadoop/libexec/../bin/hadoop job  -Dmapred.job.tracker=h001:9001 -kill job_201306271950_0005
13/06/27 20:52:38 INFO streaming.StreamJob: Tracking URL: http://h001:50030/jobdetails.jsp?jobid=job_201306271950_0005
13/06/27 20:52:39 INFO streaming.StreamJob:  map 0%  reduce 0%
13/06/27 20:53:21 INFO streaming.StreamJob:  map 33%  reduce 0%
13/06/27 20:53:28 INFO streaming.StreamJob:  map 67%  reduce 0%
13/06/27 20:53:32 INFO streaming.StreamJob:  map 100%  reduce 0%
13/06/27 20:53:51 INFO streaming.StreamJob:  map 100%  reduce 100%
13/06/27 20:54:09 INFO streaming.StreamJob: Job complete: job_201306271950_0005
13/06/27 20:54:09 INFO streaming.StreamJob: Output: test_output
[hadoop@h001 hadoop]$ 


vi mapper.sh
sed '1d' | cut -f 3,4 -d , | awk 'NF' 

./bin/hadoop jar contrib/streaming/hadoop-streaming-1.0.4.jar \
        -file mapper.sh \
        -input test_input \
        -output test_output \
        -mapper mapper.sh \
        -reducer "uniq" 

In R

> b.time <- proc.time()

> small.ints= to.dfs(1:9000)

Warning: $HADOOP_HOME is deprecated.


13/06/27 20:02:34 INFO util.NativeCodeLoader: Loaded the native-hadoop library

13/06/27 20:02:34 INFO zlib.ZlibFactory: Successfully loaded & initialized native-zlib library

13/06/27 20:02:34 INFO compress.CodecPool: Got brand-new compressor

Warning message:

In to.dfs(1:9000) : Converting to.dfs argument to keyval with a NULL key

> result = mapreduce(input = small.ints, map = function(k,v) cbind(v,v^2))

Warning: $HADOOP_HOME is deprecated.


packageJobJar: [/tmp/RtmpMyf0SJ/rmr-local-enve0353f7e13f, /tmp/RtmpMyf0SJ/rmr-global-enve0360ef47b1, /tmp/RtmpMyf0SJ/rmr-streaming-mape035ee85bdf, /home/hadoop/hadoop/hadoop-data/hadoop-unjar3810178518057658498/] [] /tmp/streamjob3895560747262473776.jar tmpDir=null

13/06/27 20:02:47 INFO mapred.FileInputFormat: Total input paths to process : 1

13/06/27 20:02:48 INFO streaming.StreamJob: getLocalDirs(): [/home/hadoop/hadoop/hadoop-data//mapred/local]

13/06/27 20:02:48 INFO streaming.StreamJob: Running job: job_201306271950_0002

13/06/27 20:02:48 INFO streaming.StreamJob: To kill this job, run:

13/06/27 20:02:48 INFO streaming.StreamJob: /home/hadoop/hadoop/libexec/../bin/hadoop job  -Dmapred.job.tracker=h001:9001 -kill job_201306271950_0002

13/06/27 20:02:48 INFO streaming.StreamJob: Tracking URL: http://h001:50030/jobdetails.jsp?jobid=job_201306271950_0002

13/06/27 20:02:50 INFO streaming.StreamJob:  map 0%  reduce 0%

13/06/27 20:03:52 INFO streaming.StreamJob:  map 50%  reduce 0%

13/06/27 20:04:30 INFO streaming.StreamJob:  map 0%  reduce 0%

13/06/27 20:05:29 INFO streaming.StreamJob:  map 50%  reduce 0%

13/06/27 20:05:32 INFO streaming.StreamJob:  map 0%  reduce 0%

13/06/27 20:06:09 INFO streaming.StreamJob:  map 100%  reduce 100%

13/06/27 20:06:09 INFO streaming.StreamJob: To kill this job, run:

13/06/27 20:06:09 INFO streaming.StreamJob: /home/hadoop/hadoop/libexec/../bin/hadoop job  -Dmapred.job.tracker=h001:9001 -kill job_201306271950_0002

13/06/27 20:06:09 INFO streaming.StreamJob: Tracking URL: http://h001:50030/jobdetails.jsp?jobid=job_201306271950_0002

13/06/27 20:06:09 ERROR streaming.StreamJob: Job not successful. Error: # of failed Map Tasks exceeded allowed limit. FailedCount: 1. LastFailedTask: task_201306271950_0002_m_000000

13/06/27 20:06:09 INFO streaming.StreamJob: killJob...

Streaming Command Failed!

Error in mr(map = map, reduce = reduce, combine = combine, vectorized.reduce,  : 

  hadoop streaming failed with error code 1

> proc.time() - b.time

   user  system elapsed 

 22.405   3.277 225.012 




In NameNode log

013-06-27 20:02:34,792 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: 49 Total time for transactions(ms): 11Number of transactions batched in Syncs: 2 Number of syncs: 33 SyncTimes(ms): 398 

2013-06-27 20:02:34,962 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee033553de1c. blk_3967343654199383609_1413

2013-06-27 20:02:35,405 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_3967343654199383609_1413 size 18083

2013-06-27 20:02:35,416 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_3967343654199383609_1413 size 18083

2013-06-27 20:02:35,456 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee033553de1c from client DFSClient_1430788318

2013-06-27 20:02:35,457 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee033553de1c is closed by DFSClient_1430788318

2013-06-27 20:02:35,458 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_3967343654199383609_1413 size 18083

2013-06-27 20:02:47,020 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.jar. blk_-2869371385157051234_1414

2013-06-27 20:02:47,450 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-2869371385157051234_1414 size 146996

2013-06-27 20:02:47,453 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-2869371385157051234_1414 size 146996

2013-06-27 20:02:47,469 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-2869371385157051234_1414 size 146996

2013-06-27 20:02:47,480 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.jar from client DFSClient_644153167

2013-06-27 20:02:47,482 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.jar is closed by DFSClient_644153167

2013-06-27 20:02:47,490 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication for file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.jar. New replication is 10

2013-06-27 20:02:47,736 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Increasing replication for file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.split. New replication is 10

2013-06-27 20:02:47,750 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.split. blk_6618818878137927046_1415

2013-06-27 20:02:47,793 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_6618818878137927046_1415 size 207

2013-06-27 20:02:47,802 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_6618818878137927046_1415 size 207

2013-06-27 20:02:47,823 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_6618818878137927046_1415 size 207

2013-06-27 20:02:47,840 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.split from client DFSClient_644153167

2013-06-27 20:02:47,842 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.split is closed by DFSClient_644153167

2013-06-27 20:02:47,876 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.splitmetainfo. blk_-4247093428178608639_1416

2013-06-27 20:02:47,922 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-4247093428178608639_1416 size 50

2013-06-27 20:02:47,926 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-4247093428178608639_1416 size 50

2013-06-27 20:02:47,941 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-4247093428178608639_1416 size 50

2013-06-27 20:02:47,955 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.splitmetainfo from client DFSClient_644153167

2013-06-27 20:02:47,957 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.splitmetainfo is closed by DFSClient_644153167

2013-06-27 20:02:48,236 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.xml. blk_-8620936890353051651_1417

2013-06-27 20:02:48,323 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-8620936890353051651_1417 size 21847

2013-06-27 20:02:48,325 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.xml from client DFSClient_644153167

2013-06-27 20:02:48,326 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /home/hadoop/hadoop/hadoop-data/mapred/staging/hadoop/.staging/job_201306271950_0002/job.xml is closed by DFSClient_644153167

2013-06-27 20:02:48,327 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-8620936890353051651_1417 size 21847

2013-06-27 20:02:48,330 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-8620936890353051651_1417 size 21847

2013-06-27 20:02:50,065 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_logs/history/job_201306271950_0002_conf.xml. blk_295913666920800678_1419

2013-06-27 20:02:50,223 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_295913666920800678_1419 size 21848

2013-06-27 20:02:50,234 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_295913666920800678_1419 size 21848

2013-06-27 20:02:50,243 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_295913666920800678_1419 size 21848

2013-06-27 20:02:50,253 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_logs/history/job_201306271950_0002_conf.xml from client DFSClient_2037988731

2013-06-27 20:02:50,256 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_logs/history/job_201306271950_0002_conf.xml is closed by DFSClient_2037988731

2013-06-27 20:02:50,307 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /home/hadoop/hadoop/hadoop-data/mapred/system/job_201306271950_0002/jobToken. blk_434917188470974142_1420

2013-06-27 20:02:50,353 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_434917188470974142_1420 size 106

2013-06-27 20:02:50,378 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_434917188470974142_1420 size 106

2013-06-27 20:02:50,385 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_434917188470974142_1420 size 106

2013-06-27 20:02:50,387 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /home/hadoop/hadoop/hadoop-data/mapred/system/job_201306271950_0002/jobToken from client DFSClient_-56887304

2013-06-27 20:02:50,389 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /home/hadoop/hadoop/hadoop-data/mapred/system/job_201306271950_0002/jobToken is closed by DFSClient_-56887304

2013-06-27 20:03:13,120 INFO org.apache.hadoop.hdfs.StateChange: *BLOCK* NameSystem.processReport: from 192.168.73.74:50010, blocks: 243, processing time: 7 msecs

2013-06-27 20:03:43,239 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: 87 Total time for transactions(ms): 16Number of transactions batched in Syncs: 2 Number of syncs: 59 SyncTimes(ms): 686 

2013-06-27 20:03:50,555 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_0/part-00000. blk_2945146197123434012_1422

2013-06-27 20:03:53,274 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_2945146197123434012_1422 size 122

2013-06-27 20:03:53,295 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_2945146197123434012_1422 size 122

2013-06-27 20:03:53,438 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_2945146197123434012_1422 size 122

2013-06-27 20:03:53,515 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_0/part-00000 from client DFSClient_attempt_201306271950_0002_m_000000_0

2013-06-27 20:03:53,516 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_0/part-00000 is closed by DFSClient_attempt_201306271950_0002_m_000000_0

2013-06-27 20:04:01,246 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2945146197123434012 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:04:01,246 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2945146197123434012 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:04:01,247 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2945146197123434012 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:04:01,319 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_2945146197123434012_1422

2013-06-27 20:04:04,353 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_2945146197123434012_1422

2013-06-27 20:04:07,401 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_2945146197123434012_1422

2013-06-27 20:04:14,777 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_0/part-00001. blk_-8415370990019919118_1422

2013-06-27 20:04:17,114 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-8415370990019919118_1422 size 122

2013-06-27 20:04:17,116 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-8415370990019919118_1422 size 122

2013-06-27 20:04:17,188 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-8415370990019919118_1422 size 122

2013-06-27 20:04:17,191 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_0/part-00001 from client DFSClient_attempt_201306271950_0002_m_000001_0

2013-06-27 20:04:17,192 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_0/part-00001 is closed by DFSClient_attempt_201306271950_0002_m_000001_0

2013-06-27 20:04:24,985 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8415370990019919118 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:04:24,985 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8415370990019919118 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:04:24,985 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8415370990019919118 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:04:25,491 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_-8415370990019919118_1422

2013-06-27 20:04:28,516 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_-8415370990019919118_1422

2013-06-27 20:04:31,519 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_-8415370990019919118_1422

2013-06-27 20:04:34,370 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_1/part-00000. blk_3266604925054130326_1423

2013-06-27 20:04:36,280 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_3266604925054130326_1423 size 122

2013-06-27 20:04:36,472 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_3266604925054130326_1423 size 122

2013-06-27 20:04:36,488 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_3266604925054130326_1423 size 122

2013-06-27 20:04:36,502 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_1/part-00000 from client DFSClient_attempt_201306271950_0002_m_000000_1

2013-06-27 20:04:36,503 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_1/part-00000 is closed by DFSClient_attempt_201306271950_0002_m_000000_1

2013-06-27 20:04:37,197 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3266604925054130326 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:04:37,197 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3266604925054130326 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:04:37,197 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3266604925054130326 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:04:37,528 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_3266604925054130326_1423

2013-06-27 20:04:40,541 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_3266604925054130326_1423

2013-06-27 20:04:43,558 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_3266604925054130326_1423

2013-06-27 20:04:53,974 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: 99 Total time for transactions(ms): 16Number of transactions batched in Syncs: 2 Number of syncs: 69 SyncTimes(ms): 801 

2013-06-27 20:04:57,465 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_1/part-00001. blk_1487678503945234647_1424

2013-06-27 20:04:57,900 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_1487678503945234647_1424 size 122

2013-06-27 20:04:57,948 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_1487678503945234647_1424 size 122

2013-06-27 20:04:57,957 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_1487678503945234647_1424 size 122

2013-06-27 20:04:57,973 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_1/part-00001 from client DFSClient_attempt_201306271950_0002_m_000001_1

2013-06-27 20:04:57,975 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_1/part-00001 is closed by DFSClient_attempt_201306271950_0002_m_000001_1

2013-06-27 20:04:59,054 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1487678503945234647 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:04:59,335 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1487678503945234647 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:04:59,335 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1487678503945234647 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:05:01,688 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_1487678503945234647_1424

2013-06-27 20:05:04,691 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_1487678503945234647_1424

2013-06-27 20:05:07,696 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_1487678503945234647_1424

2013-06-27 20:05:12,291 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_2/part-00000. blk_-8601492449160753115_1425

2013-06-27 20:05:14,293 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-8601492449160753115_1425 size 122

2013-06-27 20:05:14,294 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-8601492449160753115_1425 size 122

2013-06-27 20:05:14,424 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-8601492449160753115_1425 size 122

2013-06-27 20:05:14,426 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_2/part-00000 from client DFSClient_attempt_201306271950_0002_m_000000_2

2013-06-27 20:05:14,427 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_2/part-00000 is closed by DFSClient_attempt_201306271950_0002_m_000000_2

2013-06-27 20:05:15,341 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8601492449160753115 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:05:15,347 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8601492449160753115 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:05:15,348 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8601492449160753115 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:05:16,754 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_-8601492449160753115_1425

2013-06-27 20:05:19,758 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_-8601492449160753115_1425

2013-06-27 20:05:22,760 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_-8601492449160753115_1425

2013-06-27 20:05:27,282 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_2/part-00001. blk_4336382202010898459_1426

2013-06-27 20:05:27,829 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_4336382202010898459_1426 size 122

2013-06-27 20:05:27,830 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_4336382202010898459_1426 size 122

2013-06-27 20:05:27,953 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_4336382202010898459_1426 size 122

2013-06-27 20:05:28,146 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_2/part-00001 from client DFSClient_attempt_201306271950_0002_m_000001_2

2013-06-27 20:05:28,148 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_2/part-00001 is closed by DFSClient_attempt_201306271950_0002_m_000001_2

2013-06-27 20:05:28,808 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_4336382202010898459 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:05:28,808 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_4336382202010898459 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:05:28,809 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_4336382202010898459 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:05:31,774 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_4336382202010898459_1426

2013-06-27 20:05:34,810 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_4336382202010898459_1426

2013-06-27 20:05:37,812 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_4336382202010898459_1426

2013-06-27 20:05:44,493 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_3/part-00000. blk_-5177021814675027927_1427

2013-06-27 20:05:45,443 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-5177021814675027927_1427 size 122

2013-06-27 20:05:45,444 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-5177021814675027927_1427 size 122

2013-06-27 20:05:45,525 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-5177021814675027927_1427 size 122

2013-06-27 20:05:45,527 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_3/part-00000 from client DFSClient_attempt_201306271950_0002_m_000000_3

2013-06-27 20:05:45,529 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000000_3/part-00000 is closed by DFSClient_attempt_201306271950_0002_m_000000_3

2013-06-27 20:05:46,681 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5177021814675027927 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:05:46,681 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5177021814675027927 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:05:46,681 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5177021814675027927 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:05:46,827 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_-5177021814675027927_1427

2013-06-27 20:05:49,832 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_-5177021814675027927_1427

2013-06-27 20:05:52,834 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_-5177021814675027927_1427

2013-06-27 20:05:53,733 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_3/part-00001. blk_-8311088233023214226_1428

2013-06-27 20:05:54,180 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_-8311088233023214226_1428 size 122

2013-06-27 20:05:54,247 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_-8311088233023214226_1428 size 122

2013-06-27 20:05:54,252 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_-8311088233023214226_1428 size 122

2013-06-27 20:05:54,255 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_3/part-00001 from client DFSClient_attempt_201306271950_0002_m_000001_3

2013-06-27 20:05:54,256 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_temporary/_attempt_201306271950_0002_m_000001_3/part-00001 is closed by DFSClient_attempt_201306271950_0002_m_000001_3

2013-06-27 20:05:54,257 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of transactions: 122 Total time for transactions(ms): 21Number of transactions batched in Syncs: 2 Number of syncs: 87 SyncTimes(ms): 1438 

2013-06-27 20:05:58,225 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Roll Edit Log from 192.168.73.72

2013-06-27 20:05:58,226 WARN org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Cannot roll edit log, edits.new files already exists in all healthy directories:

  /home/hadoop/hadoop/hdfs/name/current/edits.new

2013-06-27 20:06:06,312 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8311088233023214226 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:06:06,312 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8311088233023214226 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:06:06,313 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8311088233023214226 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:06:06,324 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2869371385157051234 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:06:06,325 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2869371385157051234 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:06:06,326 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2869371385157051234 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:06:06,326 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_6618818878137927046 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:06:06,326 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_6618818878137927046 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:06:06,326 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_6618818878137927046 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:06:06,327 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-4247093428178608639 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:06:06,327 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-4247093428178608639 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:06:06,327 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-4247093428178608639 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:06:06,328 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8620936890353051651 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:06:06,328 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8620936890353051651 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:06:06,329 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8620936890353051651 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:06:07,853 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_6618818878137927046_1415 blk_-2869371385157051234_1414 blk_-8311088233023214226_1428 blk_-4247093428178608639_1416 blk_-8620936890353051651_1417

2013-06-27 20:06:08,967 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/RtmpMyf0SJ/filee035adb6c74/_logs/history/job_201306271950_0002_1372330968345_hadoop_streamjob3895560747262473776.jar. blk_5599950019053202949_1428

2013-06-27 20:06:09,051 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.74:50010 is added to blk_5599950019053202949_1428 size 15748

2013-06-27 20:06:09,075 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.72:50010 is added to blk_5599950019053202949_1428 size 15748

2013-06-27 20:06:09,078 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 192.168.73.73:50010 is added to blk_5599950019053202949_1428 size 15748

2013-06-27 20:06:09,102 INFO org.apache.hadoop.hdfs.StateChange: Removing lease on  file /tmp/RtmpMyf0SJ/filee035adb6c74/_logs/history/job_201306271950_0002_1372330968345_hadoop_streamjob3895560747262473776.jar from client DFSClient_2037988731

2013-06-27 20:06:09,103 INFO org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/RtmpMyf0SJ/filee035adb6c74/_logs/history/job_201306271950_0002_1372330968345_hadoop_streamjob3895560747262473776.jar is closed by DFSClient_2037988731

2013-06-27 20:06:09,144 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_434917188470974142 is added to invalidSet of 192.168.73.73:50010

2013-06-27 20:06:09,145 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_434917188470974142 is added to invalidSet of 192.168.73.74:50010

2013-06-27 20:06:09,145 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_434917188470974142 is added to invalidSet of 192.168.73.72:50010

2013-06-27 20:06:10,855 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.73:50010 to delete  blk_434917188470974142_1420 blk_6618818878137927046_1415 blk_-2869371385157051234_1414 blk_-8311088233023214226_1428 blk_-4247093428178608639_1416 blk_-8620936890353051651_1417

2013-06-27 20:06:13,858 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.72:50010 to delete  blk_434917188470974142_1420

2013-06-27 20:06:16,862 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 192.168.73.74:50010 to delete  blk_434917188470974142_1420 blk_6618818878137927046_1415 blk_-2869371385157051234_1414 blk_-8311088233023214226_1428 blk_-4247093428178608639_1416 blk_-8620936890353051651_1417



In jobtracker log

2013-06-27 20:05:32,286 INFO org.apache.hadoop.mapred.JobInProgress: Choosing a failed task task_201306271950_0002_m_000001

2013-06-27 20:05:32,292 INFO org.apache.hadoop.mapred.JobTracker: Adding task (MAP) 'attempt_201306271950_0002_m_000001_3' to tip task_201306271950_0002_m_000001, for tracker 'tracker_h002:127.0.0.1/127.0.0.1:46586'

2013-06-27 20:05:32,293 INFO org.apache.hadoop.mapred.JobInProgress: Choosing data-local task task_201306271950_0002_m_000001

2013-06-27 20:05:32,294 INFO org.apache.hadoop.mapred.JobTracker: Removing task 'attempt_201306271950_0002_m_000001_2'

2013-06-27 20:05:47,666 INFO org.apache.hadoop.mapred.TaskInProgress: Error from attempt_201306271950_0002_m_000000_3: java.lang.RuntimeException: PipeMapRed.waitOutputThreads(): subprocess failed with code 1

at org.apache.hadoop.streaming.PipeMapRed.waitOutputThreads(PipeMapRed.java:362)

at org.apache.hadoop.streaming.PipeMapRed.mapRedFinished(PipeMapRed.java:576)

at org.apache.hadoop.streaming.PipeMapper.close(PipeMapper.java:135)

at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:57)

at org.apache.hadoop.streaming.PipeMapRunner.run(PipeMapRunner.java:36)

at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:436)

at org.apache.hadoop.mapred.MapTask.run(MapTask.java:372)

at org.apache.hadoop.mapred.Child$4.run(Child.java:255)

at java.security.AccessController.doPrivileged(Native Method)

at javax.security.auth.Subject.doAs(Subject.java:415)

at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1121)

at org.apache.hadoop.mapred.Child.main(Child.java:249)


2013-06-27 20:05:50,705 INFO org.apache.hadoop.mapred.TaskInProgress: TaskInProgress task_201306271950_0002_m_000000 has failed 4 times.

2013-06-27 20:05:50,707 INFO org.apache.hadoop.mapred.JobInProgress: Aborting job job_201306271950_0002

2013-06-27 20:05:50,709 INFO org.apache.hadoop.mapred.JobInProgress: Killing job 'job_201306271950_0002'

2013-06-27 20:05:50,722 INFO org.apache.hadoop.mapred.JobTracker: Adding task (JOB_CLEANUP) 'attempt_201306271950_0002_m_000002_0' to tip task_201306271950_0002_m_000002, for tracker 'tracker_h004:127.0.0.1/127.0.0.1:59316'

2013-06-27 20:05:50,743 INFO org.apache.hadoop.mapred.JobTracker: Removing task 'attempt_201306271950_0002_m_000000_3'

2013-06-27 20:05:56,666 INFO org.apache.hadoop.mapred.JobTracker: Removing task 'attempt_201306271950_0002_m_000001_3'

2013-06-27 20:06:08,946 INFO org.apache.hadoop.mapred.JobInProgress: Task 'attempt_201306271950_0002_m_000002_0' has completed task_201306271950_0002_m_000002 successfully.

2013-06-27 20:06:08,953 INFO org.apache.hadoop.mapred.JobInProgress$JobSummary: jobId=job_201306271950_0002,submitTime=1372330968345,launchTime=1372330970456,firstMapTaskLaunchTime=1372330990530,firstJobSetupTaskLaunchTime=1372330972060,firstJobCleanupTaskLaunchTime=1372331150721,finishTime=1372331168952,numMaps=2,numSlotsPerMap=1,numReduces=0,numSlotsPerReduce=1,user=hadoop,queue=default,status=FAILED,mapSlotSeconds=347,reduceSlotsSeconds=0,clusterMapCapacity=6,clusterReduceCapacity=6,jobName=streamjob3895560747262473776.jar

2013-06-27 20:06:09,115 INFO org.apache.hadoop.mapred.JobHistory: Moving file:/home/hadoop/hadoop/logs/history/job_201306271950_0002_1372330968345_hadoop_streamjob3895560747262473776.jar to file:/home/hadoop/hadoop/logs/history/done/version-1/h001_1372330234505_/2013/06/27/000000

2013-06-27 20:06:09,161 INFO org.apache.hadoop.mapred.JobTracker: Removing task 'attempt_201306271950_0002_m_000002_0'

2013-06-27 20:06:09,196 INFO org.apache.hadoop.mapred.JobHistory: Moving file:/home/hadoop/hadoop/logs/history/job_201306271950_0002_conf.xml to file:/home/hadoop/hadoop/logs/history/done/version-1/h001_1372330234505_/2013/06/27/000000

2013-06-27 20:06:09,491 INFO org.apache.hadoop.mapred.JobTracker: Killing job job_201306271950_0002

2013-06-27 20:06:11,839 INFO org.apache.hadoop.mapred.JobTracker: Removing task 'attempt_201306271950_0002_m_000003_0'