Parachain collator stuck on rococo and unable to recover

[xlc]

I have a 1 collator testnet connecting to Rococo. It is unable to reliably produce new blocks. I have to run the revert command on the collator then it is able to produce blocks and have it included on relaychain. However after 30-60 mins, the collator will get stuck again and require another revert to restore it.

Here are some logs

2022-10-05 05:11:12.181  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xd95c0c3e23496f146aa7e6065b0cc8acf3246c093fd3041ac2e786b77d4aa320 at=0x3c1a9b9070c887a00aee3dc9ee1e643a41f6166dbed994519288f6c5a6be79b0
2022-10-05 05:11:12.181  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0x3c1a9b9070c887a00aee3dc9ee1e643a41f6166dbed994519288f6c5a6be79b0    
2022-10-05 05:11:12.184  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136439 (0 ms) [hash: 0x8fd17878b594ba6f153f5b938b90cf2d8841ab9bf9f35487ea8c211ca98ae1e4; parent_hash: 0x3c1a…79b0; extrinsics (2): [0xbb06…f29c, 0x3475…d9d4]]    
2022-10-05 05:11:12.186  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136439. Hash now 0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1, previously 0x8fd17878b594ba6f153f5b938b90cf2d8841ab9bf9f35487ea8c211ca98ae1e4.    
2022-10-05 05:11:12.187  INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 20.484375kb }
2022-10-05 05:11:12.188  INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 16.6005859375kb
2022-10-05 05:11:12.188  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1
2022-10-05 05:11:12.188  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136439 (0xfcf4…2ac1)    
2022-10-05 05:11:15.794  INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136438 (0x3c1a…79b0), finalized #1136436 (0xfd9b…73f4), ⬇ 64 B/s ⬆ 2.4kiB/s    
2022-10-05 05:11:15.831  INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (29 peers), best: #2226536 (0xd95c…a320), finalized #2226533 (0xf5a9…cf08), ⬇ 19.7kiB/s ⬆ 28.8kiB/s    
2022-10-05 05:11:18.178  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2226537 (0xdf10…c8f3)    
2022-10-05 05:11:18.194  INFO tokio-runtime-worker sc_informant: [Relaychain] ♻️  Reorg on #2226537,0xdf10…c8f3 to #2226537,0xb2eb…9f8c, common ancestor #2226536,0xd95c…a320    
2022-10-05 05:11:18.194  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2226537 (0xb2eb…9f8c)    
2022-10-05 05:11:20.794  INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136438 (0x3c1a…79b0), finalized #1136437 (0xacfd…db76), ⬇ 24 B/s ⬆ 24 B/s    
2022-10-05 05:11:20.832  INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (29 peers), best: #2226537 (0xb2eb…9f8c), finalized #2226534 (0xa5bf…16fc), ⬇ 37.0kiB/s ⬆ 41.0kiB/s    
2022-10-05 05:11:24.155  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2226538 (0x4fa8…1947)    
2022-10-05 05:11:24.159  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x4fa826a6bc5a18a06a5218ff2af4d543a2d5c7931ae3fe91154e663275a51947 at=0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1
2022-10-05 05:11:24.160  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1    
2022-10-05 05:11:24.164  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136440 (0 ms) [hash: 0x0eecc1f6c4c986179044597d6544879ccfa1af79f1b9089377ab9b6ffda2f6a0; parent_hash: 0xfcf4…2ac1; extrinsics (2): [0x9eee…a23c, 0x681c…c2e2]]    
2022-10-05 05:11:24.165  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136440. Hash now 0x8f12e8921d582c6e603604e5a0c3c6c97c36a88168646ad0f497d3524d72b4c9, previously 0x0eecc1f6c4c986179044597d6544879ccfa1af79f1b9089377ab9b6ffda2f6a0.    
2022-10-05 05:11:24.165  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136440 (0x8f12…b4c9)    
2022-10-05 05:11:24.166  INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 21.96875kb }
2022-10-05 05:11:24.166  INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.7705078125kb
2022-10-05 05:11:24.167  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x8f12e8921d582c6e603604e5a0c3c6c97c36a88168646ad0f497d3524d72b4c9
2022-10-05 05:11:25.794  INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136439 (0xfcf4…2ac1), finalized #1136437 (0xacfd…db76), ⬇ 0 ⬆ 0    
2022-10-05 05:11:25.833  INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (28 peers), best: #2226538 (0x4fa8…1947), finalized #2226534 (0xa5bf…16fc), ⬇ 9.8kiB/s ⬆ 21.2kiB/s    
2022-10-05 05:11:30.158  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2226539 (0xb19e…4369)    
2022-10-05 05:11:30.170  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xb19ec3db69f18bb892cb6b47976a7bce87d8435842fc1607bfdb3a4c05634369 at=0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1
2022-10-05 05:11:30.171  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1    
2022-10-05 05:11:30.178  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136440 (0 ms) [hash: 0x0da8abcf0139bb6f8cdd0232f9944faca915a48653443091a30ec988c16efcad; parent_hash: 0xfcf4…2ac1; extrinsics (2): [0x084a…a9ba, 0xbf1a…eeca]]    
2022-10-05 05:11:30.185  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136440. Hash now 0xae73bc9ec38d12f4d365b3f54464bd0036f7ec82deba356a74c0aa6a3ecf8090, previously 0x0da8abcf0139bb6f8cdd0232f9944faca915a48653443091a30ec988c16efcad.    
2022-10-05 05:11:30.185  INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 21.96875kb }
2022-10-05 05:11:30.186  INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.8408203125kb
2022-10-05 05:11:30.186  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0xae73bc9ec38d12f4d365b3f54464bd0036f7ec82deba356a74c0aa6a3ecf8090
2022-10-05 05:11:30.187  INFO tokio-runtime-worker sc_informant: [Relaychain] ♻️  Reorg on #2226539,0xb19e…4369 to #2226539,0x6000…ec16, common ancestor #2226538,0x4fa8…1947    
2022-10-05 05:11:30.187  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2226539 (0x6000…ec16)    
2022-10-05 05:11:30.188  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136440 (0xae73…8090)    
2022-10-05 05:11:30.197  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x60003e96132d5d63e5881f0311241ee40a79c3018974b3ae55db125cfc35ec16 at=0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1
2022-10-05 05:11:30.199  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1    
2022-10-05 05:11:30.206  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136440 (0 ms) [hash: 0xbdd86e5eeb9cb9265791e351622892821ba1f18a4fd9cea854047efc0f00b213; parent_hash: 0xfcf4…2ac1; extrinsics (2): [0x66c1…7c64, 0x6976…c8c7]]    
2022-10-05 05:11:30.208  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136440. Hash now 0x66e11814ead6b80fbb3c05f3ed42e7e365fbc30385848b29cc73e2f785f4ae1a, previously 0xbdd86e5eeb9cb9265791e351622892821ba1f18a4fd9cea854047efc0f00b213.    
2022-10-05 05:11:30.209  INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 21.96875kb }
2022-10-05 05:11:30.209  INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.8408203125kb
2022-10-05 05:11:30.209  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x66e11814ead6b80fbb3c05f3ed42e7e365fbc30385848b29cc73e2f785f4ae1a
2022-10-05 05:11:30.212  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136440 (0x66e1…ae1a)    
2022-10-05 05:11:30.795  INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136439 (0xfcf4…2ac1), finalized #1136437 (0xacfd…db76), ⬇ 0 ⬆ 0    
2022-10-05 05:11:30.834  INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (28 peers), best: #2226539 (0x6000…ec16), finalized #2226535 (0xbc23…0221), ⬇ 41.9kiB/s ⬆ 37.0kiB/s    
2022-10-05 05:11:35.795  INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136439 (0xfcf4…2ac1), finalized #1136437 (0xacfd…db76), ⬇ 57 B/s ⬆ 63 B/s    
2022-10-05 05:11:35.835  INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (28 peers), best: #2226539 (0x6000…ec16), finalized #2226535 (0xbc23…0221), ⬇ 2.9kiB/s ⬆ 2.8kiB/s    
2022-10-05 05:11:36.167  INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2226540 (0xe1d6…412d)    
2022-10-05 05:11:36.168  WARN tokio-runtime-worker parachain::collator-protocol: [Relaychain] Collation wasn't advertised to any validator. candidate_hash=0xcf5ae2bb8651673a3e1348edb03f94b998631e5ff50ddf7fbc00a6da2eda00e7 pov_hash=0xa4fb51bad8592d440097acb8055b6f1080c0eaafa45988e59314e02b7cd00294 traceID=275622100526551937408183663280663794873
2022-10-05 05:11:36.171  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xe1d6233d302ccb48db75127f4c02db4ad522cef8ad60b26933801d9419fb412d at=0xfcf42ecd0cbee4f75e539cf46cea1ef835c000558c4beb7a242c7a7db7102ac1

