hive-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Amareshwari Sriramadasu (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (HIVE-9324) Reduce side joins failing with IOException from RowContainer.nextBlock
Date Fri, 09 Jan 2015 05:55:34 GMT

    [ https://issues.apache.org/jira/browse/HIVE-9324?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14270588#comment-14270588
] 

Amareshwari Sriramadasu edited comment on HIVE-9324 at 1/9/15 5:54 AM:
-----------------------------------------------------------------------

More task log :

{noformat}
2014-12-14 16:58:03,905 INFO org.apache.hadoop.hive.ql.exec.mr.ObjectCache: Ignoring retrieval
request: __REDUCE_PLAN__
2014-12-14 16:58:03,945 INFO org.apache.hadoop.hive.ql.log.PerfLogger: <PERFLOG method=deserializePlan
from=org.apache.hadoop.hive.ql.exec.Utilities>
2014-12-14 16:58:03,945 INFO org.apache.hadoop.hive.ql.exec.Utilities: Deserializing ReduceWork
via kryo
2014-12-14 16:58:04,987 INFO org.apache.hadoop.hive.ql.log.PerfLogger: </PERFLOG method=deserializePlan
start=1418576283945 end=1418576284987 duration=1042 from=org.apache.hadoop.hive.ql.exec.Utilities>
2014-12-14 16:58:04,988 INFO org.apache.hadoop.hive.ql.exec.mr.ObjectCache: Ignoring cache
key: __REDUCE_PLAN__
2014-12-14 16:58:05,327 INFO ExecReducer: 
<JOIN>Id =0
  <Children>
    <FS>Id =1
      <Children>
      <\Children>
      <Parent>Id = 0 null<\Parent>
    <\FS>
  <\Children>
  <Parent><\Parent>
<\JOIN>
2014-12-14 16:58:05,327 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Initializing Self
0 JOIN
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: JOIN struct<_col23:string,_col65:double,_col99:double,_col237:double,_col240:double,_col250:string,_col367:int>
totalsz = 7
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Operator 0 JOIN
initialized
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Initializing children
of 0 JOIN
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Initializing
child 1 FS
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Initializing
Self 1 FS
2014-12-14 16:58:05,394 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Operator 1 FS
initialized
2014-12-14 16:58:05,394 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Initialization
Done 1 FS
2014-12-14 16:58:05,395 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Initialization Done
0 JOIN
2014-12-14 16:58:05,401 INFO ExecReducer: ExecReducer: processing 1 rows: used memory = 242598168
2014-12-14 16:58:05,406 INFO ExecReducer: ExecReducer: processing 10 rows: used memory = 242759392
2014-12-14 16:58:05,437 INFO ExecReducer: ExecReducer: processing 100 rows: used memory =
242759392
2014-12-14 16:58:05,657 INFO ExecReducer: ExecReducer: processing 1000 rows: used memory =
243653240
2014-12-14 16:58:06,976 INFO ExecReducer: ExecReducer: processing 10000 rows: used memory
= 247197944
2014-12-14 16:58:07,646 INFO ExecReducer: ExecReducer: processing 100000 rows: used memory
= 277801256
2014-12-14 16:58:11,511 INFO ExecReducer: ExecReducer: processing 1000000 rows: used memory
= 283150744
2014-12-14 16:58:14,993 INFO ExecReducer: ExecReducer: processing 2000000 rows: used memory
= 293036992
2014-12-14 16:58:18,497 INFO ExecReducer: ExecReducer: processing 3000000 rows: used memory
= 311449488
2014-12-14 16:58:20,815 INFO ExecReducer: ExecReducer: processing 4000000 rows: used memory
= 285251752
2014-12-14 16:58:26,460 INFO ExecReducer: ExecReducer: processing 5000000 rows: used memory
= 328223864
2014-12-14 16:58:29,412 INFO ExecReducer: ExecReducer: processing 6000000 rows: used memory
= 263175576
2014-12-14 16:58:31,331 INFO ExecReducer: ExecReducer: processing 7000000 rows: used memory
= 282021320
2014-12-14 16:58:35,099 INFO ExecReducer: ExecReducer: processing 8000000 rows: used memory
= 299301184
2014-12-14 16:58:37,981 INFO ExecReducer: ExecReducer: processing 9000000 rows: used memory
= 306925648
2014-12-14 16:58:40,506 INFO ExecReducer: ExecReducer: processing 10000000 rows: used memory
= 307407920
2014-12-14 16:58:42,242 INFO ExecReducer: ExecReducer: processing 11000000 rows: used memory
= 304664048
2014-12-14 16:58:46,142 INFO ExecReducer: ExecReducer: processing 12000000 rows: used memory
= 298347024
2014-12-14 16:58:48,549 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [003b9de7876541c2bcce9029ff0d3873]
2014-12-14 16:58:48,622 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [003b9de7876541c2bcce9029ff0d3873]
2014-12-14 16:58:48,677 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [003b9de7876541c2bcce9029ff0d3873]
2014-12-14 16:58:48,679 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Final Path:
FS hdfs://test-machine:8020/tmp/hive-dataqa/hive_2014-12-14_16-49-14_996_1630664550753106415-32/_tmp.-mr-10002/000000_0
2014-12-14 16:58:48,680 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Writing to temp
file: FS hdfs://test-machine:8020/tmp/hive-dataqa/hive_2014-12-14_16-49-14_996_1630664550753106415-32/_task_tmp.-mr-10002/_tmp.000000_0
2014-12-14 16:58:48,680 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: New Final Path:
FS hdfs://test-machine:8020/tmp/hive-dataqa/hive_2014-12-14_16-49-14_996_1630664550753106415-32/_tmp.-mr-10002/000000_0
2014-12-14 16:58:49,620 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [00729c21c3bf4f4e9e1482da36444110]
2014-12-14 16:58:49,626 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [00729c21c3bf4f4e9e1482da36444110]
2014-12-14 16:58:49,827 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:49,848 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:49,896 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:49,979 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
8000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:50,339 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [0396225019a047b09469171877207c53]
2014-12-14 16:58:50,341 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [0396225019a047b09469171877207c53]
2014-12-14 16:58:50,396 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [040b5ed4eea348cfbd83b1c92648654b]
2014-12-14 16:58:50,431 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [04eb04e3947244099d88df950db9d1da]
2014-12-14 16:58:50,450 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [04eb04e3947244099d88df950db9d1da]
2014-12-14 16:58:50,483 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,485 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,489 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,496 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
8000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,611 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [08829d0f49874ddda9f5fb3cf72a8983]
2014-12-14 16:58:50,613 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [08829d0f49874ddda9f5fb3cf72a8983]
2014-12-14 16:58:50,684 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [0b26c249f77a470eb5158a0aa0bcfde3]
2014-12-14 16:58:50,686 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [0b26c249f77a470eb5158a0aa0bcfde3]
2014-12-14 16:58:50,690 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [0b26c249f77a470eb5158a0aa0bcfde3]
2014-12-14 16:58:50,733 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [0ce237b24173426595c90107f0922265]
2014-12-14 16:58:50,735 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [0ce237b24173426595c90107f0922265]
2014-12-14 16:58:50,784 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [129a3aff8c9941e79181954c88dfd42a]
2014-12-14 16:58:50,797 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [1346b3be4d764b35ba94aebd07f9151d]
2014-12-14 16:58:50,812 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,816 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,821 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,830 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
8000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,847 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
16000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,866 INFO org.apache.hadoop.hive.ql.exec.persistence.RowContainer: RowContainer
created temp file /data0/hadoop/mapred/local/taskTracker/test/jobcache/job_201411270515_0443/attempt_201411270515_0443_r_000000_0/work/tmp/hive-rowcontainer6700226405284000754/RowContainer6659702872024238761.tmp
2014-12-14 16:58:51,025 INFO org.apache.hadoop.mapred.FileInputFormat: Total input paths to
process : 42
2014-12-14 16:58:51,276 INFO org.apache.hadoop.io.compress.CodecPool: Got brand-new decompressor
[.gz]
2014-12-14 16:58:51,296 ERROR org.apache.hadoop.hive.ql.exec.persistence.RowContainer: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should
read 27264
	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:416)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
	at org.apache.hadoop.mapred.Child.main(Child.java:262)
