[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16774606#comment-16774606 ] ASF subversion and git services commented on IMPALA-7605: - Commit 4ed947365447934c55eeec94610a2b3cbd993937 in impala's branch refs/heads/master from Bharath Vissapragada [ https://gitbox.apache.org/repos/asf?p=impala.git;h=4ed9473 ] IMPALA-6900: Fix the min version invariant for invalidate metadata Current flow of invalidate metadata is as follows. 1. Catalog server records the global catalog version *before* reset() 2. Catalog server invalidates all the metadata. 3. Catalog server returns the version recorded in step (1) 4. Coordinator should wait until the minimum version across all the local catalog objects is > the version returned in the step (3). However, the invariant in step 4 on the coordinator side was incorrectly coded resulting in an early termination of the wait loop. This breaks the invalidate metadata contract and the subsequent queries can fail while resolving catalog objects in the local cache. Testing: I could reproduce this issue reliably on a pristine HMS with high --statestore_update_frequency_ms (see IMPALA-7605 for details). With the patch, I'm not able to reproduce it. Change-Id: I22ace3f5917b6167af63c3dfd2620e69ce8ec1cb Reviewed-on: http://gerrit.cloudera.org:8080/12547 Reviewed-by: Impala Public Jenkins Tested-by: Impala Public Jenkins > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Labels: regression > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16634210#comment-16634210 ] bharath v commented on IMPALA-7605: --- I think this is a dupe of IMPALA-6900. I could reliably repro the issue by increasing {{statestore_update_frequency_ms}} to {{1}} which increases the window of race. With the defaults, the race window is much smaller and that's the reason I was not hitting it locally. > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Labels: regression > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:53.609027 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:53.609058 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:53.609087 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:53.614903 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: foo1537550878 > I0921 10:28:53.614946 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: foo1537550878 > I0921 10:28:53.614977 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: foo1537550878 > I0921 10:28:53.615005 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: foo1537550878 > I0921 10:28:53.632726 48924 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:54.782857 48041
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16626120#comment-16626120 ] Philip Zeyliger commented on IMPALA-7605: - To belabor this: you're likely seeing a race. I wonder if CDH-73078 is similar. It was filed recently after https://review.infra.cloudera.com/r/97460/ added a sleep() somewhere. > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Labels: regression > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:53.609027 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:53.609058 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:53.609087 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:53.614903 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: foo1537550878 > I0921 10:28:53.614946 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: foo1537550878 > I0921 10:28:53.614977 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: foo1537550878 > I0921 10:28:53.615005 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: foo1537550878 > I0921 10:28:53.632726 48924 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:54.782857 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=5, original size=156 >
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16626027#comment-16626027 ] Michael Brown commented on IMPALA-7605: --- [~bharathv] It reproduces for me at hash 083352b1e7e39e53d7146f37d206443057778653: {noformat} + impala-shell.sh Starting Impala Shell without Kerberos authentication Connected to localhost:21000 Server version: impalad version 3.1.0-SNAPSHOT DEBUG (build 083352b1e7e39e53d7146f37d206443057778653) *** Welcome to the Impala shell. (Impala Shell v3.1.0-SNAPSHOT (083352b) built on Mon Sep 24 08:24:06 PDT 2018) After running a query, type SUMMARY to see a summary of where time was spent. *** Query: invalidate metadata Query submitted at: 2018-09-24 08:27:01 (Coordinator: http://mikeb-ub16:25000) Query progress can be monitored at: http://mikeb-ub16:25000/query_plan?query_id=a4469b3d0bd93bc3:3a195423 Fetched 0 row(s) in 0.20s Query: select * from foo1537802777.foo Query submitted at: 2018-09-24 08:27:01 (Coordinator: http://mikeb-ub16:25000) ERROR: AnalysisException: Could not resolve table reference: 'foo1537802777.foo' {noformat} I can tell you aren't actually running my reproduction script, because it uses a timestamp for a uniqueness factor. One difference is that you are issuing commands one at a time at a shell prompt, and the script feeds lines to impala-shell's stdin. Maybe you should try feeding commands to impala-shell.sh's stdin like the script does, or just run the script completely as I've been doing. > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Labels: regression > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245]
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16624291#comment-16624291 ] bharath v commented on IMPALA-7605: --- No luck. {noformat} ➜ Impala git:(imp7605) ✗ ./buildall.sh -notests -format .. [50%] Building CXX object CMakeFiles/impalalzo.dir/hdfs-lzo-text-scanner.cc.o [100%] Linking CXX shared library build/libimpalalzo.so [100%] Built target impalalzo [100%] Built target impala-lzo Stopping Sentry Stopping Hive Stopping Hbase Stopping kudu Stopping kms Stopping hdfs The minikdc is not running. Creating node-3 at /home/bharath/Impala/testdata/cluster/cdh6/node-3 node-3 will use ports DATANODE_PORT=31000, DATANODE_HTTP_PORT=31010, DATANODE_IPC_PORT=31020, DATANODE_HTTPS_PORT=31030, NODEMANAGER_PORT=31100, NODEMANAGER_LOCALIZER_PORT=31120, NODEMANAGER_WEBUI_PORT=31140, KUDU_TS_RPC_PORT=31200, and KUDU_TS_WEBUI_PORT=31300 Creating node-2 at /home/bharath/Impala/testdata/cluster/cdh6/node-2 node-2 will use ports DATANODE_PORT=31001, DATANODE_HTTP_PORT=31011, DATANODE_IPC_PORT=31021, DATANODE_HTTPS_PORT=31031, NODEMANAGER_PORT=31101, NODEMANAGER_LOCALIZER_PORT=31121, NODEMANAGER_WEBUI_PORT=31141, KUDU_TS_RPC_PORT=31201, and KUDU_TS_WEBUI_PORT=31301 Creating node-1 at /home/bharath/Impala/testdata/cluster/cdh6/node-1 node-1 will use ports DATANODE_PORT=31002, DATANODE_HTTP_PORT=31012, DATANODE_IPC_PORT=31022, DATANODE_HTTPS_PORT=31032, NODEMANAGER_PORT=31102, NODEMANAGER_LOCALIZER_PORT=31122, NODEMANAGER_WEBUI_PORT=31142, KUDU_TS_RPC_PORT=31202, and KUDU_TS_WEBUI_PORT=31302 Config dir: /home/bharath/Impala/fe/src/test/resources Current user: bharath Metastore DB: hive_impala_imp_7605 ~/Impala/fe/src/test/resources ~/Impala Creating postgresql database for Hive metastore ~/Impala/toolchain/cdh_components-559250/hive-2.1.1-cdh6.x-SNAPSHOT/scripts/metastore/upgrade/postgres ~/Impala/fe/src/test/resources ~/Impala psql:hive-schema-2.1.1.postgres.sql:1462: WARNING: no privileges could be revoked for "public" psql:hive-schema-2.1.1.postgres.sql:1463: WARNING: no privileges were granted for "public" ~/Impala/fe/src/test/resources ~/Impala Creating Sentry Policy Server DB Linking core-site.xml from local cluster Linking hdfs-site.xml from local cluster ➜ Impala git:(imp7605) ✗ hive SLF4J: Class path contains multiple SLF4J bindings. SLF4J: Found binding in [jar:file:/home/bharath/Impala/toolchain/cdh_components-559250/hive-2.1.1-cdh6.x-SNAPSHOT/lib/log4j-slf4j-impl-2.8.2.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: Found binding in [jar:file:/home/bharath/Impala/toolchain/cdh_components-559250/hadoop-3.0.0-cdh6.x-SNAPSHOT/share/hadoop/common/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] Logging initialized using configuration in file:/home/bharath/Impala/fe/src/test/resources/hive-log4j2.properties Async: false WARNING: Hive CLI is deprecated and migration to Beeline is recommended. hive> create database foo; OK Time taken: 1.304 seconds hive> use foo; OK Time taken: 0.034 seconds hive> create table test(a int); OK Time taken: 0.694 seconds hive> insert into test values (1); Query ID = bharath_2018092119_fc517153-a54b-4fc1-a9d8-66b8cffb6e22 Total jobs = 3 Launching Job 1 out of 3 Number of reduce tasks is set to 0 since there's no reduce operator 18/09/21 15:56:01 INFO lzo.GPLNativeCodeLoader: Loaded native gpl library 18/09/21 15:56:01 INFO lzo.LzoCodec: Successfully loaded & initialized native-lzo library [hadoop-lzo rev d5ed4529bd7dc713375eff15f516fcfa1d20090b] 18/09/21 15:56:01 INFO mapred.LocalDistributedCacheManager: Creating symlink: /tmp/hadoop-bharath/mapred/local/1537570561408/libjars <- /home/bharath/Impala/libjars/* 18/09/21 15:56:01 WARN mapred.LocalDistributedCacheManager: Failed to create symlink: /tmp/hadoop-bharath/mapred/local/1537570561408/libjars <- /home/bharath/Impala/libjars/* 18/09/21 15:56:01 INFO mapred.LocalDistributedCacheManager: Localized file:/tmp/hadoop/mapred/staging/bharath839177781/.staging/job_local839177781_0001/libjars as file:/tmp/hadoop-bharath/mapred/local/1537570561408/libjars Job running in-process (local Hadoop) 18/09/21 15:56:01 INFO mapred.LocalJobRunner: OutputCommitter set in config org.apache.hadoop.hive.ql.io.HiveFileFormatUtils$NullOutputCommitter 18/09/21 15:56:01 INFO mapred.LocalJobRunner: OutputCommitter is org.apache.hadoop.hive.ql.io.HiveFileFormatUtils$NullOutputCommitter 18/09/21 15:56:01 INFO mapred.LocalJobRunner: Waiting for map tasks 18/09/21 15:56:01 INFO mapred.LocalJobRunner: Starting task: attempt_local839177781_0001_m_00_0 18/09/21 15:56:01 INFO mapred.LocalJobRunner: 18/09/21 15:56:01 INFO mapred.LocalJobRunner:
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16624214#comment-16624214 ] Michael Brown commented on IMPALA-7605: --- I've been able to, yes. I also had done a ./buildall.sh -notests -format initially as a harder, more drastic way of resetting. Maybe you need to do that as well? > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Labels: regression > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:53.609027 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:53.609058 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:53.609087 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:53.614903 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: foo1537550878 > I0921 10:28:53.614946 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: foo1537550878 > I0921 10:28:53.614977 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: foo1537550878 > I0921 10:28:53.615005 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: foo1537550878 > I0921 10:28:53.632726 48924 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:54.782857 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=5, original size=156 > I0921
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16624210#comment-16624210 ] bharath v commented on IMPALA-7605: --- Thanks Michael for the detailed steps. I tried a couple of times from a clean HMS, not able to reproduce it. Maybe I'm doing something wrong. Are you able to repro it on demand? > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Labels: regression > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:53.609027 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:53.609058 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:53.609087 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:53.614903 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: foo1537550878 > I0921 10:28:53.614946 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: foo1537550878 > I0921 10:28:53.614977 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: foo1537550878 > I0921 10:28:53.615005 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: foo1537550878 > I0921 10:28:53.632726 48924 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:54.782857 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=5, original size=156 > I0921
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16624026#comment-16624026 ] Michael Brown commented on IMPALA-7605: --- bq. Upon the first access, AnalysisException is raised. What I mean here is, when impala tries to select from the table created in hive. > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:53.609027 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:53.609058 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:53.609087 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:53.614903 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: foo1537550878 > I0921 10:28:53.614946 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: foo1537550878 > I0921 10:28:53.614977 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: foo1537550878 > I0921 10:28:53.615005 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: foo1537550878 > I0921 10:28:53.632726 48924 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:54.782857 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=5, original size=156 > I0921 10:28:54.782948 48041 catalog-server.cc:490] Collected update: >
[jira] [Commented] (IMPALA-7605) AnalysisException when first accessing Hive-create table on pristine HMS
[ https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16624016#comment-16624016 ] Michael Brown commented on IMPALA-7605: --- [~bharathv] I've attached 3.0 vs. 3.1 logs, and the reproduction script. > AnalysisException when first accessing Hive-create table on pristine HMS > > > Key: IMPALA-7605 > URL: https://issues.apache.org/jira/browse/IMPALA-7605 > Project: IMPALA > Issue Type: Bug > Components: Catalog >Affects Versions: Impala 3.1.0 >Reporter: Michael Brown >Assignee: bharath v >Priority: Blocker > Attachments: 3.0-logs.tar.gz, 3.1-logs.tar.gz, metadata-bug.sh > > > This is a corner case encountered when loading test data from Hive on a > pristine/new cluster. As we tend to keep bigger clusters around and upgrade > them, as opposed to refreshing them, and our data load doesn't hit this > either, this was tough to spot. > The procedure in general is to start with a pristine HMS, create a table in > Hive, and use Impala to access the table. Upon the first access, > AnalysisException is raised. Subsequent accesses work. > This is a P1 in the sense that, while a user can try again and succeed, test > automation is going to increasingly load data via Hive and then access it in > Impala. This case needs to work. The other thing making this a P1 is that > it's a change behavior relative to both 2.12 and 3.0 and thus a regression. > Here's what catalogd.INFO looks like in the successful case (3.0): > {noformat} > I0921 10:28:23.697592 47879 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 0 > I0921 10:28:23.810739 47879 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:23.811686 47879 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:23.811738 47879 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:23.811772 47879 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:23.853292 47879 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:23.860013 47879 statestore-subscriber.cc:190] Starting statestore > subscriber > I0921 10:28:23.861377 47879 thrift-server.cc:452] ThriftServer > 'StatestoreSubscriber' started on port: 23020 > I0921 10:28:23.861383 47879 statestore-subscriber.cc:217] Registering with > statestore > I0921 10:28:23.861979 47879 statestore-subscriber.cc:174] Subscriber > registration ID: 624d03c923c15c12:f9204d9fb14054a9 > I0921 10:28:23.861989 47879 statestore-subscriber.cc:221] statestore > registration successful > I0921 10:28:23.868679 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=2, original size=156 > I0921 10:28:23.870929 48041 catalog-server.cc:490] Collected deletion: > DATABASE:_impala_builtins, version=3, original size=140 > I0921 10:28:23.872802 48041 catalog-server.cc:490] Collected update: > CATALOG_SERVICE_ID, version=3, original size=49 > I0921 10:28:23.875424 47879 thrift-server.cc:452] ThriftServer > 'CatalogService' started on port: 26000 > I0921 10:28:23.875434 47879 catalogd-main.cc:111] CatalogService started on > port: 26000 > I0921 10:28:26.776692 48047 catalog-server.cc:245] A catalog update with 3 > entries is assembled. Catalog version: 3 Last sent catalog version: 0 > I0921 10:28:53.571209 48924 CatalogServiceCatalog.java:1102] Invalidating all > metadata. Version: 3 > I0921 10:28:53.608983 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: default > I0921 10:28:53.609027 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: default > I0921 10:28:53.609058 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: default > I0921 10:28:53.609087 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: default > I0921 10:28:53.614903 48924 CatalogServiceCatalog.java:914] Loading native > functions for database: foo1537550878 > I0921 10:28:53.614946 48924 CatalogServiceCatalog.java:930] Loaded native > functions for database: foo1537550878 > I0921 10:28:53.614977 48924 CatalogServiceCatalog.java:941] Loading Java > functions for database: foo1537550878 > I0921 10:28:53.615005 48924 CatalogServiceCatalog.java:952] Loaded Java > functions for database: foo1537550878 > I0921 10:28:53.632726 48924 CatalogServiceCatalog.java:1170] Invalidated all > metadata. > I0921 10:28:54.782857 48041 catalog-server.cc:490] Collected update: > DATABASE:default, version=5, original size=156 > I0921 10:28:54.782948 48041 catalog-server.cc:490] Collected update: > DATABASE:foo1537550878, version=6, original size=156 > I0921