fix: add time to the sdk.Context used in PrepareProposal #2515

evan-forbes · 2023-09-15T12:10:48Z

Overview

I'm not sure if this fixes all of #2454, but it at least fixes one bug similar to it.

The fix in this PR allows for the antehandlers that are ran during prepare proposal to have access to a time close to the actual block time. It does this by simply adding time.Now to the header used for antehandler state access.

Checklist

New and updated code has appropriate documentation
New and updated code has new and/or updated testing
Required CI checks are passing
Visual proof for any user facing features like CLI or documentation updates
Linked issues closed with keywords

evan-forbes · 2023-09-15T12:13:01Z

app/test/prepare_proposal_context_test.go

+// TestTimeInPrepareProposalContext checks for an edge case where the block time
+// needs to be included in the sdk.Context that is being used in the
+// antehandlers. If a time is not included in the context, then the second
+// transaction in this test will always be filtered out, result in vesting
+// accounts never being able to spend funds.
+func TestTimeInPrepareProposalContext(t *testing.T) {
+	if testing.Short() {


we could have included this in the standard cosmos-sdk test that we're already running, however since the tx needs to be second it felt a bit too hacky to do that

codecov-commenter · 2023-09-15T12:15:47Z

Codecov Report

Merging #2515 (2baaf49) into main (56312f2) will decrease coverage by 0.03%.
Report is 1 commits behind head on main.
The diff coverage is 0.00%.

@@            Coverage Diff             @@
##             main    #2515      +/-   ##
==========================================
- Coverage   20.61%   20.58%   -0.03%     
==========================================
  Files         131      131              
  Lines       15269    15273       +4     
==========================================
- Hits         3147     3144       -3     
- Misses      11819    11825       +6     
- Partials      303      304       +1

Files Changed	Coverage Δ
app/prepare_proposal.go	`0.00% <0.00%> (ø)`

... and 1 file with indirect coverage changes

app/test/prepare_proposal_context_test.go

Co-authored-by: Rootul P <rootulp@gmail.com>

cmwaters · 2023-09-15T17:14:09Z

app/prepare_proposal.go

+	sdkCtx := app.NewProposalContext(core.Header{
+		ChainID: req.ChainId,
+		Height:  app.LastBlockHeight() + 1,
+		Time:    time.Now(),


There is a high possibility that time.Now() is greater than the block time proposed in the header (as it stems from the commit of the previous block). This could compromise the consistency property whereby a transaction seems valid in PrepareProposal but invalid in ProcessProposal. If the transaction isn't kicked from the mempool it could result in the chain halting (as proposers continue to propose a vesting transaction that they think is valid (it has a later time) but continues to get rejected (as validators are basing it off the last block time). Ideally we find a way to add the last block time to the context. If it's too difficult I would recommend setting Time to time.Now().Sub(TargetBlockTime) as an extra precaution but if there are multi rounds the same consistency problem could occur

good point! I totally blanked this morning on us running the entire antehandler on all txs in process proposal

we definitely shouldn't do this

I think the only solution here is to get the time in the request from comet similar to how its done on celestia-core/main or comet

liamsi · 2023-09-16T11:51:59Z

app/prepare_proposal.go

+	sdkCtx := app.NewProposalContext(core.Header{
+		ChainID: req.ChainId,
+		Height:  app.LastBlockHeight() + 1,
+		Time:    time.Now(),


Yes, this must be the last block's time! Otherwise this is wrong. For example, when calculating the spendable amount, the only real reference the chain has is the last block, as the current block has not been finalized. Only use block time

This looks about right:
https://github.com/cosmos/cosmos-sdk/blob/c7e0bd7b54d037a36ef7d31cc89ecabdf2124913/baseapp/abci.go#L409-L416

But please double-check that the req actually contains the correct time.

Note: it does not seem to be the case that the correct time is set here:
https://github.com/celestiaorg/celestia-core/blob/d24c81afe0ecc4ccfbb7eb543a45a11794f04db4/state/execution.go#L118-L124

Only later in MakeBlock the time is set (correctly):

https://github.com/celestiaorg/celestia-core/blob/d24c81afe0ecc4ccfbb7eb543a45a11794f04db4/state/execution.go#L152

https://github.com/celestiaorg/celestia-core/blob/3f3b7cc57f5cfc5e846ce781a9a407920e54fb72/state/state.go#L249

Compare main of vanilla cometBFT: https://github.com/cometbft/cometbft/blob/1c6f86c840c64f83f4409ccca6b664234866cc38/state/execution.go#L128C9-L139

liamsi

See either: https://github.com/celestiaorg/celestia-app/pull/2515/files#r1327951681
or: https://github.com/celestiaorg/celestia-app/pull/2515/files#r1327582804

evan-forbes · 2023-09-18T01:56:55Z

Thanks again @cmwaters and @liamsi for catching the time.Now bug, I don't know what I was thinking. Too many late nights deugging testground last week! 😅 . Per the first and second thread, the only solution to this is to use the same time that will be used in process proposal and deliver tx (the time in the header from the last commit). That's what's done in celestiaorg/celestia-core#1081, which should be merged before this PR.

evan-forbes · 2023-09-18T16:51:49Z

app/test/prepare_proposal_context_test.go

+		{
+			name: "create continuous vesting account with a start time in the future",
+			msgFunc: func() (msgs []sdk.Msg, signer string) {
+				_, _, err := cctx.Keyring.NewMnemonic(vestAccName, keyring.English, "", "", hd.Secp256k1)
+				require.NoError(t, err)
+				sendAcc := accounts[0]
+				sendingAccAddr := testfactory.GetAddress(cctx.Keyring, sendAcc)
+				vestAccAddr := testfactory.GetAddress(cctx.Keyring, vestAccName)
+				msg := vestingtypes.NewMsgCreateVestingAccount(
+					sendingAccAddr,
+					vestAccAddr,
+					sdk.NewCoins(sdk.NewCoin(app.BondDenom, sdk.NewInt(1000000))),
+					time.Now().Unix(),
+					time.Now().Add(time.Second*100).Unix(),
+					false,
+				)
+				return []sdk.Msg{msg}, sendAcc
+			},
+			expectedCode: abci.CodeTypeOK,
+		},
+		{
+			name: "send funds from the vesting account after it has been created",
+			msgFunc: func() (msgs []sdk.Msg, signer string) {
+				sendAcc := accounts[1]
+				sendingAccAddr := testfactory.GetAddress(cctx.Keyring, sendAcc)
+				vestAccAddr := testfactory.GetAddress(cctx.Keyring, vestAccName)
+				msg := banktypes.NewMsgSend(
+					vestAccAddr,
+					sendingAccAddr,
+					sdk.NewCoins(sdk.NewCoin(app.BondDenom, sdk.NewInt(1))),
+				)
+				return []sdk.Msg{msg}, vestAccName
+			},
+			expectedCode: abci.CodeTypeOK,
+		},
+	}


one additional test we can do is to have a third test case where we attempt to send too much and expect it to fail. I have a commit with this ready, however I'm worried that it will cause flakiness do to the process requiring a specific time delay window.

I don't think it will be flaky if you set the end time well in the future and try send all the funds

well in the future and try send all the funds

yeah good point, sorry I was not clear enough. the thing that I was trying to test with the additional case here was not just that a tx would fail if there was not enough of a spendable balance, I think we have that somehwere already (#2004 iirc). That wouldn't be flakey.

I was trying to create a test that checks that puts us in the exact scenario we would get in if we used time.Now(). Where a tx doesn't get filtered but is invalid.

liamsi

👏🏼

cmwaters

Few minor comments but mostly looks good

cmwaters · 2023-09-18T18:23:18Z

app/test/prepare_proposal_context_test.go

+// antehandlers. If a time is not included in the context, then the second
+// transaction in this test will always be filtered out, result in vesting
+// accounts never being able to spend funds.
+func TestTimeInPrepareProposalContext(t *testing.T) {


I feel like we defer to using integration tests too often when unit tests would suffice

cmwaters · 2023-09-18T18:25:40Z

app/test/prepare_proposal_context_test.go

+					sendingAccAddr,
+					vestAccAddr,
+					sdk.NewCoins(sdk.NewCoin(app.BondDenom, sdk.NewInt(1000000))),
+					time.Now().Unix(),


This is not a start time in the future as is stated in the test name

will grab this in a followup

cmwaters · 2023-09-18T18:31:53Z

app/test/prepare_proposal_context_test.go

+		{
+			name: "create continuous vesting account with a start time in the future",
+			msgFunc: func() (msgs []sdk.Msg, signer string) {
+				_, _, err := cctx.Keyring.NewMnemonic(vestAccName, keyring.English, "", "", hd.Secp256k1)
+				require.NoError(t, err)
+				sendAcc := accounts[0]
+				sendingAccAddr := testfactory.GetAddress(cctx.Keyring, sendAcc)
+				vestAccAddr := testfactory.GetAddress(cctx.Keyring, vestAccName)
+				msg := vestingtypes.NewMsgCreateVestingAccount(
+					sendingAccAddr,
+					vestAccAddr,
+					sdk.NewCoins(sdk.NewCoin(app.BondDenom, sdk.NewInt(1000000))),
+					time.Now().Unix(),
+					time.Now().Add(time.Second*100).Unix(),
+					false,
+				)
+				return []sdk.Msg{msg}, sendAcc
+			},
+			expectedCode: abci.CodeTypeOK,
+		},
+		{
+			name: "send funds from the vesting account after it has been created",
+			msgFunc: func() (msgs []sdk.Msg, signer string) {
+				sendAcc := accounts[1]
+				sendingAccAddr := testfactory.GetAddress(cctx.Keyring, sendAcc)
+				vestAccAddr := testfactory.GetAddress(cctx.Keyring, vestAccName)
+				msg := banktypes.NewMsgSend(
+					vestAccAddr,
+					sendingAccAddr,
+					sdk.NewCoins(sdk.NewCoin(app.BondDenom, sdk.NewInt(1))),
+				)
+				return []sdk.Msg{msg}, vestAccName
+			},
+			expectedCode: abci.CodeTypeOK,
+		},
+	}


I don't think it will be flaky if you set the end time well in the future and try send all the funds

## Overview I'm not sure if this fixes all of #2454, but it at least fixes one bug similar to it. The fix in this PR allows for the antehandlers that are ran during prepare proposal to have access to a time close to the actual block time. It does this by simply adding `time.Now` to the header used for antehandler state access. ## Checklist - [x] New and updated code has appropriate documentation - [x] New and updated code has new and/or updated testing - [x] Required CI checks are passing - [x] Visual proof for any user facing features like CLI or documentation updates - [x] Linked issues closed with keywords --------- Co-authored-by: Rootul P <rootulp@gmail.com> (cherry picked from commit 9617549) # Conflicts: # app/test/fuzz_abci_test.go

) (#2534) This is an automatic backport of pull request #2515 done by [Mergify](https://mergify.com). Cherry-pick of 9617549 has failed: ``` On branch mergify/bp/v1.x/pr-2515 Your branch is up to date with 'origin/v1.x'. You are currently cherry-picking commit 9617549. (fix conflicts and run "git cherry-pick --continue") (use "git cherry-pick --skip" to skip this patch) (use "git cherry-pick --abort" to cancel the cherry-pick operation) Changes to be committed: modified: Makefile modified: app/prepare_proposal.go new file: app/test/prepare_proposal_context_test.go modified: app/test/prepare_proposal_test.go modified: app/test/process_proposal_test.go modified: go.mod modified: go.sum Unmerged paths: (use "git add <file>..." to mark resolution) both modified: app/test/fuzz_abci_test.go ``` To fix up this pull request, you can check it out locally. See documentation: https://docs.github.com/en/github/collaborating-with-pull-requests/reviewing-changes-in-pull-requests/checking-out-pull-requests-locally --- <details> <summary>Mergify commands and options</summary> <br /> More conditions and actions can be found in the [documentation](https://docs.mergify.com/). You can also trigger Mergify actions by commenting on this pull request: - `@Mergifyio refresh` will re-evaluate the rules - `@Mergifyio rebase` will rebase this PR on its base branch - `@Mergifyio update` will merge the base branch into this PR - `@Mergifyio backport <destination>` will backport this PR on `<destination>` branch Additionally, on Mergify [dashboard](https://dashboard.mergify.com) you can: - look at your merge queues - generate the Mergify configuration with the config editor. Finally, you can contact us on https://mergify.com </details> --------- Co-authored-by: Evan Forbes <42654277+evan-forbes@users.noreply.github.com> Co-authored-by: evan-forbes <evan.samuel.forbes@gmail.com>

fix: add time to the sdk.Context used in PrepareProposal

ee482b0

evan-forbes added the bug Something isn't working label Sep 15, 2023

evan-forbes added this to the Mainnet milestone Sep 15, 2023

evan-forbes requested a review from rootulp as a code owner September 15, 2023 12:10

evan-forbes self-assigned this Sep 15, 2023

evan-forbes requested a review from cmwaters as a code owner September 15, 2023 12:10

evan-forbes requested a review from liamsi September 15, 2023 12:11

celestia-bot requested a review from a team September 15, 2023 12:11

evan-forbes commented Sep 15, 2023

View reviewed changes

evan-forbes requested a review from rach-id September 15, 2023 12:24

evan-forbes added the backport:v1.x PR will be backported automatically to the v1.x branch upon merging label Sep 15, 2023

evan-forbes enabled auto-merge (squash) September 15, 2023 12:24

rootulp previously approved these changes Sep 15, 2023

View reviewed changes

app/test/prepare_proposal_context_test.go Outdated Show resolved Hide resolved

app/test/prepare_proposal_context_test.go Outdated Show resolved Hide resolved

evan-forbes dismissed rootulp’s stale review via 9f896e8 September 15, 2023 13:20

Update app/test/prepare_proposal_context_test.go

9f896e8

Co-authored-by: Rootul P <rootulp@gmail.com>

celestia-bot requested a review from a team September 15, 2023 13:20

refactor: review feedback

5ad8371

rootulp previously approved these changes Sep 15, 2023

View reviewed changes

cmwaters requested changes Sep 15, 2023

View reviewed changes

evan-forbes disabled auto-merge September 15, 2023 21:43

evan-forbes marked this pull request as draft September 15, 2023 21:43

liamsi reviewed Sep 16, 2023

View reviewed changes

liamsi requested changes Sep 16, 2023

View reviewed changes

fix: use the same time process proposal uses

0f48861

evan-forbes dismissed rootulp’s stale review via 0f48861 September 17, 2023 18:19

evan-forbes added 2 commits September 17, 2023 20:43

fix: tests

f5710fc

fix: TestPrepareProposalPutsPFBsAtEnd

d873db1

fix: TestPrepareProposalFiltering

d80e551

evan-forbes added 2 commits September 17, 2023 21:12

fix: TestProcessProposal

2baaf49

chore: use official release tag of core

8e2b4d7

evan-forbes marked this pull request as ready for review September 18, 2023 16:49

evan-forbes requested review from liamsi, rootulp and cmwaters September 18, 2023 16:50

evan-forbes commented Sep 18, 2023

View reviewed changes

rootulp approved these changes Sep 18, 2023

View reviewed changes

liamsi approved these changes Sep 18, 2023

View reviewed changes

cmwaters approved these changes Sep 18, 2023

View reviewed changes

evan-forbes mentioned this pull request Sep 18, 2023

Remove integration tests where possible to replace with unit #2533

Open

evan-forbes merged commit 9617549 into main Sep 18, 2023
28 checks passed

evan-forbes deleted the evan/add-time-to-prepare-proposal-context branch September 18, 2023 20:34

mergify bot mentioned this pull request Sep 18, 2023

fix: add time to the sdk.Context used in PrepareProposal (backport #2515) #2534

Merged

evan-forbes mentioned this pull request Oct 27, 2023

Transactions on mocha-4 got stuck in the mempool #2454

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: add time to the sdk.Context used in PrepareProposal #2515

fix: add time to the sdk.Context used in PrepareProposal #2515

evan-forbes commented Sep 15, 2023

evan-forbes Sep 15, 2023 •

edited

Loading

codecov-commenter commented Sep 15, 2023 •

edited

Loading

cmwaters Sep 15, 2023

evan-forbes Sep 15, 2023

evan-forbes Sep 15, 2023

liamsi Sep 16, 2023 •

edited

Loading

liamsi Sep 16, 2023

liamsi Sep 16, 2023

liamsi left a comment

evan-forbes commented Sep 18, 2023 •

edited

Loading

evan-forbes Sep 18, 2023

cmwaters Sep 18, 2023

evan-forbes Sep 18, 2023

liamsi left a comment

cmwaters left a comment

cmwaters Sep 18, 2023

evan-forbes Sep 18, 2023

cmwaters Sep 18, 2023

evan-forbes Sep 18, 2023

cmwaters Sep 18, 2023

fix: add time to the sdk.Context used in PrepareProposal #2515

fix: add time to the sdk.Context used in PrepareProposal #2515

Conversation

evan-forbes commented Sep 15, 2023

Overview

Checklist

evan-forbes Sep 15, 2023 • edited Loading

Choose a reason for hiding this comment

codecov-commenter commented Sep 15, 2023 • edited Loading

Codecov Report

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

liamsi Sep 16, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

liamsi left a comment

Choose a reason for hiding this comment

evan-forbes commented Sep 18, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

liamsi left a comment

Choose a reason for hiding this comment

cmwaters left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

evan-forbes Sep 15, 2023 •

edited

Loading

codecov-commenter commented Sep 15, 2023 •

edited

Loading

liamsi Sep 16, 2023 •

edited

Loading

evan-forbes commented Sep 18, 2023 •

edited

Loading