[
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)