Another case

2022-10-05 10:20:12.184 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xcc9fb35df956b3526aa1004e1e27c4df491ab257a7f16f3da2e8ef99272d939f
2022-10-05 10:20:12.189 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136639 (1 ms) [hash: 0x521308dac08373203233a3fe54498283f59f46a1d9e569f5e5cfd218a5d4c8e6; parent_hash: 0xcc9f…939f; extrinsics (2): [0x6490…ec9b, 0x4abc…aa82]]
2022-10-05 10:20:12.191 INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136639. Hash now 0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d, previously 0x521308dac08373203233a3fe54498283f59f46a1d9e569f5e5cfd218a5d4c8e6.
2022-10-05 10:20:12.192 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136639 (0x46a4…ab6d)
2022-10-05 10:20:12.192 INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 20.958984375kb }
2022-10-05 10:20:12.192 INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.138671875kb
2022-10-05 10:20:12.193 INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:12.201 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2229626 (0x5d8e…4908)
2022-10-05 10:20:12.208 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x5d8e5566b21f7cf00988e6b43284de03f8e0e617771746b048df602d15414908 at=0xcc9fb35df956b3526aa1004e1e27c4df491ab257a7f16f3da2e8ef99272d939f
2022-10-05 10:20:12.209 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xcc9fb35df956b3526aa1004e1e27c4df491ab257a7f16f3da2e8ef99272d939f
2022-10-05 10:20:12.212 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136639 (0 ms) [hash: 0x2f061e89fb4a93d0187131d96382676b0d46912b6239a4b83983ff85156fc536; parent_hash: 0xcc9f…939f; extrinsics (2): [0xe214…994d, 0x19c9…0ea3]]
2022-10-05 10:20:12.214 INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136639. Hash now 0x5d87b1d631bfcfdd4ff71746481ad8027ac176c1a211760f9094bc937427e344, previously 0x2f061e89fb4a93d0187131d96382676b0d46912b6239a4b83983ff85156fc536.
2022-10-05 10:20:12.214 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136639 (0x5d87…e344)
2022-10-05 10:20:12.214 INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 20.958984375kb }
2022-10-05 10:20:12.215 INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.10546875kb
2022-10-05 10:20:12.215 INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x5d87b1d631bfcfdd4ff71746481ad8027ac176c1a211760f9094bc937427e344
2022-10-05 10:20:14.520 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136638 (0xcc9f…939f), finalized #1136636 (0x2950…f2eb), ⬇ 0.2kiB/s ⬆ 7.1kiB/s
2022-10-05 10:20:14.820 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (40 peers), best: #2229626 (0x8f4c…7bc1), finalized #2229622 (0x9bd5…deef), ⬇ 45.9kiB/s ⬆ 38.9kiB/s
2022-10-05 10:20:18.186 INFO tokio-runtime-worker sc_informant: [Relaychain] ♻️ Reorg on #2229626,0x8f4c…7bc1 to #2229627,0xf935…6677, common ancestor #2229625,0x78dc…c2f0
2022-10-05 10:20:18.187 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2229627 (0xf935…6677)
2022-10-05 10:20:19.521 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136638 (0xcc9f…939f), finalized #1136636 (0x2950…f2eb), ⬇ 24 B/s ⬆ 24 B/s
2022-10-05 10:20:19.821 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (40 peers), best: #2229627 (0xf935…6677), finalized #2229623 (0xc5c1…c491), ⬇ 72.3kiB/s ⬆ 35.6kiB/s
2022-10-05 10:20:24.164 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2229628 (0x99ba…f1cf)
2022-10-05 10:20:24.174 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x99ba4bc26abc26400b85193f5bd83a4a5c4689697442ed9133195c643f12f1cf at=0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:24.175 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:24.178 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136640 (1 ms) [hash: 0x995961238bd631df62e899bc8e323761d5684ee1d3f193dfaf8c72ab4f9301aa; parent_hash: 0x46a4…ab6d; extrinsics (2): [0x8911…6548, 0xdee0…a1f7]]
2022-10-05 10:20:24.181 INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136640. Hash now 0x3cfaae6a3d8157209b837e88e669dfd69ad8215d18b7fba2f35bb44994246a30, previously 0x995961238bd631df62e899bc8e323761d5684ee1d3f193dfaf8c72ab4f9301aa.
2022-10-05 10:20:24.181 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136640 (0x3cfa…6a30)
2022-10-05 10:20:24.182 INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 22.0009765625kb }
2022-10-05 10:20:24.182 INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.7880859375kb
2022-10-05 10:20:24.183 INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x3cfaae6a3d8157209b837e88e669dfd69ad8215d18b7fba2f35bb44994246a30
2022-10-05 10:20:24.521 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136639 (0x46a4…ab6d), finalized #1136636 (0x2950…f2eb), ⬇ 0 ⬆ 0
2022-10-05 10:20:24.822 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (40 peers), best: #2229628 (0x99ba…f1cf), finalized #2229625 (0x78dc…c2f0), ⬇ 43.1kiB/s ⬆ 92.3kiB/s
2022-10-05 10:20:29.522 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136639 (0x46a4…ab6d), finalized #1136637 (0x4202…751a), ⬇ 0 ⬆ 0
2022-10-05 10:20:29.823 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (40 peers), best: #2229628 (0x99ba…f1cf), finalized #2229625 (0x78dc…c2f0), ⬇ 12.6kiB/s ⬆ 9.5kiB/s
2022-10-05 10:20:30.187 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2229629 (0x69c0…9db9)
2022-10-05 10:20:30.193 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x69c08c2aeced9f0c89cedb3a47bb9b90b7041e28dae1438cd4cc35d4e0b39db9 at=0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:30.194 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:30.197 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136640 (0 ms) [hash: 0x52ae420e8e2ea9ca6a0cf6fe88f57d21cbc5b79c0ef9cdff398445d0aefa85ae; parent_hash: 0x46a4…ab6d; extrinsics (2): [0xb73c…8248, 0xa7f2…1d40]]
2022-10-05 10:20:30.198 INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136640. Hash now 0x845e8cfc5ef9061eb9dca50549e7e987a576fa20fb50397e124384a6a502452c, previously 0x52ae420e8e2ea9ca6a0cf6fe88f57d21cbc5b79c0ef9cdff398445d0aefa85ae.
2022-10-05 10:20:30.199 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136640 (0x845e…452c)
2022-10-05 10:20:30.199 INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.7587890625kb, storage_proof: 22.0009765625kb }
2022-10-05 10:20:30.200 INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.8212890625kb
2022-10-05 10:20:30.200 INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x845e8cfc5ef9061eb9dca50549e7e987a576fa20fb50397e124384a6a502452c
2022-10-05 10:20:34.522 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136639 (0x46a4…ab6d), finalized #1136638 (0xcc9f…939f), ⬇ 57 B/s ⬆ 63 B/s
2022-10-05 10:20:34.824 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (40 peers), best: #2229629 (0x69c0…9db9), finalized #2229626 (0xe6d3…6b0e), ⬇ 58.2kiB/s ⬆ 54.9kiB/s
2022-10-05 10:20:36.147 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2229630 (0xde6e…895b)
2022-10-05 10:20:36.149 WARN tokio-runtime-worker parachain::collator-protocol: [Relaychain] Collation wasn't advertised to any validator. candidate_hash=0x0d44a2ac490e2f5d9f5af380256d6ace561435a3c9221f7142388c79b7571850 pov_hash=0x18fbfd30982b3b0637c8e3dc2b503a764b1e046b97e2f218f791b87e6fe7d95e traceID=17636339531793573007251757563611278030
2022-10-05 10:20:36.154 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xde6ef2c8f6c620cfb0ae1c4a58516c22355b7621db28d1c6f5d1d4e0549a895b at=0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:36.155 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0x46a4f6b16500fb1b780345bbd0fb31dd1fe5e6338160695509f6bd18d07aab6d
2022-10-05 10:20:36.159 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136640 (1 ms) [hash: 0x38ed2507f91d4264d8d6cbea35e362fd544331e319d852dda8e03e1ac60865fd; parent_hash: 0x46a4…ab6d; extrinsics (2): [0x01b7…3dd0, 0xf3ce…3a35]]