2014-12-14 16:58:51,334 FATAL ExecReducer: org.apache.hadoop.hive.ql.metadata.HiveException:
org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:237)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:416)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
	at org.apache.hadoop.mapred.Child.main(Child.java:262)
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:385)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
	... 12 more
Caused by: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read
1 bytes, should read 27264
	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
	... 13 more

2014-12-14 16:58:51,337 INFO org.apache.hadoop.mapred.TaskLogsTruncater: Initializing logs'
truncater with mapRetainSize=-1 and reduceRetainSize=-1
2014-12-14 16:58:51,340 WARN org.apache.hadoop.mapred.Child: Error running child
java.lang.RuntimeException: org.apache.hadoop.hive.ql.metadata.HiveException: org.apache.hadoop.hive.ql.metadata.HiveException:
java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should
read 27264
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:283)
	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:416)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
	at org.apache.hadoop.mapred.Child.main(Child.java:262)
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: org.apache.hadoop.hive.ql.metadata.HiveException:
java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should
read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:237)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
	... 7 more
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:385)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
	... 12 more
Caused by: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read
1 bytes, should read 27264
	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
	... 13 more
2014-12-14 16:58:51,343 INFO org.apache.hadoop.mapred.Task: Runnning cleanup for the task
{noformat}


was (Author: amareshwari):
More task log :

