[ 
https://issues.apache.org/jira/browse/IMPALA-13850?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17934054#comment-17934054
 ] 

Wenzhe Zhou commented on IMPALA-13850:
--------------------------------------

statestore log messages:
{code:java}
I0310 12:08:22.766993  1204 statestore.cc:959] Registering: 
catalog-ser...@catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000
I0310 12:08:22.767011  1204 statestore.cc:562] Subscriber 
'catalog-ser...@catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000'
 with type CATALOGD registered (registration id: 
e1480793e0dd3c07:1fdc13e236f6e4b3)
I0310 12:08:25.875408    82 statestore.cc:1448] All 5 subscribers successfully 
heartbeat in the last 60000ms.
I0310 12:08:32.854318    84 statestore-catalogd-mgr.cc:182] 
catalog-ser...@catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000
 is assigned as active catalogd after preemption waiting period.
I0310 12:08:32.854363    84 statestore.cc:1510] Send notification for active 
catalogd version: 1
I0310 12:08:35.913833    84 client-cache.h:371] RPC recv timed out: dest 
address: 59.07.3.741:23020, rpc: N6impala23TUpdateCatalogdResponseE
I0310 12:08:35.913884    84 client-cache.cc:174] Broken Connection, destroy 
client for 59.07.3.741:23020
E0310 12:08:35.913954    84 statestore.cc:1587] Couldn't send UpdateCatalogd 
RPC,  RPC recv timed out: dest address: 59.07.3.741:23020, rpc: 
N6impala23TUpdateCatalogdResponseE
Subscriber 
catalog-ser...@catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000
 timed-out during update catalogd RPC. Timeout is 3s.
I0310 12:08:39.050787    84 client-cache.h:371] RPC recv timed out: dest 
address: 59.07.3.741:23020, rpc: N6impala23TUpdateCatalogdResponseE
I0310 12:08:39.050828    84 client-cache.cc:174] Broken Connection, destroy 
client for 59.07.3.741:23020
E0310 12:08:39.050895    84 statestore.cc:1587] Couldn't send UpdateCatalogd 
RPC,  RPC recv timed out: dest address: 59.07.3.741:23020, rpc: 
N6impala23TUpdateCatalogdResponseE
Subscriber 
catalog-ser...@catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000
 timed-out during update catalogd RPC. Timeout is 3s.
I0310 12:08:42.185699    84 client-cache.h:371] RPC recv timed out: dest 
address: 59.07.3.741:23020, rpc: N6impala23TUpdateCatalogdResponseE
I0310 12:08:42.185745    84 client-cache.cc:174] Broken Connection, destroy 
client for 59.07.3.741:23020
E0310 12:08:42.185806    84 statestore.cc:1587] Couldn't send UpdateCatalogd 
RPC,  RPC recv timed out: dest address: 59.07.3.741:23020, rpc: 
N6impala23TUpdateCatalogdResponseE
Subscriber 
catalog-ser...@catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000
 timed-out during update catalogd RPC. Timeout is 3s.
I0310 12:08:45.322778    84 client-cache.h:371] RPC recv timed out: dest 
address: 59.07.3.741:23020, rpc: N6impala23TUpdateCatalogdResponseE
I0310 12:08:45.322814    84 client-cache.cc:174] Broken Connection, destroy 
client for 59.07.3.741:23020
{code}

catalogd log messages:
{code:java}
I0310 12:21:34.083273     1 CatalogServiceCatalog.java:2028] Loaded table list 
for database: zln_mdoz_tmp_sec. Number of tables: 1
I0310 12:21:34.093585     1 MetastoreEventsProcessor.java:828] Metastore event 
processing restarted. Last synced event id was updated from 755574979
 to 755574979