I have noticed on both case there is a reorg on relaychain after the last parachain is included and then all the future parachain block candidates are getting Collation wasn't advertised to any validator. error

[xlc]

Seems like this isn't related to reorg, but validator somehow reject our collator

2022-10-11 01:05:06.173 INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136832. Hash now 0x78d800cf316213517c725f60f8c5035113f89e4bf02de4ddccb23a25be6e8d8c, previously 0x5aec9a1de28ff0f91124cbca2731449235daa41c537092d07938835c74efc72f.
2022-10-11 01:05:06.173 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136832 (0x78d8…8d8c)
2022-10-11 01:05:06.174 INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.783203125kb, storage_proof: 20.9658203125kb }
2022-10-11 01:05:06.174 INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.1630859375kb
2022-10-11 01:05:06.174 INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x78d800cf316213517c725f60f8c5035113f89e4bf02de4ddccb23a25be6e8d8c
2022-10-11 01:05:06.178 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Received session info session_index=3987
2022-10-11 01:05:06.178 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Accepted collation, connecting to validators. para_id=2000 relay_parent=0x3399…afe3 candidate_hash=0xfdf34b3ac4175dca12dfde56a64c2dc6a4627f86ae21c84984de68f92426f5a9 pov_hash=0xaa0b69b3d6a924bf7a9790fbbd665f5e42ecfb552c229f3c2e9fdca52ee3ade1 core=CoreIndex(5) current_validators=GroupValidators { validators: [Public(aeac54c92e1a8a59a93f44eac04fbe1202311f07983e7457ed5ff31d4d07003c (sFJbPRMC...)), Public(f4fc4ea1de9fc3f0c3655fee1f25eeb3966df50ba8510f7cac72417ba5d0d817 (tqVhkdRL...))] } traceID=337557936906848688787529503111960604102
2022-10-11 01:05:06.178 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Advertising collation. relay_parent=0x339997be6c4033b1fb824f7320a85a18f367856c4e0ff87adb48f4e85a34afe3 peer_id=12D3KooWGXFrvqU8J3h9EtpZzz7BYQXCvb1xocwtn5oTP3mb3Df1
2022-10-11 01:05:06.178 TRACE tokio-runtime-worker parachain::collator-protocol: [Relaychain] Peer disconnected peer_id=PeerId("12D3KooWGXFrvqU8J3h9EtpZzz7BYQXCvb1xocwtn5oTP3mb3Df1")
2022-10-11 01:05:07.300 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (38 peers), best: #2309949 (0x3399…afe3), finalized #2309945 (0x3f8b…849e), ⬇ 121.0kiB/s ⬆ 59.4kiB/s
2022-10-11 01:05:07.303 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136831 (0xff16…6baa), finalized #1136829 (0xce6d…93ed), ⬇ 0 ⬆ 0
2022-10-11 01:05:08.158 TRACE tokio-runtime-worker parachain::provisioner: [Relaychain] Inherent Data became ready relay_parent=0x339997be6c4033b1fb824f7320a85a18f367856c4e0ff87adb48f4e85a34afe3
2022-10-11 01:05:09.344 TRACE tokio-runtime-worker parachain::collator-protocol: [Relaychain] Own view change view=OurView { view: View { heads: [0x339997be6c4033b1fb824f7320a85a18f367856c4e0ff87adb48f4e85a34afe3], finalized_number: 2309946 }, span_per_head: {0x339997be6c4033b1fb824f7320a85a18f367856c4e0ff87adb48f4e85a34afe3: <jaeger span>} }
2022-10-11 01:05:09.344 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Removing relay parent because our view changed. relay_parent=0x61e78d8499f2949b15e52b75de3880f2ad5cb9ffbcba50ed610826aa09c40178
2022-10-11 01:05:12.142 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2309950 (0xe11c…a98f)
2022-10-11 01:05:12.143 TRACE tokio-runtime-worker parachain::collator-protocol: [Relaychain] Own view change view=OurView { view: View { heads: [0xe11c43e61e5df08c99f01aa49c11ea5b53dd9429f8cf2f11e75b22ea8e85a98f], finalized_number: 2309946 }, span_per_head: {0xe11c43e61e5df08c99f01aa49c11ea5b53dd9429f8cf2f11e75b22ea8e85a98f: <jaeger span>} }
2022-10-11 01:05:12.143 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Removing relay parent because our view changed. relay_parent=0x339997be6c4033b1fb824f7320a85a18f367856c4e0ff87adb48f4e85a34afe3
2022-10-11 01:05:12.143 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Collation was requested. candidate_hash=0xfdf34b3ac4175dca12dfde56a64c2dc6a4627f86ae21c84984de68f92426f5a9 pov_hash=0xaa0b69b3d6a924bf7a9790fbbd665f5e42ecfb552c229f3c2e9fdca52ee3ade1 traceID=337557936906848688787529503111960604102
2022-10-11 01:05:12.150 INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0xe11c43e61e5df08c99f01aa49c11ea5b53dd9429f8cf2f11e75b22ea8e85a98f at=0xff168695f9afa81991addf787c7036942ded49914f8cb92d99abc2eb75ea6baa
2022-10-11 01:05:12.150 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xff168695f9afa81991addf787c7036942ded49914f8cb92d99abc2eb75ea6baa
2022-10-11 01:05:12.153 INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1136832 (0 ms) [hash: 0xa5ecbb52b74b02e07e9f53bbee29b839bdaf7a65f27bef33530aa647597b6d37; parent_hash: 0xff16…6baa; extrinsics (2): [0xee8d…ce85, 0xf618…0a99]]
2022-10-11 01:05:12.155 INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1136832. Hash now 0x904e4743b929841ff8df7f589c4c74ea037cdac020534d6747633a40c7e8c65e, previously 0xa5ecbb52b74b02e07e9f53bbee29b839bdaf7a65f27bef33530aa647597b6d37.
2022-10-11 01:05:12.155 INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1136832 (0x904e…c65e)
2022-10-11 01:05:12.156 INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.181640625kb, extrinsics: 10.783203125kb, storage_proof: 20.9658203125kb }
2022-10-11 01:05:12.156 INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 17.1650390625kb
2022-10-11 01:05:12.157 INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x904e4743b929841ff8df7f589c4c74ea037cdac020534d6747633a40c7e8c65e
2022-10-11 01:05:12.160 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Received session info session_index=3987
2022-10-11 01:05:12.160 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Accepted collation, connecting to validators. para_id=2000 relay_parent=0xe11c…a98f candidate_hash=0xa38fd4f990a6d3f981fa6d7b0b6d86152cc1ecae4ca76bfd0bb5c47c43921894 pov_hash=0x49583ac924da0c16687d40c5dde58d14f9c7eae5656f3d7cd92922794fe2ac57 core=CoreIndex(5) current_validators=GroupValidators { validators: [Public(aeac54c92e1a8a59a93f44eac04fbe1202311f07983e7457ed5ff31d4d07003c (sFJbPRMC...)), Public(f4fc4ea1de9fc3f0c3655fee1f25eeb3966df50ba8510f7cac72417ba5d0d817 (tqVhkdRL...))] } traceID=217410981407127731962413146348989548053
2022-10-11 01:05:12.301 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (39 peers), best: #2309950 (0xe11c…a98f), finalized #2309946 (0x68d4…440f), ⬇ 52.5kiB/s ⬆ 33.9kiB/s
2022-10-11 01:05:12.303 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136831 (0xff16…6baa), finalized #1136829 (0xce6d…93ed), ⬇ 27 B/s ⬆ 24 B/s
2022-10-11 01:05:14.143 TRACE tokio-runtime-worker parachain::provisioner: [Relaychain] Inherent Data became ready relay_parent=0xe11c43e61e5df08c99f01aa49c11ea5b53dd9429f8cf2f11e75b22ea8e85a98f
2022-10-11 01:05:17.302 INFO tokio-runtime-worker substrate: [Relaychain] 💤 Idle (39 peers), best: #2309950 (0xe11c…a98f), finalized #2309946 (0x68d4…440f), ⬇ 15.2kiB/s ⬆ 11.0kiB/s
2022-10-11 01:05:17.303 INFO tokio-runtime-worker substrate: [Parachain] 💤 Idle (1 peers), best: #1136831 (0xff16…6baa), finalized #1136829 (0xce6d…93ed), ⬇ 33 B/s ⬆ 36 B/s
2022-10-11 01:05:18.134 INFO tokio-runtime-worker substrate: [Relaychain] ✨ Imported #2309951 (0x2999…6601)
2022-10-11 01:05:18.134 TRACE tokio-runtime-worker parachain::collator-protocol: [Relaychain] Own view change view=OurView { view: View { heads: [0x29999a99d26ad066ebb23ae0cc23e27982c64d8a17e0dcac42b05a8d043b6601], finalized_number: 2309948 }, span_per_head: {0x29999a99d26ad066ebb23ae0cc23e27982c64d8a17e0dcac42b05a8d043b6601: <jaeger span>} }
2022-10-11 01:05:18.134 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Removing relay parent because our view changed. relay_parent=0xe11c43e61e5df08c99f01aa49c11ea5b53dd9429f8cf2f11e75b22ea8e85a98f
2022-10-11 01:05:18.134 WARN tokio-runtime-worker parachain::collator-protocol: [Relaychain] Collation wasn't advertised to any validator. candidate_hash=0xa38fd4f990a6d3f981fa6d7b0b6d86152cc1ecae4ca76bfd0bb5c47c43921894 pov_hash=0x49583ac924da0c16687d40c5dde58d14f9c7eae5656f3d7cd92922794fe2ac57 traceID=217410981407127731962413146348989548053

