Here are warning logs from the machine you have shared access with:
Proof of time chain was extended from block import
2024-03-12T19:18:42.970333Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3417177 to_next_slot=3417178
2024-03-12T23:03:53.841201Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3430883 to_next_slot=3430884
2024-03-12T23:14:28.649307Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3431527 to_next_slot=3431528
2024-03-12T23:44:24.767989Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3433349 to_next_slot=3433350
2024-03-12T23:54:49.690373Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3433983 to_next_slot=3433984
2024-03-13T00:34:31.930028Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3436383 to_next_slot=3436384
2024-03-13T00:49:24.102653Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3437288 to_next_slot=3437289
2024-03-13T01:51:29.358894Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3441067 to_next_slot=3441068
2024-03-13T02:51:59.943461Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3444750 to_next_slot=3444751
2024-03-13T03:01:51.410814Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3445350 to_next_slot=3445351
2024-03-13T03:07:26.560577Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3445690 to_next_slot=3445691
2024-03-13T03:43:37.177761Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3447892 to_next_slot=3447893
2024-03-13T03:55:43.723378Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3448629 to_next_slot=3448630
2024-03-13T04:08:55.304595Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3449432 to_next_slot=3449433
2024-03-13T04:29:14.733894Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3450669 to_next_slot=3450670
2024-03-13T05:30:54.331070Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3454422 to_next_slot=3454423
As can be seen, it is always 1 slot difference and it doesn’t happen all the time, just from time to time.
The way protocol works is the following:
- slot arrives
- farmer does the audit and in case there is a solution candidate will try to generate a proof
- with solution ready to go node waits for future slot (+4 from slot for which solution was generated)
- once future proof of time arrives, block is created, signed and sent to the network
Now let’s see the logs when things work fine:
Good
2024-03-12T18:21:22.580703Z TRACE Consensus: sc_proof_of_time::source::gossip: Superficial verification succeeded sender=12D3KooWMssTp9dMeTqm5TKE9Hjawv5kYoZ3u2YZjvuH5T9MbKZH slot=3413688
2024-03-12T18:21:22.724102Z TRACE Consensus: sc_proof_of_time::source: Block import didn't result in proof of time chain changes best_slot=3413687
2024-03-12T18:21:22.724134Z INFO Consensus: substrate: ✨ Imported #602616 (0xa5c9…23e7)
2024-03-12T18:21:23.245389Z DEBUG Consensus: sc_proof_of_time::source::gossip: Full verification succeeded sender=12D3KooWMssTp9dMeTqm5TKE9Hjawv5kYoZ3u2YZjvuH5T9MbKZH slot=3413688
We can see that future proof of time checkpoints for slot 3413688 were received just before block that contains future proof of time slot 3413687. This is how things are supposed to work.
Here is an example where this wasn’t the case:
Less good
2024-03-12T18:21:38.363184Z TRACE Consensus: sc_proof_of_time::source::gossip: Superficial verification succeeded sender=12D3KooWMssTp9dMeTqm5TKE9Hjawv5kYoZ3u2YZjvuH5T9MbKZH slot=3413704
2024-03-12T18:21:38.765137Z INFO Consensus: substrate: 💤 Idle (40 peers), best: #602619 (0x1a10…f52b), finalized #522672 (0xc9e8…1f33), ⬇ 42.6kiB/s ⬆ 94.6kiB/s
2024-03-12T18:21:39.038338Z DEBUG Consensus: sc_proof_of_time::source::gossip: Full verification succeeded sender=12D3KooWMssTp9dMeTqm5TKE9Hjawv5kYoZ3u2YZjvuH5T9MbKZH slot=3413704
2024-03-12T18:21:39.038604Z WARN Consensus: sc_proof_of_time::source: Proof of time chain was extended from block import from_next_slot=3413704 to_next_slot=3413705
2024-03-12T18:21:39.038860Z INFO Consensus: substrate: ✨ Imported #602620 (0xef01…625c)
2024-03-12T18:21:39.336517Z TRACE Consensus: sc_proof_of_time::source::gossip: Superficial verification succeeded sender=12D3KooWMssTp9dMeTqm5TKE9Hjawv5kYoZ3u2YZjvuH5T9MbKZH slot=3413705
2024-03-12T18:21:39.997988Z DEBUG Consensus: sc_proof_of_time::source::gossip: Full verification succeeded sender=12D3KooWMssTp9dMeTqm5TKE9Hjawv5kYoZ3u2YZjvuH5T9MbKZH slot=3413705
Here future proof of time in the block was received slightly before the checkpoints from gossip.
To be clear, this is not great, but not catastrophe either. Basically it means that when this happens and there is a fork, it is likely that the block you’ve produced will not win the fork. However, if there are no forks or you produce a vote, there should be not difference.
So strictly speaking you are in a bit of disadvantage when this happens, and this likely happens to different participants from time to time (I saw it in my logs a few times as well) due to how time sensitive this stuff is, but it is not the end of the world. Running fast timekeeper helps, but is not a strict requirement.