diff --git a/frame/message-queue/src/lib.rs b/frame/message-queue/src/lib.rs index 409503d31725a..bed131e5f0669 100644 --- a/frame/message-queue/src/lib.rs +++ b/frame/message-queue/src/lib.rs @@ -961,11 +961,11 @@ impl Pallet { book_state.begin.saturating_inc(); } let next_ready = book_state.ready_neighbours.as_ref().map(|x| x.next.clone()); - if book_state.begin >= book_state.end && total_processed > 0 { + if book_state.begin >= book_state.end { // No longer ready - unknit. if let Some(neighbours) = book_state.ready_neighbours.take() { Self::ready_ring_unknit(&origin, neighbours); - } else { + } else if total_processed > 0 { defensive!("Freshly processed queue must have been ready"); } } diff --git a/frame/message-queue/src/mock.rs b/frame/message-queue/src/mock.rs index 28a599bcf83c6..a0fe0105671e0 100644 --- a/frame/message-queue/src/mock.rs +++ b/frame/message-queue/src/mock.rs @@ -320,3 +320,12 @@ pub fn knit(queue: &MessageOrigin) { pub fn unknit(queue: &MessageOrigin) { super::mock_helpers::unknit::(queue); } + +pub fn num_overweight_enqueued_events() -> u32 { + frame_system::Pallet::::events() + .into_iter() + .filter(|e| { + matches!(e.event, RuntimeEvent::MessageQueue(crate::Event::OverweightEnqueued { .. })) + }) + .count() as u32 +} diff --git a/frame/message-queue/src/mock_helpers.rs b/frame/message-queue/src/mock_helpers.rs index 716a60782ec7f..257691cae4171 100644 --- a/frame/message-queue/src/mock_helpers.rs +++ b/frame/message-queue/src/mock_helpers.rs @@ -74,11 +74,11 @@ where } /// Create a message from the given data. -pub fn msg>(x: &'static str) -> BoundedSlice { +pub fn msg>(x: &str) -> BoundedSlice { BoundedSlice::defensive_truncate_from(x.as_bytes()) } -pub fn vmsg(x: &'static str) -> Vec { +pub fn vmsg(x: &str) -> Vec { x.as_bytes().to_vec() } diff --git a/frame/message-queue/src/tests.rs b/frame/message-queue/src/tests.rs index d3b0555f281f7..15bb905738531 100644 --- a/frame/message-queue/src/tests.rs +++ b/frame/message-queue/src/tests.rs @@ -1083,6 +1083,121 @@ fn execute_overweight_works() { assert_eq!(consumed, Err(ExecuteOverweightError::NotFound)); assert!(QueueChanges::take().is_empty()); assert!(!Pages::::contains_key(origin, 0), "Page is gone"); + // The book should have been unknit from the ready ring. + assert!(!ServiceHead::::exists(), "No ready book"); + }); +} + +#[test] +fn permanently_overweight_book_unknits() { + use MessageOrigin::*; + + new_test_ext::().execute_with(|| { + set_weight("bump_service_head", 1.into_weight()); + set_weight("service_queue_base", 1.into_weight()); + set_weight("service_page_base_completion", 1.into_weight()); + + MessageQueue::enqueue_messages([msg("weight=9")].into_iter(), Here); + + // It is the only ready book. + assert_ring(&[Here]); + // Mark the message as overweight. + assert_eq!(MessageQueue::service_queues(8.into_weight()), 4.into_weight()); + assert_last_event::( + Event::OverweightEnqueued { + hash: ::Hashing::hash(b"weight=9"), + origin: Here, + message_index: 0, + page_index: 0, + } + .into(), + ); + // The book is not ready anymore. + assert_ring(&[]); + assert_eq!(MessagesProcessed::take().len(), 0); + assert_eq!(BookStateFor::::get(Here).message_count, 1); + // Now if we enqueue another message, it will become ready again. + MessageQueue::enqueue_messages([msg("weight=1")].into_iter(), Here); + assert_ring(&[Here]); + assert_eq!(MessageQueue::service_queues(8.into_weight()), 5.into_weight()); + assert_eq!(MessagesProcessed::take().len(), 1); + assert_ring(&[]); + }); +} + +#[test] +fn permanently_overweight_book_unknits_multiple() { + use MessageOrigin::*; + + new_test_ext::().execute_with(|| { + set_weight("bump_service_head", 1.into_weight()); + set_weight("service_queue_base", 1.into_weight()); + set_weight("service_page_base_completion", 1.into_weight()); + + MessageQueue::enqueue_messages( + [msg("weight=1"), msg("weight=9"), msg("weight=9")].into_iter(), + Here, + ); + + assert_ring(&[Here]); + // Process the first message. + assert_eq!(MessageQueue::service_queues(4.into_weight()), 4.into_weight()); + assert_eq!(num_overweight_enqueued_events(), 0); + assert_eq!(MessagesProcessed::take().len(), 1); + + // Book is still ready since it was not marked as overweight yet. + assert_ring(&[Here]); + assert_eq!(MessageQueue::service_queues(8.into_weight()), 5.into_weight()); + assert_eq!(num_overweight_enqueued_events(), 2); + assert_eq!(MessagesProcessed::take().len(), 0); + // Now it is overweight. + assert_ring(&[]); + // Enqueue another message. + MessageQueue::enqueue_messages([msg("weight=1")].into_iter(), Here); + assert_ring(&[Here]); + assert_eq!(MessageQueue::service_queues(4.into_weight()), 4.into_weight()); + assert_eq!(MessagesProcessed::take().len(), 1); + assert_ring(&[]); + }); +} + +/// We don't want empty books in the ready ring, but if they somehow make their way in there, it +/// should not panic. +#[test] +#[cfg(not(debug_assertions))] // Would trigger a defensive failure otherwise. +fn ready_but_empty_does_not_panic() { + use MessageOrigin::*; + + new_test_ext::().execute_with(|| { + BookStateFor::::insert(Here, empty_book::()); + BookStateFor::::insert(There, empty_book::()); + + knit(&Here); + knit(&There); + assert_ring(&[Here, There]); + + assert_eq!(MessageQueue::service_queues(Weight::MAX), 0.into_weight()); + assert_ring(&[]); + }); +} + +/// We don't want permanently books in the ready ring, but if they somehow make their way in there, +/// it should not panic. +#[test] +#[cfg(not(debug_assertions))] // Would trigger a defensive failure otherwise. +fn ready_but_perm_overweight_does_not_panic() { + use MessageOrigin::*; + + new_test_ext::().execute_with(|| { + MessageQueue::enqueue_message(msg("weight=9"), Here); + assert_eq!(MessageQueue::service_queues(8.into_weight()), 0.into_weight()); + assert_ring(&[]); + // Force it back into the ready ring. + knit(&Here); + assert_ring(&[Here]); + assert_eq!(MessageQueue::service_queues(Weight::MAX), 0.into_weight()); + // Unready again. + assert_ring(&[]); }); } diff --git a/frame/message-queue/src/weights.rs b/frame/message-queue/src/weights.rs index d1ccb338e66c3..fd788f2ba4052 100644 --- a/frame/message-queue/src/weights.rs +++ b/frame/message-queue/src/weights.rs @@ -18,7 +18,7 @@ //! Autogenerated weights for pallet_message_queue //! //! THIS FILE WAS AUTO-GENERATED USING THE SUBSTRATE BENCHMARK CLI VERSION 4.0.0-dev -//! DATE: 2023-02-27, STEPS: `50`, REPEAT: `20`, LOW RANGE: `[]`, HIGH RANGE: `[]` +//! DATE: 2023-03-06, STEPS: `50`, REPEAT: `20`, LOW RANGE: `[]`, HIGH RANGE: `[]` //! WORST CASE MAP SIZE: `1000000` //! HOSTNAME: `bm3`, CPU: `Intel(R) Core(TM) i7-7700K CPU @ 4.20GHz` //! EXECUTION: Some(Wasm), WASM-EXECUTION: Compiled, CHAIN: Some("dev"), DB CACHE: 1024 @@ -34,7 +34,7 @@ // --wasm-execution=compiled // --heap-pages=4096 // --json-file=/var/lib/gitlab-runner/builds/zyw4fam_/0/parity/mirrors/substrate/.git/.artifacts/bench.json -// --pallet=pallet_message_queue +// --pallet=pallet-message-queue // --chain=dev // --header=./HEADER-APACHE2 // --output=./frame/message-queue/src/weights.rs @@ -72,9 +72,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `295` // Estimated: `7527` - // Minimum execution time: 12_538 nanoseconds. - Weight::from_parts(12_799_000, 0) - .saturating_add(Weight::from_parts(0, 7527)) + // Minimum execution time: 12_283_000 picoseconds. + Weight::from_parts(12_554_000, 7527) .saturating_add(T::DbWeight::get().reads(3_u64)) .saturating_add(T::DbWeight::get().writes(2_u64)) } @@ -86,9 +85,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `295` // Estimated: `7527` - // Minimum execution time: 11_727 nanoseconds. - Weight::from_parts(12_177_000, 0) - .saturating_add(Weight::from_parts(0, 7527)) + // Minimum execution time: 11_484_000 picoseconds. + Weight::from_parts(11_900_000, 7527) .saturating_add(T::DbWeight::get().reads(3_u64)) .saturating_add(T::DbWeight::get().writes(3_u64)) } @@ -98,9 +96,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `42` // Estimated: `3514` - // Minimum execution time: 4_983 nanoseconds. - Weight::from_parts(5_174_000, 0) - .saturating_add(Weight::from_parts(0, 3514)) + // Minimum execution time: 4_793_000 picoseconds. + Weight::from_parts(4_990_000, 3514) .saturating_add(T::DbWeight::get().reads(1_u64)) .saturating_add(T::DbWeight::get().writes(1_u64)) } @@ -110,9 +107,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `113` // Estimated: `69049` - // Minimum execution time: 6_299 nanoseconds. - Weight::from_parts(6_670_000, 0) - .saturating_add(Weight::from_parts(0, 69049)) + // Minimum execution time: 6_231_000 picoseconds. + Weight::from_parts(6_442_000, 69049) .saturating_add(T::DbWeight::get().reads(1_u64)) .saturating_add(T::DbWeight::get().writes(1_u64)) } @@ -122,9 +118,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `113` // Estimated: `69049` - // Minimum execution time: 6_762 nanoseconds. - Weight::from_parts(7_059_000, 0) - .saturating_add(Weight::from_parts(0, 69049)) + // Minimum execution time: 6_660_000 picoseconds. + Weight::from_parts(6_825_000, 69049) .saturating_add(T::DbWeight::get().reads(1_u64)) .saturating_add(T::DbWeight::get().writes(1_u64)) } @@ -132,9 +127,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `0` // Estimated: `0` - // Minimum execution time: 72_681 nanoseconds. - Weight::from_parts(73_147_000, 0) - .saturating_add(Weight::from_parts(0, 0)) + // Minimum execution time: 72_805_000 picoseconds. + Weight::from_parts(74_650_000, 0) } /// Storage: MessageQueue ServiceHead (r:1 w:1) /// Proof: MessageQueue ServiceHead (max_values: Some(1), max_size: Some(4), added: 499, mode: MaxEncodedLen) @@ -144,9 +138,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `172` // Estimated: `5003` - // Minimum execution time: 7_066 nanoseconds. - Weight::from_parts(7_214_000, 0) - .saturating_add(Weight::from_parts(0, 5003)) + // Minimum execution time: 7_078_000 picoseconds. + Weight::from_parts(7_230_000, 5003) .saturating_add(T::DbWeight::get().reads(2_u64)) .saturating_add(T::DbWeight::get().writes(1_u64)) } @@ -158,9 +151,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `65742` // Estimated: `72563` - // Minimum execution time: 57_778 nanoseconds. - Weight::from_parts(58_778_000, 0) - .saturating_add(Weight::from_parts(0, 72563)) + // Minimum execution time: 56_799_000 picoseconds. + Weight::from_parts(57_634_000, 72563) .saturating_add(T::DbWeight::get().reads(2_u64)) .saturating_add(T::DbWeight::get().writes(2_u64)) } @@ -172,9 +164,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `65742` // Estimated: `72563` - // Minimum execution time: 72_144 nanoseconds. - Weight::from_parts(72_942_000, 0) - .saturating_add(Weight::from_parts(0, 72563)) + // Minimum execution time: 72_290_000 picoseconds. + Weight::from_parts(72_754_000, 72563) .saturating_add(T::DbWeight::get().reads(2_u64)) .saturating_add(T::DbWeight::get().writes(2_u64)) } @@ -186,9 +177,8 @@ impl WeightInfo for SubstrateWeight { // Proof Size summary in bytes: // Measured: `65742` // Estimated: `72563` - // Minimum execution time: 84_890 nanoseconds. - Weight::from_parts(86_073_000, 0) - .saturating_add(Weight::from_parts(0, 72563)) + // Minimum execution time: 84_987_000 picoseconds. + Weight::from_parts(85_562_000, 72563) .saturating_add(T::DbWeight::get().reads(2_u64)) .saturating_add(T::DbWeight::get().writes(2_u64)) } @@ -204,9 +194,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `295` // Estimated: `7527` - // Minimum execution time: 12_538 nanoseconds. - Weight::from_parts(12_799_000, 0) - .saturating_add(Weight::from_parts(0, 7527)) + // Minimum execution time: 12_283_000 picoseconds. + Weight::from_parts(12_554_000, 7527) .saturating_add(RocksDbWeight::get().reads(3_u64)) .saturating_add(RocksDbWeight::get().writes(2_u64)) } @@ -218,9 +207,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `295` // Estimated: `7527` - // Minimum execution time: 11_727 nanoseconds. - Weight::from_parts(12_177_000, 0) - .saturating_add(Weight::from_parts(0, 7527)) + // Minimum execution time: 11_484_000 picoseconds. + Weight::from_parts(11_900_000, 7527) .saturating_add(RocksDbWeight::get().reads(3_u64)) .saturating_add(RocksDbWeight::get().writes(3_u64)) } @@ -230,9 +218,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `42` // Estimated: `3514` - // Minimum execution time: 4_983 nanoseconds. - Weight::from_parts(5_174_000, 0) - .saturating_add(Weight::from_parts(0, 3514)) + // Minimum execution time: 4_793_000 picoseconds. + Weight::from_parts(4_990_000, 3514) .saturating_add(RocksDbWeight::get().reads(1_u64)) .saturating_add(RocksDbWeight::get().writes(1_u64)) } @@ -242,9 +229,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `113` // Estimated: `69049` - // Minimum execution time: 6_299 nanoseconds. - Weight::from_parts(6_670_000, 0) - .saturating_add(Weight::from_parts(0, 69049)) + // Minimum execution time: 6_231_000 picoseconds. + Weight::from_parts(6_442_000, 69049) .saturating_add(RocksDbWeight::get().reads(1_u64)) .saturating_add(RocksDbWeight::get().writes(1_u64)) } @@ -254,9 +240,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `113` // Estimated: `69049` - // Minimum execution time: 6_762 nanoseconds. - Weight::from_parts(7_059_000, 0) - .saturating_add(Weight::from_parts(0, 69049)) + // Minimum execution time: 6_660_000 picoseconds. + Weight::from_parts(6_825_000, 69049) .saturating_add(RocksDbWeight::get().reads(1_u64)) .saturating_add(RocksDbWeight::get().writes(1_u64)) } @@ -264,9 +249,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `0` // Estimated: `0` - // Minimum execution time: 72_681 nanoseconds. - Weight::from_parts(73_147_000, 0) - .saturating_add(Weight::from_parts(0, 0)) + // Minimum execution time: 72_805_000 picoseconds. + Weight::from_parts(74_650_000, 0) } /// Storage: MessageQueue ServiceHead (r:1 w:1) /// Proof: MessageQueue ServiceHead (max_values: Some(1), max_size: Some(4), added: 499, mode: MaxEncodedLen) @@ -276,9 +260,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `172` // Estimated: `5003` - // Minimum execution time: 7_066 nanoseconds. - Weight::from_parts(7_214_000, 0) - .saturating_add(Weight::from_parts(0, 5003)) + // Minimum execution time: 7_078_000 picoseconds. + Weight::from_parts(7_230_000, 5003) .saturating_add(RocksDbWeight::get().reads(2_u64)) .saturating_add(RocksDbWeight::get().writes(1_u64)) } @@ -290,9 +273,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `65742` // Estimated: `72563` - // Minimum execution time: 57_778 nanoseconds. - Weight::from_parts(58_778_000, 0) - .saturating_add(Weight::from_parts(0, 72563)) + // Minimum execution time: 56_799_000 picoseconds. + Weight::from_parts(57_634_000, 72563) .saturating_add(RocksDbWeight::get().reads(2_u64)) .saturating_add(RocksDbWeight::get().writes(2_u64)) } @@ -304,9 +286,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `65742` // Estimated: `72563` - // Minimum execution time: 72_144 nanoseconds. - Weight::from_parts(72_942_000, 0) - .saturating_add(Weight::from_parts(0, 72563)) + // Minimum execution time: 72_290_000 picoseconds. + Weight::from_parts(72_754_000, 72563) .saturating_add(RocksDbWeight::get().reads(2_u64)) .saturating_add(RocksDbWeight::get().writes(2_u64)) } @@ -318,9 +299,8 @@ impl WeightInfo for () { // Proof Size summary in bytes: // Measured: `65742` // Estimated: `72563` - // Minimum execution time: 84_890 nanoseconds. - Weight::from_parts(86_073_000, 0) - .saturating_add(Weight::from_parts(0, 72563)) + // Minimum execution time: 84_987_000 picoseconds. + Weight::from_parts(85_562_000, 72563) .saturating_add(RocksDbWeight::get().reads(2_u64)) .saturating_add(RocksDbWeight::get().writes(2_u64)) }