[bkchr]

Seems like this isn't related to reorg, but validator somehow reject our collator

Which log line makes you think this?

[xlc]

2022-10-11 01:05:06.178 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Accepted collation, connecting to validators. para_id=2000 relay_parent=0x3399…afe3 candidate_hash=0xfdf34b3ac4175dca12dfde56a64c2dc6a4627f86ae21c84984de68f92426f5a9 pov_hash=0xaa0b69b3d6a924bf7a9790fbbd665f5e42ecfb552c229f3c2e9fdca52ee3ade1 core=CoreIndex(5) current_validators=GroupValidators { validators: [Public(aeac54c92e1a8a59a93f44eac04fbe1202311f07983e7457ed5ff31d4d07003c (sFJbPRMC...)), Public(f4fc4ea1de9fc3f0c3655fee1f25eeb3966df50ba8510f7cac72417ba5d0d817 (tqVhkdRL...))] } traceID=337557936906848688787529503111960604102
2022-10-11 01:05:06.178 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Advertising collation. relay_parent=0x339997be6c4033b1fb824f7320a85a18f367856c4e0ff87adb48f4e85a34afe3 peer_id=12D3KooWGXFrvqU8J3h9EtpZzz7BYQXCvb1xocwtn5oTP3mb3Df1
2022-10-11 01:05:06.178 TRACE tokio-runtime-worker parachain::collator-protocol: [Relaychain] Peer disconnected peer_id=PeerId("12D3KooWGXFrvqU8J3h9EtpZzz7BYQXCvb1xocwtn5oTP3mb3Df1")

