Evicting failed runtime instance error=Runtime panicked: Slot must increase

[stakeworks]

After upgrade to v1.7.0 these errors showed up:

2024-05-09 18:38:19 [Parachain] Evicting failed runtime instance error=Runtime panicked: Slot must increase
2024-05-09 18:38:19 [Parachain] err=Error { inner: Proposing
0: Error at calling runtime api: Execution failed: Runtime panicked: Slot must increase
1: Execution failed: Runtime panicked: Slot must increase }

Ubuntu 22.04 LTS
Binary: tinkernet-collator 1.6.2-906e59161d7

ExecStart=tinkernet-collator
--collator
--chain tinker-raw.json
--base-path /path
--name "StakeWorks | Tinkernet | MEV02"
--force-authoring
--no-private-ipv4
--trie-cache-size 134217728
--max-runtime-instances 32
--bootnodes bootnode
--bootnodes bootnode
--bootnodes bootnode
--reserved-nodes node
--reserved-nodes node
--prometheus-port port
--prometheus-external
--listen-addr "/ip4/xx.xx.xx.xx/tcp/nnnnn/ws"
--listen-addr "/ip6/xx:xx:xx:xx:xx:xx/tcp/nnnnn/ws"
--rpc-port port
--out-peers 50
--in-peers 75
--relay-chain-rpc-urls "url"
--relay-chain-rpc-urls "url" \

[arrudagates]

This error appears to be harmless (paritytech/polkadot-sdk#3282 (comment)).
Still trying to understand what's causing it.

[bkchr]

Yes the error is harmless. More information here.

[stakeworks]

The two not invulnerables are kicked out of the active set tonight, only invulnerables left now. It seems more harmfull then thought. Also I cannot register as a candidate because my balance is insufficient although I've 15005 reserved TNKR and more then 500 TNKR tranferable.

[bkchr]

It seems more harmfull then thought.

Is there any more info why they got kicked? Because they didn't produced any blocks or what?

[stakeworks]

The error I described above turned out to be a bit more extensive after looking at the logs. This error precedes the error above:

My node didn't produce any blocks since 02:46 h, only one block at 10:44 h. The errors stopped right after the node stopped producing blocks.

2 hour time difference with logs

Logs
tinkernet-collator.log

[bkchr]

My node didn't produce any blocks since 02:46 h, only one block at 10:44 h. The errors stopped right after the node stopped producing blocks.

Yes, the error is related to block production. Your node also did not try to build any blocks since 02:46. Looks like it got removed from the set?

At 2:43 it for example still build successfully blocks:

May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] 🙌 Starting consensus session on top of parent 0x370e6dfba07858acc0be589bdc7e3677efeb861d99e8470aad6dca49e566a4fa
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] 🎁 Prepared block for proposing at 4039191 (2 ms) [hash: 0xdc3759de22df23ce2ba1aac24a245dee15d3d9eb97a00c68b382877c2f58c4a4; parent_hash: 0x370e…a4fa; extrinsics (2): [0x0ce7…1650, 0x78a4…7435]
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] 🔖 Pre-sealed block for proposal at 4039191. Hash now 0xce9e2e436c2119bb983f6059008872c3863430c90a1fffe0d680af2f91f97281, previously 0xdc3759de22df23ce2ba1aac24a245dee15d3d9eb97a00c68b382877c2f58c4a4.
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] ✨ Imported #4039191 (0xce9e…7281)
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] PoV size { header: 0.22265625kb, extrinsics: 14.33203125kb, storage_proof: 9.072265625kb }
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] Compressed PoV size: 20.8212890625kb
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Relaychain] Received finalized block via RPC: #23101735 (0x9875…2ef1 -> 0x17f8…6c31)
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] 🙌 Starting consensus session on top of parent 0x370e6dfba07858acc0be589bdc7e3677efeb861d99e8470aad6dca49e566a4fa
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] 🎁 Prepared block for proposing at 4039191 (2 ms) [hash: 0xd85406229abecdb60fa9ae486f92b9b5d62a85e094b86103af7ce061587b5cf9; parent_hash: 0x370e…a4fa; extrinsics (2): [0x1e23…d990, 0x78a4…7435]
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] 🔖 Pre-sealed block for proposal at 4039191. Hash now 0xda903ba16d891c5eca2251686978ab585f283bc8c2d2ccd49ce84b09a4a3a3fa, previously 0xd85406229abecdb60fa9ae486f92b9b5d62a85e094b86103af7ce061587b5cf9.
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] ✨ Imported #4039191 (0xda90…a3fa)
May 10 02:43:01 mev02 tinkernet-collator[67382]: 2024-05-10 02:43:01 [Parachain] PoV size { header: 0.22265625kb, extrinsics: 14.33203125kb, storage_proof: 9.072265625kb }

