search

skalenetwork / node-cli

A command line tool to setup, register and maintain your SKALE node. Written in Python.
https://skale.network
GNU Affero General Public License v3.0
20 stars 7 forks source link

Part of the skaled logs are lost during container removal #542

Closed sync-by-unito[bot] closed 2 years ago

sync-by-unito[bot] commented 3 years ago

When we're stopping and removing skaled containers in the node-cli, logs are saved before the stop signal. Instead of this, we should save logs after the stop signal and before removing the container.

┆Issue is synchronized with this Jira Bug ┆Attachments: skale_schain_quiet-pherkad-minor-2.log

sync-by-unito[bot] commented 2 years ago

➤ Automation for Jira commented:

Corresponding Pull Request https://github.com/skalenetwork/node-cli/pull/549

sync-by-unito[bot] commented 2 years ago

➤ Automation for Jira commented:

Corresponding Pull Request https://github.com/skalenetwork/node-cli/pull/550

sync-by-unito[bot] commented 2 years ago

➤ Automation for Jira commented:

Corresponding Pull Request https://github.com/skalenetwork/node-cli/pull/551

sync-by-unito[bot] commented 2 years ago

➤ Oleksandr Sydorenko commented:

Still actual on node-cli:2.0.1-develop.25

2021-11-02 14:22:20,215 - INFO - Stopping container: skale_schain_attractive-sabik, timeout: 60 2021-11-02 14:23:20,970 - INFO - Going to backup container logs: skale_schain_attractive-sabik stop recoredring logs in 14:23:09 2021-11-02 14:23:21,616 - INFO - Old container logs saved to /root/.skale/node_data/log/.removed_containers/skale_schain_attractive-sabik-11.log, tail: 10000 2021-11-02 14:23:21,617 - INFO - Removing container: skale_schain_attractive-sabik, kwargs: {} 2021-11-02 14:23:21,629 - INFO - Container removed: skale_schain_attractive-sabik[2021-11-02 14:22:14.962] [23:main] [info] 174168:BIN_CONSENSUS_START: PROPOSING: 1110 [2021-11-02 14:22:14.996] [23:consensus] [info] 174168:Decided round stats::896:483:237:127:49:25:12:5:3:3:1:0:0:0:0:0 [2021-11-02 14:22:14.996] [23:consensus] [info] 174168:BLOCK_DECIDE: PRPSR:3:BID:174169:STATS:|1|D1R0P2L10|2||3|D1R1P0L17|4||| Now signing block ... [2021-11-02 14:22:15.091] [23:consensus] [info] 174168:BLOCK_DECIDE (GOT SIG): PRPSR:3:BID:174169| Now signing block ... [2021-11-02 14:22:15.091] [23:main] [info] 174168:BLOCK_SIGNED: Now finalizing block ... BID:174169 [2021-11-02 14:22:15.091] [23:main] [info] 174168:BLOCK_COMMIT: PRPSR:3:BID: 174169:ROOT:100506516883108491508394373357325690190883170054265925375785513029667628919513:HASH:4b88b9ca:BLOCK_TXS:0:DMSG:0:MP RPS:3:RPRPS:9:TXS:0:TXLS:12:KNWN:0:MGS:37:INSTS:81:BPS:0:HDRS:6:SOCK:0:CONS:0:DSDS:0:FDS:349:PRT:10762:BTA:10815:BSA:0:TPS:0:LWT:0:LRT:0:LWC:15267:LRC:22181:SET:40:SBT:57:SEC:463:SBC:637:ZSC:1:STAMP:1635 862934.366 2021-11-02 14:22:15.095483 createBlock ID = #174169

2021-11-02 14:22:15.095823 Block sealed #174169 (#f29c400e…) 2021-11-02 14:22:15.095862 Block stats:TXS:0:HDRS:10:LOGS:34:SENGS:1:TXRS:0:BLCKS:3:ACCS:857:BQS:1:BDS:495:TSS:0:UTX:0:VTX:0:CMM:531748 2021-11-02 14:22:15.096221 noteChanged: {chain} 2021-11-02 14:22:15.096256 Block timestamp: 1635862934 2021-11-02 14:22:15.096457 Successfully imported 0 of 0 transactions