12D3KooWGXFrvqU8J3h9EtpZzz7BYQXCvb1xocwtn5oTP3mb3Df1 rejected the connection for some reason

[bkchr]

@dmitry-markin could you maybe take a look at this? If you need some support to debug this, @xlc would be happy to help you with this. Aka getting some logs or whatever you need.

[dmitry-markin]

Is it possible to reproduce the issue in some local toy network? Like having two validators + 1 collator to see why validators reject the collator? Is it only one collator, or some more parachain nodes are needed behind it to reproduce the issue?

[bkchr]

I think as a starting point you want to have some logs of sub-libp2py=trace,peerset=trace from @xlc around when the disconnect happens. This will probably generate tons of logs. If these logs don't reveal anything, we will need to enable the same logs on our validators and then compare both sides on what they think happens.

[dmitry-markin]

@xlc could you gather logs with -lsub-libp2p=trace,peerset=trace around the point where disconnect happens, as @bkchr suggested?

[xlc]

logs.txt.zip
here is the logs. I can provide more if needed
The last included block is 1139883 0xe92a5524e79646a5aded1341c5d5dd24694dce30be7325aec2c925b9c3310a0a

[dmitry-markin]

Dummy question: how do you tell from the logs that the parachain block in question was included into the relaychain?

I don't have much to share, but some observations are: up to block 1139883 the parachain block numbers keep increasing. Starting from block 1139884 everything looks the same, except the parachain keeps producing blocks with the same parent of 1139883 (0xe92...0a0a). So every time a block at height 1139884 is imported, and every time it's a different block.

