[
https://issues.apache.org/jira/browse/IMPALA-7605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=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 {{10000}} 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 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 10:28:54.790092 48041 catalog-server.cc:490] Collected update:
> TABLE:foo1537550878.foo, version=7, original size=53
> I0921 10:28:54.790212 48041 catalog-server.cc:490] Collected update:
> CATALOG_SERVICE_ID, version=7, original size=49
> I0921 10:28:56.781760 48047 catalog-server.cc:245] A catalog update with 4
> entries is assembled. Catalog version: 7 Last sent catalog version: 3
> I0921 10:28:57.392699 48927 TableLoader.java:58] Loading metadata for:
> foo1537550878.foo
> I0921 10:28:57.392915 48008 TableLoadingMgr.java:70] Loading metadata for
> table: foo1537550878.foo
> I0921 10:28:57.393100 48008 TableLoadingMgr.java:72] Remaining items in
> queue: 0. Loads in progress: 1
> I0921 10:28:57.555173 48927 HdfsTable.java:1276] Fetching partition metadata
> from the Metastore: foo1537550878.foo
> W0921 10:28:57.591965 48927 HiveConf.java:4001] HiveConf of name
> hive.access.conf.url does not exist
> W0921 10:28:57.592538 48927 HiveConf.java:4001] HiveConf of name
> hive.stats.jdbcdriver does not exist
> I0921 10:28:57.624528 48927 HdfsTable.java:1280] Fetched partition metadata
> from the Metastore: foo1537550878.foo
> I0921 10:28:57.686586 48927 HdfsTable.java:902] Loading file and block
> metadata for 1 paths for table foo1537550878.foo using a thread pool of size 1
> I0921 10:28:57.718747 48927 HdfsTable.java:942] Loaded file and block
> metadata for foo1537550878.foo
> I0921 10:28:57.720115 48927 TableLoader.java:97] Loaded metadata for:
> foo1537550878.foo
> I0921 10:28:58.803722 48041 catalog-server.cc:490] Collected update:
> TABLE:foo1537550878.foo, version=8, original size=1461
> I0921 10:28:58.803853 48041 catalog-server.cc:490] Collected update:
> CATALOG_SERVICE_ID, version=8, original size=49
> I0921 10:29:00.782649 48047 catalog-server.cc:245] A catalog update with 2
> entries is assembled. Catalog version: 8 Last sent catalog version: 7
> {noformat}
> Unsuccessful / 3.1 case:
> {noformat}
> I0921 10:11:36.916322 31686 CatalogServiceCatalog.java:1126] Invalidating all
> metadata. Version: 0
> I0921 10:11:37.032959 31686 CatalogServiceCatalog.java:940] Loading native
> functions for database: default
> I0921 10:11:37.033780 31686 CatalogServiceCatalog.java:948] Loaded native
> functions for database: default
> I0921 10:11:37.033839 31686 CatalogServiceCatalog.java:963] Loading Java
> functions for database: default
> I0921 10:11:37.033871 31686 CatalogServiceCatalog.java:976] Loaded Java
> functions for database: default
> I0921 10:11:37.065071 31686 CatalogServiceCatalog.java:1194] Invalidated all
> metadata.
> I0921 10:11:37.072490 31686 statestore-subscriber.cc:206] Starting statestore
> subscriber
> I0921 10:11:37.073854 31686 thrift-server.cc:454] ThriftServer
> 'StatestoreSubscriber' started on port: 23020
> I0921 10:11:37.073860 31686 statestore-subscriber.cc:234] Registering with
> statestore
> I0921 10:11:37.074478 31686 statestore-subscriber.cc:191] Subscriber
> registration ID: 6546bb97909c4886:72c8d38c1dc963a5
> I0921 10:11:37.074489 31686 statestore-subscriber.cc:238] statestore
> registration successful
> I0921 10:11:37.086359 31853 catalog-server.cc:560] Collected update:
> 1:DATABASE:default, version=2, original size=156, compressed size=141
> I0921 10:11:37.090330 31853 catalog-server.cc:560] Collected update:
> 1:CATALOG_SERVICE_ID, version=2, original size=49, compressed size=51
> I0921 10:11:37.092770 31686 thrift-server.cc:454] ThriftServer
> 'CatalogService' started on port: 26000
> I0921 10:11:37.092779 31686 catalogd-main.cc:111] CatalogService started on
> port: 26000
> I0921 10:11:39.075608 31858 catalog-server.cc:316] A catalog update with 2
> entries is assembled. Catalog version: 2 Last sent catalog version: 0
> I0921 10:16:54.972216 33117 CatalogServiceCatalog.java:1126] Invalidating all
> metadata. Version: 2
> I0921 10:16:55.008399 33117 CatalogServiceCatalog.java:940] Loading native
> functions for database: default
> I0921 10:16:55.008447 33117 CatalogServiceCatalog.java:948] Loaded native
> functions for database: default
> I0921 10:16:55.008479 33117 CatalogServiceCatalog.java:963] Loading Java
> functions for database: default
> I0921 10:16:55.008508 33117 CatalogServiceCatalog.java:976] Loaded Java
> functions for database: default
> I0921 10:16:55.013880 33117 CatalogServiceCatalog.java:940] Loading native
> functions for database: foo1537549871
> I0921 10:16:55.013923 33117 CatalogServiceCatalog.java:948] Loaded native
> functions for database: foo1537549871
> I0921 10:16:55.013955 33117 CatalogServiceCatalog.java:963] Loading Java
> functions for database: foo1537549871
> I0921 10:16:55.013983 33117 CatalogServiceCatalog.java:976] Loaded Java
> functions for database: foo1537549871
> I0921 10:16:55.044209 33117 CatalogServiceCatalog.java:1194] Invalidated all
> metadata.
> I0921 10:16:55.140169 31853 catalog-server.cc:560] Collected update:
> 1:DATABASE:default, version=4, original size=156, compressed size=141
> I0921 10:16:55.140234 31853 catalog-server.cc:560] Collected update:
> 1:DATABASE:foo1537549871, version=5, original size=156, compressed size=132
> I0921 10:16:55.145579 31853 catalog-server.cc:560] Collected update:
> 1:TABLE:foo1537549871.foo, version=6, original size=53, compressed size=54
> I0921 10:16:55.145676 31853 catalog-server.cc:560] Collected update:
> 1:CATALOG_SERVICE_ID, version=6, original size=49, compressed size=51
> I0921 10:16:57.139628 31858 catalog-server.cc:316] A catalog update with 4
> entries is assembled. Catalog version: 6 Last sent catalog version: 2
> {noformat}
> I have a script that can reproduce the problem. Again, I stress that I'm only
> able to trigger this on a pristine HMS. Also, the script will blow away your
> HMS via {{bin/create-test-configuration.sh -create_metastore}}. Take care
> when running it. You may want to make sure the commit {{IMPALA-7383:
> Configurable HMS and Sentry policy DB}} is applied so that you can pivot on
> different HMS DBs.
> I'll attach the script and 3.0 and 3.1 logs.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscr...@impala.apache.org
For additional commands, e-mail: issues-all-h...@impala.apache.org