[2021-11-02 14:22:25.857] [23:main] [info] 174169:BIN_CONSENSUS_START: PROPOSING: 1011 [2021-11-02 14:22:25.893] [23:consensus] [info] 174169:Decided round stats::899:485:237:127:49:25:12:5:3:3:1:0:0:0:0:0 [2021-11-02 14:22:25.893] [23:consensus] [info] 174169:BLOCK_DECIDE: PRPSR:4:BID:174170:STATS:|1|D1R0P12L18|2|D1R0P11L19|3|*|4|D1R0P9L25|| Now signing block ... [2021-11-02 14:22:25.982] [23:consensus] [info] 174169:BLOCK_DECIDE (GOT SIG): PRPSR:4:BID:174170| Now signing block ... [2021-11-02 14:22:25.982] [23:main] [info] 174169:BLOCK_SIGNED: Now finalizing block ... BID:174170 [2021-11-02 14:22:25.982] [23:main] [info] 174169:BLOCK_COMMIT: PRPSR:4:BID: 174170:ROOT:100506516883108491508394373357325690190883170054265925375785513029667628919513:HASH:e61a2dd7:BLOCK_TXS:0:DMSG:0:MP RPS:3:RPRPS:9:TXS:0:TXLS:12:KNWN:0:MGS:40:INSTS:82:BPS:0:HDRS:9:SOCK:0:CONS:0:DSDS:0:FDS:273:PRT:10761:BTA:10815:BSA:0:TPS:0:LWT:0:LRT:0:LWC:15295:LRC:22223:SET:40:SBT:57:SEC:464:SBC:638:ZSC:1:STAMP:1635 862945.277 2021-11-02 14:22:25.985404 createBlock ID = #174170

2021-11-02 14:22:25.985700 Block sealed #174170 (#f6499aa9…) 2021-11-02 14:22:25.985727 Block stats:TXS:0:HDRS:10:LOGS:34:SENGS:1:TXRS:0:BLCKS:3:ACCS:857:BQS:1:BDS:496:TSS:0:UTX:0:VTX:0:CMM:532588 2021-11-02 14:22:25.986283 noteChanged: {chain} 2021-11-02 14:22:25.986307 Block timestamp: 1635862945 2021-11-02 14:22:25.986496 Successfully imported 0 of 0 transactions

[2021-11-02 14:22:36.739] [23:main] [info] 174170:BIN_CONSENSUS_START: PROPOSING: 1110 [2021-11-02 14:22:36.801] [23:consensus] [info] 174170:Decided round stats::900:486:239:127:49:25:12:5:3:3:1:0:0:0:0:0 [2021-11-02 14:22:36.801] [23:consensus] [info] 174170:BLOCK_DECIDE: PRPSR:3:BID:174171:STATS:|1|D0R0P0L23|2|*|3|D1R2P2L26|4|D1R2P1L23|| Now signing block ... [2021-11-02 14:22:36.889] [23:consensus] [info] 174170:BLOCK_DECIDE (GOT SIG): PRPSR:3:BID:174171| Now signing block ... [2021-11-02 14:22:36.889] [23:main] [info] 174170:BLOCK_SIGNED: Now finalizing block ... BID:174171 [2021-11-02 14:22:36.889] [23:main] [info] 174170:BLOCK_COMMIT: PRPSR:3:BID: 174171:ROOT:100506516883108491508394373357325690190883170054265925375785513029667628919513:HASH:e2fae148:BLOCK_TXS:0:DMSG:0:MP RPS:3:RPRPS:9:TXS:0:TXLS:12:KNWN:0:MGS:38:INSTS:82:BPS:0:HDRS:8:SOCK:0:CONS:0:DSDS:0:FDS:273:PRT:10753:BTA:10815:BSA:0:TPS:0:LWT:0:LRT:0:LWC:15337:LRC:22279:SET:40:SBT:57:SEC:465:SBC:639:ZSC:1:STAMP:1635 862956.152 2021-11-02 14:22:36.891885 createBlock ID = #174171