{noformat}
2014-12-14 16:58:03,905 INFO org.apache.hadoop.hive.ql.exec.mr.ObjectCache: Ignoring retrieval
request: __REDUCE_PLAN__
2014-12-14 16:58:03,945 INFO org.apache.hadoop.hive.ql.log.PerfLogger: <PERFLOG method=deserializePlan
from=org.apache.hadoop.hive.ql.exec.Utilities>
2014-12-14 16:58:03,945 INFO org.apache.hadoop.hive.ql.exec.Utilities: Deserializing ReduceWork
via kryo
2014-12-14 16:58:04,987 INFO org.apache.hadoop.hive.ql.log.PerfLogger: </PERFLOG method=deserializePlan
start=1418576283945 end=1418576284987 duration=1042 from=org.apache.hadoop.hive.ql.exec.Utilities>
2014-12-14 16:58:04,988 INFO org.apache.hadoop.hive.ql.exec.mr.ObjectCache: Ignoring cache
key: __REDUCE_PLAN__
2014-12-14 16:58:05,327 INFO ExecReducer: 
<JOIN>Id =0
  <Children>
    <FS>Id =1
      <Children>
      <\Children>
      <Parent>Id = 0 null<\Parent>
    <\FS>
  <\Children>
  <Parent><\Parent>
