got wrong beaconEpoch when mining block

[firesWu]

Checklist

• This is not a security-related bug/issue. If it is, please follow please follow the security policy.
• I have searched on the issue tracker and the lotus forum, and there is no existing related issue or discussion.
• I am running the Latest release, the most recent RC(release canadiate) for the upcoming release or the dev branch(master), or have an issue updating to any of these.
• I did not make any code changes to lotus.

Lotus component

• lotus daemon - chain sync
• lotus fvm/fevm - Lotus FVM and FEVM interactions
• lotus miner/worker - sealing
• lotus miner - proving(WindowPoSt/WinningPoSt)
• lotus JSON-RPC API
• lotus message management (mpool)
• Other

Lotus Version

lotus 1.26.3+mainnet+git.0d656fd59.dirty+api1.5.0
lotus-miner 1.26.2+mainnet+git.94cbd1f9b.dirty

Repro Steps

No response

Describe the Bug

According to the log, when the miner calls MinerGetBaseInfo, lotus requests beaconEpoch from Drand, which are 7442432 and 7442992, but what the miner actually obtains is 7442434 and 7442994. The miner maybe lose block production rights.
In most cases, the correct beaconEpoch can be obtained.

Logging Information

miner log

2024-05-08T09:11:15.313+0800    INFO    miner   miner/miner.go:520      completed mineOne       {"tookMilliseconds": 55, "forRound": 3894143, "baseEpoch": 3894142, "baseDeltaSeconds": 15, "nullRounds": 0, "lateStart": false, "beaconEpoch": 7442434, "lookbackEpochs": 900, "networkPowerAtLookback": "26857725393166368768", "minerPowerAtLookback": "", "isEligible": true, "isWinner": false, "error": null}
2024-05-08T09:39:15.108+0800    INFO    miner   miner/miner.go:520      completed mineOne       {"tookMilliseconds": 55, "forRound": 3894199, "baseEpoch": 3894198, "baseDeltaSeconds": 15, "nullRounds": 0, "lateStart": false, "beaconEpoch": 7442994, "lookbackEpochs": 900, "networkPowerAtLookback": "26856586338241380352", "minerPowerAtLookback": "", "isEligible": true, "isWinner": false, "error": null}

lotus log

2024-05-08T09:11:15.128+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442432}
2024-05-08T09:11:15.175+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442432, "took": 0.046632802}
2024-05-08T09:11:15.178+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442432}
2024-05-08T09:11:15.208+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442432}
2024-05-08T09:11:15.224+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442432, "took": 0.045782022}
2024-05-08T09:11:15.254+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442432, "took": 0.045786932}
2024-05-08T09:11:15.257+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442432}
2024-05-08T09:11:15.302+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442432, "took": 0.045689681}

2024-05-08T09:39:15.005+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442992}
2024-05-08T09:39:15.043+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442992}
2024-05-08T09:39:15.051+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442992, "took": 0.046659262}
2024-05-08T09:39:15.054+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442992}
2024-05-08T09:39:15.090+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442992, "took": 0.046588242}
2024-05-08T09:39:15.092+0800    DEBUG   drand   drand/drand.go:160      start fetching randomness       {"round": 7442992}
2024-05-08T09:39:15.099+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442992, "took": 0.044534201}
2024-05-08T09:39:15.139+0800    DEBUG   drand   drand/drand.go:170      done fetching randomness        {"round": 7442992, "took": 0.046507842}

[lyswifter]

Also, we got the beacon round which does not match the round I specified. Otherwise, looks like the drand service lost some rounds of signature, eg. 7580362 in the above pic.

[TippyFlitsUK]

Can you please add your lotus -v output @lyswifter? Many thanks!

[rjan90]

@TippyFlitsUK Can you turn on the DEBUG logs for Drand on your miner, and monitor over a couple of days, then we can see if you also see this type of discrepancy.

[rjan90]

@lyswifter / @firesWu Are you caching the caching the Drand entry by any chance? And if so, is that a modification that you have added?

Additional, where are you fetching Drand from?

[lyswifter]

Can you please add your lotus -v output @lyswifter? Many thanks!

Before the upgrade of Quicknet, we had never encountered this issue.

[lyswifter]

@lyswifter / @firesWu Are you caching the caching the Drand entry by any chance? And if so, is that a modification that you have added?

Additional, where are you fetching Drand from?

Actually we had turned off the caching loop of RunWatchConsole function beforehand, then we had turned it on, but this problem had still existed.

[lyswifter]

@lyswifter / @firesWu Are you caching the caching the Drand entry by any chance? And if so, is that a modification that you have added?

Additional, where are you fetching Drand from?

I had not figure out which api we used when the problem arose, but I had not changed the default drand services.

[firesWu]

@lyswifter / @firesWu Are you caching the caching the Drand entry by any chance? And if so, is that a modification that you have added?

Additional, where are you fetching Drand from?

We haven't made any modifications about drand. and use default drand config.

After the upgrade of 'Quicknet', we founds that sometimes we lose block production rights due to obtaining the wrong beacon epoch.

[TippyFlitsUK]

@TippyFlitsUK Can you turn on the DEBUG logs for Drand on your miner, and monitor over a couple of days, then we can see if you also see this type of discrepancy.

Running now Phi 👍

[arajasek]

@TippyFlitsUK Can you turn on the DEBUG logs for Drand on your miner, and monitor over a couple of days, then we can see if you also see this type of discrepancy.

I was concerned about this, so I hacked my daemon to request beacons from Drand the way a miner would and FREAK OUT if it got an unexpected response (that is, a round that isn't what I requested). It ran for a few days with no issue, but that doesn't confirm there isn't an issue.