Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Skaled sleeps for empty block interval during catchup under load #1560

Closed
oleksandrSydorenkoJ opened this issue Jun 22, 2023 · 12 comments · Fixed by #1566, #1571, #1585, #1593 or #1630
Closed

Skaled sleeps for empty block interval during catchup under load #1560

oleksandrSydorenkoJ opened this issue Jun 22, 2023 · 12 comments · Fixed by #1566, #1571, #1585, #1593 or #1630
Assignees
@kladkogex
Labels
bug Something isn't working release:2.2 skaled

Comments

@oleksandrSydorenkoJ
Copy link

oleksandrSydorenkoJ commented Jun 22, 2023 •
edited
Loading

Description:
Skaled on updated node stuck because of #1558 and starting catching up and never reaching the actual block.

Preconditions:
Active schain medium type with MTM

Versions:
15 nodes with 3.16.1 (2.1.1 release)
1 node with schain:3.17.0-beta.1 (2.2 release)

To Reproduce

  1. Run a small load on the chain for a long time (1-10 TPB) - select to load skaled on 2.1.1 verisons
  2. check skaled on the updated node

Expected behavior
Skaled should catching up with blocks faster rather than new blocks being mined

Actual state
10-12 blocks catching up in 15-30 seconds

Logs:

skaled_slow_catchup.log

[2023-06-22 12:43:52.940] [29:catchup] [info] 1218078:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1218078:FROM_NODE:31
[2023-06-22 12:44:20.186] [29:catchup] [info] 1218088:CATCHUP_GOT_BLOCKS:COUNT:12:STARTBLOCK:1218089:FROM_NODE:25
[2023-06-22 12:44:34.810] [29:catchup] [info] 1218101:CATCHUP_GOT_BLOCKS:COUNT:8:STARTBLOCK:1218101:FROM_NODE:9
[2023-06-22 12:44:55.970] [29:catchup] [info] 1218109:CATCHUP_GOT_BLOCKS:COUNT:9:STARTBLOCK:1218109:FROM_NODE:24
[2023-06-22 12:45:16.871] [29:catchup] [info] 1218118:CATCHUP_GOT_BLOCKS:COUNT:9:STARTBLOCK:1218118:FROM_NODE:23
[2023-06-22 12:45:37.907] [29:catchup] [info] 1218127:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1218127:FROM_NODE:15
[2023-06-22 12:45:58.555] [29:catchup] [info] 1218137:CATCHUP_GOT_BLOCKS:COUNT:7:STARTBLOCK:1218137:FROM_NODE:14
[2023-06-22 12:46:19.381] [29:catchup] [info] 1218144:CATCHUP_GOT_BLOCKS:COUNT:8:STARTBLOCK:1218144:FROM_NODE:16
[2023-06-22 12:46:40.195] [29:catchup] [info] 1218152:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1218152:FROM_NODE:19
[2023-06-22 12:47:00.985] [29:catchup] [info] 1218162:CATCHUP_GOT_BLOCKS:COUNT:8:STARTBLOCK:1218162:FROM_NODE:11
[2023-06-22 12:47:22.087] [29:catchup] [info] 1218170:CATCHUP_GOT_BLOCKS:COUNT:11:STARTBLOCK:1218170:FROM_NODE:17
@DmytroNazarenko DmytroNazarenko moved this to Ready For Pickup in SKALE Engineering 🚀 Jun 22, 2023
@DmytroNazarenko DmytroNazarenko moved this from Ready For Pickup to Ready For Release Candidate in SKALE Engineering 🚀 Jun 26, 2023
@DmytroNazarenko DmytroNazarenko linked a pull request Jun 26, 2023 that will close this issue
1558 skaled stucks fix #1566
Merged
@DmytroNazarenko
Copy link
Collaborator

skaled: 3.17.0-beta.3

@DmytroNazarenko DmytroNazarenko moved this from Ready For Release Candidate to Merged To Release Candidate in SKALE Engineering 🚀 Jun 26, 2023
@oleksandrSydorenkoJ
Copy link
Author

Network: Regressions
Actual for skalenetwork/schain:3.17.0-beta.3
schain name: quiet-alchiba

