[
https://issues.apache.org/jira/browse/IMPALA-13850?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17934054#comment-17934054
]
Wenzhe Zhou edited comment on IMPALA-13850 at 3/10/25 11:53 PM:
----------------------------------------------------------------
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 refused
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}
was (Author: wzhou):
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]
