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