Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id CF6D0200BCB for ; Thu, 24 Nov 2016 11:16:01 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id CDE6A160B1E; Thu, 24 Nov 2016 10:16:01 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id A8295160B1F for ; Thu, 24 Nov 2016 11:16:00 +0100 (CET) Received: (qmail 77066 invoked by uid 500); 24 Nov 2016 10:15:58 -0000 Mailing-List: contact issues-help@hive.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@hive.apache.org Delivered-To: mailing list issues@hive.apache.org Received: (qmail 77051 invoked by uid 99); 24 Nov 2016 10:15:58 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 24 Nov 2016 10:15:58 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id A00AE2C03E0 for ; Thu, 24 Nov 2016 10:15:58 +0000 (UTC) Date: Thu, 24 Nov 2016 10:15:58 +0000 (UTC) From: "Marta Kuczora (JIRA)" To: issues@hive.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (HIVE-15282) Different modification times are used when an index is built and when its staleness is checked MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 24 Nov 2016 10:16:02 -0000 [ https://issues.apache.org/jira/browse/HIVE-15282?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Marta Kuczora updated HIVE-15282: --------------------------------- Affects Version/s: (was: 2.1.0) 2.2.0 > 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 > > 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) > > 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: > {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 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.4#6332)