<\JOIN>
2014-12-14 16:58:05,327 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Initializing Self
0 JOIN
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: JOIN struct<_col23:string,_col65:double,_col99:double,_col237:double,_col240:double,_col250:string,_col367:int>
totalsz = 7
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Operator 0 JOIN
initialized
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Initializing children
of 0 JOIN
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Initializing
child 1 FS
2014-12-14 16:58:05,377 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Initializing
Self 1 FS
2014-12-14 16:58:05,394 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Operator 1 FS
initialized
2014-12-14 16:58:05,394 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Initialization
Done 1 FS
2014-12-14 16:58:05,395 INFO org.apache.hadoop.hive.ql.exec.JoinOperator: Initialization Done
0 JOIN
2014-12-14 16:58:05,401 INFO ExecReducer: ExecReducer: processing 1 rows: used memory = 242598168
2014-12-14 16:58:05,406 INFO ExecReducer: ExecReducer: processing 10 rows: used memory = 242759392
2014-12-14 16:58:05,437 INFO ExecReducer: ExecReducer: processing 100 rows: used memory =
242759392
2014-12-14 16:58:05,657 INFO ExecReducer: ExecReducer: processing 1000 rows: used memory =
243653240
2014-12-14 16:58:06,976 INFO ExecReducer: ExecReducer: processing 10000 rows: used memory
= 247197944
2014-12-14 16:58:07,646 INFO ExecReducer: ExecReducer: processing 100000 rows: used memory
= 277801256
2014-12-14 16:58:11,511 INFO ExecReducer: ExecReducer: processing 1000000 rows: used memory
= 283150744
2014-12-14 16:58:14,993 INFO ExecReducer: ExecReducer: processing 2000000 rows: used memory
= 293036992
2014-12-14 16:58:18,497 INFO ExecReducer: ExecReducer: processing 3000000 rows: used memory
= 311449488
2014-12-14 16:58:20,815 INFO ExecReducer: ExecReducer: processing 4000000 rows: used memory
= 285251752
2014-12-14 16:58:26,460 INFO ExecReducer: ExecReducer: processing 5000000 rows: used memory
= 328223864
2014-12-14 16:58:29,412 INFO ExecReducer: ExecReducer: processing 6000000 rows: used memory
= 263175576
2014-12-14 16:58:31,331 INFO ExecReducer: ExecReducer: processing 7000000 rows: used memory
= 282021320
2014-12-14 16:58:35,099 INFO ExecReducer: ExecReducer: processing 8000000 rows: used memory
= 299301184
2014-12-14 16:58:37,981 INFO ExecReducer: ExecReducer: processing 9000000 rows: used memory
= 306925648
2014-12-14 16:58:40,506 INFO ExecReducer: ExecReducer: processing 10000000 rows: used memory
= 307407920
2014-12-14 16:58:42,242 INFO ExecReducer: ExecReducer: processing 11000000 rows: used memory
= 304664048
2014-12-14 16:58:46,142 INFO ExecReducer: ExecReducer: processing 12000000 rows: used memory
= 298347024
2014-12-14 16:58:48,549 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [003b9de7876541c2bcce9029ff0d3873]
2014-12-14 16:58:48,622 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [003b9de7876541c2bcce9029ff0d3873]
2014-12-14 16:58:48,677 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [003b9de7876541c2bcce9029ff0d3873]
2014-12-14 16:58:48,679 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Final Path:
FS hdfs://data-grill300-null.arshad.ev1.inmobi.com:8020/tmp/hive-dataqa/hive_2014-12-14_16-49-14_996_1630664550753106415-32/_tmp.-mr-10002/000000_0
2014-12-14 16:58:48,680 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: Writing to temp
file: FS hdfs://data-grill300-null.arshad.ev1.inmobi.com:8020/tmp/hive-dataqa/hive_2014-12-14_16-49-14_996_1630664550753106415-32/_task_tmp.-mr-10002/_tmp.000000_0
2014-12-14 16:58:48,680 INFO org.apache.hadoop.hive.ql.exec.FileSinkOperator: New Final Path:
FS hdfs://data-grill300-null.arshad.ev1.inmobi.com:8020/tmp/hive-dataqa/hive_2014-12-14_16-49-14_996_1630664550753106415-32/_tmp.-mr-10002/000000_0
2014-12-14 16:58:49,620 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [00729c21c3bf4f4e9e1482da36444110]
2014-12-14 16:58:49,626 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [00729c21c3bf4f4e9e1482da36444110]
2014-12-14 16:58:49,827 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:49,848 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:49,896 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:49,979 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
8000 rows for join key [009fdcb880ea42669189cdf23770d694]
2014-12-14 16:58:50,339 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [0396225019a047b09469171877207c53]
2014-12-14 16:58:50,341 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [0396225019a047b09469171877207c53]
2014-12-14 16:58:50,396 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [040b5ed4eea348cfbd83b1c92648654b]
2014-12-14 16:58:50,431 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [04eb04e3947244099d88df950db9d1da]
2014-12-14 16:58:50,450 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [04eb04e3947244099d88df950db9d1da]
2014-12-14 16:58:50,483 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,485 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,489 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,496 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
8000 rows for join key [07a822d85c214d7fbecef2deb10e8a0c]
2014-12-14 16:58:50,611 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [08829d0f49874ddda9f5fb3cf72a8983]
2014-12-14 16:58:50,613 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [08829d0f49874ddda9f5fb3cf72a8983]
2014-12-14 16:58:50,684 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [0b26c249f77a470eb5158a0aa0bcfde3]
2014-12-14 16:58:50,686 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [0b26c249f77a470eb5158a0aa0bcfde3]
2014-12-14 16:58:50,690 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [0b26c249f77a470eb5158a0aa0bcfde3]
2014-12-14 16:58:50,733 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [0ce237b24173426595c90107f0922265]
2014-12-14 16:58:50,735 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [0ce237b24173426595c90107f0922265]
2014-12-14 16:58:50,784 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [129a3aff8c9941e79181954c88dfd42a]
2014-12-14 16:58:50,797 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [1346b3be4d764b35ba94aebd07f9151d]
2014-12-14 16:58:50,812 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
1000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,816 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
2000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,821 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
4000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,830 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
8000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,847 INFO org.apache.hadoop.hive.ql.exec.CommonJoinOperator: table 0 has
16000 rows for join key [149564f947b543af84f1e439c572c6d8]
2014-12-14 16:58:50,866 INFO org.apache.hadoop.hive.ql.exec.persistence.RowContainer: RowContainer
created temp file /data0/hadoop/mapred/local/taskTracker/test/jobcache/job_201411270515_0443/attempt_201411270515_0443_r_000000_0/work/tmp/hive-rowcontainer6700226405284000754/RowContainer6659702872024238761.tmp
2014-12-14 16:58:51,025 INFO org.apache.hadoop.mapred.FileInputFormat: Total input paths to
process : 42
2014-12-14 16:58:51,276 INFO org.apache.hadoop.io.compress.CodecPool: Got brand-new decompressor
[.gz]
2014-12-14 16:58:51,296 ERROR org.apache.hadoop.hive.ql.exec.persistence.RowContainer: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should
read 27264
	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:416)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
	at org.apache.hadoop.mapred.Child.main(Child.java:262)
