You are viewing a plain text version of this content. The canonical link for it is here.
Posted to hdfs-user@hadoop.apache.org by s2323 <s2...@land.ru> on 2013/01/23 10:39:56 UTC

EOF when Combiner works

Hi!

When I run job with this options:
  -Dmapred.map.child.java.opts=-Xmx2048M
  -Dio.sort.mb=1424
  -Dio.sort.record.percent=0.08
all tasks fails on combiner step with:

...
2013-01-23 12:20:28,143 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb = 1424
2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: data buffer = 1098974720/1373718448
2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: record buffer = 5972689/7465861
2013-01-23 12:23:03,790 INFO com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
2013-01-23 12:23:03,792 INFO com.hadoop.compression.lzo.LzoCodec: Successfully loaded & initialized native-lzo library [hadoop-lzo rev Unknown build revision]
2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: Spilling map output: buffer full= true
2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: bufstart = 0; bufend = 1098974551; bufvoid = 1373718448
2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: kvstart = 0; kvend = 5661226; length = 7465861
2013-01-23 12:52:01,389 INFO org.apache.hadoop.io.compress.CodecPool: Got brand-new compressor
2013-01-23 12:52:02,526 INFO org.apache.hadoop.mapred.TaskLogsTruncater: Initializing logs' truncater with mapRetainSize=-1 and reduceRetainSize=-1
2013-01-23 12:52:02,528 ERROR org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException as:user (auth:SIMPLE) cause:java.io.IOException: Spill failed
2013-01-23 12:52:02,529 WARN org.apache.hadoop.mapred.Child: Error running child
java.io.IOException: Spill failed
	at org.apache.hadoop.mapred.MapTask$MapOutputBuffer.collect(MapTask.java:886)
	at org.apache.hadoop.mapred.MapTask$NewOutputCollector.write(MapTask.java:574)
	at org.apache.hadoop.mapreduce.TaskInputOutputContext.write(TaskInputOutputContext.java:80)
	at my.mapreduce.StatisticsHostMapper.calculateCounters(StatisticsHostMapper.java:104)
	at my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:116)
	at my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:1)
	at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:144)
	at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:647)
	at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:266)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:396)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1278)
	at org.apache.hadoop.mapred.Child.main(Child.java:260)
Caused by: java.lang.RuntimeException: next value iterator failed
	at org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:166)
	at my.mapreduce.HostCounters.calculate(HostCounters.java:147)
	at my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:17)
	at my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:1)
	at org.apache.hadoop.mapreduce.Reducer.run(Reducer.java:176)
	at org.apache.hadoop.mapred.Task$NewCombinerRunner.combine(Task.java:1445)
	at org.apache.hadoop.mapred.MapTask$MapOutputBuffer.sortAndSpill(MapTask.java:1291)
	at org.apache.hadoop.mapred.MapTask$MapOutputBuffer.access$1800(MapTask.java:712)
	at org.apache.hadoop.mapred.MapTask$MapOutputBuffer$SpillThread.run(MapTask.java:1199)
Caused by: java.io.EOFException
	at java.io.DataInputStream.readFully(DataInputStream.java:180)
	at java.io.DataInputStream.readLong(DataInputStream.java:399)
	at my.mapreduce.HostCounters.readFields(HostCounters.java:54)
	at org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:67)
	at org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:40)
	at org.apache.hadoop.mapreduce.ReduceContext.nextKeyValue(ReduceContext.java:116)
	at org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:163)
	... 8 more
2013-01-23 12:52:02,578 INFO org.apache.hadoop.mapred.Task: Runnning cleanup for the task




When I run the same task with this options:
  -Dmapred.map.child.java.opts=-Xmx2048M
  -Dio.sort.mb=1024
  -Dio.sort.record.percent=0.08
everything is OK:

...
2013-01-23 13:01:46,168 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb = 1024
2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: data buffer = 790273984/987842480
2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: record buffer = 4294967/5368709
2013-01-23 13:01:47,602 INFO com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
2013-01-23 13:01:47,621 INFO com.hadoop.compression.lzo.LzoCodec: Successfully loaded & initialized native-lzo library [hadoop-lzo rev Unknown build revision]
2013-01-23 13:28:42,168 INFO org.apache.hadoop.mapred.MapTask: Spilling map output: buffer full= true
2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: bufstart = 0; bufend = 790273835; bufvoid = 987842480
2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: kvstart = 0; kvend = 4072970; length = 5368709
2013-01-23 13:28:56,417 INFO org.apache.hadoop.io.compress.CodecPool: Got brand-new compressor
2013-01-23 13:29:18,998 INFO org.apache.hadoop.mapred.MapTask: Finished spill 0
...


Please help me to understand the reason of task fails.

Re: EOF when Combiner works

Posted by Harsh J <ha...@cloudera.com>.
Can you add in what exactly is your combiner logic performing?


On Wed, Jan 23, 2013 at 3:09 PM, s2323 <s2...@land.ru> wrote:

> Hi!
>
> When I run job with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1424
>   -Dio.sort.record.percent=0.08
> all tasks fails on combiner step with:
>
> ...
> 2013-01-23 12:20:28,143 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1424
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 1098974720/1373718448
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 5972689/7465861
> 2013-01-23 12:23:03,790 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 12:23:03,792 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 1098974551; bufvoid = 1373718448
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 5661226; length = 7465861
> 2013-01-23 12:52:01,389 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 12:52:02,526 INFO org.apache.hadoop.mapred.TaskLogsTruncater:
> Initializing logs' truncater with mapRetainSize=-1 and reduceRetainSize=-1
> 2013-01-23 12:52:02,528 ERROR
> org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
> as:user (auth:SIMPLE) cause:java.io.IOException: Spill failed
> 2013-01-23 12:52:02,529 WARN org.apache.hadoop.mapred.Child: Error running
> child
> java.io.IOException: Spill failed
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.collect(MapTask.java:886)
>         at
> org.apache.hadoop.mapred.MapTask$NewOutputCollector.write(MapTask.java:574)
>         at
> org.apache.hadoop.mapreduce.TaskInputOutputContext.write(TaskInputOutputContext.java:80)
>         at
> my.mapreduce.StatisticsHostMapper.calculateCounters(StatisticsHostMapper.java:104)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:116)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:1)
>         at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:144)
>         at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:647)
>         at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323)
>         at org.apache.hadoop.mapred.Child$4.run(Child.java:266)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:396)
>         at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1278)
>         at org.apache.hadoop.mapred.Child.main(Child.java:260)
> Caused by: java.lang.RuntimeException: next value iterator failed
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:166)
>         at my.mapreduce.HostCounters.calculate(HostCounters.java:147)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:17)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:1)
>         at org.apache.hadoop.mapreduce.Reducer.run(Reducer.java:176)
>         at
> org.apache.hadoop.mapred.Task$NewCombinerRunner.combine(Task.java:1445)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.sortAndSpill(MapTask.java:1291)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.access$1800(MapTask.java:712)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer$SpillThread.run(MapTask.java:1199)
> Caused by: java.io.EOFException
>         at java.io.DataInputStream.readFully(DataInputStream.java:180)
>         at java.io.DataInputStream.readLong(DataInputStream.java:399)
>         at my.mapreduce.HostCounters.readFields(HostCounters.java:54)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:67)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:40)
>         at
> org.apache.hadoop.mapreduce.ReduceContext.nextKeyValue(ReduceContext.java:116)
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:163)
>         ... 8 more
> 2013-01-23 12:52:02,578 INFO org.apache.hadoop.mapred.Task: Runnning
> cleanup for the task
>
>
>
>
> When I run the same task with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1024
>   -Dio.sort.record.percent=0.08
> everything is OK:
>
> ...
> 2013-01-23 13:01:46,168 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1024
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 790273984/987842480
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 4294967/5368709
> 2013-01-23 13:01:47,602 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 13:01:47,621 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 13:28:42,168 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 790273835; bufvoid = 987842480
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 4072970; length = 5368709
> 2013-01-23 13:28:56,417 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 13:29:18,998 INFO org.apache.hadoop.mapred.MapTask: Finished
> spill 0
> ...
>
>
> Please help me to understand the reason of task fails.
>