[2023-06-26 12:38:32.222] [7:catchup] [info] 1519303:CATCHUP_GOT_BLOCKS:COUNT:15106:STARTBLOCK:1519304:FROM_NODE:11
[2023-06-26 13:09:40.302] [7:catchup] [info] 1534409:CATCHUP_GOT_BLOCKS:COUNT:10069:STARTBLOCK:1534410:FROM_NODE:31
[2023-06-26 13:17:33.759] [7:catchup] [info] 1544479:CATCHUP_GOT_BLOCKS:COUNT:96:STARTBLOCK:1544480:FROM_NODE:14
[2023-06-26 13:17:52.858] [7:catchup] [info] 1544576:CATCHUP_GOT_BLOCKS:COUNT:2:STARTBLOCK:1544576:FROM_NODE:33
[2023-06-26 13:18:13.429] [7:catchup] [info] 1544578:CATCHUP_GOT_BLOCKS:COUNT:2:STARTBLOCK:1544578:FROM_NODE:54
[2023-06-26 13:18:34.071] [7:catchup] [info] 1544580:CATCHUP_GOT_BLOCKS:COUNT:2:STARTBLOCK:1544580:FROM_NODE:9

skaled_long_start.txt

@github-project-automation github-project-automation bot moved this from Merged To Release Candidate to Ready For Pickup in SKALE Engineering 🚀 Jun 26, 2023
@kladkogex kladkogex linked a pull request Jun 27, 2023 that will close this issue
1558 consensus stucks #1571
Merged
@DmytroNazarenko DmytroNazarenko moved this from Ready For Pickup to In Progress in SKALE Engineering 🚀 Jun 27, 2023
@github-project-automation github-project-automation bot moved this from In Progress to Ready For Release Candidate in SKALE Engineering 🚀 Jun 27, 2023
@DmytroNazarenko
Copy link
Collaborator

skaled: 3.17.0-beta.4

@DmytroNazarenko DmytroNazarenko moved this from Ready For Release Candidate to Merged To Release Candidate in SKALE Engineering 🚀 Jun 30, 2023
@oleksandrSydorenkoJ
Copy link
Author

Not solved in 3.17.0-beta.4

skaled couldn't reach actual block number due load (10 tx per block, block mining time = 3-4 seconds)

[2023-06-30 15:06:28.669] [7:catchup] [info] 1279876:CATCHUP_GOT_BLOCKS:COUNT:24:STARTBLOCK:1279877:FROM_NODE:15
[2023-06-30 15:06:40.175] [7:catchup] [info] 1279901:CATCHUP_GOT_BLOCKS:COUNT:7:STARTBLOCK:1279901:FROM_NODE:14
[2023-06-30 15:07:01.213] [7:catchup] [info] 1279908:CATCHUP_GOT_BLOCKS:COUNT:9:STARTBLOCK:1279908:FROM_NODE:16
[2023-06-30 15:07:22.416] [7:catchup] [info] 1279917:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1279917:FROM_NODE:19
[2023-06-30 15:07:43.155] [7:catchup] [info] 1279927:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1279927:FROM_NODE:11
[2023-06-30 15:08:04.164] [7:catchup] [info] 1279937:CATCHUP_GOT_BLOCKS:COUNT:11:STARTBLOCK:1279937:FROM_NODE:17
[2023-06-30 15:08:25.202] [7:catchup] [info] 1279948:CATCHUP_GOT_BLOCKS:COUNT:8:STARTBLOCK:1279948:FROM_NODE:35
[2023-06-30 15:08:46.336] [7:catchup] [info] 1279956:CATCHUP_GOT_BLOCKS:COUNT:9:STARTBLOCK:1279956:FROM_NODE:28
[2023-06-30 15:09:07.948] [7:catchup] [info] 1279965:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1279965:FROM_NODE:20
[2023-06-30 15:09:29.020] [7:catchup] [info] 1279975:CATCHUP_GOT_BLOCKS:COUNT:11:STARTBLOCK:1279975:FROM_NODE:31
[2023-06-30 15:09:49.889] [7:catchup] [info] 1279986:CATCHUP_GOT_BLOCKS:COUNT:11:STARTBLOCK:1279986:FROM_NODE:29
[2023-06-30 15:10:11.227] [7:catchup] [info] 1279997:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1279997:FROM_NODE:25
[2023-06-30 15:10:31.883] [7:catchup] [info] 1280007:CATCHUP_GOT_BLOCKS:COUNT:9:STARTBLOCK:1280007:FROM_NODE:9
[2023-06-30 15:10:52.858] [7:catchup] [info] 1280016:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1280016:FROM_NODE:24
[2023-06-30 15:11:14.004] [7:catchup] [info] 1280026:CATCHUP_GOT_BLOCKS:COUNT:9:STARTBLOCK:1280026:FROM_NODE:23
[2023-06-30 15:11:34.737] [7:catchup] [info] 1280035:CATCHUP_GOT_BLOCKS:COUNT:10:STARTBLOCK:1280035:FROM_NODE:15