[stakeworks]

Yes, the error is related to block production. Your node also did not try to build any blocks since 02:46. Looks like it got removed from the set?

At 2:43 it for example still build successfully blocks:

It may be that the block has not reached the validator, because of this error?
2024-05-09 23:29:28 [Relaychain] Runtime requires feature bit 1 that node doesn't support, please upgrade node version

[bkchr]

2024-05-09 23:29:28 [Relaychain] Runtime requires feature bit 1 that node doesn't support, please upgrade node version

Should not be related. Did you check if any of the blocks it build made it into the canonical chain?

[stakeworks]

After update to v1.7.0 the "[Parachain] Starting collation. relay_parent" stopped, so probably the blocks has never reached the validator.

[bkchr]

After the update of the collator or what?

[stakeworks]

After updating collator to v1.7.0 and restarting node there is no collating. You can see in the tinkernet-collator.log I attached at a previous message.

May 09 18:12:13 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:13 [Parachain] Trying to disconnect unknown peer 12D3KooWErYv2H8DginEQ1Zqhn1dC5N68hVuiSFiVQx5xWPrH3X1 from SetId(0).
May 09 18:12:13 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:13 [Parachain] Trying to disconnect unknown peer 12D3KooWErYv2H8DginEQ1Zqhn1dC5N68hVuiSFiVQx5xWPrH3X1 from SetId(1).
May 09 18:12:17 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:17 [Relaychain] Received finalized block via RPC: #23096646 (0x6936…8fc0 -> 0xd7e2…f474)
May 09 18:12:17 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:17 [Parachain] 💤 Idle (1 peers), best: #4037404 (0x0352…5b4c), finalized #4037403 (0x7bdb…c2ec), ⬇ 0.7kiB/s ⬆ 0.6kiB/s
May 09 18:12:18 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:18 [Relaychain] Received imported block via RPC: #23096649 (0xe61e…b995 -> 0xbbff…da1d)

**Latest collation before upgrade to v1.7.0
May 09 18:12:18 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:18 [Parachain] Starting collation. relay_parent=0xbbff908872bef25e2c45c46e8e720200d2ed393a764a8d8a7614e6118b5fda1d at=0x0352878bfd158ec406e535b6fbaf7c89923f4b85214957268580f5e739e75b4c**

