From 2efc191818512ff6200b2aa55d71a0523c6cd3c5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Rok=20=C4=8Cerni=C4=8D?= Date: Fri, 19 Jul 2024 11:57:12 +0200 Subject: [PATCH 1/6] chore: add some logs --- pallets/market/src/lib.rs | 13 +++--- pallets/storage-provider/src/lib.rs | 65 +++++++++++++++++++++++------ 2 files changed, 61 insertions(+), 17 deletions(-) diff --git a/pallets/market/src/lib.rs b/pallets/market/src/lib.rs index 12f4f1f71..cac075f94 100644 --- a/pallets/market/src/lib.rs +++ b/pallets/market/src/lib.rs @@ -923,25 +923,27 @@ pub mod pallet { >, provider: &T::AccountId, ) -> Result<(), ProposalError> { - Self::validate_signature( - &Encode::encode(&deal.proposal), - &deal.client_signature, - &deal.proposal.client, - )?; + log::trace!(target: LOG_TARGET, "validating signature... {:?}", deal.client_signature); + let encoded = Encode::encode(&deal.proposal); + Self::validate_signature(&encoded, &deal.client_signature, &deal.proposal.client)?; // Ensure the Piece's Cid is parsable and valid + log::trace!(target: LOG_TARGET, "validating cid..."); let _ = deal.proposal.cid()?; + log::trace!(target: LOG_TARGET, "checking if provider is the same across deals"); ensure!( deal.proposal.provider == *provider, ProposalError::DifferentProvider ); + log::trace!(target: LOG_TARGET, "check if deal.start_block < deal.end_block"); ensure!( deal.proposal.start_block < deal.proposal.end_block, ProposalError::DealEndBeforeStart ); + log::trace!(target: LOG_TARGET, "check if deal.state == PUBLISHED"); ensure!( deal.proposal.state == DealState::Published, ProposalError::DealNotPublished @@ -949,6 +951,7 @@ pub mod pallet { let min_dur = T::BlocksPerDay::get() * T::MinDealDuration::get(); let max_dur = T::BlocksPerDay::get() * T::MaxDealDuration::get(); + log::trace!(target: LOG_TARGET, "checking if deal.duration() {:?} <= {:?} <= {:?}", min_dur, deal.proposal.duration(), max_dur); ensure!( deal.proposal.duration() >= min_dur && deal.proposal.duration() <= max_dur, ProposalError::DealDurationOutOfBounds diff --git a/pallets/storage-provider/src/lib.rs b/pallets/storage-provider/src/lib.rs index 4617eabb3..976e1259e 100644 --- a/pallets/storage-provider/src/lib.rs +++ b/pallets/storage-provider/src/lib.rs @@ -221,29 +221,43 @@ pub mod pallet { .map_err(|_| Error::::StorageProviderNotFound)?; let sector_number = sector.sector_number; let current_block = >::block_number(); + + log::trace!( + target: LOG_TARGET, + "checking sector number {sector_number} <= {SECTORS_MAX}", + ); ensure!( sector_number <= SECTORS_MAX.into(), Error::::InvalidSector ); + log::trace!(target: LOG_TARGET, "checking proof type"); ensure!( sp.info.window_post_proof_type == sector.seal_proof.registered_window_post_proof(), Error::::InvalidProofType ); + log::trace!(target: LOG_TARGET, "checking sector number not used"); ensure!( !sp.pre_committed_sectors.contains_key(§or_number) && !sp.sectors.contains_key(§or_number), Error::::SectorNumberAlreadyUsed ); validate_cid::(§or.unsealed_cid[..])?; - let balance = T::Currency::total_balance(&owner); - let deposit = calculate_pre_commit_deposit::(); + Self::validate_expiration( current_block, current_block + T::MaxProveCommitDuration::get(), sector.expiration, )?; + + let balance = T::Currency::total_balance(&owner); + let deposit = calculate_pre_commit_deposit::(); + log::trace!(target: LOG_TARGET, "checking balance {balance:?} >= {deposit:?}"); ensure!(balance >= deposit, Error::::NotEnoughFunds); + + // Reserve deposit from storage provider T::Currency::reserve(&owner, deposit)?; + + // TODO(no-ref,@cernicc,19/07/2024): If mutation fails do we need to explicitly unreserve the deposit? StorageProviders::::try_mutate(&owner, |maybe_sp| -> DispatchResult { let sp = maybe_sp .as_mut() @@ -257,7 +271,10 @@ pub mod pallet { .map_err(|_| Error::::MaxPreCommittedSectorExceeded)?; Ok(()) })?; + + // Notify that the sector has been pre-committed Self::deposit_event(Event::SectorPreCommitted { owner, sector }); + Ok(()) } @@ -268,18 +285,24 @@ pub mod pallet { origin: OriginFor, sector: ProveCommitSector, ) -> DispatchResult { + log::trace!(target: LOG_TARGET, "prove_commit_sector: {:?}", sector); + let owner = ensure_signed(origin)?; - let sp = StorageProviders::::try_get(&owner) - .map_err(|_| Error::::StorageProviderNotFound)?; - let sector_number = sector.sector_number; + let sp = StorageProviders::::try_get(&owner).map_err(|_| { + log::error!(target: LOG_TARGET, "storage provider {owner:?} not found "); + Error::::StorageProviderNotFound + })?; - let precommit = sp - .get_pre_committed_sector(sector_number) - .map_err(|_| Error::::InvalidSector)?; + let sector_number = sector.sector_number; + let precommit = sp.get_pre_committed_sector(sector_number).map_err(|_| { + log::error!(target: LOG_TARGET, "precommitted sector {sector_number} not found "); + Error::::InvalidSector + })?; let current_block = >::block_number(); let prove_commit_due = precommit.pre_commit_block_number + T::MaxProveCommitDuration::get(); + log::trace!(target: LOG_TARGET, "prove_commit_sector: {current_block:?} < {prove_commit_due:?}"); ensure!( current_block < prove_commit_due, Error::::ProveCommitAfterDeadline @@ -311,6 +334,7 @@ pub mod pallet { let deal_amount = sector_deals.len(); T::Market::activate_deals(&owner, sector_deals, deal_amount > 0)?; + // Notify that the sector has been proven Self::deposit_event(Event::SectorProven { owner, sector_number, @@ -327,35 +351,51 @@ pub mod pallet { expiration: BlockNumberFor, ) -> Result<(), Error> { // Expiration must be after activation. Check this explicitly to avoid an underflow below. + log::trace!(target: LOG_TARGET, "validate_expiration: {expiration:?} >= {activation:?}"); ensure!( expiration >= activation, Error::::ExpirationBeforeActivation ); + // expiration cannot be less than minimum after activation + let min_sector_expiration = T::MinSectorExpiration::get(); + log::trace!(target: LOG_TARGET, "validate_expiration: {expiration:?} - {activation:?} > {min_sector_expiration:?}"); ensure!( - expiration - activation > T::MinSectorExpiration::get(), + expiration - activation > min_sector_expiration, Error::::ExpirationTooSoon ); + // expiration cannot exceed MaxSectorExpirationExtension from now + let max_sector_expiration_extension = T::MaxSectorExpirationExtension::get(); + log::trace!(target: LOG_TARGET, "validate_expiration: {expiration:?} < {curr_block:?} + {max_sector_expiration_extension:?}"); ensure!( - expiration < curr_block + T::MaxSectorExpirationExtension::get(), + expiration < curr_block + max_sector_expiration_extension, Error::::ExpirationTooLong, ); + // total sector lifetime cannot exceed SectorMaximumLifetime for the sector's seal proof + let sector_maximum_lifetime = T::SectorMaximumLifetime::get(); + log::trace!(target: LOG_TARGET, "validate_expiration: {expiration:?} - {activation:?} < {sector_maximum_lifetime:?}"); ensure!( - expiration - activation < T::SectorMaximumLifetime::get(), + expiration - activation < sector_maximum_lifetime, Error::::MaxSectorLifetimeExceeded ); + Ok(()) } } // Adapted from filecoin reference here: https://github.com/filecoin-project/builtin-actors/blob/54236ae89880bf4aa89b0dba6d9060c3fd2aacee/actors/miner/src/commd.rs#L51-L56 fn validate_cid(bytes: &[u8]) -> Result<(), Error> { + log::trace!(target: LOG_TARGET, "validating cid: {bytes:?}"); + let c = Cid::try_from(bytes).map_err(|e| { log::error!(target: LOG_TARGET, "failed to validate cid: {:?}", e); Error::::InvalidCid })?; + + log::trace!(target: LOG_TARGET, "cid metadata: {:?}", c); + // these values should be consistent with the cid's created by the SP. // They could change in the future when we make a definitive decision on what hashing algorithm to use and such ensure!( @@ -374,9 +414,10 @@ pub mod pallet { } fn validate_seal_proof( - _seal_proof_type: &RegisteredSealProof, + seal_proof_type: &RegisteredSealProof, proofs: BoundedVec>, ) -> bool { + log::trace!(target: LOG_TARGET, "validate_seal_proof: {seal_proof_type:?} {proofs:?}"); proofs.len() != 0 // TODO(@aidan46, no-ref, 2024-06-24): Actually check proof } } From 4ae18978dc2ff0f082541e352b3a1242545cbb36 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Rok=20=C4=8Cerni=C4=8D?= Date: Fri, 19 Jul 2024 13:20:51 +0200 Subject: [PATCH 2/6] chore: add some more logs --- pallets/market/src/lib.rs | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/pallets/market/src/lib.rs b/pallets/market/src/lib.rs index cac075f94..19ef87419 100644 --- a/pallets/market/src/lib.rs +++ b/pallets/market/src/lib.rs @@ -834,18 +834,25 @@ pub mod pallet { sector_expiry: BlockNumberFor, sector_activation: BlockNumberFor, ) -> Result<(), DealActivationError> { + log::trace!(target: LOG_TARGET, "validate_deal_can_activate: {provider:?} == {:?}", deal.provider); ensure!( *provider == deal.provider, DealActivationError::InvalidProvider ); + + log::trace!(target: LOG_TARGET, "validate_deal_can_activate: {:?} == DealState::Published", deal.state); ensure!( deal.state == DealState::Published, DealActivationError::InvalidDealState ); + + log::trace!(target: LOG_TARGET, "validate_deal_can_activate: {sector_activation:?} <= {:?}", deal.start_block); ensure!( sector_activation <= deal.start_block, DealActivationError::StartBlockElapsed ); + + log::trace!(target: LOG_TARGET, "validate_deal_can_activate: {sector_expiry:?} >= {:?}", deal.end_block); ensure!( sector_expiry >= deal.end_block, DealActivationError::SectorExpiresBeforeDeal From d89669515a8a53e14a5d34ad5302e39e80e9c732 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Rok=20=C4=8Cerni=C4=8D?= Date: Fri, 19 Jul 2024 14:54:18 +0200 Subject: [PATCH 3/6] fix: deal settling --- pallets/market/src/lib.rs | 5 +++-- pallets/storage-provider/src/lib.rs | 1 - 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/pallets/market/src/lib.rs b/pallets/market/src/lib.rs index 19ef87419..8c6e5c0ee 100644 --- a/pallets/market/src/lib.rs +++ b/pallets/market/src/lib.rs @@ -1410,6 +1410,9 @@ pub mod pallet { log::error!(target: LOG_TARGET, "on_finalize: invariant violated, cannot slash the deal {}", deal_id); continue; }; + + // Deal has been processed, no need to process it twice. + Proposals::::remove(&deal_id); } DealState::Active(_) => { log::info!( @@ -1419,8 +1422,6 @@ pub mod pallet { } } - // Deal has been processed, no need to process it twice. - Proposals::::remove(&deal_id); // PRE-COND: all deals in DealsPerBlock are published. // All Published deals are hashed and added to [`PendingProposals`]. let _ = pending_proposals.remove(&Self::hash_proposal(&proposal)); diff --git a/pallets/storage-provider/src/lib.rs b/pallets/storage-provider/src/lib.rs index 976e1259e..12a67ec5e 100644 --- a/pallets/storage-provider/src/lib.rs +++ b/pallets/storage-provider/src/lib.rs @@ -257,7 +257,6 @@ pub mod pallet { // Reserve deposit from storage provider T::Currency::reserve(&owner, deposit)?; - // TODO(no-ref,@cernicc,19/07/2024): If mutation fails do we need to explicitly unreserve the deposit? StorageProviders::::try_mutate(&owner, |maybe_sp| -> DispatchResult { let sp = maybe_sp .as_mut() From 3cb879777973014b5fc22f5388826f1659454bb7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Rok=20=C4=8Cerni=C4=8D?= Date: Fri, 19 Jul 2024 15:13:23 +0200 Subject: [PATCH 4/6] chore: change log --- pallets/storage-provider/src/lib.rs | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) diff --git a/pallets/storage-provider/src/lib.rs b/pallets/storage-provider/src/lib.rs index 12a67ec5e..a04f4b2ff 100644 --- a/pallets/storage-provider/src/lib.rs +++ b/pallets/storage-provider/src/lib.rs @@ -393,15 +393,19 @@ pub mod pallet { Error::::InvalidCid })?; - log::trace!(target: LOG_TARGET, "cid metadata: {:?}", c); + let version = c.version(); + let codec = c.codec(); + let hash = c.hash(); + + log::trace!(target: LOG_TARGET, "cid: version {version:?} codec {codec} hash {hash:?}"); // these values should be consistent with the cid's created by the SP. // They could change in the future when we make a definitive decision on what hashing algorithm to use and such ensure!( - c.version() == Version::V1 - && c.codec() == CID_CODEC // The codec should align with our CID_CODEC value. - && c.hash().code() == BLAKE2B_MULTIHASH_CODE // The CID should be hashed using blake2b - && c.hash().size() == 32, + version == Version::V1 + && codec == CID_CODEC // The codec should align with our CID_CODEC value. + && hash.code() == BLAKE2B_MULTIHASH_CODE // The CID should be hashed using blake2b + && hash.size() == 32, Error::::InvalidCid ); Ok(()) From d46a8183102f6b9280aa58a3bc98bc043ea9ad59 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Rok=20=C4=8Cerni=C4=8D?= Date: Fri, 19 Jul 2024 21:38:48 +0200 Subject: [PATCH 5/6] test: add couple of tests for market on_finalize --- pallets/market/src/lib.rs | 1 - pallets/market/src/test.rs | 98 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 98 insertions(+), 1 deletion(-) diff --git a/pallets/market/src/lib.rs b/pallets/market/src/lib.rs index 8c6e5c0ee..abab345c1 100644 --- a/pallets/market/src/lib.rs +++ b/pallets/market/src/lib.rs @@ -1373,7 +1373,6 @@ pub mod pallet { // this scheduled block. Nothing more to do for this deal. continue; }; - match &proposal.state { DealState::Published => { debug_assert!( diff --git a/pallets/market/src/test.rs b/pallets/market/src/test.rs index b08ab7e7a..d6a1483fc 100644 --- a/pallets/market/src/test.rs +++ b/pallets/market/src/test.rs @@ -1618,6 +1618,104 @@ fn on_sector_terminate_active() { }); } +#[test] +fn on_finalize_hook_activated_deal() { + new_test_ext().execute_with(|| { + let alice_proposal = DealProposalBuilder::::default().signed(ALICE); + let alice_start_block = alice_proposal.proposal.start_block; + let alice_deal_id = 0; + + // Add some balance to the accounts + let _ = Market::add_balance(RuntimeOrigin::signed(account::(ALICE)), 60); + let _ = Market::add_balance(RuntimeOrigin::signed(account::(PROVIDER)), 75); + + // Publish the deal + assert_ok!(Market::publish_storage_deals( + RuntimeOrigin::signed(account::(PROVIDER)), + bounded_vec![alice_proposal] + )); + + // Activate the deal + assert_ok!(Market::activate_deals( + &account::(PROVIDER), + bounded_vec![SectorDeal { + sector_number: 1, + sector_expiry: 200, + sector_type: RegisteredSealProof::StackedDRG2KiBV1P1, + deal_ids: bounded_vec![0] + }], + true, + )); + + // We need to activate the on_finalize hook for the block in which our + // deal should be Activated. + run_to_block(alice_start_block + 1); + + assert!(Proposals::::get(&alice_deal_id).is_some()); + assert!(PendingProposals::::get().is_empty()); + assert!(DealsForBlock::::get(&alice_start_block).is_empty()); + + assert_eq!( + BalanceTable::::get(account::(ALICE)), + BalanceEntry:: { + free: 10, + locked: 50 + } + ); + assert_eq!( + BalanceTable::::get(account::(PROVIDER)), + BalanceEntry:: { + free: 50, + locked: 25 + } + ); + }); +} + +#[test] +fn on_finalize_hook_slash_deal() { + new_test_ext().execute_with(|| { + let alice_proposal = DealProposalBuilder::::default().signed(ALICE); + let alice_start_block = alice_proposal.proposal.start_block; + let alice_deal_id = 0; + + // Add some balance to the accounts + let _ = Market::add_balance(RuntimeOrigin::signed(account::(ALICE)), 60); + let _ = Market::add_balance(RuntimeOrigin::signed(account::(PROVIDER)), 75); + + // Publish the deal + assert_ok!(Market::publish_storage_deals( + RuntimeOrigin::signed(account::(PROVIDER)), + bounded_vec![alice_proposal] + )); + + // We need to activate the on_finalize hook for the block in which our + // deal should be Activated or it's going to be slashed. + run_to_block(alice_start_block + 1); + + assert!(Proposals::::get(&alice_deal_id).is_none()); + assert!(PendingProposals::::get().is_empty()); + assert!(DealsForBlock::::get(&alice_start_block).is_empty()); + + // Deal was slashed, Alice's balance should be unlocked + assert_eq!( + BalanceTable::::get(account::(ALICE)), + BalanceEntry:: { + free: 60, + locked: 0 + } + ); + // Provider's balance should be slashed + assert_eq!( + BalanceTable::::get(account::(PROVIDER)), + BalanceEntry:: { + free: 50, + locked: 0 + } + ); + }); +} + /// Builder with nice defaults for test purposes. struct SectorDealBuilder { sector_number: u64, From f1927f84ab9aef3b39d078692b7ee3360ca25d6b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Rok=20=C4=8Cerni=C4=8D?= Date: Mon, 22 Jul 2024 09:19:54 +0200 Subject: [PATCH 6/6] test: merge tests --- pallets/market/src/test.rs | 104 +++---------------------------------- 1 file changed, 6 insertions(+), 98 deletions(-) diff --git a/pallets/market/src/test.rs b/pallets/market/src/test.rs index d6a1483fc..07cc021f8 100644 --- a/pallets/market/src/test.rs +++ b/pallets/market/src/test.rs @@ -862,6 +862,7 @@ fn verifies_deals_on_block_finalization() { .storage_price_per_block(5) .provider_collateral(25) .signed(ALICE); + let alice_proposal_hash = Market::hash_proposal(&alice_proposal.proposal); let bob_start_block = 130; let bob_deal_id = 1; @@ -872,6 +873,7 @@ fn verifies_deals_on_block_finalization() { .storage_price_per_block(10) .provider_collateral(15) .signed(BOB); + let bob_proposal_hash = Market::hash_proposal(&bob_proposal.proposal); let _ = Market::add_balance(RuntimeOrigin::signed(account::(ALICE)), 60); let _ = Market::add_balance(RuntimeOrigin::signed(account::(BOB)), 70); @@ -903,7 +905,9 @@ fn verifies_deals_on_block_finalization() { ); // After Alice's block, nothing changes to the balance. It has been activated properly. run_to_block(alice_start_block + 1); + assert!(Proposals::::get(&alice_deal_id).is_some()); assert!(!DealsForBlock::::get(&alice_start_block).contains(&alice_deal_id)); + assert!(!PendingProposals::::get().contains(&alice_proposal_hash)); assert_eq!( BalanceTable::::get(account::(ALICE)), BalanceEntry:: { @@ -946,7 +950,9 @@ fn verifies_deals_on_block_finalization() { } ); + assert!(Proposals::::get(&bob_deal_id).is_none()); assert!(!DealsForBlock::::get(&bob_start_block).contains(&bob_deal_id)); + assert!(!PendingProposals::::get().contains(&bob_proposal_hash)); }); } @@ -1618,104 +1624,6 @@ fn on_sector_terminate_active() { }); } -#[test] -fn on_finalize_hook_activated_deal() { - new_test_ext().execute_with(|| { - let alice_proposal = DealProposalBuilder::::default().signed(ALICE); - let alice_start_block = alice_proposal.proposal.start_block; - let alice_deal_id = 0; - - // Add some balance to the accounts - let _ = Market::add_balance(RuntimeOrigin::signed(account::(ALICE)), 60); - let _ = Market::add_balance(RuntimeOrigin::signed(account::(PROVIDER)), 75); - - // Publish the deal - assert_ok!(Market::publish_storage_deals( - RuntimeOrigin::signed(account::(PROVIDER)), - bounded_vec![alice_proposal] - )); - - // Activate the deal - assert_ok!(Market::activate_deals( - &account::(PROVIDER), - bounded_vec![SectorDeal { - sector_number: 1, - sector_expiry: 200, - sector_type: RegisteredSealProof::StackedDRG2KiBV1P1, - deal_ids: bounded_vec![0] - }], - true, - )); - - // We need to activate the on_finalize hook for the block in which our - // deal should be Activated. - run_to_block(alice_start_block + 1); - - assert!(Proposals::::get(&alice_deal_id).is_some()); - assert!(PendingProposals::::get().is_empty()); - assert!(DealsForBlock::::get(&alice_start_block).is_empty()); - - assert_eq!( - BalanceTable::::get(account::(ALICE)), - BalanceEntry:: { - free: 10, - locked: 50 - } - ); - assert_eq!( - BalanceTable::::get(account::(PROVIDER)), - BalanceEntry:: { - free: 50, - locked: 25 - } - ); - }); -} - -#[test] -fn on_finalize_hook_slash_deal() { - new_test_ext().execute_with(|| { - let alice_proposal = DealProposalBuilder::::default().signed(ALICE); - let alice_start_block = alice_proposal.proposal.start_block; - let alice_deal_id = 0; - - // Add some balance to the accounts - let _ = Market::add_balance(RuntimeOrigin::signed(account::(ALICE)), 60); - let _ = Market::add_balance(RuntimeOrigin::signed(account::(PROVIDER)), 75); - - // Publish the deal - assert_ok!(Market::publish_storage_deals( - RuntimeOrigin::signed(account::(PROVIDER)), - bounded_vec![alice_proposal] - )); - - // We need to activate the on_finalize hook for the block in which our - // deal should be Activated or it's going to be slashed. - run_to_block(alice_start_block + 1); - - assert!(Proposals::::get(&alice_deal_id).is_none()); - assert!(PendingProposals::::get().is_empty()); - assert!(DealsForBlock::::get(&alice_start_block).is_empty()); - - // Deal was slashed, Alice's balance should be unlocked - assert_eq!( - BalanceTable::::get(account::(ALICE)), - BalanceEntry:: { - free: 60, - locked: 0 - } - ); - // Provider's balance should be slashed - assert_eq!( - BalanceTable::::get(account::(PROVIDER)), - BalanceEntry:: { - free: 50, - locked: 0 - } - ); - }); -} - /// Builder with nice defaults for test purposes. struct SectorDealBuilder { sector_number: u64,