bug: Rollkit attempts to create 2 blocks with identical Unix timestamps

[jcstein]

Version of Git SHA

1. running polaris on cd5f8ef https://github.com/berachain/polaris/commit/cd5f8ef51b3ebeb89e2936ba6f945cf563271013
2. running polaris on this PR https://github.com/berachain/polaris/pull/1482

these both use rollkit v0.11.19-no-fraud-proofs https://github.com/rollkit/cosmos-sdk/releases/tag/v0.50.1-rollkit-v0.11.19-no-fraud-proofs

System OS

macOS

Installed tools

necessary dependencies

Others

No response

Steps to reproduce it

copied from https://github.com/berachain/polaris/pull/1482#issuecomment-1930668866

testing setup

1. running on celestia-da v0.12.10

docker run -d \
-e NODE_TYPE=light \
-e P2P_NETWORK=mocha \
-p 26650:26650 \
-p 26658:26658 \
-p 26659:26659 \
-v $HOME/.celestia-light-mocha-4/:/home/celestia/.celestia-light-mocha-4/ \
ghcr.io/rollkit/celestia-da:v0.12.10 \
celestia-da light start \
--p2p.network=mocha \
--da.grpc.namespace=0000506f6c6172697332 \
--da.grpc.listen=0.0.0.0:26650 \
--core.ip rpc-mocha.pops.one \
--gateway

2. using https://github.com/berachain/polaris/pull/1482
3. with default 1s block times, following instructions from https://rollkit.dev/tutorials/polaris-evm#start-your-light-node
4. posting to mocha's "Polaris2" namespace: https://mocha.celenium.io/namespace/0000000000000000000000000000000000000000506f6c6172697332

Expected result

Rollkit does not try to make 2 blocks with the same Unix timestamp.

Actual result

Rollkit tries to make 2 blocks with the same Unix timestamp. Chain crashes. Unrecoverable for the developer and for the chain.

copied from https://github.com/berachain/polaris/pull/1482#issuecomment-1930744236

testing update

Unfortunately, the chain crashed, due to an error seen on previous testing (before branch was updated):

3:47PM ERR failed to build payload err="invalid timestamp, parent 1707252473 given 1707252473" module=server
3:47PM INF exiting prepare proposal duration=3.421708 height=3149 module=polaris-proposal-provider timestamp=2024-02-06T15:47:53-05:00
3:47PM ERR failed to prepare proposal err="invalid timestamp, parent 1707252473 given 1707252473" height=3149 module=server
3:47PM INF entering process proposal height=3149 module=polaris-proposal-provider timestamp=2024-02-06T15:47:53-05:00
3:47PM INF exiting process proposal duration=1.003917 height=3149 module=polaris-proposal-provider timestamp=2024-02-06T15:47:53-05:00
3:47PM ERR failed to process proposal err="failed to find envelope in proposal" hash=FECD964A8D720D3E9BB272ED49C154D563ED876BCA112DC9DF6A8ED7603BF11D height=3149 module=server
panic: error while processing the proposal: <nil>

goroutine 421 [running]:
github.com/rollkit/rollkit/block.(*Manager).publishBlock(0x14000df1a40, {0x1063fac60, 0x14001b11e00?})
	github.com/rollkit/[email protected]/block/manager.go:732 +0xbd8
github.com/rollkit/rollkit/block.(*Manager).AggregationLoop(0x14000df1a40, {0x1063fac60, 0x14001b11e00}, 0x0)
	github.com/rollkit/[email protected]/block/manager.go:274 +0x1d0
github.com/rollkit/rollkit/node.(*FullNode).OnStart.func1()
	github.com/rollkit/[email protected]/node/full.go:379 +0x30
github.com/rollkit/rollkit/types.(*ThreadManage()
	github.com/rollkit/[email protected]/types/threadmanager.go:26 +0x58
created by github.com/rollkit/rollkit/types.(*ThreadManager).Go in goroutine 1
	github.com/rollkit/[email protected]/types/threadmanager.go:24 +0x7c
make: *** [start] Error 2

root issue

3:47PM ERR failed to build payload err="invalid timestamp, parent 1707252473 given 1707252473" module=server

logs

• see full logs of rollup
• see docker logs from light node (celestia-da)

Relevant log output

No response

Notes

No response

[jcstein]

source https://github.com/rollkit/cosmos-sdk/commit/306e719663dda2d65db37f35de4bcd5f75007e37

[tzdybal]

The invalid timestamp, parent) error is thrown by geth code, not rollkit nor cosmos-sdk. (I double checked, and there is no invalid timestamp string in rollkit/cosmos-sdk repos).