Block 1139883:

63805 2022-10-20 06:08:12.175  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x0551cf577754b5ef573f88f240526b0eabac0c1f544ee89a7c3d5ac2336610b3 at=0xabdfd750b2253984bd       d3d49c0d9c501b26c0a8874cdb805bd7c0834ac735127c
63806 2022-10-20 06:08:12.175  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xabdfd750b2253984bdd3d49c0d9c501b26c0a8874cdb805bd7c08       34ac735127c
63809 2022-10-20 06:08:12.178  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1139883 (0 ms) [hash: 0xbf91485ead882350e03042bff9d76a9ab69974b0c50       abfd0cc275f8891317742; parent_hash: 0xabdf…127c; extrinsics (2): [0x3106…0e89, 0x96c9…f78b]]
63810 2022-10-20 06:08:12.179  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1139883. Hash now 0xe92a5524e79646a5aded1341c5d5dd24694dce30be7325aec2c925b9c3310a0a, previously 0x       bf91485ead882350e03042bff9d76a9ab69974b0c50abfd0cc275f8891317742.                                              
63813 2022-10-20 06:08:12.180  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0xe92a5524e79646a5aded1341c5d5dd24694dce30be7325aec2c925b9c3310a0a
63814 2022-10-20 06:08:12.181  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1139883 (0xe92a…0a0a)