May 09 18:12:21 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:21 [Relaychain] Received finalized block via RPC: #23096647 (0xd7e2…f474 -> 0xea77…986b)
May 09 18:12:22 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:22 [Parachain] 💤 Idle (1 peers), best: #4037404 (0x0352…5b4c), finalized #4037403 (0x7bdb…c2ec), ⬇ 1.0kiB/s ⬆ 1.3kiB/s
May 09 18:12:24 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:24 [Relaychain] Received imported block via RPC: #23096650 (0xbbff…da1d -> 0x6e6f…a250)
May 09 18:12:27 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:27 [Parachain] 💤 Idle (1 peers), best: #4037404 (0x0352…5b4c), finalized #4037403 (0x7bdb…c2ec), ⬇ 1.5kiB/s ⬆ 1.6kiB/s
May 09 18:12:30 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:29 [Relaychain] Received finalized block via RPC: #23096648 (0xea77…986b -> 0xe61e…b995)
May 09 18:12:30 mev02 systemd[1]: Stopping Tinkernet (InvArch) Collator...
May 09 18:12:30 mev02 tinkernet-collator[1428]: 2024-05-09 18:12:30 [Relaychain] Received imported block via RPC: #23096651 (0x6e6f…a250 -> 0x77da…87b4)
May 09 18:12:30 mev02 systemd[1]: tinkernet-collator.service: Deactivated successfully.
May 09 18:12:30 mev02 systemd[1]: Stopped Tinkernet (InvArch) Collator.
May 09 18:12:30 mev02 systemd[1]: tinkernet-collator.service: Consumed 4h 28min 24.278s CPU time.
May 09 18:18:58 mev02 systemd[1]: Started Tinkernet (InvArch) Collator.
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 InvArch Tinkernet Node
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 ✌️  version 1.6.2-906e59161d7
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 ❤️  by InvArch Association <https://github.com/InvArch>, 2021-2024
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 📋 Chain specification: InvArch Tinker Network
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 🏷  Node name: StakeWorks | Tinkernet | MEV02
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 👤 Role: AUTHORITY
May 09 18:18:58 mev02 tinkernet-collator[60941]: 2024-05-09 18:18:58 💾 Database: RocksDb at /invarch_tinker_kusama/db/full
May 09 18:19:00 mev02 tinkernet-collator[60941]: 2024-05-09 18:19:00 Parachain id: Id(2125)
May 09 18:19:00 mev02 tinkernet-collator[60941]: 2024-05-09 18:19:00 Parachain Account: 5Ec4AhP2h16vvjGwqkwWX6aDsLtY7ZA3XfqsQSevkKAnTCZi
May 09 18:19:00 mev02 tinkernet-collator[60941]: 2024-05-09 18:19:00 Is collating: yes
May 09 18:19:03 mev02 tinkernet-collator[60941]: 2024-05-09 18:19:03 [Parachain] Trying to connect to next external relaychain node. index=0 url="wss://kusama-rpc-01.stake.works:443/"

[bkchr]

There are collations:

May 09 18:20:36 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:36 [Parachain] 🙌 Starting consensus session on top of parent 0x104e2f36aa383637343e73ffe338ec2ba7d5228fae93b8f68c97b625f3af9a6b
May 09 18:20:36 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:36 [Parachain] 🎁 Prepared block for proposing at 4037431 (2 ms) [hash: 0x1ece55b6224f5af2f65848f374e5d91d10394472da6bc426765e0d5738f865a4; parent_hash: 0x104e…9a6b; extrinsics (2): [0xc468…dd3e, 0x2a5d…db28]
May 09 18:20:36 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:36 [Parachain] 🔖 Pre-sealed block for proposal at 4037431. Hash now 0x247cc2d8453c299b52fe5f3cf6e349d9304b358fe06636af8f72cdfd74bf9d8e, previously 0x1ece55b6224f5af2f65848f374e5d91d10394472da6bc426765e0d5738f865a4.
May 09 18:20:36 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:36 [Parachain] ✨ Imported #4037431 (0x247c…9d8e)
May 09 18:20:36 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:36 [Parachain] PoV size { header: 0.22265625kb, extrinsics: 14.4140625kb, storage_proof: 8.9912109375kb }
May 09 18:20:36 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:36 [Parachain] Compressed PoV size: 20.8232421875kb
May 09 18:20:38 mev02 tinkernet-collator[60941]: 2024-05-09 18:20:38 [Parachain] 💤 Idle (5 peers), best: #4037431 (0x75ee…10d8), finalized #4037429 (0xd0a7…2cea), ⬇ 7.0kiB/s ⬆ 11.2kiB/s

And the block is also part of the canonical chain.

[stakeworks]

Yes, you're right. But why is my collator kicked out of the active set after running for 1,5 years?
I also cannot re-register as candidate although I've 15005 TNKR bonded and 574 TKNR free.

[bkchr]

But why is my collator kicked out of the active set after running for 1,5 years?

I have no idea ;) Better to ask the experts like @arrudagates.

[stakeworks]

Will do, thanks!