-- 
Harsh J

Re: EOF when Combiner works

Posted by Harsh J <ha...@cloudera.com>.
Can you add in what exactly is your combiner logic performing?


On Wed, Jan 23, 2013 at 3:09 PM, s2323 <s2...@land.ru> wrote:

> Hi!
>
> When I run job with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1424
>   -Dio.sort.record.percent=0.08
> all tasks fails on combiner step with:
>
> ...
> 2013-01-23 12:20:28,143 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1424
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 1098974720/1373718448
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 5972689/7465861
> 2013-01-23 12:23:03,790 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 12:23:03,792 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 1098974551; bufvoid = 1373718448
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 5661226; length = 7465861
> 2013-01-23 12:52:01,389 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 12:52:02,526 INFO org.apache.hadoop.mapred.TaskLogsTruncater:
> Initializing logs' truncater with mapRetainSize=-1 and reduceRetainSize=-1
> 2013-01-23 12:52:02,528 ERROR
> org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
> as:user (auth:SIMPLE) cause:java.io.IOException: Spill failed
> 2013-01-23 12:52:02,529 WARN org.apache.hadoop.mapred.Child: Error running
> child
> java.io.IOException: Spill failed
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.collect(MapTask.java:886)
>         at
> org.apache.hadoop.mapred.MapTask$NewOutputCollector.write(MapTask.java:574)
>         at
> org.apache.hadoop.mapreduce.TaskInputOutputContext.write(TaskInputOutputContext.java:80)
>         at
> my.mapreduce.StatisticsHostMapper.calculateCounters(StatisticsHostMapper.java:104)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:116)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:1)
>         at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:144)
>         at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:647)
>         at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323)
>         at org.apache.hadoop.mapred.Child$4.run(Child.java:266)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:396)
>         at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1278)
>         at org.apache.hadoop.mapred.Child.main(Child.java:260)
> Caused by: java.lang.RuntimeException: next value iterator failed
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:166)
>         at my.mapreduce.HostCounters.calculate(HostCounters.java:147)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:17)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:1)
>         at org.apache.hadoop.mapreduce.Reducer.run(Reducer.java:176)
>         at
> org.apache.hadoop.mapred.Task$NewCombinerRunner.combine(Task.java:1445)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.sortAndSpill(MapTask.java:1291)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.access$1800(MapTask.java:712)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer$SpillThread.run(MapTask.java:1199)
> Caused by: java.io.EOFException
>         at java.io.DataInputStream.readFully(DataInputStream.java:180)
>         at java.io.DataInputStream.readLong(DataInputStream.java:399)
>         at my.mapreduce.HostCounters.readFields(HostCounters.java:54)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:67)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:40)
>         at
> org.apache.hadoop.mapreduce.ReduceContext.nextKeyValue(ReduceContext.java:116)
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:163)
>         ... 8 more
> 2013-01-23 12:52:02,578 INFO org.apache.hadoop.mapred.Task: Runnning
> cleanup for the task
>
>
>
>
> When I run the same task with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1024
>   -Dio.sort.record.percent=0.08
> everything is OK:
>
> ...
> 2013-01-23 13:01:46,168 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1024
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 790273984/987842480
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 4294967/5368709
> 2013-01-23 13:01:47,602 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 13:01:47,621 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 13:28:42,168 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 790273835; bufvoid = 987842480
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 4072970; length = 5368709
> 2013-01-23 13:28:56,417 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 13:29:18,998 INFO org.apache.hadoop.mapred.MapTask: Finished
> spill 0
> ...
>
>
> Please help me to understand the reason of task fails.
>



-- 
Harsh J

Re: EOF when Combiner works

Posted by Harsh J <ha...@cloudera.com>.
Can you add in what exactly is your combiner logic performing?


On Wed, Jan 23, 2013 at 3:09 PM, s2323 <s2...@land.ru> wrote:

> Hi!
>
> When I run job with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1424
>   -Dio.sort.record.percent=0.08
> all tasks fails on combiner step with:
>
> ...
> 2013-01-23 12:20:28,143 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1424
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 1098974720/1373718448
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 5972689/7465861
> 2013-01-23 12:23:03,790 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 12:23:03,792 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 1098974551; bufvoid = 1373718448
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 5661226; length = 7465861
> 2013-01-23 12:52:01,389 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 12:52:02,526 INFO org.apache.hadoop.mapred.TaskLogsTruncater:
> Initializing logs' truncater with mapRetainSize=-1 and reduceRetainSize=-1
> 2013-01-23 12:52:02,528 ERROR
> org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
> as:user (auth:SIMPLE) cause:java.io.IOException: Spill failed
> 2013-01-23 12:52:02,529 WARN org.apache.hadoop.mapred.Child: Error running
> child
> java.io.IOException: Spill failed
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.collect(MapTask.java:886)
>         at
> org.apache.hadoop.mapred.MapTask$NewOutputCollector.write(MapTask.java:574)
>         at
> org.apache.hadoop.mapreduce.TaskInputOutputContext.write(TaskInputOutputContext.java:80)
>         at
> my.mapreduce.StatisticsHostMapper.calculateCounters(StatisticsHostMapper.java:104)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:116)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:1)
>         at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:144)
>         at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:647)
>         at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323)
>         at org.apache.hadoop.mapred.Child$4.run(Child.java:266)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:396)
>         at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1278)
>         at org.apache.hadoop.mapred.Child.main(Child.java:260)
> Caused by: java.lang.RuntimeException: next value iterator failed
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:166)
>         at my.mapreduce.HostCounters.calculate(HostCounters.java:147)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:17)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:1)
>         at org.apache.hadoop.mapreduce.Reducer.run(Reducer.java:176)
>         at
> org.apache.hadoop.mapred.Task$NewCombinerRunner.combine(Task.java:1445)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.sortAndSpill(MapTask.java:1291)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.access$1800(MapTask.java:712)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer$SpillThread.run(MapTask.java:1199)
> Caused by: java.io.EOFException
>         at java.io.DataInputStream.readFully(DataInputStream.java:180)
>         at java.io.DataInputStream.readLong(DataInputStream.java:399)
>         at my.mapreduce.HostCounters.readFields(HostCounters.java:54)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:67)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:40)
>         at
> org.apache.hadoop.mapreduce.ReduceContext.nextKeyValue(ReduceContext.java:116)
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:163)
>         ... 8 more
> 2013-01-23 12:52:02,578 INFO org.apache.hadoop.mapred.Task: Runnning
> cleanup for the task
>
>
>
>
> When I run the same task with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1024
>   -Dio.sort.record.percent=0.08
> everything is OK:
>
> ...
> 2013-01-23 13:01:46,168 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1024
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 790273984/987842480
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 4294967/5368709
> 2013-01-23 13:01:47,602 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 13:01:47,621 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 13:28:42,168 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 790273835; bufvoid = 987842480
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 4072970; length = 5368709
> 2013-01-23 13:28:56,417 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 13:29:18,998 INFO org.apache.hadoop.mapred.MapTask: Finished
> spill 0
> ...
>
>
> Please help me to understand the reason of task fails.
>



-- 
Harsh J

Re: EOF when Combiner works

Posted by Harsh J <ha...@cloudera.com>.
Can you add in what exactly is your combiner logic performing?


On Wed, Jan 23, 2013 at 3:09 PM, s2323 <s2...@land.ru> wrote:

> Hi!
>
> When I run job with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1424
>   -Dio.sort.record.percent=0.08
> all tasks fails on combiner step with:
>
> ...
> 2013-01-23 12:20:28,143 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1424
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 1098974720/1373718448
> 2013-01-23 12:23:03,772 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 5972689/7465861
> 2013-01-23 12:23:03,790 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 12:23:03,792 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 1098974551; bufvoid = 1373718448
> 2013-01-23 12:51:47,211 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 5661226; length = 7465861
> 2013-01-23 12:52:01,389 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 12:52:02,526 INFO org.apache.hadoop.mapred.TaskLogsTruncater:
> Initializing logs' truncater with mapRetainSize=-1 and reduceRetainSize=-1
> 2013-01-23 12:52:02,528 ERROR
> org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
> as:user (auth:SIMPLE) cause:java.io.IOException: Spill failed
> 2013-01-23 12:52:02,529 WARN org.apache.hadoop.mapred.Child: Error running
> child
> java.io.IOException: Spill failed
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.collect(MapTask.java:886)
>         at
> org.apache.hadoop.mapred.MapTask$NewOutputCollector.write(MapTask.java:574)
>         at
> org.apache.hadoop.mapreduce.TaskInputOutputContext.write(TaskInputOutputContext.java:80)
>         at
> my.mapreduce.StatisticsHostMapper.calculateCounters(StatisticsHostMapper.java:104)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:116)
>         at
> my.mapreduce.StatisticsHostMapper.map(StatisticsHostMapper.java:1)
>         at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:144)
>         at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:647)
>         at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323)
>         at org.apache.hadoop.mapred.Child$4.run(Child.java:266)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:396)
>         at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1278)
>         at org.apache.hadoop.mapred.Child.main(Child.java:260)
> Caused by: java.lang.RuntimeException: next value iterator failed
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:166)
>         at my.mapreduce.HostCounters.calculate(HostCounters.java:147)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:17)
>         at
> my.mapreduce.StatisticsHostCombiner.reduce(StatisticsHostCombiner.java:1)
>         at org.apache.hadoop.mapreduce.Reducer.run(Reducer.java:176)
>         at
> org.apache.hadoop.mapred.Task$NewCombinerRunner.combine(Task.java:1445)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.sortAndSpill(MapTask.java:1291)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer.access$1800(MapTask.java:712)
>         at
> org.apache.hadoop.mapred.MapTask$MapOutputBuffer$SpillThread.run(MapTask.java:1199)
> Caused by: java.io.EOFException
>         at java.io.DataInputStream.readFully(DataInputStream.java:180)
>         at java.io.DataInputStream.readLong(DataInputStream.java:399)
>         at my.mapreduce.HostCounters.readFields(HostCounters.java:54)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:67)
>         at
> org.apache.hadoop.io.serializer.WritableSerialization$WritableDeserializer.deserialize(WritableSerialization.java:40)
>         at
> org.apache.hadoop.mapreduce.ReduceContext.nextKeyValue(ReduceContext.java:116)
>         at
> org.apache.hadoop.mapreduce.ReduceContext$ValueIterator.next(ReduceContext.java:163)
>         ... 8 more
> 2013-01-23 12:52:02,578 INFO org.apache.hadoop.mapred.Task: Runnning
> cleanup for the task
>
>
>
>
> When I run the same task with this options:
>   -Dmapred.map.child.java.opts=-Xmx2048M
>   -Dio.sort.mb=1024
>   -Dio.sort.record.percent=0.08
> everything is OK:
>
> ...
> 2013-01-23 13:01:46,168 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb
> = 1024
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: data buffer
> = 790273984/987842480
> 2013-01-23 13:01:47,593 INFO org.apache.hadoop.mapred.MapTask: record
> buffer = 4294967/5368709
> 2013-01-23 13:01:47,602 INFO
> com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library
> 2013-01-23 13:01:47,621 INFO com.hadoop.compression.lzo.LzoCodec:
> Successfully loaded & initialized native-lzo library [hadoop-lzo rev
> Unknown build revision]
> 2013-01-23 13:28:42,168 INFO org.apache.hadoop.mapred.MapTask: Spilling
> map output: buffer full= true
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: bufstart =
> 0; bufend = 790273835; bufvoid = 987842480
> 2013-01-23 13:28:42,169 INFO org.apache.hadoop.mapred.MapTask: kvstart =
> 0; kvend = 4072970; length = 5368709
> 2013-01-23 13:28:56,417 INFO org.apache.hadoop.io.compress.CodecPool: Got
> brand-new compressor
> 2013-01-23 13:29:18,998 INFO org.apache.hadoop.mapred.MapTask: Finished
> spill 0
> ...
>
>
> Please help me to understand the reason of task fails.
>



-- 
Harsh J