I0310 12:21:34.093617     1 CatalogServiceCatalog.java:2188] Invalidated all 
metadata.
I0310 12:21:34.094341     1 thrift-server.cc:419] ThriftServer 
'StatestoreSubscriber' started on port: 23020
I0310 12:21:34.094341  1816 TAcceptQueueServer.cpp:329] 
connection_setup_thread_pool_size is set to 2
I0310 12:21:34.094586     1 thrift-util.cc:198] TSocket::open() error on socket 
(after THRIFT_POLL) <Host: localhost Port: 23020>: Connection refuse
d
I0310 12:21:34.094790     1 statestore-subscriber.cc:745] Starting statestore 
subscriber
I0310 12:21:34.094823  1816 TAcceptQueueServer.cpp:355] New connection to 
server StatestoreSubscriber from client <Host: 512.5.4.6 Port: 39594>
I0310 12:21:34.095959     1 statestore-subscriber.cc:365] Registering with 
statestore with resolved address 59.07.3.741
I0310 12:21:34.096110     1 statestore-subscriber.cc:686] Statestore protocol 
version: V2
I0310 12:21:34.096123     1 statestore-subscriber.cc:695] Subscriber 
registration ID: 2a463fb558c8486f:f7fef348ff24aba1
I0310 12:21:34.096130     1 statestore-subscriber.cc:703] Statestore ID: 
8440625c843eddaf:2ecb580a1824659c
I0310 12:21:34.096135     1 statestore-subscriber.cc:721] Active catalogd 
address: 
catalogd-0.catalogd-headless.impala-1741626283-5mrb.svc.cluster.local:26000
I0310 12:21:34.096145     1 statestore-subscriber.cc:755] statestore 
registration successful on startup
I0310 12:21:34.096380  1816 TAcceptQueueServer.cpp:355] New connection to 
server StatestoreSubscriber from client <Host: 59.07.3.740 Port: 35892>
I0310 12:21:34.096421  1816 TAcceptQueueServer.cpp:355] New connection to 
server StatestoreSubscriber from client <Host: 59.07.3.740 Port: 35906>
I0310 12:21:34.096553  1816 TAcceptQueueServer.cpp:355] New connection to 
server StatestoreSubscriber from client <Host: 59.07.3.740 Port: 35910>
I0310 12:21:34.096657  1820 statestore-subscriber.cc:943] Unable to acquire the 
lock, skip UpdateCatalogd RPC notification.
I0310 12:21:34.109297  1814 JniUtil.java:166] getCatalogDelta request: Getting 
catalog delta from version 0
I0310 12:21:34.118454  1814 catalog-server.cc:1176] Collected update: 
2:DATABASE:vwrl_msptrxn, version=431507, original size=42, compressed size=45
I0310 12:21:34.119469  1814 catalog-server.cc:1176] Collected update: 
2:DATABASE:vwda_aml, version=425628, original size=38, compressed size=40
I0310 12:21:34.119518  1814 catalog-server.cc:1176] Collected update: 
2:DATABASE:flc_1h_rs2_sec, version=123878, original size=44, compressed size=47
I0310 12:21:34.129040  1814 catalog-server.cc:1176] Collected update: 
2:TABLE:flc_1h_rs2_sec.merch_comm_chargbk_rtvl_bkp20240315, version=123895, 
original size=86, compressed size=88
I0310 12:21:34.129134  1814 catalog-server.cc:1176] Collected update: 
2:TABLE:flc_1h_rs2_sec.pmt_card_and_tp_ntwrk_tran_tax_st_tot_stag, 
version=123886, original size=93, compressed size=95
I0310 12:21:34.129170  1814 catalog-server.cc:1176] Collected update: 
2:TABLE:flc_1h_rs2_sec.merch_setl_pmt_xfer_aug_prt, version=123916, original 
size=78, compressed size=80
I0310 12:21:34.129199  1814 catalog-server.cc:1176] Collected update: 
2:TABLE:flc_1h_rs2_sec.merch_comm_chargbk_rtvl_test, version=123910, original 
size=79, compressed size=81
I0310 12:21:34.129228  1814 catalog-server.cc:1176] Collected update: 
2:TABLE:flc_1h_rs2_sec.mrch_stmt_mo_tran, version=123927, original size=68, 
compressed size=70
I0310 12:21:34.129257  1814 catalog-server.cc:1176] Collected update: 
2:TABLE:flc_1h_rs2_sec.mrch_stmt_oth_fee, version=123928, original size=68, co
{code}


> Catalogd should not start metadata operation until initialization is done if 
> HA is enabled
> ------------------------------------------------------------------------------------------
>
>                 Key: IMPALA-13850
>                 URL: https://issues.apache.org/jira/browse/IMPALA-13850
>             Project: IMPALA
>          Issue Type: Bug
>          Components: Catalog
>            Reporter: Wenzhe Zhou
>            Priority: Major
>
> In a case reported by user, the catalogd initialization failed to complete. 
> Log messages showed that catalog HA was enabled. catalogd was blocked when 
> trying to acquire "CatalogServer.catalog_lock_" when calling 
> CatalogServer::UpdateActiveCatalogd() during statestore subscriber 
> registration.
> Log message showed that there was IM command issued before catalogd tried to 
> register to statestore.
> {code:java}
> I0310 12:21:34.093617     1 CatalogServiceCatalog.java:2188] Invalidated all 
> metadata.
> I0310 12:21:34.094341     1 thrift-server.cc:419] ThriftServer 
> 'StatestoreSubscriber' started on port: 23020
> I0310 12:21:34.094341  1816 TAcceptQueueServer.cpp:329] 
> connection_setup_thread_pool_size is set to 2
> I0310 12:21:34.094586     1 thrift-util.cc:198] TSocket::open() error on 
> socket (after THRIFT_POLL) <Host: localhost Port: 23020>: Connection refused
> I0310 12:21:34.094790     1 statestore-subscriber.cc:745] Starting statestore 
> subscriber
> {code}
> We should not allow any metadata operation until initialization is done. When 
> HA is enabled, catalog-server should not hold "CatalogServer.catalog_lock_" 
> for long time before active catalogd is assigned.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to