And then we are stuck at 1139884:

[1]
76021 2022-10-20 06:08:24.188  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x6ce3cd40c8d9d6692ca225280f5c077e6a8c278e9d3eb9efc020e5a6e54a31bc at=0xe92a5524e79646a5ad       ed1341c5d5dd24694dce30be7325aec2c925b9c3310a0a                                                                                                                     
76022 2022-10-20 06:08:24.189  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xe92a5524e79646a5aded1341c5d5dd24694dce30be7325aec2c92       5b9c3310a0a
76026 2022-10-20 06:08:24.192  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1139884 (0 ms) [hash: 0x64daa7228818c7f11a095a7c9cb2b768616ae7ac273       e55de2824d224c7cdaa29; parent_hash: 0xe92a…0a0a; extrinsics (2): [0x5232…891e, 0x54b2…3f05]]
76027 2022-10-20 06:08:24.194  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1139884. Hash now 0x40a7d2ef0e7fde181c7a00b352d7f2d496ce1c6cdb8730d62610dee3fef6d9c3, previously 0x       64daa7228818c7f11a095a7c9cb2b768616ae7ac273e55de2824d224c7cdaa29.
76030 2022-10-20 06:08:24.195  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x40a7d2ef0e7fde181c7a00b352d7f2d496ce1c6cdb8730d62610dee3fef6d9c3
76031 2022-10-20 06:08:24.195  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1139884 (0x40a7…d9c3)
...
[2]
78873 2022-10-20 06:08:30.193  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x3d04ff16979c6a738a15d825da1ec22348ade44097fd2a037a1fdc957ad6a8ce at=0xe92a5524e79646a5ad       ed1341c5d5dd24694dce30be7325aec2c925b9c3310a0a
78878 2022-10-20 06:08:30.194  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xe92a5524e79646a5aded1341c5d5dd24694dce30be7325aec2c92       5b9c3310a0a
78879 2022-10-20 06:08:30.196  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1139884 (0 ms) [hash: 0xf8819b1b04575a848a950e02510e657f090d22771c5       e6ef426367227bcf45778; parent_hash: 0xe92a…0a0a; extrinsics (2): [0xa965…4a50, 0xf61f…634d]]
78880 2022-10-20 06:08:30.198  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1139884. Hash now 0x9b9806e4168a8a9b7a00f6202af7c615811c55a3b6d5ea373780c2458401e319, previously 0x       f8819b1b04575a848a950e02510e657f090d22771c5e6ef426367227bcf45778.
78887 2022-10-20 06:08:30.199  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x9b9806e4168a8a9b7a00f6202af7c615811c55a3b6d5ea373780c2458401e319       
78888 2022-10-20 06:08:30.199  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1139884 (0x9b98…e319)
...
[3]
86596 2022-10-20 06:08:36.152  INFO tokio-runtime-worker cumulus-collator: [Parachain] Starting collation. relay_parent=0x5f8262da8d3ffce493b452a3195eb3081b35e3adc47a83cf53a08f982e194afd at=0xe92a5524e79646a5ad       ed1341c5d5dd24694dce30be7325aec2c925b9c3310a0a
86599 2022-10-20 06:08:36.153  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0xe92a5524e79646a5aded1341c5d5dd24694dce30be7325aec2c92       5b9c3310a0a
86605 2022-10-20 06:08:36.156  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 1139884 (0 ms) [hash: 0x2393b7b7ca378081c2ec3b5cc2f0dd6fe1fccaac0a0       2f7c66a66755794e8c3bf; parent_hash: 0xe92a…0a0a; extrinsics (2): [0x0ef6…2888, 0x21b7…0fe1]]                                                                                                        
86606 2022-10-20 06:08:36.158  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 1139884. Hash now 0xc911e390fbba88cfdac40b4dcfb782cc68d5d75282e7345296d6fdbd354c2ca7, previously 0x       2393b7b7ca378081c2ec3b5cc2f0dd6fe1fccaac0a02f7c66a66755794e8c3bf.
86609 2022-10-20 06:08:36.159  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0xc911e390fbba88cfdac40b4dcfb782cc68d5d75282e7345296d6fdbd354c2ca7
86610 2022-10-20 06:08:36.160  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #1139884 (0xc911…2ca7)
...(and so on)...