The timestamp (integer value) in the error message in clearly the Unix timestamp with seconds precission (you can test this with $ date -d @1707252473).

• Rollkit internally use UnixNano so initially all timestamps have nanosecond precision.
• ABCI gRPC use google.protobuf.Timestamp - precision is nanoseconds.
• cosmos-sdk use time.Time in go objects - precision is nanoseconds.
• Polaris explicitly trims the timestamp to seconds in Miner.submitPayloadForBuilding.

[gupadhyaya]

this commit uncomments the recover logic in PrepareProposal which should consume the identical timestamp errors, which was mostly intentional to begin with. will close this issue after testing the fix.

[MSevey]

Pending polaris v2 migration.

[yarikbratashchuk]

I don't see exactly this issue with invalid timestamps, after

• updating to the to latest version of rollkit/cosmossdk (v0.50.7-rollkit-v0.13.6-no-fraud-proofs)
• updating rollkiit/rollkit to the latest version (v0.13.6)
• setting --rollkit.block_time 1s (default) and --rollkit.da_block_time 1s
• switching DA to local-da by setting --rollkit.da_address=http://localhost:7980

But sometimes (1 in 10 runs id say) I see a bit different crash

10:14AM INF Starting work on payload id=0x34390224c553c2c4 module=polaris-geth
10:14AM INF submitted payload for building module=server
10:14AM INF Updated payload elapsed="58.68µs" fees=0 gas=0 hash=0x057e323a328f1f81080b14bbb3e8c132d9f359d9c2dede023ae3c6a41f3fa073 id=0x34390224c553c2c4 module=polaris-geth number=1 root=0x0000000000000000000000000000000000000000000000000000000000000000 txs=0 withdrawals=0
10:14AM INF exiting prepare proposal duration=1.018358 height=1 module=polaris-proposal-provider timestamp=2024-07-30T10:14:10Z
10:14AM ERR panic recovered in PrepareProposal height=1 module=server panic="runtime error: invalid memory address or nil pointer dereference"
10:14AM INF entering process proposal height=1 module=polaris-proposal-provider timestamp=2024-07-30T10:14:10Z
10:14AM INF exiting process proposal duration=0.261823 height=1 module=polaris-proposal-provider timestamp=2024-07-30T10:14:10Z
10:14AM ERR failed to process proposal err="failed to find envelope in proposal" hash=486E9344956CBFC519087D2BE90472FA7E4B66A581C72C66AA993FEC3435A803 height=1 module=server
panic: proposal processing resulted in an invalid application state

goroutine 286 [running]:
github.com/rollkit/rollkit/block.(*Manager).publishBlock(0xc0018b4400, {0x4d3a2e0, 0xc001f6d6d0})
	github.com/rollkit/[email protected]/block/manager.go:842 +0x11a5
github.com/rollkit/rollkit/block.(*Manager).AggregationLoop(0xc0018b4400, {0x4d3a2e0, 0xc001f6d6d0}, 0x0)
	github.com/rollkit/[email protected]/block/manager.go:402 +0x67a
github.com/rollkit/rollkit/node.(*FullNode).OnStart.func1()
	github.com/rollkit/[email protected]/node/full.go:389 +0x33
github.com/rollkit/rollkit/types.(*ThreadManager).Go.func1()
	github.com/rollkit/[email protected]/types/threadmanager.go:26 +0x52
created by github.com/rollkit/rollkit/types.(*ThreadManager).Go in goroutine 1
	github.com/rollkit/[email protected]/types/threadmanager.go:24 +0x73
make: *** [build/scripts/main.mk:158: start] Error 2

Posting it here for now, but feel free to move it to separate issue

[Manav-Aggarwal]

Closing this issue since Rollkit now has support for Omni Octane and BeaconKit EVMs. Please reopen if Polaris becomes relevant again.

[jcstein]

yep good to close this as it was polaris-specific AFAIU