miner
2023-06-30 15:05:40.586210   Block stats:BN:1279876:BTS:1688137537:TXS:35:HDRS:11:LOGS:40:SENGS:1:TXRS:542:BLCKS:3:ACCS:101:BQS:1:BDS:72:TSS:0:UTX:0:VTX:9:CMM:254029
2023-06-30 15:06:32.649743   Block stats:BN:1279901:BTS:1688137585:TXS:57:HDRS:11:LOGS:40:SENGS:1:TXRS:1149:BLCKS:3:ACCS:101:BQS:1:BDS:97:TSS:0:UTX:0:VTX:6:CMM:426445
2023-06-30 15:06:42.759175   Block stats:BN:1279908:BTS:1688137599:TXS:26:HDRS:11:LOGS:40:SENGS:1:TXRS:1225:BLCKS:3:ACCS:101:BQS:1:BDS:104:TSS:0:UTX:0:VTX:20:CMM:458824
2023-06-30 15:07:03.672560   Block stats:BN:1279917:BTS:1688137619:TXS:59:HDRS:11:LOGS:40:SENGS:1:TXRS:1337:BLCKS:3:ACCS:101:BQS:1:BDS:113:TSS:0:UTX:0:VTX:5:CMM:558665
2023-06-30 15:07:25.737028   Block stats:BN:1279927:BTS:1688137641:TXS:53:HDRS:11:LOGS:40:SENGS:1:TXRS:1429:BLCKS:3:ACCS:101:BQS:1:BDS:123:TSS:0:UTX:0:VTX:5:CMM:619754
2023-06-30 15:07:44.932762   Block stats:BN:1279937:BTS:1688137662:TXS:29:HDRS:11:LOGS:40:SENGS:1:TXRS:1525:BLCKS:3:ACCS:101:BQS:1:BDS:133:TSS:0:UTX:0:VTX:11:CMM:702905
2023-06-30 15:08:10.659780   Block stats:BN:1279948:BTS:1688137682:TXS:27:HDRS:11:LOGS:40:SENGS:1:TXRS:1633:BLCKS:3:ACCS:101:BQS:1:BDS:144:TSS:0:UTX:0:VTX:6:CMM:785898
2023-06-30 15:08:31.923217   Block stats:BN:1279956:BTS:1688137704:TXS:37:HDRS:11:LOGS:40:SENGS:1:TXRS:1691:BLCKS:3:ACCS:101:BQS:1:BDS:152:TSS:0:UTX:0:VTX:16:CMM:840687
2023-06-30 15:08:49.458370   Block stats:BN:1279965:BTS:1688137724:TXS:73:HDRS:11:LOGS:40:SENGS:1:TXRS:1799:BLCKS:3:ACCS:101:BQS:1:BDS:161:TSS:0:UTX:0:VTX:4:CMM:891990
2023-06-30 15:09:09.466644   Block stats:BN:1279975:BTS:1688137746:TXS:43:HDRS:11:LOGS:40:SENGS:1:TXRS:1890:BLCKS:3:ACCS:101:BQS:1:BDS:171:TSS:0:UTX:0:VTX:7:CMM:967635
2023-06-30 15:09:30.898519   Block stats:BN:1279986:BTS:1688137767:TXS:39:HDRS:11:LOGS:40:SENGS:1:TXRS:1992:BLCKS:3:ACCS:101:BQS:1:BDS:182:TSS:0:UTX:0:VTX:9:CMM:1073929
2023-06-30 15:09:53.733234   Block stats:BN:1279997:BTS:1688137787:TXS:41:HDRS:11:LOGS:40:SENGS:1:TXRS:2078:BLCKS:3:ACCS:101:BQS:1:BDS:193:TSS:0:UTX:0:VTX:20:CMM:1141107
2023-06-30 15:10:16.235360   Block stats:BN:1280007:BTS:1688137808:TXS:19:HDRS:11:LOGS:40:SENGS:1:TXRS:2186:BLCKS:3:ACCS:101:BQS:1:BDS:203:TSS:0:UTX:0:VTX:10:CMM:1229321
2023-06-30 15:10:33.370247   Block stats:BN:1280016:BTS:1688137830:TXS:34:HDRS:11:LOGS:40:SENGS:1:TXRS:2257:BLCKS:3:ACCS:101:BQS:1:BDS:212:TSS:0:UTX:0:VTX:4:CMM:1268529
2023-06-30 15:10:56.619567   Block stats:BN:1280026:BTS:1688137852:TXS:35:HDRS:11:LOGS:40:SENGS:1:TXRS:2340:BLCKS:3:ACCS:101:BQS:1:BDS:222:TSS:0:UTX:0:VTX:2:CMM:1341215
2023-06-30 15:11:15.147509   Block stats:BN:1280035:BTS:1688137871:TXS:33:HDRS:11:LOGS:40:SENGS:1:TXRS:2409:BLCKS:3:ACCS:101:BQS:1:BDS:231:TSS:0:UTX:0:VTX:6:CMM:1389011

