search

yugabyte / yugabyte-db

YugabyteDB - the cloud native distributed SQL database for mission-critical applications.
https://www.yugabyte.com
Other
8.91k stars 1.06k forks source link

[DocDB][LST] ERROR: Timed out: Perform RPC (request call id ...) to ... timed out after 302.000s #14000

Closed def- closed 1 year ago

def- commented 2 years ago

Jira Link: DB-3500

Description

$ cd ~/code/yugabyte-db
$ git checkout 235f23fd3a4f62d5a44d3a58d67e037a10aa5256
$ arc patch D18082
$ arc patch D18251
$ cd ~/code/yb-long-system-test
$ git checkout 9b545334 && ./long_system_test.py --complexity=full --create-destroy-local --yb-ctl-flags=--replication_factor 3 
2022-09-13 22:42:41,500 MainThread INFO     --------------------------------------------------------------------------------
2022-09-13 22:42:41,500 MainThread INFO     Running Long System Test 0.1 - https://github.com/yugabyte/yb-long-system-test/
2022-09-13 22:42:41,500 MainThread INFO     --------------------------------------------------------------------------------
2022-09-13 22:42:41,500 MainThread INFO
2022-09-13 22:42:41,514 MainThread INFO     Reproduce with: git checkout 9b545334 && ./long_system_test.py --complexity=full --create-destroy-local --yb-ctl-flags=--replication_factor 3 --nodes=127.0.0.1:5433,127.0.0.2:5433,127.0.0.3:5433 --runtime=15 --threads=8 --seed=786315
2022-09-13 22:42:41,514 MainThread INFO     /nfusr/dev-server/dfelsing/code/yugabyte-db/bin/yb-ctl destroy
2022-09-13 22:42:45,319 MainThread INFO     /nfusr/dev-server/dfelsing/code/yugabyte-db/bin/yb-ctl --replication_factor 3 create --tserver_flags=yb_enable_read_committed_isolation=false,enable_stream_compression=true,enable_automatic_tablet_splitting=true,ysql_enable_packed_row=false,ycql_enable_packed_row=false,enable_pessimistic_locking=true,log_ysql_catalog_versions=false,ysql_disable_index_backfill=false,ysql_beta_features=true --master_flags=yb_enable_read_committed_isolation=false,enable_stream_compression=true,enable_automatic_tablet_splitting=true,ysql_enable_packed_row=false,ycql_enable_packed_row=false,enable_pessimistic_locking=true,log_ysql_catalog_versions=false,ysql_disable_index_backfill=false,ysql_beta_features=true
2022-09-13 22:43:00,782 MainThread INFO     Database version: PostgreSQL 11.2-YB-2.15.3.0-b0 on x86_64-pc-linux-gnu, compiled by clang version 13.0.1 (https://github.com/yugabyte/llvm-project.git 0131d8e1a20f72a0f374979985db4c2871be71bc), 64-bit
2022-09-13 22:43:00,784 MainThread INFO     Creating tables for database db_lst_786315
2022-09-13 22:43:34,277 MainThread INFO     Starting worker_0: SingleInsertAction, SingleUpdateAction, SingleDeleteAction, BulkInsertAction, BulkUpdateAction, SetConfigAction
2022-09-13 22:43:34,279 MainThread INFO     Starting worker_1: SingleInsertAction, SingleUpdateAction, SingleDeleteAction, BulkInsertAction, BulkUpdateAction, SetConfigAction
2022-09-13 22:43:34,279 MainThread INFO     Starting worker_2: RandomSelectAction, SetConfigAction
2022-09-13 22:43:34,282 MainThread INFO     Starting worker_3: RandomSelectAction, SetConfigAction
2022-09-13 22:43:34,283 MainThread INFO     Starting worker_4: RandomSelectAction, SetConfigAction
2022-09-13 22:43:34,283 MainThread INFO     Starting worker_5: RandomSelectAction, SetConfigAction
2022-09-13 22:43:34,284 MainThread INFO     Starting worker_6: RandomSelectAction, SetConfigAction
2022-09-13 22:43:34,285 MainThread INFO     Starting worker_7: RandomSelectAction, SetConfigAction
2022-09-13 22:43:44,297 MainThread INFO     Worker queries/s: [047.7][013.9][014.7][003.5][017.7][005.7][004.0][015.4]
2022-09-13 22:43:54,307 MainThread INFO     Worker queries/s: [046.1][033.8][024.9][008.6][022.9][009.9][005.2][025.9]
2022-09-13 22:44:04,317 MainThread INFO     Worker queries/s: [044.0][020.1][000.0][016.6][030.2][024.1][000.0][023.6]
2022-09-13 22:44:14,327 MainThread INFO     Worker queries/s: [024.8][018.8][000.0][001.3][010.6][018.7][000.0][017.4]
2022-09-13 22:44:24,337 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:44:34,347 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:44:44,357 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:44:54,367 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:45:04,377 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:45:14,387 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:45:24,397 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:45:34,407 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][0
2022-09-13 22:48:04,557 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:48:14,567 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:48:24,577 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:48:34,587 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:48:44,597 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:48:54,608 MainThread INFO     Worker queries/s: [000.0][000.0][001.7][000.0][000.0][000.0][003.3][000.0]
2022-09-13 22:49:04,609 MainThread INFO     Worker queries/s: [000.0][000.0][000.0][000.0][000.0][000.0][000.0][000.0]
2022-09-13 22:49:11,342 worker_4   ERROR    Unexpected query failure: InternalError_
Query: SELECT (2147483647) - (96), (range_merge(('(24.803004621466698,56.13132978633385]'::NUMRANGE), ('[-87.75769478294472,-50.33708248007602)'::NUMRANGE))) @> (range_merge(('[88.42780490699698,97.72443249454773]'::NUMRANGE), ((range_merge((range_merge(('[-94.24942522010858,51.687167036191056)'::NUMRANGE), ((range_merge(('(-33.615209035491915,-3.2975732496626478]'::NUMRANGE), ((numrange((-85.47452670161172), NULL)) * (numrange(NULL, (21.194846459533295)))))) * ('(-39.86120537464197,70.82327527607163]'::NUMRANGE)))), ('[-73.01970076876745,1.9637786004980597]'::NUMRANGE))) * ('(-81.25646668851405,99.15953622816508]'::NUMRANGE)))) FROM t2 ORDER BY 1 DESC LIMIT 6 FOR UPDATE OF t2 NOWAIT;
  values: None
  runtime: 2022-09-13 22:44:09.306 - 2022-09-13 22:49:11.341
  supports explain: True
  supports rollback: True
  affected rows: None
Action: RandomSelectAction
Error class: InternalError_
Error code: XX000
Error message: ERROR:  Timed out: Perform RPC (request call id 14451) to 127.0.0.2:9100 timed out after 302.000s
Transaction isolation level: read uncommitted
DB Node: host: 127.0.0.2, port: 5433
DB Backend PID: 628735

At 22:44 all queries start hanging, then 5 minutes later at 22:49 they get Internal Errors with RPC timeout. tserver log:

W0913 22:43:30.072561 627412 leader_election.cc:283] T f82722dc9d28436a91f30a69e8ed9eb7 P 1b6d1330ab474051a97d858a58846eb4 [CANDIDATE]: Term 1 pre-election: Tablet error from VoteRequest() call to peer 589497abef274c44ac803c683efeef01: Illegal state (yb/tserver/service_util.cc:257): Tablet f82722dc9d28436a91f30a69e8ed9eb7 not RUNNING: BOOTSTRAPPING (tablet server error 12) (raft group state error 0)
W0913 22:43:30.941064 627417 replica_state.cc:793] T 6c5c150b888a424b81fe3a76f73511d1 P 1b6d1330ab474051a97d858a58846eb4 [term 1 LEADER]: Can't advance the committed index across term boundaries until operations from the current term are replicated. Last committed operation was: 0.0, New majority replicated is: 0.0, Current term is: 1
W0913 22:43:53.760143 628439 log.cc:884] Time spent Append to log took a long time: real 0.093s user 0.000s sys 0.000s
W0913 22:43:54.179759 627464 log.cc:884] Time spent Append to log took a long time: real 0.061s user 0.000s sys 0.000s
W0913 22:43:54.335515 628439 log.cc:884] Time spent Append to log took a long time: real 0.056s user 0.000s sys 0.000s
W0913 22:44:00.025610 627464 log.cc:735] Time spent T 3709656533d34c2f9272c52fdf36f128 P 1b6d1330ab474051a97d858a58846eb4: Log roll took a long time: real 0.159s   user 0.000s sys 0.000s
W0913 22:44:00.027290 628979 transaction_participant.cc:1323] T 3709656533d34c2f9272c52fdf36f128 P 1b6d1330ab474051a97d858a58846eb4: Transaction not found: 1a69a730-9cfe-4d51-b51e-6ef3d84c9bc3, for: metadata with write id
W0913 22:44:00.410105 629042 log.cc:884] Time spent Append to log took a long time: real 0.102s user 0.000s sys 0.000s
W0913 22:44:00.478040 628953 log.cc:884] Time spent Append to log took a long time: real 0.076s user 0.000s sys 0.000s
W0913 22:44:02.628480 627990 tablet_rpc.cc:459] Internal error (yb/docdb/conflict_resolution.cc:1095): Failed Read(tablet: 4b6803980ce143a4bbd43206fb80482f, num_ops: 1, num_attempts: 1, txn: e03677b2-86d8-4008-86c2-8c568e7464c4, subtxn: [none]) to tablet 4b6803980ce143a4bbd43206fb80482f on tablet server { uuid: 589497abef274c44ac803c683efeef01 private: [host: "127.0.0.3" port: 9100] cloud_info: placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" after 1 attempt(s): Skip locking since entity was modified by a recent commit: kSkipLocking (transaction error 5)
W0913 22:44:49.350191 629101 replica_state.cc:793] T 276798a27297448bbfa58d9e114bb5b9 P 1b6d1330ab474051a97d858a58846eb4 [term 2 LEADER]: Can't advance the committed index across term boundaries until operations from the current term are replicated. Last committed operation was: 1.98, New majority replicated is: 1.98, Current term is: 2
[...]
I0913 22:44:08.226104 627401 write_operation.cc:93] Apply operation failed: Operation failed. Try again (yb/tablet/transaction_participant.cc:204): Transaction was recently aborted: a5b6822f-5e27-4f28-8c67-55bef7caa29b: 40001 (pgsql error 40001) (transaction error 1)
I0913 22:44:09.495718 627966 tablet_rpc.cc:457] Operation failed. Try again (yb/docdb/conflict_resolution.cc:117): Failed Write(tablet: 950e2b8edca94c49bd8b9167936f4030, num_ops: 1, num_attempts: 1, txn: d140b31c-1c30-48cb-8ef7-703da10f4eb4, subtxn: [none]) to tablet 950e2b8edca94c49bd8b9167936f4030 on tablet server { uuid: 814814c00c6d4c9a9112ea6d69bad532 private: [host: "127.0.0.2" port: 9100] cloud_info: placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" after 1 attempt(s): d140b31c-1c30-48cb-8ef7-703da10f4eb4 Conflicts with committed transaction: 10905e35-0424-4941-ae0b-1cab75826a38 (transaction error 3)
I0913 22:44:27.091799 627202 reactor.cc:466] TabletServer_R003: DEBUG: Closing idle connection: Connection (0x0000000005bb9578) server 127.0.0.2:40025 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:27.092259 627206 reactor.cc:466] TabletServer_R007: DEBUG: Closing idle connection: Connection (0x0000000005bb9458) server 127.0.0.3:38483 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:37.592485 627202 reactor.cc:466] TabletServer_R003: DEBUG: Closing idle connection: Connection (0x0000000009913458) server 127.0.0.2:35105 => 127.0.0.1:9100 - it has been idle for 65.1008s
I0913 22:44:37.592622 627199 reactor.cc:466] TabletServer_R000: DEBUG: Closing idle connection: Connection (0x00000000099137b8) server 127.0.0.3:33705 => 127.0.0.1:9100 - it has been idle for 65.1008s
I0913 22:44:39.191627 627199 reactor.cc:466] TabletServer_R000: DEBUG: Closing idle connection: Connection (0x000000000294ea38) server 127.0.0.1:32827 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:39.191908 627203 reactor.cc:466] TabletServer_R004: DEBUG: Closing idle connection: Connection (0x0000000002953b18) server 127.0.0.1:36283 => 127.0.0.1:9100 - it has been idle for 65.0988s
I0913 22:44:39.192191 627200 reactor.cc:466] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000000000294e5b8) server 127.0.0.1:39051 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:39.192298 627206 reactor.cc:466] TabletServer_R007: DEBUG: Closing idle connection: Connection (0x000000000294e498) server 127.0.0.1:44099 => 127.0.0.1:9100 - it has been idle for 65.1008s
I0913 22:44:39.292212 627206 reactor.cc:466] TabletServer_R007: DEBUG: Closing idle connection: Connection (0x0000000002953c38) server 127.0.0.1:37429 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:39.292342 627200 reactor.cc:466] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000000000294e6d8) server 127.0.0.1:40191 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:39.292443 627200 reactor.cc:466] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000000000294e918) server 127.0.0.1:45615 => 127.0.0.1:9100 - it has been idle for 65.0998s
I0913 22:44:39.292587 627205 reactor.cc:466] TabletServer_R006: DEBUG: Closing idle connection: Connection (0x0000000002953d58) server 127.0.0.1:46195 => 127.0.0.1:9100 - it has been idle for 65.0008s
I0913 22:44:42.791659 627464 log.cc:869] T 3709656533d34c2f9272c52fdf36f128 P 1b6d1330ab474051a97d858a58846eb4: Max segment size 4194304 reached. Starting new segment allocation.
I0913 22:44:42.792302 627464 log.cc:744] T 3709656533d34c2f9272c52fdf36f128 P 1b6d1330ab474051a97d858a58846eb4: Last appended OpId in segment /nfusr/dev-server/dfelsing/yugabyte-data/node-1/disk-1/yb-data/tserver/wals/table-00004000000030008000000000004018.tablegroup.parent.uuid/tablet-3709656533d34c2f9272c52fdf36f128/wal-000000003: 1.35621
I0913 22:44:42.796336 627464 log.cc:753] T 3709656533d34c2f9272c52fdf36f128 P 1b6d1330ab474051a97d858a58846eb4: Rolled over to a new segment: /nfusr/dev-server/dfelsing/yugabyte-data/node-1/disk-1/yb-data/tserver/wals/table-00004000000030008000000000004018.tablegroup.parent.uuid/tablet-3709656533d34c2f9272c52fdf36f128/wal-000000004
I0913 22:44:49.329372 627357 tablet_service.cc:2090] Received Leader stepdown RPC: tablet_id: "28f021cf640d40cbb3894bc059095666" dest_uuid: "1b6d1330ab474051a97d858a58846eb4" new_leader_uuid: "814814c00c6d4c9a9112ea6d69bad532"
I0913 22:44:49.329469 627357 raft_consensus.cc:727] Active config has 0 and committed has 0 servers in transition.
I0913 22:44:49.329555 627357 raft_consensus.cc:751] T 28f021cf640d40cbb3894bc059095666 P 1b6d1330ab474051a97d858a58846eb4 [term 1 LEADER]: Transferring leadership to 814814c00c6d4c9a9112ea6d69bad532
I0913 22:44:49.329572 627357 raft_consensus.cc:1099] T 28f021cf640d40cbb3894bc059095666 P 1b6d1330ab474051a97d858a58846eb4 [term 1 LEADER]: Becoming Follower/Learner. State: Replica: 1b6d1330ab474051a97d858a58846eb4, State: 1, Role: LEADER, Watermarks: {Received: 1.39 Committed: 1.39} Leader: 1.39, new leader: 814814c00c6d4c9a9112ea6d69bad532, initial_fd_wait: <uninitialized>
I0913 22:44:49.329609 627357 consensus_meta.cc:317] T 28f021cf640d40cbb3894bc059095666 P 1b6d1330ab474051a97d858a58846eb4: Updating active role from LEADER to FOLLOWER. Consensus state: current_term: 1 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "1b6d1330ab474051a97d858a58846eb4" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } peers { permanent_uuid: "589497abef274c44ac803c683efeef01" member_type: VOTER last_known_private_addr { host: "127.0.0.3" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } peers { permanent_uuid: "814814c00c6d4c9a9112ea6d69bad532" member_type: VOTER last_known_private_addr { host: "127.0.0.2" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I0913 22:44:49.329679 627357 consensus_queue.cc:287] T 28f021cf640d40cbb3894bc059095666 P 1b6d1330ab474051a97d858a58846eb4 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated op: 1.39, Majority replicated op: 1.39, Committed index: 1.39, Last applied: 1.39, Last appended: 1.39, Current term: 1, Majority size: -1, State: QUEUE_OPEN, Mode: NON_LEADER
[...]
W0913 22:44:56.383209 629097 replica_state.cc:793] T 4b6803980ce143a4bbd43206fb80482f P 1b6d1330ab474051a97d858a58846eb4 [term 2 LEADER]: Can't advance the committed index across term boundaries until operations from the current term are replicated. Last committed operation was: 1.4093, New majority replicated is: 1.4093, Current term is: 2
W0913 22:49:11.476877 627419 yb_rpc.cc:392] Call yb.tserver.PgClientService.Perform 127.0.0.1:47259 => 127.0.0.1:9100 (request call id 4301) took 302137ms (client timeout 302000ms).
W0913 22:49:11.477766 629098 yb_rpc.cc:392] Call yb.tserver.TabletServerService.Read 127.0.0.2:36879 => 127.0.0.1:9100 (request call id 60454) took 302018ms (client timeout 302000ms).
W0913 22:49:11.478963 627399 yb_rpc.cc:392] Call yb.tserver.PgClientService.Perform 127.0.0.1:49933 => 127.0.0.1:9100 (request call id 12872) took 301955ms (client timeout 302000ms).
W0913 22:49:11.479280 627932 yb_rpc.cc:392] Call yb.tserver.TabletServerService.Read 127.0.0.3:41723 => 127.0.0.1:9100 (request call id 102240) took 301772ms (client timeout 302000ms).
W0913 22:49:11.480187 627395 yb_rpc.cc:392] Call yb.tserver.TabletServerService.Write 127.0.0.2:36879 => 127.0.0.1:9100 (request call id 60727) took 301721ms (client timeout 302000ms).