I see a bunch of errors like the following one, but they start to appear only after [2] above:

86503 2022-10-20 06:08:36.143  WARN tokio-runtime-worker parachain::collator-protocol: [Relaychain] Collation wasn't advertised to any validator. candidate_hash=0xc4cac10be5b2fe3d841d29c265d160abaa411ceae739c81       1c424450272b6f208 pov_hash=0x8b3a5cd88d88226da6130d59dfaa19ed2c37ce9d6ba1cd194450fda8960a8d9f traceID=261581446586919295360246152641410850987

And there are none of the messages like [Relaychain] Accepted collation / [Relaychain] Advertising collation. Basically the only message in the log of parachain::collator-protocol is Collation wasn't advertised to any validator.

[bkchr]

Dummy question: how do you tell from the logs that the parachain block in question was included into the relaychain?

If it would be included, we would not build on the same block over and over again.

Basically the only message in the log of parachain::collator-protocol is Collation wasn't advertised to any validator.

This is really bad. This should not happen, especially on these small networks like Rococo. This message indicates that for whatever reason we could not connect to a relay chain validator that is assigned to our parachain. We should check why this happens. Maybe some reputation problem?

[xlc]

Somehow this is getting more stable as it have been running smoothly without issue for 24h. I will keep an eye on it and provide new logs if it got stuck again.

[xlc]

looks stable now. will reopen if stuck again.