@github-project-automation github-project-automation bot moved this from Merged To Release Candidate to Ready For Pickup in SKALE Engineering 🚀 Jun 30, 2023
@kladkogex
Copy link
Collaborator

It is strange it is giving very small number of blocks per catchup

It should give more blocks.

There is a bug somewhere. How large is each transaction in bytes?

@kladkogex kladkogex assigned dimalit and unassigned dimalit Jun 30, 2023
@DmytroNazarenko DmytroNazarenko moved this from Ready For Pickup to In Progress in SKALE Engineering 🚀 Jul 3, 2023
@dimalit
Copy link
Contributor

dimalit commented Jul 4, 2023

Probably, all incoming transactions go to future queue. Also, I'd suggest to check if consensus can create latest blocks by processing received earlier consensus messages, and not catch-up

@kladkogex kladkogex linked a pull request Jul 11, 2023 that will close this issue
1560_slow_catchup_under_load #1585
Merged
@PolinaKiporenko PolinaKiporenko moved this from Ready For Pickup to In Progress in SKALE Engineering 🚀 Aug 28, 2023
@kladkogex kladkogex linked a pull request Aug 29, 2023 that will close this issue
1560 slow catchup #1630
Merged
@github-project-automation github-project-automation bot moved this from In Progress to Ready For Release Candidate in SKALE Engineering 🚀 Aug 31, 2023
@kladkogex
Copy link
Collaborator

Reopening this bug and moving it to 2.3 as there may be some slow cases remaining but they are non-critical

@kladkogex kladkogex reopened this Sep 1, 2023
@github-project-automation github-project-automation bot moved this from Ready For Release Candidate to Ready For Pickup in SKALE Engineering 🚀 Sep 1, 2023
@PolinaKiporenko PolinaKiporenko added this to the SKALE 2.3 milestone Sep 1, 2023
@oleksandrSydorenkoJ
Copy link
Author

catchup_3_17_0_beta-8.txt

@oleksandrSydorenkoJ oleksandrSydorenkoJ changed the title Slow catchup under load Skled sleeps for emty block interval during catchup under load Sep 7, 2023
@oleksandrSydorenkoJ oleksandrSydorenkoJ mentioned this issue Sep 7, 2023
Closed
@oleksandrSydorenkoJ
Copy link
Author

Closed as fixed.

Slow catcup will be fixed in #1640

@github-project-automation github-project-automation bot moved this from Ready For Pickup to Ready For Release Candidate in SKALE Engineering 🚀 Sep 7, 2023
@kladkogex kladkogex reopened this Sep 7, 2023
@github-project-automation github-project-automation bot moved this from Ready For Release Candidate to Ready For Pickup in SKALE Engineering 🚀 Sep 7, 2023
@PolinaKiporenko PolinaKiporenko removed this from the SKALE 2.3 milestone Sep 7, 2023
@PolinaKiporenko PolinaKiporenko changed the title Skled sleeps for emty block interval during catchup under load Skaled sleeps for empty block interval during catchup under load Sep 8, 2023
@PolinaKiporenko PolinaKiporenko moved this from Ready For Pickup to Ready For Release Candidate in SKALE Engineering 🚀 Sep 8, 2023
@PolinaKiporenko PolinaKiporenko moved this from Ready For Release Candidate to Merged To Release Candidate in SKALE Engineering 🚀 Sep 8, 2023
@oleksandrSydorenkoJ oleksandrSydorenkoJ mentioned this issue Sep 25, 2023
Open
@github-project-automation github-project-automation bot moved this from Merged To Release Candidate to Ready For Release Candidate in SKALE Engineering 🚀 Sep 25, 2023
@EvgeniyZZ EvgeniyZZ moved this from Ready For Release Candidate to Done in SKALE Engineering 🚀 Oct 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@kladkogex kladkogex

Labels
bug Something isn't working release:2.2 skaled
Projects
SKALE Engineering 🚀
Archived in project
Milestone
No milestone
5 participants
@dimalit @kladkogex @DmytroNazarenko @oleksandrSydorenkoJ @PolinaKiporenko