2014-12-14 16:58:51,334 FATAL ExecReducer: org.apache.hadoop.hive.ql.metadata.HiveException:
org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:237)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:416)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
	at org.apache.hadoop.mapred.Child.main(Child.java:262)
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:385)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
	... 12 more
Caused by: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read
1 bytes, should read 27264
	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
	... 13 more

2014-12-14 16:58:51,337 INFO org.apache.hadoop.mapred.TaskLogsTruncater: Initializing logs'
truncater with mapRetainSize=-1 and reduceRetainSize=-1
2014-12-14 16:58:51,340 WARN org.apache.hadoop.mapred.Child: Error running child
java.lang.RuntimeException: org.apache.hadoop.hive.ql.metadata.HiveException: org.apache.hadoop.hive.ql.metadata.HiveException:
java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should
read 27264
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:283)
	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:416)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
	at org.apache.hadoop.mapred.Child.main(Child.java:262)
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: org.apache.hadoop.hive.ql.metadata.HiveException:
java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should
read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:237)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
	... 7 more
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:385)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
	... 12 more
Caused by: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read
1 bytes, should read 27264
	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
	... 13 more
2014-12-14 16:58:51,343 INFO org.apache.hadoop.mapred.Task: Runnning cleanup for the task
{noformat}

> Reduce side joins failing with IOException from RowContainer.nextBlock
> ----------------------------------------------------------------------
>
>                 Key: HIVE-9324
>                 URL: https://issues.apache.org/jira/browse/HIVE-9324
>             Project: Hive
>          Issue Type: Bug
>          Components: Query Processor
>    Affects Versions: 0.13.1
>            Reporter: Amareshwari Sriramadasu
>
> We are seeing some reduce side join mapreduce jobs failing with following exception :
> {noformat}
> 2014-12-14 16:58:51,296 ERROR org.apache.hadoop.hive.ql.exec.persistence.RowContainer:
org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes, should read 27264
> java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8 read 1 bytes,
should read 27264
> 	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
> 	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
> 	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
> 	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
> 	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
> 	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
> 	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
> 	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
> 	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
> 	at java.security.AccessController.doPrivileged(Native Method)
> 	at javax.security.auth.Subject.doAs(Subject.java:416)
> 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
> 	at org.apache.hadoop.mapred.Child.main(Child.java:262)
> 2014-12-14 16:58:51,334 FATAL ExecReducer: org.apache.hadoop.hive.ql.metadata.HiveException:
org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:237)
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:74)
> 	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.genUniqueJoinObject(CommonJoinOperator.java:644)
> 	at org.apache.hadoop.hive.ql.exec.CommonJoinOperator.checkAndGenObject(CommonJoinOperator.java:758)
> 	at org.apache.hadoop.hive.ql.exec.JoinOperator.endGroup(JoinOperator.java:256)
> 	at org.apache.hadoop.hive.ql.exec.mr.ExecReducer.reduce(ExecReducer.java:216)
> 	at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:506)
> 	at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:447)
> 	at org.apache.hadoop.mapred.Child$4.run(Child.java:268)
> 	at java.security.AccessController.doPrivileged(Native Method)
> 	at javax.security.auth.Subject.doAs(Subject.java:416)
> 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1408)
> 	at org.apache.hadoop.mapred.Child.main(Child.java:262)
> Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:385)
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.first(RowContainer.java:230)
> 	... 12 more
> Caused by: java.io.IOException: org.apache.hadoop.hive.ql.io.RCFile$KeyBuffer@42610e8
read 1 bytes, should read 27264
> 	at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2435)
> 	at org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:76)
> 	at org.apache.hadoop.hive.ql.exec.persistence.RowContainer.nextBlock(RowContainer.java:360)
> 	... 13 more
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message