[
https://issues.apache.org/jira/browse/HIVE-15282?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15900255#comment-15900255
]
Ashutosh Chauhan commented on HIVE-15282:
-----------------------------------------
+1
> Different modification times are used when an index is built and when its
> staleness is checked
> ----------------------------------------------------------------------------------------------
>
> Key: HIVE-15282
> URL: https://issues.apache.org/jira/browse/HIVE-15282
> Project: Hive
> Issue Type: Bug
> Components: Indexing
> Affects Versions: 2.2.0
> Reporter: Marta Kuczora
> Assignee: Marta Kuczora
> Attachments: HIVE-15282.2.patch, HIVE-15282.patch
>
>
> The index_auto_mult_tables and index_auto_mult_tables_compact q tests are
> failing from time to time with the following error:
> {noformat}
> org.apache.hadoop.hive.cli.TestCliDriver.testCliDriver_index_auto_mult_tables
> Failing for the past 1 build (Since Failed#16 )
> Took 16 sec.
> Error Message
> Unexpected exception junit.framework.AssertionFailedError: Client Execution
> results failed with error code = 1
> See ./ql/target/tmp/log/hive.log or ./itests/qtest/target/tmp/log/hive.log,
> or check ./ql/target/surefire-reports or
> ./itests/qtest/target/surefire-reports/ for specific test cases logs.
> at junit.framework.Assert.fail(Assert.java:57)
> at org.apache.hadoop.hive.ql.QTestUtil.failedDiff(QTestUtil.java:2001)
> at org.apache.hadoop.hive.cli.TestCliDriver.runTest(TestCliDriver.java:194)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.testCliDriver_index_auto_mult_tables(TestCliDriver.java:142)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
> at
> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
> at
> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
> at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
> See ./ql/target/tmp/log/hive.log or ./itests/qtest/target/tmp/log/hive.log,
> or check ./ql/target/surefire-reports or
> ./itests/qtest/target/surefire-reports/ for specific test cases logs.
> Stacktrace
> junit.framework.AssertionFailedError: Unexpected exception
> junit.framework.AssertionFailedError: Client Execution results failed with
> error code = 1
> See ./ql/target/tmp/log/hive.log or ./itests/qtest/target/tmp/log/hive.log,
> or check ./ql/target/surefire-reports or
> ./itests/qtest/target/surefire-reports/ for specific test cases logs.
> at junit.framework.Assert.fail(Assert.java:57)
> at org.apache.hadoop.hive.ql.QTestUtil.failedDiff(QTestUtil.java:2001)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.runTest(TestCliDriver.java:194)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.testCliDriver_index_auto_mult_tables(TestCliDriver.java:142)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
> at
> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
> at
> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
> at
> org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
> See ./ql/target/tmp/log/hive.log or ./itests/qtest/target/tmp/log/hive.log,
> or check ./ql/target/surefire-reports or
> ./itests/qtest/target/surefire-reports/ for specific test cases logs.
> at junit.framework.Assert.fail(Assert.java:57)
> at org.apache.hadoop.hive.ql.QTestUtil.failed(QTestUtil.java:2011)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.runTest(TestCliDriver.java:198)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.testCliDriver_index_auto_mult_tables(TestCliDriver.java:142)
> Standard Output
> Running: diff -a
> /home/hiveptest/hive-ptest-cloudera-slaves-0c70-6.vpc.cloudera.com-hiveptest-1/cdh-source/itests/qtest/../../itests/qtest/target/qfile-results/clientpositive/index_auto_mult_tables.q.out
>
> /home/hiveptest/hive-ptest-cloudera-slaves-0c70-6.vpc.cloudera.com-hiveptest-1/cdh-source/itests/qtest/../../ql/src/test/results/clientpositive/index_auto_mult_tables.q.out
> 216c216,218
> < Stage-1 depends on stages: Stage-3
> ---
> > Stage-1 depends on stages: Stage-3, Stage-5
> > Stage-6 is a root stage
> > Stage-5 depends on stages: Stage-6
> 224,225c226,227
> < alias: default__src_src_index__
> < filterExpr: (((((UDFToDouble(key) > 80.0) and (UDFToDouble(key)
> < 100.0)) and (UDFToDouble(key) > 70.0)) and (UDFToDouble(key) < 90.0)) and
> (not EWAH_BITMAP_EMPTY(_bitmaps))) (type: boolean)
> ---
> > alias: default__srcpart_srcpart_index__
> > filterExpr: (((((UDFToDouble(key) > 70.0) and (UDFToDouble(key)
> > < 90.0)) and (UDFToDouble(key) > 80.0)) and (UDFToDouble(key) < 100.0)) and
> > (not EWAH_BITMAP_EMPTY(_bitmaps))) (type: boolean)
> 227c229
> < predicate: (((((UDFToDouble(key) > 80.0) and
> (UDFToDouble(key) < 100.0)) and (UDFToDouble(key) > 70.0)) and
> (UDFToDouble(key) < 90.0)) and (not EWAH_BITMAP_EMPTY(_bitmaps))) (type:
> boolean)
> ---
> > predicate: (((((UDFToDouble(key) > 70.0) and
> > (UDFToDouble(key) < 90.0)) and (UDFToDouble(key) > 80.0)) and
> > (UDFToDouble(key) < 100.0)) and (not EWAH_BITMAP_EMPTY(_bitmaps))) (type:
> > boolean)
> 316a319,358
> > Stage: Stage-6
> > Map Reduce
> > Map Operator Tree:
> > TableScan
> > alias: default__src_src_index__
> > filterExpr: (((((UDFToDouble(key) > 80.0) and (UDFToDouble(key)
> > < 100.0)) and (UDFToDouble(key) > 70.0)) and (UDFToDouble(key) < 90.0)) and
> > (not EWAH_BITMAP_EMPTY(_bitmaps))) (type: boolean)
> > Filter Operator
> > predicate: (((((UDFToDouble(key) > 80.0) and
> > (UDFToDouble(key) < 100.0)) and (UDFToDouble(key) > 70.0)) and
> > (UDFToDouble(key) < 90.0)) and (not EWAH_BITMAP_EMPTY(_bitmaps))) (type:
> > boolean)
> > Select Operator
> > expressions: _bucketname (type: string), _offset (type:
> > bigint)
> > outputColumnNames: _col0, _col1
> > Group By Operator
> > aggregations: collect_set(_col1)
> > keys: _col0 (type: string)
> > mode: hash
> > outputColumnNames: _col0, _col1
> > Reduce Output Operator
> > key expressions: _col0 (type: string)
> > sort order: +
> > Map-reduce partition columns: _col0 (type: string)
> > value expressions: _col1 (type: array<bigint>)
> > Reduce Operator Tree:
> > Group By Operator
> > aggregations: collect_set(VALUE._col0)
> > keys: KEY._col0 (type: string)
> > mode: mergepartial
> > outputColumnNames: _col0, _col1
> > File Output Operator
> > compressed: false
> > table:
> > input format: org.apache.hadoop.mapred.TextInputFormat
> > output format:
> > org.apache.hadoop.hive.ql.io.HiveIgnoreKeyTextOutputFormat
> > serde: org.apache.hadoop.hive.serde2.lazy.LazySimpleSerDe
> >
> > Stage: Stage-5
> > Move Operator
> > files:
> > hdfs directory: true
> > #### A masked pattern was here ####
> >
> 325a368,372
> > PREHOOK: Input: default@default__srcpart_srcpart_index__
> > PREHOOK: Input: default@default__srcpart_srcpart_index__@ds=2008-04-08/hr=11
> > PREHOOK: Input: default@default__srcpart_srcpart_index__@ds=2008-04-08/hr=12
> > PREHOOK: Input: default@default__srcpart_srcpart_index__@ds=2008-04-09/hr=11
> > PREHOOK: Input: default@default__srcpart_srcpart_index__@ds=2008-04-09/hr=12
> 335a383,387
> > POSTHOOK: Input: default@default__srcpart_srcpart_index__
> > POSTHOOK: Input:
> > default@default__srcpart_srcpart_index__@ds=2008-04-08/hr=11
> > POSTHOOK: Input:
> > default@default__srcpart_srcpart_index__@ds=2008-04-08/hr=12
> > POSTHOOK: Input:
> > default@default__srcpart_srcpart_index__@ds=2008-04-09/hr=11
> > POSTHOOK: Input:
> > default@default__srcpart_srcpart_index__@ds=2008-04-09/hr=12
> 342a395,442
> > 82 val_82
> > 82 val_82
> > 82 val_82
> > 82 val_82
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 83 val_83
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 84 val_84
> > 85 val_85
> > 85 val_85
> > 85 val_85
> > 85 val_85
> > 86 val_86
> > 86 val_86
> > 86 val_86
> > 86 val_86
> > 87 val_87
> > 87 val_87
> > 87 val_87
> > 87 val_87
> Standard Error
> Begin query: index_auto_mult_tables.q
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Warning: fs.defaultFS is not set when running "chgrp" command.
> Warning: fs.defaultFS is not set when running "chmod" command.
> Exception: Client Execution results failed with error code = 1
> See ./ql/target/tmp/log/hive.log or ./itests/qtest/target/tmp/log/hive.log,
> or check ./ql/target/surefire-reports or
> ./itests/qtest/target/surefire-reports/ for specific test cases logs.
> junit.framework.AssertionFailedError: Client Execution results failed with
> error code = 1
> See ./ql/target/tmp/log/hive.log or ./itests/qtest/target/tmp/log/hive.log,
> or check ./ql/target/surefire-reports or
> ./itests/qtest/target/surefire-reports/ for specific test cases logs.
> at junit.framework.Assert.fail(Assert.java:57)
> at org.apache.hadoop.hive.ql.QTestUtil.failedDiff(QTestUtil.java:2001)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.runTest(TestCliDriver.java:194)
> at
> org.apache.hadoop.hive.cli.TestCliDriver.testCliDriver_index_auto_mult_tables(TestCliDriver.java:142)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
> at
> org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
> at
> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
> at
> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
> at
> org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
> Failed query: index_auto_mult_tables.q
> {noformat}
> From the output of the failing test, it seems that the index on the srcpart
> table is not used.
> The hive.log contains the following:
> {noformat}
> 2016-11-07T02:47:45,992 INFO [6401ee51-9d53-4101-a14e-9067d0bc357d main]
> index.IndexWhereProcessor: checking index staleness...
> 2016-11-07T02:47:45,998 INFO [6401ee51-9d53-4101-a14e-9067d0bc357d main]
> index.IndexWhereProcessor: Index is stale on partition 'ds=2008-04-09/hr=11'.
> Modified time (1478515600000) for
> 'pfile:/home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/kv1.txt'
> is higher than index creation time (1478515599000).
> {noformat}
> The staleness check fails for the index on the srcpart table for the
> ds=2008-04-09/hr=11 partition, so the index is really not used. The staleness
> check fails, because the modification time of the
> itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/kv1.txt file
> (11:46:40:0) is higher than the index creation time (11:46:39:0).
> After some investigation, I found that this happens if the creation of the
> partition folder and moving the kv1.txt file happens when the second turns.
> So the folder is created at 11:46:39,961, but the MoveTask which moves the
> kv1.txt file to the folder starts at 11:46:39:961 and finishes at
> 11:46:40,012.
> {noformat}
> 2016-11-07T02:46:39,961 INFO [9b9edc01-22c2-460e-b008-03878e74077e main]
> common.FileUtils: Creating directory if it doesn't exist:
> pfile:/home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11
> 2016-11-07T02:46:39,973 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils:
> {-chgrp,-R,hiveptest,pfile:/home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09}
> 2016-11-07T02:46:39,981 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils: Return value is :0
> 2016-11-07T02:46:39,981 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils:
> {-chmod,-R,755,pfile:/home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09}
> 2016-11-07T02:46:39,992 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils: Return value is :0
> 2016-11-07T02:46:39,992 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> metadata.Hive: The source path is
> /home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/data/files/kv1.txt/
> and the destination path is
> /home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/kv1.txt/
> 2016-11-07T02:46:40,001 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils:
> {-chgrp,-R,hiveptest,pfile:/home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/kv1.txt}
> 2016-11-07T02:46:40,006 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils: Return value is :0
> 2016-11-07T02:46:40,006 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils:
> {-chmod,-R,755,pfile:/home/hiveptest/54.215.115.117-hiveptest-0/apache-github-source-source/itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/kv1.txt}
> 2016-11-07T02:46:40,012 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> shims.HdfsUtils: Return value is :0
> 2016-11-07T02:46:40,012 DEBUG [9b9edc01-22c2-460e-b008-03878e74077e main]
> log.PerfLogger: </PERFLOG method=FileMoves start=1478515599961
> end=1478515600012 duration=51 from=MoveTask>
> {noformat}
> In this case, the last modification time of the folder
> itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/ will be 11:46:39
> and of the kv1.txt will be 11:46:40.
> When the index is built in the DDLTask.alterIndex method, the modification
> time which is stored for each partition is the modification time of the
> folder:
> {noformat}
> if (baseTbl.isPartitioned()) {
> List<Partition> baseParts;
> if (alterIndex.getSpec() != null) {
> baseParts = db.getPartitions(baseTbl, alterIndex.getSpec());
> } else {
> baseParts = db.getPartitions(baseTbl);
> }
> if (baseParts != null) {
> for (Partition p : baseParts) {
> FileSystem fs = p.getDataLocation().getFileSystem(db.getConf());
> FileStatus fss = fs.getFileStatus(p.getDataLocation());
> basePartTs.put(p.getSpec(), fss.getModificationTime());
> }
> }
> } else {
> {noformat}
> But when the staleness is checked in the IndexUtils.isIndexPartitionFresh
> method, it checks the modification time of the files in the partition folder:
> {noformat}
> private static boolean isIndexPartitionFresh(Hive hive, Index index,
> Partition part) throws HiveException {
> LOG.info("checking index staleness...");
> try {
> String indexTs = index.getParameters().get(part.getSpec().toString());
> if (indexTs == null) {
> return false;
> }
> FileSystem partFs =
> part.getDataLocation().getFileSystem(hive.getConf());
> FileStatus[] parts = partFs.listStatus(part.getDataLocation(),
> FileUtils.HIDDEN_FILES_PATH_FILTER);
> for (FileStatus status : parts) {
> if (status.getModificationTime() > Long.parseLong(indexTs)) {
> LOG.info("Index is stale on partition '" + part.getName()
> + "'. Modified time (" + status.getModificationTime() + ") for
> '" + status.getPath()
> + "' is higher than index creation time (" + indexTs + ").");
> return false;
> }
> }
> } catch (IOException e) {
> throw new HiveException("Failed to grab timestamp information from
> partition '" + part.getName() + "': " + e.getMessage(), e);
> }
> return true;
> }
> {noformat}
> Because of the modification time of the
> itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11/kv1.txt file is
> higher (11:46:40), than the modification time of the
> itests/qtest/target/warehouse/srcpart/ds=2008-04-09/hr=11 folder (11:46:39),
> the check fails and the index is not used which leads to the failure of the q
> test.
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
