From 17ae06272b366cbeb9429e01a3bf70d30a885a6f Mon Sep 17 00:00:00 2001
From: Guillaume Thiolliere <gui.thiolliere@gmail.com>
Date: Sun, 26 Jan 2025 06:32:45 +0900
Subject: [PATCH] Improve debugging by using `#[track_caller]` in system
`assert_last_event` and `assert_has_event` (#7142)
Without track caller the error message of the assert points to the
`assert_last_event` function, which is not useful.
```
thread 'tests::set_metadata_works' panicked at /home/gui/Developpement/polkadot-sdk/substrate/frame/system/src/lib.rs:2034:9:
assertion `left == right` failed: expected event RuntimeEvent::Referenda(Event::MetadataSet { index: 0, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa }) is not equal to the last event RuntimeEvent::Referenda(Event::MetadataSet { index: 1, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa })
left: RuntimeEvent::Referenda(Event::MetadataSet { index: 1, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa })
right: RuntimeEvent::Referenda(Event::MetadataSet { index: 0, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa })
```
With the track caller the error message points to the caller, showing
the source of the error:
```
thread 'tests::set_metadata_works' panicked at substrate/frame/referenda/src/tests.rs:639:9:
assertion `left == right` failed: expected event RuntimeEvent::Referenda(Event::MetadataSet { index: 0, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa }) is not equal to the last event RuntimeEvent::Referenda(Event::MetadataSet { index: 1, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa })
left: RuntimeEvent::Referenda(Event::MetadataSet { index: 1, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa })
right: RuntimeEvent::Referenda(Event::MetadataSet { index: 0, hash: 0xbb30a42c1e62f0afda5f0a4e8a562f7a13a24cea00ee81917b86b89e801314aa })
```
I also improved the error message to include a warning when checking
events on block number zero.
---
substrate/frame/system/src/lib.rs | 24 +++++++++++++++++++++---
1 file changed, 21 insertions(+), 3 deletions(-)
diff --git a/substrate/frame/system/src/lib.rs b/substrate/frame/system/src/lib.rs
index f2bb5e290c9..8980c6d6c8f 100644
--- a/substrate/frame/system/src/lib.rs
+++ b/substrate/frame/system/src/lib.rs
@@ -2062,11 +2062,18 @@ impl<T: Config> Pallet<T> {
///
/// NOTE: Events not registered at the genesis block and quietly omitted.
#[cfg(any(feature = "std", feature = "runtime-benchmarks", test))]
+ #[track_caller]
pub fn assert_has_event(event: T::RuntimeEvent) {
+ let warn = if Self::block_number().is_zero() {
+ "WARNING: block number is zero, and events are not registered at block number zero.\n"
+ } else {
+ ""
+ };
+
let events = Self::events();
assert!(
events.iter().any(|record| record.event == event),
- "expected event {event:?} not found in events {events:?}",
+ "{warn}expected event {event:?} not found in events {events:?}",
);
}
@@ -2074,11 +2081,22 @@ impl<T: Config> Pallet<T> {
///
/// NOTE: Events not registered at the genesis block and quietly omitted.
#[cfg(any(feature = "std", feature = "runtime-benchmarks", test))]
+ #[track_caller]
pub fn assert_last_event(event: T::RuntimeEvent) {
- let last_event = Self::events().last().expect("events expected").event.clone();
+ let warn = if Self::block_number().is_zero() {
+ "WARNING: block number is zero, and events are not registered at block number zero.\n"
+ } else {
+ ""
+ };
+
+ let last_event = Self::events()
+ .last()
+ .expect(&alloc::format!("{warn}events expected"))
+ .event
+ .clone();
assert_eq!(
last_event, event,
- "expected event {event:?} is not equal to the last event {last_event:?}",
+ "{warn}expected event {event:?} is not equal to the last event {last_event:?}",
);
}
--
GitLab