I am seeing these timeouts often. The logs in other cases look similar. LST logs: lst_2022-09-13_22:42:41_786315.zip Yugabyte-data directory, accessible from withing Yugabyte org: https://drive.google.com/file/d/1Dg5GEm_w2ZX2IajtmiX1zruSBLKvm74r/view?usp=sharing

rthallamko3 commented 2 years ago

@def- , As discussed offline, if this occurs when the server is overwhelmed - over 75% CPU consumption, then the lack of resources can cause the workload to hit timeouts. So in essence this could be a sizing exercise for the test. Can you check and let us know if adding additional nodes helps run the stress test without timeouts?

def- commented 2 years ago

Alright, I'm trying with fewer threads now to get a lower CPU utilization (50-60%) on the same system.

def- commented 2 years ago

@rthallamko3 I can confirm that with lower CPU usage (50-60%) this issue doesn't appear. I am still seeing occurrences where the universe can't run any queries for ~4 minutes, but it resolves itself before the 5 minute timeout mark. Example:

2022-09-20 23:20:03,504 MainThread INFO     --------------------------------------------------------------------------------
2022-09-20 23:20:03,504 MainThread INFO     Running Long System Test 0.1 - https://github.com/yugabyte/yb-long-system-test/
2022-09-20 23:20:03,504 MainThread INFO     --------------------------------------------------------------------------------
2022-09-20 23:20:03,504 MainThread INFO
2022-09-20 23:20:03,515 MainThread INFO     Reproduce with: git checkout 6e7997a3 && ./long_system_test.py --nodes=127.0.0.1:5433,127.0.0.2:5433,127.0.0.3:5433 --threads=2 --runtime=60 --max-columns=20 --complexity=full --seed=078365
2022-09-20 23:20:03,834 MainThread INFO     Database version: PostgreSQL 11.2-YB-2.15.3.0-b0 on x86_64-pc-linux-gnu, compiled by clang version 13.0.1 (https://github.com/yugabyte/llvm-project.git 0131d8e1a20f72a0f374979985db4c2871be71bc), 64-bit
2022-09-20 23:20:03,837 MainThread INFO     Creating tables for database db_lst_078365
2022-09-20 23:20:19,473 MainThread INFO     Starting worker_0: RandomSelectAction, SetConfigAction
2022-09-20 23:20:19,474 MainThread INFO     Starting worker_1: RandomSelectAction, SetConfigAction
2022-09-20 23:20:29,481 MainThread INFO     Worker queries/s: [062.7][114.8]
2022-09-20 23:20:39,491 MainThread INFO     Worker queries/s: [135.4][142.9]
2022-09-20 23:20:49,502 MainThread INFO     Worker queries/s: [149.8][144.1]
2022-09-20 23:20:59,512 MainThread INFO     Worker queries/s: [153.1][140.1]
2022-09-20 23:21:09,522 MainThread INFO     Worker queries/s: [155.6][148.6]
2022-09-20 23:21:19,532 MainThread INFO     Worker queries/s: [152.3][145.1]
2022-09-20 23:21:29,542 MainThread INFO     Worker queries/s: [157.2][141.7]
2022-09-20 23:21:39,552 MainThread INFO     Worker queries/s: [149.4][145.7]
2022-09-20 23:21:49,562 MainThread INFO     Worker queries/s: [153.0][133.4]
2022-09-20 23:21:59,572 MainThread INFO     Worker queries/s: [156.6][147.5]
2022-09-20 23:22:09,582 MainThread INFO     Worker queries/s: [144.2][149.3]
2022-09-20 23:22:19,592 MainThread INFO     Worker queries/s: [150.5][146.3]
2022-09-20 23:22:29,602 MainThread INFO     Worker queries/s: [144.1][142.2]
2022-09-20 23:22:39,612 MainThread INFO     Worker queries/s: [145.1][138.0]
2022-09-20 23:22:49,622 MainThread INFO     Worker queries/s: [149.1][146.5]
2022-09-20 23:22:59,632 MainThread INFO     Worker queries/s: [146.2][139.8]
2022-09-20 23:23:09,642 MainThread INFO     Worker queries/s: [147.6][135.6]
2022-09-20 23:23:19,652 MainThread INFO     Worker queries/s: [159.3][142.8]
2022-09-20 23:23:29,662 MainThread INFO     Worker queries/s: [155.5][150.1]
2022-09-20 23:23:39,671 MainThread INFO     Worker queries/s: [148.2][138.6]
2022-09-20 23:23:49,681 MainThread INFO     Worker queries/s: [161.2][150.2]
2022-09-20 23:23:59,691 MainThread INFO     Worker queries/s: [149.7][059.7]
2022-09-20 23:24:09,701 MainThread INFO     Worker queries/s: [156.0][143.1]
2022-09-20 23:24:19,711 MainThread INFO     Worker queries/s: [157.7][150.7]
2022-09-20 23:24:29,721 MainThread INFO     Worker queries/s: [154.6][148.2]
2022-09-20 23:24:39,731 MainThread INFO     Worker queries/s: [154.9][138.3]
2022-09-20 23:24:49,741 MainThread INFO     Worker queries/s: [160.8][147.6]
2022-09-20 23:24:59,751 MainThread INFO     Worker queries/s: [155.6][143.7]
2022-09-20 23:25:09,761 MainThread INFO     Worker queries/s: [147.6][134.7]
2022-09-20 23:25:19,771 MainThread INFO     Worker queries/s: [149.8][148.6]
2022-09-20 23:25:29,781 MainThread INFO     Worker queries/s: [157.2][148.7]
2022-09-20 23:25:39,791 MainThread INFO     Worker queries/s: [153.5][135.6]
2022-09-20 23:25:49,801 MainThread INFO     Worker queries/s: [156.2][153.5]
2022-09-20 23:25:59,811 MainThread INFO     Worker queries/s: [153.7][150.4]
2022-09-20 23:26:09,821 MainThread INFO     Worker queries/s: [149.8][151.0]
2022-09-20 23:26:19,831 MainThread INFO     Worker queries/s: [152.1][140.5]
2022-09-20 23:26:29,841 MainThread INFO     Worker queries/s: [158.4][155.5]
2022-09-20 23:26:39,851 MainThread INFO     Worker queries/s: [152.8][149.2]
2022-09-20 23:26:49,861 MainThread INFO     Worker queries/s: [144.3][151.2]
2022-09-20 23:26:59,872 MainThread INFO     Worker queries/s: [146.2][147.2]
2022-09-20 23:27:09,881 MainThread INFO     Worker queries/s: [146.6][146.3]
2022-09-20 23:27:19,891 MainThread INFO     Worker queries/s: [155.9][145.1]
2022-09-20 23:27:29,901 MainThread INFO     Worker queries/s: [158.9][146.2]
2022-09-20 23:27:39,911 MainThread INFO     Worker queries/s: [150.1][137.2]
2022-09-20 23:27:49,920 MainThread INFO     Worker queries/s: [140.9][120.7]
2022-09-20 23:27:59,930 MainThread INFO     Worker queries/s: [141.0][136.6]
2022-09-20 23:28:09,940 MainThread INFO     Worker queries/s: [153.2][145.5]
2022-09-20 23:28:19,950 MainThread INFO     Worker queries/s: [159.8][151.0]
2022-09-20 23:28:29,960 MainThread INFO     Worker queries/s: [156.5][148.3]
2022-09-20 23:28:39,970 MainThread INFO     Worker queries/s: [146.2][143.8]
2022-09-20 23:28:49,980 MainThread INFO     Worker queries/s: [155.2][143.7]
2022-09-20 23:28:59,990 MainThread INFO     Worker queries/s: [153.3][139.8]
2022-09-20 23:29:10,000 MainThread INFO     Worker queries/s: [158.6][152.1]
2022-09-20 23:29:20,010 MainThread INFO     Worker queries/s: [150.6][139.7]
2022-09-20 23:29:30,019 MainThread INFO     Worker queries/s: [145.3][143.6]
2022-09-20 23:29:40,029 MainThread INFO     Worker queries/s: [145.3][140.9]
2022-09-20 23:29:50,039 MainThread INFO     Worker queries/s: [143.9][137.5]
2022-09-20 23:30:00,049 MainThread INFO     Worker queries/s: [151.2][146.5]
2022-09-20 23:30:10,059 MainThread INFO     Worker queries/s: [152.0][149.0]
2022-09-20 23:30:20,069 MainThread INFO     Worker queries/s: [152.0][150.1]
2022-09-20 23:30:30,079 MainThread INFO     Worker queries/s: [151.7][145.0]
2022-09-20 23:30:40,089 MainThread INFO     Worker queries/s: [149.0][150.3]
2022-09-20 23:30:50,099 MainThread INFO     Worker queries/s: [148.1][141.2]
2022-09-20 23:31:00,109 MainThread INFO     Worker queries/s: [155.2][148.8]
2022-09-20 23:31:10,119 MainThread INFO     Worker queries/s: [154.3][147.3]
2022-09-20 23:31:20,129 MainThread INFO     Worker queries/s: [150.2][140.2]
2022-09-20 23:31:30,139 MainThread INFO     Worker queries/s: [155.1][147.3]
2022-09-20 23:31:40,149 MainThread INFO     Worker queries/s: [146.6][144.4]
2022-09-20 23:31:50,159 MainThread INFO     Worker queries/s: [151.4][144.4]
2022-09-20 23:32:00,169 MainThread INFO     Worker queries/s: [153.5][142.3]
2022-09-20 23:32:10,179 MainThread INFO     Worker queries/s: [157.2][144.8]
2022-09-20 23:32:20,189 MainThread INFO     Worker queries/s: [145.5][147.6]
2022-09-20 23:32:30,199 MainThread INFO     Worker queries/s: [149.4][139.4]
2022-09-20 23:32:40,207 MainThread INFO     Worker queries/s: [153.0][144.2]
2022-09-20 23:32:50,217 MainThread INFO     Worker queries/s: [149.4][140.1]
2022-09-20 23:33:00,227 MainThread INFO     Worker queries/s: [157.5][145.7]
2022-09-20 23:33:10,237 MainThread INFO     Worker queries/s: [158.7][139.1]
2022-09-20 23:33:20,241 MainThread INFO     Worker queries/s: [156.6][149.7]
2022-09-20 23:33:30,251 MainThread INFO     Worker queries/s: [151.0][135.3]
2022-09-20 23:33:40,261 MainThread INFO     Worker queries/s: [147.5][147.3]
2022-09-20 23:33:50,271 MainThread INFO     Worker queries/s: [159.3][135.3]
2022-09-20 23:34:00,281 MainThread INFO     Worker queries/s: [153.9][137.1]
2022-09-20 23:34:10,291 MainThread INFO     Worker queries/s: [158.9][147.0]
2022-09-20 23:34:20,301 MainThread INFO     Worker queries/s: [152.0][135.7]
2022-09-20 17:57:51,886 MainThread INFO     Worker queries/s: [078.2][050.8]
2022-09-20 17:58:01,896 MainThread INFO     Worker queries/s: [085.0][052.2]
2022-09-21 06:31:07,732 MainThread INFO     Worker queries/s: [036.0][041.2]
2022-09-21 06:31:17,742 MainThread INFO     Worker queries/s: [036.1][037.6]
2022-09-21 06:31:27,751 MainThread INFO     Worker queries/s: [039.9][039.1]
2022-09-21 06:31:37,761 MainThread INFO     Worker queries/s: [033.0][039.4]
2022-09-21 06:31:47,771 MainThread INFO     Worker queries/s: [031.8][033.7]
2022-09-21 06:31:57,781 MainThread INFO     Worker queries/s: [027.2][036.3]
2022-09-21 06:32:07,794 MainThread INFO     Worker queries/s: [035.3][036.2]
2022-09-21 06:32:17,803 MainThread INFO     Worker queries/s: [034.7][034.5]
2022-09-21 06:32:27,816 MainThread INFO     Worker queries/s: [034.2][026.8]
2022-09-21 06:32:37,826 MainThread INFO     Worker queries/s: [038.3][036.3]
2022-09-21 06:32:47,836 MainThread INFO     Worker queries/s: [034.5][035.1]
2022-09-21 06:32:57,846 MainThread INFO     Worker queries/s: [030.3][035.0]
2022-09-21 06:33:07,857 MainThread INFO     Worker queries/s: [033.1][032.2]
2022-09-21 06:33:17,866 MainThread INFO     Worker queries/s: [034.8][035.6]
2022-09-21 06:33:27,876 MainThread INFO     Worker queries/s: [033.8][031.9]
2022-09-21 06:33:37,878 MainThread INFO     Worker queries/s: [029.7][028.9]
2022-09-21 06:33:47,887 MainThread INFO     Worker queries/s: [027.6][026.8]
2022-09-21 06:33:57,897 MainThread INFO     Worker queries/s: [032.9][032.1]
2022-09-21 06:34:07,901 MainThread INFO     Worker queries/s: [032.4][029.8]
2022-09-21 06:34:17,906 MainThread INFO     Worker queries/s: [018.0][014.9]
2022-09-21 06:34:27,916 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:34:37,919 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:34:47,920 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:34:57,924 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:35:07,925 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:35:17,931 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:35:27,932 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:35:37,943 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:35:47,952 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:35:57,962 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:36:07,971 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:36:17,977 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:36:27,987 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:36:37,997 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:36:48,004 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:36:58,009 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:37:08,019 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:37:18,029 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:37:28,032 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:37:38,036 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:37:48,046 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:37:58,051 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:38:08,061 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:38:18,071 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:38:28,078 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:38:38,087 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:38:48,093 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:38:58,104 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:39:08,114 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:39:18,124 MainThread INFO     Worker queries/s: [013.5][013.1]
2022-09-21 06:39:28,134 MainThread INFO     Worker queries/s: [028.8][026.5]
2022-09-21 06:39:38,147 MainThread INFO     Worker queries/s: [028.1][029.8]
2022-09-21 06:39:48,157 MainThread INFO     Worker queries/s: [029.1][028.0]
2022-09-21 06:39:58,169 MainThread INFO     Worker queries/s: [029.4][030.7]
2022-09-21 06:40:08,179 MainThread INFO     Worker queries/s: [030.1][029.5]
2022-09-21 06:40:18,189 MainThread INFO     Worker queries/s: [026.8][028.2]
2022-09-21 06:40:28,202 MainThread INFO     Worker queries/s: [032.0][027.8]
2022-09-21 06:40:38,213 MainThread INFO     Worker queries/s: [024.3][029.5]
2022-09-21 06:40:48,223 MainThread INFO     Worker queries/s: [029.2][022.9]
2022-09-21 06:40:58,233 MainThread INFO     Worker queries/s: [031.3][032.3]
2022-09-21 06:41:08,243 MainThread INFO     Worker queries/s: [028.4][031.1]
2022-09-21 06:41:18,253 MainThread INFO     Worker queries/s: [028.8][029.2]
2022-09-21 06:41:28,263 MainThread INFO     Worker queries/s: [029.7][023.9]
2022-09-21 06:41:38,272 MainThread INFO     Worker queries/s: [024.4][027.9]
2022-09-21 06:41:48,282 MainThread INFO     Worker queries/s: [031.1][029.2]
2022-09-21 06:41:58,292 MainThread INFO     Worker queries/s: [024.9][028.8]
2022-09-21 06:42:08,302 MainThread INFO     Worker queries/s: [023.8][026.1]
2022-09-21 06:42:18,312 MainThread INFO     Worker queries/s: [025.6][025.9]
2022-09-21 06:42:28,322 MainThread INFO     Worker queries/s: [029.2][028.6]
2022-09-21 06:42:38,332 MainThread INFO     Worker queries/s: [030.1][021.7]
2022-09-21 06:42:48,342 MainThread INFO     Worker queries/s: [028.8][029.5]
2022-09-21 06:42:58,352 MainThread INFO     Worker queries/s: [030.2][029.0]
2022-09-21 06:43:08,362 MainThread INFO     Worker queries/s: [027.5][023.0]
2022-09-21 06:43:18,365 MainThread INFO     Worker queries/s: [030.9][026.6]
2022-09-21 06:43:28,378 MainThread INFO     Worker queries/s: [031.9][028.0]
2022-09-21 06:43:38,384 MainThread INFO     Worker queries/s: [032.3][027.5]
2022-09-21 06:43:48,394 MainThread INFO     Worker queries/s: [026.5][027.0]
2022-09-21 06:43:58,404 MainThread INFO     Worker queries/s: [024.0][026.1]
2022-09-21 06:44:08,414 MainThread INFO     Worker queries/s: [027.8][023.0]
2022-09-21 06:44:18,424 MainThread INFO     Worker queries/s: [027.2][025.9]
2022-09-21 06:44:28,436 MainThread INFO     Worker queries/s: [027.4][027.6]
2022-09-21 06:44:38,446 MainThread INFO     Worker queries/s: [027.2][023.3]
2022-09-21 06:44:48,456 MainThread INFO     Worker queries/s: [027.0][028.6]
2022-09-21 06:44:58,467 MainThread INFO     Worker queries/s: [026.1][026.2]
2022-09-21 06:45:08,475 MainThread INFO     Worker queries/s: [025.6][026.1]
2022-09-21 06:45:18,486 MainThread INFO     Worker queries/s: [026.8][026.4]
2022-09-21 06:45:28,496 MainThread INFO     Worker queries/s: [024.4][025.9]
2022-09-21 06:45:38,506 MainThread INFO     Worker queries/s: [022.8][024.7]
2022-09-21 06:45:48,516 MainThread INFO     Worker queries/s: [025.9][030.9]
2022-09-21 06:45:58,526 MainThread INFO     Worker queries/s: [025.1][023.2]
2022-09-21 06:46:08,536 MainThread INFO     Worker queries/s: [007.0][008.9]
2022-09-21 06:46:18,546 MainThread INFO     Worker queries/s: [005.6][001.3]
2022-09-21 06:46:28,556 MainThread INFO     Worker queries/s: [028.2][024.8]
2022-09-21 06:46:38,566 MainThread INFO     Worker queries/s: [025.0][030.2]
2022-09-21 06:46:48,576 MainThread INFO     Worker queries/s: [027.6][024.7]
2022-09-21 06:46:58,586 MainThread INFO     Worker queries/s: [024.1][022.4]
2022-09-21 06:47:08,599 MainThread INFO     Worker queries/s: [027.1][024.1]
2022-09-21 06:47:18,609 MainThread INFO     Worker queries/s: [026.3][024.7]
2022-09-21 06:47:28,619 MainThread INFO     Worker queries/s: [024.3][023.5]
2022-09-21 06:47:38,629 MainThread INFO     Worker queries/s: [025.5][026.6]
2022-09-21 06:47:48,632 MainThread INFO     Worker queries/s: [019.1][021.0]
2022-09-21 06:47:58,640 MainThread INFO     Worker queries/s: [007.1][008.0]
2022-09-21 06:48:08,649 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:48:18,659 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:48:28,669 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:48:38,671 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:48:48,675 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:48:58,684 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:49:08,690 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:49:18,700 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:49:28,711 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:49:38,713 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:49:48,721 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:49:58,731 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:50:08,731 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:50:18,742 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:50:28,745 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:50:38,754 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:50:48,764 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:50:58,766 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:51:08,768 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:51:18,770 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:51:28,780 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:51:38,790 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:51:48,802 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:51:58,808 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:52:08,818 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:52:18,828 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:52:28,838 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:52:38,848 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:52:48,850 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:52:58,860 MainThread INFO     Worker queries/s: [016.2][015.1]
2022-09-21 06:53:08,870 MainThread INFO     Worker queries/s: [024.0][024.3]
2022-09-21 06:53:18,880 MainThread INFO     Worker queries/s: [020.1][023.2]
2022-09-21 06:53:28,894 MainThread INFO     Worker queries/s: [021.0][020.9]
2022-09-21 06:53:38,906 MainThread INFO     Worker queries/s: [019.8][021.3]
2022-09-21 06:53:48,917 MainThread INFO     Worker queries/s: [019.6][019.7]
2022-09-21 06:53:58,927 MainThread INFO     Worker queries/s: [023.7][027.1]
2022-09-21 06:54:08,937 MainThread INFO     Worker queries/s: [021.5][023.5]
2022-09-21 06:54:18,948 MainThread INFO     Worker queries/s: [022.2][018.9]
2022-09-21 06:54:28,956 MainThread INFO     Worker queries/s: [024.5][023.2]
2022-09-21 06:54:38,968 MainThread INFO     Worker queries/s: [017.9][022.6]
2022-09-21 06:54:48,978 MainThread INFO     Worker queries/s: [025.9][023.1]
2022-09-21 06:54:58,988 MainThread INFO     Worker queries/s: [018.8][027.9]
2022-09-21 06:55:08,995 MainThread INFO     Worker queries/s: [023.1][016.3]
2022-09-21 06:55:18,997 MainThread INFO     Worker queries/s: [022.6][023.5]
2022-09-21 06:55:29,007 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:55:39,017 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:55:49,027 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:55:59,034 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:09,045 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:19,050 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:29,060 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:39,064 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:49,074 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:59,079 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:57:09,081 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:57:19,091 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:57:29,105 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:57:39,115 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:57:49,125 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:57:59,130 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:58:09,140 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:58:19,142 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:58:29,152 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:58:39,156 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:58:49,169 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:58:59,179 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:09,189 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:19,198 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:29,208 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:39,212 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:49,222 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:59,232 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:00:09,234 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:54:28,956 MainThread INFO     Worker queries/s: [024.5][023.2]
2022-09-21 06:54:38,968 MainThread INFO     Worker queries/s: [017.9][022.6]
2022-09-21 06:54:48,978 MainThread INFO     Worker queries/s: [025.9][023.1]
2022-09-21 06:54:58,988 MainThread INFO     Worker queries/s: [018.8][027.9]
2022-09-21 06:55:08,995 MainThread INFO     Worker queries/s: [023.1][016.3]
2022-09-21 06:55:18,997 MainThread INFO     Worker queries/s: [022.6][023.5]
2022-09-21 06:55:29,007 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:55:39,017 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:55:49,027 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:55:59,034 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:09,045 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:19,050 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:29,060 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:39,064 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:56:49,074 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:09,189 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:19,198 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:29,208 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:39,212 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:49,222 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:59,232 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:00:09,234 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:00:19,244 MainThread INFO     Worker queries/s: [001.0][001.3]
2022-09-21 07:00:29,260 MainThread INFO     Worker queries/s: [023.8][021.3]
2022-09-21 07:00:39,271 MainThread INFO     Worker queries/s: [019.9][020.3]
2022-09-21 07:00:49,280 MainThread INFO     Worker queries/s: [023.7][021.3]
2022-09-21 07:00:59,293 MainThread INFO     Worker queries/s: [024.4][018.2]
2022-09-21 07:01:09,304 MainThread INFO     Worker queries/s: [024.2][022.9]
2022-09-21 07:01:19,318 MainThread INFO     Worker queries/s: [025.5][023.3]
2022-09-21 07:01:29,329 MainThread INFO     Worker queries/s: [021.9][023.4]
2022-09-21 07:01:39,339 MainThread INFO     Worker queries/s: [023.6][023.2]
2022-09-21 07:01:49,349 MainThread INFO     Worker queries/s: [021.2][020.9]
2022-09-21 07:01:59,359 MainThread INFO     Worker queries/s: [019.5][022.5]
2022-09-21 07:02:09,374 MainThread INFO     Worker queries/s: [019.7][022.0]
2022-09-21 07:02:19,385 MainThread INFO     Worker queries/s: [022.1][022.0]
2022-09-21 07:02:29,392 MainThread INFO     Worker queries/s: [020.0][020.6]
2022-09-21 07:02:39,402 MainThread INFO     Worker queries/s: [022.2][020.5]
2022-09-21 06:59:09,189 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:19,198 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:29,208 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:39,212 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:49,222 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 06:59:59,232 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:00:09,234 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:00:19,244 MainThread INFO     Worker queries/s: [001.0][001.3]
2022-09-21 07:00:29,260 MainThread INFO     Worker queries/s: [023.8][021.3]
2022-09-21 07:00:39,271 MainThread INFO     Worker queries/s: [019.9][020.3]
2022-09-21 07:00:49,280 MainThread INFO     Worker queries/s: [023.7][021.3]
2022-09-21 07:00:59,293 MainThread INFO     Worker queries/s: [024.4][018.2]
2022-09-21 07:01:09,304 MainThread INFO     Worker queries/s: [024.2][022.9]
2022-09-21 07:01:19,318 MainThread INFO     Worker queries/s: [025.5][023.3]
2022-09-21 07:01:29,329 MainThread INFO     Worker queries/s: [021.9][023.4]
2022-09-21 07:01:39,339 MainThread INFO     Worker queries/s: [023.6][023.2]
2022-09-21 07:01:49,349 MainThread INFO     Worker queries/s: [021.2][020.9]
2022-09-21 07:01:59,359 MainThread INFO     Worker queries/s: [019.5][022.5]
2022-09-21 07:02:09,374 MainThread INFO     Worker queries/s: [019.7][022.0]
2022-09-21 07:02:19,385 MainThread INFO     Worker queries/s: [022.1][022.0]
2022-09-21 07:02:29,392 MainThread INFO     Worker queries/s: [020.0][020.6]
2022-09-21 07:02:39,402 MainThread INFO     Worker queries/s: [022.2][020.5]
2022-09-21 07:02:49,412 MainThread INFO     Worker queries/s: [020.6][021.7]
2022-09-21 07:02:59,422 MainThread INFO     Worker queries/s: [021.0][021.9]
2022-09-21 07:03:09,434 MainThread INFO     Worker queries/s: [021.7][022.3]
2022-09-21 07:03:19,444 MainThread INFO     Worker queries/s: [021.7][021.0]
2022-09-21 07:03:29,451 MainThread INFO     Worker queries/s: [023.7][022.8]
2022-09-21 07:03:39,461 MainThread INFO     Worker queries/s: [016.5][019.2]
2022-09-21 07:03:49,471 MainThread INFO     Worker queries/s: [018.9][017.4]
2022-09-21 07:03:59,482 MainThread INFO     Worker queries/s: [022.4][026.2]
2022-09-21 07:04:09,492 MainThread INFO     Worker queries/s: [020.8][022.8]
2022-09-21 07:04:19,506 MainThread INFO     Worker queries/s: [022.9][024.2]
2022-09-21 07:04:29,516 MainThread INFO     Worker queries/s: [018.9][022.2]
2022-09-21 07:04:39,526 MainThread INFO     Worker queries/s: [021.5][024.4]
2022-09-21 07:04:49,536 MainThread INFO     Worker queries/s: [025.1][022.5]
2022-09-21 07:04:59,546 MainThread INFO     Worker queries/s: [020.2][018.0]
2022-09-21 07:05:09,555 MainThread INFO     Worker queries/s: [019.6][017.8]
2022-09-21 07:05:19,567 MainThread INFO     Worker queries/s: [020.2][017.7]
2022-09-21 07:05:29,577 MainThread INFO     Worker queries/s: [020.0][019.1]
2022-09-21 07:05:39,587 MainThread INFO     Worker queries/s: [022.7][020.7]
2022-09-21 07:05:49,597 MainThread INFO     Worker queries/s: [020.2][019.5]
2022-09-21 07:05:59,610 MainThread INFO     Worker queries/s: [023.3][020.4]
2022-09-21 07:06:09,621 MainThread INFO     Worker queries/s: [021.5][023.8]
2022-09-21 07:06:19,631 MainThread INFO     Worker queries/s: [016.6][020.3]
2022-09-21 07:06:29,641 MainThread INFO     Worker queries/s: [020.3][019.0]
2022-09-21 07:06:39,651 MainThread INFO     Worker queries/s: [021.3][018.2]
2022-09-21 07:06:49,661 MainThread INFO     Worker queries/s: [021.1][019.1]
2022-09-21 07:06:59,672 MainThread INFO     Worker queries/s: [019.0][018.9]
2022-09-21 07:07:09,686 MainThread INFO     Worker queries/s: [017.9][022.7]
2022-09-21 07:07:19,696 MainThread INFO     Worker queries/s: [018.0][019.0]
2022-09-21 07:07:29,706 MainThread INFO     Worker queries/s: [019.1][020.6]
2022-09-21 07:07:39,716 MainThread INFO     Worker queries/s: [017.6][022.1]
2022-09-21 07:07:49,726 MainThread INFO     Worker queries/s: [020.2][020.5]
2022-09-21 07:07:59,736 MainThread INFO     Worker queries/s: [015.9][020.4]
2022-09-21 07:08:09,749 MainThread INFO     Worker queries/s: [021.4][020.0]
2022-09-21 07:08:19,763 MainThread INFO     Worker queries/s: [018.7][021.0]
2022-09-21 07:08:29,773 MainThread INFO     Worker queries/s: [018.5][021.7]
2022-09-21 07:08:39,783 MainThread INFO     Worker queries/s: [022.0][019.6]
2022-09-21 07:08:49,793 MainThread INFO     Worker queries/s: [018.6][022.3]
2022-09-21 07:08:59,803 MainThread INFO     Worker queries/s: [018.9][018.1]
2022-09-21 07:09:09,813 MainThread INFO     Worker queries/s: [020.8][015.9]
2022-09-21 07:09:19,818 MainThread INFO     Worker queries/s: [018.1][020.2]
2022-09-21 07:09:29,833 MainThread INFO     Worker queries/s: [018.2][020.8]
2022-09-21 07:09:39,843 MainThread INFO     Worker queries/s: [019.6][017.7]
2022-09-21 07:09:49,853 MainThread INFO     Worker queries/s: [017.0][019.5]
2022-09-21 07:09:59,863 MainThread INFO     Worker queries/s: [014.0][018.3]
2022-09-21 07:10:09,873 MainThread INFO     Worker queries/s: [017.6][018.9]
2022-09-21 07:10:19,886 MainThread INFO     Worker queries/s: [020.5][018.5]
2022-09-21 07:10:29,896 MainThread INFO     Worker queries/s: [019.4][019.6]
2022-09-21 07:10:39,904 MainThread INFO     Worker queries/s: [017.4][017.2]
2022-09-21 07:10:49,914 MainThread INFO     Worker queries/s: [015.4][017.4]
2022-09-21 07:10:59,924 MainThread INFO     Worker queries/s: [017.8][021.1]
2022-09-21 07:11:09,934 MainThread INFO     Worker queries/s: [019.5][021.1]
2022-09-21 07:11:19,944 MainThread INFO     Worker queries/s: [019.5][017.8]
2022-09-21 07:11:29,954 MainThread INFO     Worker queries/s: [019.9][019.1]
2022-09-21 07:11:39,962 MainThread INFO     Worker queries/s: [018.8][018.2]
2022-09-21 07:11:49,972 MainThread INFO     Worker queries/s: [019.8][020.2]
2022-09-21 07:11:59,982 MainThread INFO     Worker queries/s: [019.6][019.3]
2022-09-21 07:12:09,984 MainThread INFO     Worker queries/s: [006.5][005.4]
2022-09-21 07:12:19,992 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:12:30,002 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:12:40,012 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:12:50,022 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:13:00,032 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:13:10,043 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:13:20,053 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:13:30,061 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:13:40,071 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:13:50,071 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:14:00,081 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:14:10,091 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:14:20,099 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:14:30,108 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:14:40,114 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:14:50,124 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:15:00,129 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:15:10,139 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:15:20,149 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:15:30,159 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:15:40,168 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:15:50,179 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:16:00,190 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:16:10,200 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:16:20,205 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:16:30,214 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:16:40,220 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:16:50,228 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:17:00,238 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:17:10,248 MainThread INFO     Worker queries/s: [012.5][010.7]
2022-09-21 07:17:20,258 MainThread INFO     Worker queries/s: [018.5][018.7]
2022-09-21 07:17:30,270 MainThread INFO     Worker queries/s: [021.6][017.9]
2022-09-21 07:17:40,280 MainThread INFO     Worker queries/s: [016.4][017.9]
2022-09-21 07:17:50,290 MainThread INFO     Worker queries/s: [016.6][019.1]
2022-09-21 07:18:00,300 MainThread INFO     Worker queries/s: [017.8][016.4]
2022-09-21 07:18:10,312 MainThread INFO     Worker queries/s: [019.8][022.0]
2022-09-21 07:18:20,326 MainThread INFO     Worker queries/s: [018.1][016.2]
2022-09-21 07:18:30,336 MainThread INFO     Worker queries/s: [016.2][018.6]
2022-09-21 07:18:40,347 MainThread INFO     Worker queries/s: [017.6][017.6]
2022-09-21 07:18:50,356 MainThread INFO     Worker queries/s: [019.2][019.9]
2022-09-21 07:19:00,366 MainThread INFO     Worker queries/s: [020.0][019.8]
2022-09-21 07:19:10,376 MainThread INFO     Worker queries/s: [018.3][017.5]
2022-09-21 07:19:20,390 MainThread INFO     Worker queries/s: [018.3][018.2]
2022-09-21 07:19:30,400 MainThread INFO     Worker queries/s: [019.5][014.5]
2022-09-21 07:19:40,410 MainThread INFO     Worker queries/s: [016.7][017.4]
2022-09-21 07:19:50,420 MainThread INFO     Worker queries/s: [021.4][017.8]
2022-09-21 07:20:00,431 MainThread INFO     Worker queries/s: [016.7][019.9]
2022-09-21 07:20:10,441 MainThread INFO     Worker queries/s: [016.9][017.4]
2022-09-21 07:20:20,451 MainThread INFO     Worker queries/s: [019.3][019.4]
2022-09-21 07:20:30,461 MainThread INFO     Worker queries/s: [014.4][016.8]
2022-09-21 07:20:40,476 MainThread INFO     Worker queries/s: [016.0][014.8]
2022-09-21 07:20:50,478 MainThread INFO     Worker queries/s: [020.3][021.8]
2022-09-21 07:21:00,491 MainThread INFO     Worker queries/s: [016.0][017.0]
2022-09-21 07:21:10,507 MainThread INFO     Worker queries/s: [013.9][018.1]
2022-09-21 07:21:20,517 MainThread INFO     Worker queries/s: [019.1][017.3]
2022-09-21 07:21:30,532 MainThread INFO     Worker queries/s: [016.9][014.9]
2022-09-21 07:21:40,542 MainThread INFO     Worker queries/s: [012.9][014.3]
2022-09-21 07:21:50,552 MainThread INFO     Worker queries/s: [016.7][019.3]
2022-09-21 07:22:00,561 MainThread INFO     Worker queries/s: [019.1][018.3]
2022-09-21 07:22:10,571 MainThread INFO     Worker queries/s: [016.0][018.3]
2022-09-21 07:22:20,587 MainThread INFO     Worker queries/s: [016.0][016.5]
2022-09-21 07:22:30,597 MainThread INFO     Worker queries/s: [014.4][017.5]
2022-09-21 07:22:40,611 MainThread INFO     Worker queries/s: [020.1][019.2]
2022-09-21 07:22:50,621 MainThread INFO     Worker queries/s: [018.0][016.2]
2022-09-21 07:23:00,631 MainThread INFO     Worker queries/s: [016.4][017.6]
2022-09-21 07:23:10,641 MainThread INFO     Worker queries/s: [015.5][018.1]
2022-09-21 07:23:20,651 MainThread INFO     Worker queries/s: [013.5][015.5]
2022-09-21 07:23:30,663 MainThread INFO     Worker queries/s: [011.2][013.3]
2022-09-21 07:23:40,672 MainThread INFO     Worker queries/s: [014.1][009.5]
2022-09-21 07:23:50,682 MainThread INFO     Worker queries/s: [014.2][016.5]
2022-09-21 07:24:00,692 MainThread INFO     Worker queries/s: [006.4][005.3]
2022-09-21 07:24:10,702 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:24:20,712 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:24:30,722 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:24:40,732 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:24:50,738 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:25:00,740 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:25:10,748 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:25:20,751 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:25:30,761 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:25:40,771 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:25:50,772 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:00,782 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:10,792 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:20,796 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:30,806 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:40,807 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:50,820 MainThread INFO     Worker queries/s: [000.0][000.0]
2022-09-21 07:26:50,820 MainThread INFO
2022-09-21 07:26:50,820 MainThread INFO     --------------------------------------------------------------------------------
2022-09-21 07:26:50,821 MainThread INFO     LST finished successfully in 3619.5 sec
2022-09-21 07:26:50,821 MainThread INFO     --------------------------------------------------------------------------------
2022-09-21 07:26:50,821 MainThread INFO
2022-09-21 07:26:50,821 MainThread INFO     Expected error statistics: 17% failures in 112154 queries
2022-09-21 07:26:50,821 MainThread INFO     XX000 ERROR:  cache lookup failed for attribute: https://github.com/yugabyte/yugabyte-db/issues/11999
2022-09-21 07:26:50,821 MainThread INFO       SingleUpdateAction: 9327, SingleDeleteAction: 9453
2022-09-21 07:26:50,821 MainThread INFO     22003 re.compile('ERROR:  .* out of range'): Overflow can curr2022-09-21 07:26:50,821 MainThread INFO     40001 ERROR:  Operation expired: Transaction aborted: kAborted: Expected, see https://github.com/yugabyte/yugabyte-db/issues/11994
2022-09-21 07:26:50,821 MainThread INFO       SingleUpdateAction: 2, SingleDeleteAction: 2
2022-09-21 07:26:50,821 MainThread INFO     40001 ERROR:  Operation expired: Heartbeat: Expected, see https://github.com/yugabyte/yugabyte-db/issues/11994
2022-09-21 07:26:50,821 MainThread INFO       SingleUpdateAction: 1
2022-09-21 07:26:50,821 MainThread INFO     57014 ERROR:  canceling statement due to statement timeout: Queries can time out, but there shouldn't be too many
2022-09-21 07:26:50,822 MainThread INFO       SingleDeleteAction: 4, SingleUpdateAction: 3
2022-09-21 07:26:50,821 MainThread INFO     40001 ERROR:  Operation expired: Transaction aborted: kAborted: Expected, see https://github.com/yugabyte/yugabyte-db/issues/11994
2022-09-21 07:26:50,821 MainThread INFO       SingleUpdateAction: 2, SingleDeleteAction: 2
2022-09-21 07:26:50,821 MainThread INFO     40001 ERROR:  Operation expired: Heartbeat: Expected, see https://github.com/yugabyte/yugabyte-db/issues/11994
2022-09-21 07:26:50,821 MainThread INFO       SingleUpdateAction: 1
2022-09-21 07:26:50,821 MainThread INFO     57014 ERROR:  canceling statement due to statement timeout: Queries can time out, but there shouldn't be too many
2022-09-21 07:26:50,822 MainThread INFO       SingleDeleteAction: 4, SingleUpdateAction: 3

LST logs: lst_2022-09-21_06:26:31_388111.zip yugabyte-data directory accessible from within Yugabyte org: https://drive.google.com/file/d/1ebFaO6PrDIkG8N1JRUrpc4gYMztsJP7n/view?usp=sharing

See the periods with 0 queries in both threads for multiple minutes. Note that this workload is only running SELECT and SET config actions. Is this really expected? How do customers deal with such situations? Since there are only SELECTs running on empty data, why are the queries even slowing down so much and getting down to hang for minutes?

Edit: The LST logs show that there is still a cancellation of query after statement timeout after 5 minutes in those situations, see for example:

2022-09-21 07:12:03,299 worker_0   DELETE FROM tg0_2 WHERE ((int4range((-2147483648), NULL)) * ('(,97)'::INT4RANGE)) -|- (int4range(NULL, (-91)));
2022-09-21 07:12:03,300 worker_0   EXPLAIN (ANALYZE TRUE, VERBOSE FALSE, COSTS TRUE, BUFFERS TRUE, TIMING TRUE, SUMMARY FALSE, FORMAT TEXT)
UPDATE t0 SET c2_int2range = '[20,)'::INT2RANGE WHERE TRUE;
2022-09-21 07:12:03,360 worker_1   UPDATE t0 SET c2_int2range = '[-23,26]'::INT2RANGE WHERE TRUE;
2022-09-21 07:12:03,520 worker_1   savepoint sp_0;
2022-09-21 07:12:03,525 worker_1   UPDATE tg0_1 SET c3_numrange = numrange(NULL, (-32.72992686927245)) WHERE TRUE;
2022-09-21 07:17:03,317 worker_0   Failed: canceling statement due to statement timeout
2022-09-21 07:17:03,325 worker_0   EXPLAIN (ANALYZE TRUE, VERBOSE FALSE, COSTS FALSE, BUFFERS FALSE, TIMING FALSE, SUMMARY TRUE, FORMAT XML)
DELETE FROM t1 WHERE TRUE;
2022-09-21 07:17:03,409 worker_1   rollback;
2022-09-21 07:17:03,456 worker_0   DELETE FROM t1 WHERE TRUE;

and

2022-09-21 06:47:52,704 worker_0   UPDATE tg1_1 SET c8_float4 = ||/ (2147483647) WHERE TRUE;
2022-09-21 06:47:52,748 worker_1   INSERT INTO tg0_3 (c0_numrange, c1_int4range, c2_int8range, c3_int, c4_json, c5_smallint, c6_int4range, c7_json) VALUES ('(-88.34693009046148,-51.79912402560767]'::NUMRANGE, '[-72,-38)'::INT4RANGE, '[43,98)'::INT8RANGE, -2147483648, '{"a": 7, "b": ["0"], "c": false}'::json, -53, '(-60,)'::INT4RANGE, '{"a": 3, "b": ["0", "1", "2", "3", "4", "5", "6", "7", "8"], "c": true}'::json);
2022-09-21 06:47:52,762 worker_1   EXPLAIN (ANALYZE TRUE, VERBOSE TRUE, COSTS FALSE, BUFFERS FALSE, TIMING FALSE, SUMMARY TRUE, FORMAT XML)
INSERT INTO tg0_3 (c0_numrange, c1_int4range, c2_int8range, c3_int, c4_json, c5_smallint, c6_int4range, c7_json) VALUES ('[-86.68695098522414,1.4244080928871483]'::NUMRANGE, '(-86,55]'::INT4RANGE, '(,80]'::INT8RANGE, -22, '{"a": 3, "b": ["0", "1"], "c": false}'::json, 32767, '[-60,67)'::INT4RANGE, '{"a": 9, "b": ["0", "1", "2"], "c": true}'::json);
2022-09-21 06:47:52,772 worker_1   INSERT INTO tg0_3 (c0_numrange, c1_int4range, c2_int8range, c3_int, c4_json, c5_smallint, c6_int4range, c7_json) VALUES ('[-86.68695098522414,1.4244080928871483]'::NUMRANGE, '(-86,55]'::INT4RANGE, '(,80]'::INT8RANGE, -22, '{"a": 3, "b": ["0", "1"], "c": false}'::json, 32767, '[-60,67)'::INT4RANGE, '{"a": 9, "b": ["0", "1", "2"], "c": true}'::json);
2022-09-21 06:47:52,778 worker_1   INSERT INTO tg1_1 (c0_int, c1_float4, c2_smallint, c3_varchar, c4_numeric, c5_numrange, c6_smallint, c7_daterange, c8_float4, c9_int2range) VALUES (32, -25.59736050379, -87, '/dev/null; touch /tmp/blns.fail ; echo', 75.74980054800679, '[-12.68671791219829,67.79780112407997)'::NUMRANGE, -81, '(1972-08-08,2017-03-05)'::DATERANGE, -53.518739372815816, '(-11,48)'::INT2RANGE);
2022-09-21 06:47:52,781 worker_1   DELETE FROM tg0_3 WHERE TRUE;
2022-09-21 06:52:52,709 worker_0   Failed: canceling statement due to statement timeout
2022-09-21 06:52:52,712 worker_0   UPDATE t0 SET c3_boolean = ('(-85.81180835864555,-11.015775217529182]'::NUMRANGE) >= (range_merge(('(-71.87712180962691,-32.156180788984855]'::NUMRANGE), (('(72.11111492702469,78.79423862748928]'::NUMRANGE) * ('[-73.56455111751808,52.59898436512384]'::NUMRANGE)))) WHERE TRUE;
2022-09-21 06:52:52,781 worker_0   EXPLAIN (ANALYZE FALSE, VERBOSE TRUE, COSTS FALSE, BUFFERS FALSE, TIMING FALSE, SUMMARY FALSE, FORMAT JSON)
UPDATE tg0_0 SET c6_bigint = -2147483648 WHERE FALSE;
2022-09-21 06:52:52,785 worker_0   Failed: cache lookup failed for attribute -8 of relation 18397
2022-09-21 06:52:52,785 worker_1   Failed: canceling statement due to statement timeout
2022-09-21 06:52:52,788 worker_0   EXPLAIN (ANALYZE TRUE, VERBOSE FALSE, COSTS TRUE, BUFFERS TRUE, TIMING TRUE, SUMMARY TRUE, FORMAT JSON)
INSERT INTO tg1_1 (c0_int, c1_float4, c2_smallint, c3_varchar, c4_numeric, c5_numrange, c6_smallint, c7_daterange, c8_float4, c9_int2range) VALUES (74, 50.03120184113459, 11, 'LS0=', -66.99221287241255, '[-73.80019931294109,-46.48471542715053]'::NUMRANGE, -25, '(1991-04-21,2005-01-29]'::DATERANGE, -39.45298214848858, '(-69,-26)'::INT2RANGE);
frozenspider commented 1 year ago

I've hit ERROR: cache lookup failed for attribute -8 of relation 16442 a few times when trying to repro #13132 (without a timeout)

rthallamko3 commented 1 year ago

https://github.com/yugabyte/yugabyte-db/issues/11999 seems to be resolved as well. Closing this for now. @kripasreenivasan , Let us know if this repros again.