2021-11-02 14:22:36.892305 Block sealed #174171 (#bdd107eb…) 2021-11-02 14:22:36.892336 Block stats:TXS:0:HDRS:10:LOGS:34:SENGS:1:TXRS:0:BLCKS:3:ACCS:857:BQS:1:BDS:497:TSS:0:UTX:0:VTX:0:CMM:533428 2021-11-02 14:22:36.892716 noteChanged: {chain} 2021-11-02 14:22:36.892738 Block timestamp: 1635862956 2021-11-02 14:22:36.892929 Successfully imported 0 of 0 transactions

[2021-11-02 14:22:47.655] [23:main] [info] 174171:BIN_CONSENSUS_START: PROPOSING: 1101 [2021-11-02 14:22:47.691] [23:consensus] [info] 174171:Decided round stats::901:488:239:128:49:25:12:5:3:3:1:0:0:0:0:0 [2021-11-02 14:22:47.691] [23:consensus] [info] 174171:BLOCK_DECIDE: PRPSR:4:BID:174172:STATS:|1|D1R0P1L8|2|*|3|D0R1P3L25|4|D1R1P2L23|| Now signing block ... [2021-11-02 14:22:47.782] [23:consensus] [info] 174171:BLOCK_DECIDE (GOT SIG): PRPSR:4:BID:174172| Now signing block ... [2021-11-02 14:22:47.783] [23:main] [info] 174171:BLOCK_SIGNED: Now finalizing block ... BID:174172 [2021-11-02 14:22:47.783] [23:main] [info] 174171:BLOCK_COMMIT: PRPSR:4:BID: 174172:ROOT:100506516883108491508394373357325690190883170054265925375785513029667628919513:HASH:537a06c0:BLOCK_TXS:0:DMSG:3:MPRPS:3:RPRPS:9:TXS:0:TXLS:12:KNWN:0:MGS:37:INSTS:82:BPS:0:HDRS:8:SOCK:0:CONS:0:DSDS:0:FDS:273:PRT:10763:BTA:10815:BSA:0:TPS:0:LWT:0:LRT:0:LWC:15371:LRC:22326:SET:40:SBT:57:SEC:466:SBC:640:ZSC:1:STAMP:1635862967.57 2021-11-02 14:22:47.786401 createBlock ID = #174172

2021-11-02 14:22:47.786708 Block sealed #174172 (#78e8ee8a…) 2021-11-02 14:22:47.786733 Block stats:TXS:0:HDRS:10:LOGS:34:SENGS:1:TXRS:0:BLCKS:3:ACCS:857:BQS:1:BDS:498:TSS:0:UTX:0:VTX:0:CMM:534268 2021-11-02 14:22:47.787077 noteChanged: {chain} 2021-11-02 14:22:47.787098 Block timestamp: 1635862967 2021-11-02 14:22:47.787373 Successfully imported 0 of 0 transactions

[2021-11-02 14:22:58.547] [23:main] [info] 174172:BIN_CONSENSUS_START: PROPOSING: 1110 [2021-11-02 14:22:58.896] [23:consensus] [info] 174172:Decided round stats::902:488:240:129:49:25:13:5:3:3:1:0:0:0:0:0 [2021-11-02 14:22:58.896] [23:consensus] [info] 174172:BLOCK_DECIDE: PRPSR:1:BID:174173:STATS:|1|D1R6P78L87|2|D1R2P4L9|3|D1R0P5L9|4|D0R3P4L10|| Now signing block ... [2021-11-02 14:22:59.000] [23:consensus] [info] 174172:BLOCK_DECIDE (GOT SIG): PRPSR:1:BID:174173| Now signing block ... [2021-11-02 14:22:59.000] [23:main] [info] 174172:BLOCK_SIGNED: Now finalizing block ... BID:174173 [2021-11-02 14:22:59.000] [23:main] [info] 174172:BLOCK_COMMIT: PRPSR:1:BID: 174173:ROOT:100506516883108491508394373357325690190883170054265925375785513029667628919513:HASH:3b00d27b:BLOCK_TXS:0:DMSG:0:MPRPS:3:RPRPS:9:TXS:0:TXLS:12:KNWN:0:MGS:39:INSTS:82:BPS:0:HDRS:10:SOCK:0:CONS:0:DSDS:0:FDS:273:PRT:10760:BTA:10815:BSA:0:TPS:0:LWT:0:LRT:0:LWC:15419:LRC:22390:SET:40:SBT:57:SEC:467:SBC:644:ZSC:1:STAMP:1635862977.959 2021-11-02 14:22:59.002899 createBlock ID = #174173

