You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues-all@impala.apache.org by "Wenzhe Zhou (Jira)" <ji...@apache.org> on 2024/09/05 01:26:00 UTC
[jira] [Commented] (IMPALA-13348) statestore.active-status timeout
[ https://issues.apache.org/jira/browse/IMPALA-13348?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17879396#comment-17879396 ]
Wenzhe Zhou commented on IMPALA-13348:
--------------------------------------
Stack trace:
{code:java}
______ TestStatestoredHA.test_statestored_manual_failover_with_failed_rpc ______
custom_cluster/test_statestored_ha.py:523: in test_statestored_manual_failover_with_failed_rpc
self.__test_statestored_manual_failover(second_failover=False)
custom_cluster/test_statestored_ha.py:414: in __test_statestored_manual_failover
"statestore.active-status", expected_value=True, timeout=120)
common/impala_service.py:144: in wait_for_metric_value
self.__metric_timeout_assert(metric_name, expected_value, timeout)
common/impala_service.py:213: in __metric_timeout_assert
assert 0, assert_string
E AssertionError: Metric statestore.active-status did not reach value True in 120s.
{code}
In test case TestStatestoredHA.test_statestored_manual_failover_with_failed_rpc, it's expected standby statestored to become active when the original active statestored is killed. But the log file of standby statestored (statestored.impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com.jenkins.log.INFO.20240828-084824.7621) shows that failover did not happen.
Log messages showed that standby statestored failed to send heartbeats to its subscribers due Thrift RPC reccv timeout so that standby statestored could not collect connection status between subscribers and active statestored. This caused failover could not be triggered.
{code:java}
I0828 08:48:25.785727 7792 statestore.cc:1938] Receive Statestore HA handshake request
I0828 08:48:25.785763 7792 statestore.cc:1969] Set the statestored as standby
I0828 08:48:27.767772 7725 TAcceptQueueServer.cpp:368] New connection to server StatestoreService from client <Host: 127.0.0.1 Port: 57662>
I0828 08:48:27.768299 8669 statestore.cc:318] Subscriber protocol version: V2
I0828 08:48:27.768764 8669 statestore.cc:971] Creating new topic: ''catalog-update' on behalf of subscriber: 'catalog-server@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:26000
I0828 08:48:27.768800 8669 statestore.cc:979] Registering: catalog-server@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:26000
I0828 08:48:27.768815 8669 statestore.cc:1002] Active catalogd role is designated to catalog-server@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:26000
I0828 08:48:27.768833 8669 statestore.cc:566] Subscriber 'catalog-server@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:26000' with type CATALOGD registered (registration id: b044a19ff5ee6a5e:e876dcb098b4ce97)
I0828 08:48:27.897858 7725 TAcceptQueueServer.cpp:368] New connection to server StatestoreService from client <Host: 127.0.0.1 Port: 57688>
I0828 08:48:27.898155 8726 statestore.cc:318] Subscriber protocol version: V2
I0828 08:48:27.898321 8726 statestore.cc:971] Creating new topic: ''impala-request-queue' on behalf of subscriber: 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001
I0828 08:48:27.898342 8726 statestore.cc:971] Creating new topic: ''impala-membership' on behalf of subscriber: 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001
I0828 08:48:27.898350 8726 statestore.cc:979] Registering: impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001
I0828 08:48:27.898362 8726 statestore.cc:566] Subscriber 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001' with type COORDINATOR AND EXECUTOR registered (registration id: b943b7cd22ec0550:2ef70c983040a0b7)
I0828 08:48:27.899354 7725 TAcceptQueueServer.cpp:368] New connection to server StatestoreService from client <Host: 127.0.0.1 Port: 57706>
I0828 08:48:27.899509 8736 statestore.cc:318] Subscriber protocol version: V2
I0828 08:48:27.899601 8736 statestore.cc:979] Registering: impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002
I0828 08:48:27.899611 8736 statestore.cc:566] Subscriber 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002' with type COORDINATOR AND EXECUTOR registered (registration id: 3c41b5f84956a912:b73a816e3e3054a3)
I0828 08:48:28.096181 7725 TAcceptQueueServer.cpp:368] New connection to server StatestoreService from client <Host: 127.0.0.1 Port: 57730>
I0828 08:48:28.096406 8767 statestore.cc:318] Subscriber protocol version: V2
I0828 08:48:28.096516 8767 statestore.cc:979] Registering: impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000
I0828 08:48:28.096532 8767 statestore.cc:566] Subscriber 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000' with type COORDINATOR AND EXECUTOR registered (registration id: 694eaacbc9d457a7:42fa29c79b65d6b9)
I0828 08:48:35.897749 7722 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001, rpc: N6impala18THeartbeatResponseE
I0828 08:48:35.897769 7722 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001
I0828 08:48:35.897831 7722 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:48:35.897838 7722 failure-detector.cc:91] 1 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001'. State is OK
I0828 08:48:35.904700 7716 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23002, rpc: N6impala18THeartbeatResponseE
I0828 08:48:35.904711 7716 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23002
I0828 08:48:35.904752 7716 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23002, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:48:35.904758 7716 failure-detector.cc:91] 1 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002'. State is OK
I0828 08:48:36.097726 7718 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23000, rpc: N6impala18THeartbeatResponseE
I0828 08:48:36.097744 7718 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23000
I0828 08:48:36.097802 7718 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23000, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:48:36.097810 7718 failure-detector.cc:91] 1 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000'. State is OK
I0828 08:48:38.947722 7720 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001, rpc: N6impala18THeartbeatResponseE
I0828 08:48:38.947739 7720 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001
I0828 08:48:38.947782 7720 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:48:38.947789 7720 failure-detector.cc:91] 2 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001'. State is OK
......
I0828 08:50:58.824801 7724 failure-detector.cc:91] 2 consecutive heartbeats failed for 'catalog-server@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:26000'. State is OK
I0828 08:51:00.054733 7719 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001, rpc: N6impala18THeartbeatResponseE
I0828 08:51:00.054735 7714 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23002, rpc: N6impala18THeartbeatResponseE
I0828 08:51:00.054756 7719 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001
I0828 08:51:00.054762 7714 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23002
I0828 08:51:00.054801 7714 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23002, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:51:00.054808 7714 failure-detector.cc:91] 4 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27002'. State is OK
I0828 08:51:00.054831 7719 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23001, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:51:00.054838 7719 failure-detector.cc:91] 4 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27001'. State is OK
I0828 08:51:00.252713 7720 client-cache.h:372] RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23000, rpc: N6impala18THeartbeatResponseE
I0828 08:51:00.252733 7720 client-cache.cc:174] Broken Connection, destroy client for impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23000
I0828 08:51:00.252782 7720 statestore.cc:1414] Unable to send heartbeat message to subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000, received error: RPC recv timed out: dest address: impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:23000, rpc: N6impala18THeartbeatResponseE
Subscriber impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000 timed-out during heartbeat RPC. Timeout is 3s.
I0828 08:51:00.252789 7720 failure-detector.cc:91] 4 consecutive heartbeats failed for 'impalad@impala-ec2-centos79-m6i-4xlarge-xldisk-09d2.vpc.cloudera.com:27000'. State is OK
Caught signal: SIGTERM. Daemon will exit.
{code}
This Thrift RPC issue seems intermittent issue on the host since it only happened for one test case.
> statestore.active-status timeout
> --------------------------------
>
> Key: IMPALA-13348
> URL: https://issues.apache.org/jira/browse/IMPALA-13348
> Project: IMPALA
> Issue Type: Bug
> Components: Backend
> Reporter: Michael Smith
> Assignee: Wenzhe Zhou
> Priority: Major
> Labels: intermittent
> Attachments: failure.tgz
>
>
> custom_cluster/test_statestored_ha.py::TestStatestoredHA::test_statestored_manual_failover_with_failed_rpc failed a UBSAN test run with
> {code:java}
> AssertionError: Metric statestore.active-status did not reach value True in 120s. {code}
> This is likely an intermittent issue; no code or test changes related to this test were added since the last failure. Logs attached.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscribe@impala.apache.org
For additional commands, e-mail: issues-all-help@impala.apache.org