2021-11-02 14:22:59.003181 Block sealed #174173 (#1ee49b92…) 2021-11-02 14:22:59.003207 Block stats:TXS:0:HDRS:10:LOGS:34:SENGS:1:TXRS:0:BLCKS:3:ACCS:857:BQS:1:BDS:499:TSS:0:UTX:0:VTX:0:CMM:535108 2021-11-02 14:22:59.003570 noteChanged: {chain} 2021-11-02 14:22:59.003592 Block timestamp: 1635862977 2021-11-02 14:22:59.003769 Successfully imported 0 of 0 transactions

[2021-11-02 14:23:09.757] [23:main] [info] 174173:BIN_CONSENSUS_START: PROPOSING: 1110 [2021-11-02 14:23:09.792] [23:consensus] [info] 174173:Decided round stats::903:489:240:130:49:25:13:5:3:3:1:0:0:0:0:0 [2021-11-02 14:23:09.792] [23:consensus] [info] 174173:BLOCK_DECIDE: PRPSR:1:BID:174174:STATS:|1|D1R1P3L13|2||3||4|D0R0P2L14|| Now signing block ... [2021-11-02 14:23:09.891] [23:consensus] [info] 174173:BLOCK_DECIDE (GOT SIG): PRPSR:1:BID:174174| Now signing block ... [2021-11-02 14:23:09.891] [23:main] [info] 174173:BLOCK_SIGNED: Now finalizing block ... BID:174174 [2021-11-02 14:23:09.892] [23:main] [info] 174173:BLOCK_COMMIT: PRPSR:1:BID: 174174:ROOT:100506516883108491508394373357325690190883170054265925375785513029667628919513:HASH:a5d2e0da:BLOCK_TXS:0:DMSG:5:MPRPS:3:RPRPS:9:TXS:0:TXLS:12:KNWN:0:MGS:41:INSTS:83:BPS:0:HDRS:13:SOCK:0:CONS:0:DSDS:0:FDS:273:PRT:10754:BTA:10816:BSA:0:TPS:0:LWT:0:LRT:0:LWC:15453:LRC:22437:SET:40:SBT:57:SEC:468:SBC:645:ZSC:1:STAMP:1635862989.173 2021-11-02 14:23:09.897581 createBlock ID = #174174

2021-11-02 14:23:09.898860 Block sealed #174174 (#793b1726…) 2021-11-02 14:23:09.898887 Block stats:TXS:0:HDRS:10:LOGS:34:SENGS:1:TXRS:0:BLCKS:3:ACCS:857:BQS:1:BDS:500:TSS:0:UTX:0:VTX:0:CMM:535948 2021-11-02 14:23:09.899675 noteChanged: {chain} 2021-11-02 14:23:09.899697 Block timestamp: 1635862989 2021-11-02 14:23:09.900070 Successfully imported 0 of 0 transactions

sync-by-unito[bot] commented 2 years ago

➤ Dima Litvinov commented:

From the logs below it follows that problem is solved - log after 14:22:20 is successfully saved (but these exact log for some other reason misses some its pats)

sync-by-unito[bot] commented 2 years ago

➤ Oleksandr Sydorenko commented:

Blocked by https://skalelabs.atlassian.net/browse/SKALE-4729 ( https://skalelabs.atlassian.net/browse/SKALE-4729|smart-link )

sync-by-unito[bot] commented 2 years ago

➤ Oleksandr Sydorenko commented:

Verified on components network skaled 3.9.1-develop.2 node-cli: 2.0.1-develop.25

[^skale_schain_quiet-pherkad-minor-2.log]