Better identifier and logging for runtime upgrades (paritytech#8123)

* A clean new attempt

* Checkpoint to move remote.

* A lot of dependency wiring to make it feature gated.

* bad macro, bad macro.

* Undo the DB mess.

* Update frame/support/src/traits.rs

Co-authored-by: Alexander Popiak <alexander.popiak@parity.io>

* Apply suggestions from code review

Co-authored-by: Alexander Popiak <alexander.popiak@parity.io>

* unbreak the build

* Better logging and ids for migrations

* Fix doc.

* Test

* Update frame/try-runtime/src/lib.rs

Co-authored-by: Bastian Köcher <bkchr@users.noreply.github.com>

* Update utils/frame/try-runtime/cli/Cargo.toml

Co-authored-by: Shawn Tabrizi <shawntabrizi@gmail.com>

* Update frame/try-runtime/Cargo.toml

Co-authored-by: Shawn Tabrizi <shawntabrizi@gmail.com>

* Address most review grumbles.

* Fix build

* Add some comments

* Remove allowing one pallet at a time.

* Rework the PR

* nit

* Slightly better error handling.

* Remove files

* Update utils/frame/remote-externalities/src/lib.rs

Co-authored-by: Bastian Köcher <bkchr@users.noreply.github.com>

* Update frame/support/src/dispatch.rs

* Update frame/support/src/dispatch.rs

* Fix test

* Make extension trait.

* Bring back try-runtime/std

* remove bincode

* Remove warning

* Change test features

Co-authored-by: Alexander Popiak <alexander.popiak@parity.io>
Co-authored-by: Bastian Köcher <bkchr@users.noreply.github.com>
Co-authored-by: Shawn Tabrizi <shawntabrizi@gmail.com>

bin/node/cli/src/command.rs

@@ -159,7 +159,7 @@ pub fn run() -> Result<()> {
 				let task_manager = sc_service::TaskManager::new(
 					config.task_executor.clone(),
 					registry,
-				).unwrap();
+				).map_err(|e| sc_cli::Error::Service(sc_service::Error::Prometheus(e)))?;
 
 				Ok((cmd.run::<Block, Executor>(config), task_manager))
 			})

frame/support/procedural/src/lib.rs

@@ -17,7 +17,7 @@
 
 //! Proc macro of Support code for the runtime.
 
-#![recursion_limit="512"]
+#![recursion_limit = "512"]
 
 mod storage;
 mod construct_runtime;

frame/support/src/dispatch.rs

@@ -80,27 +80,29 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 /// 		// FRAME pallets.
 /// 		#[weight = 0]
 /// 		fn my_function(origin, var: u64) -> dispatch::DispatchResult {
-///				// Your implementation
-///				Ok(())
+/// 				// Your implementation
+/// 				Ok(())
 /// 		}
 ///
-///			// Public functions are both dispatchable and available to other
+/// 			// Public functions are both dispatchable and available to other
 /// 		// FRAME pallets.
 /// 		#[weight = 0]
-///			pub fn my_public_function(origin) -> dispatch::DispatchResult {
+/// 			pub fn my_public_function(origin) -> dispatch::DispatchResult {
 /// 			// Your implementation
-///				Ok(())
+/// 				Ok(())
+/// 		}
 /// 		}
-///		}
 /// }
 /// # fn main() {}
 /// ```
 ///
 /// The declaration is set with the header where:
 ///
 /// * `Module`: The struct generated by the macro, with type `Config`.
-/// * `Call`: The enum generated for every pallet, which implements [`Callable`](./dispatch/trait.Callable.html).
-/// * `origin`: Alias of `T::Origin`, declared by the [`impl_outer_origin!`](./macro.impl_outer_origin.html) macro.
+/// * `Call`: The enum generated for every pallet, which implements
+///   [`Callable`](./dispatch/trait.Callable.html).
+/// * `origin`: Alias of `T::Origin`, declared by the
+///   [`impl_outer_origin!`](./macro.impl_outer_origin.html) macro.
 /// * `Result`: The expected return type from pallet functions.
 ///
 /// The first parameter of dispatchable functions must always be `origin`.
@@ -119,15 +121,15 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 /// 	pub struct Module<T: Config> for enum Call where origin: T::Origin {
 /// 		#[weight = 0]
 /// 		fn my_long_function(origin) -> dispatch::DispatchResult {
-///				// Your implementation
+/// 				// Your implementation
 /// 			Ok(())
 /// 		}
 ///
 /// 		#[weight = 0]
 /// 		fn my_short_function(origin) {
-///				// Your implementation
+/// 				// Your implementation
+/// 		}
 /// 		}
-///		}
 /// }
 /// # fn main() {}
 /// ```
@@ -184,7 +186,7 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 /// 		#[weight = 0]
 /// 		#[transactional]
 /// 		fn my_short_function(origin) {
-///				// Your implementation
+/// 				// Your implementation
 /// 		}
 /// 	}
 /// }
@@ -203,12 +205,12 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 /// decl_module! {
 /// 	pub struct Module<T: Config> for enum Call where origin: T::Origin {
 /// 		#[weight = 0]
-///			fn my_privileged_function(origin) -> dispatch::DispatchResult {
+/// 			fn my_privileged_function(origin) -> dispatch::DispatchResult {
 /// 			ensure_root(origin)?;
-///				// Your implementation
+/// 				// Your implementation
 /// 			Ok(())
 /// 		}
-///		}
+/// 		}
 /// }
 /// # fn main() {}
 /// ```
@@ -218,15 +220,17 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 /// Attributes on functions are supported, but must be in the order of:
 /// 1. Optional #\[doc\] attribute.
 /// 2. #\[weight\] attribute.
-/// 3. Optional function attributes, for instance #\[transactional\]. Those function attributes will be written
-/// only on the dispatchable functions implemented on `Module`, not on the `Call` enum variant.
+/// 3. Optional function attributes, for instance #\[transactional\]. Those function attributes will
+/// be written only on the dispatchable functions implemented on `Module`, not on the `Call` enum
+/// variant.
 ///
 /// ## Multiple Module Instances Example
 ///
-/// A Substrate module can be built such that multiple instances of the same module can be used within a single
-/// runtime. For example, the [Balances module](../pallet_balances/index.html) can be added multiple times to your
-/// runtime in order to support multiple, independent currencies for your blockchain. Here is an example of how
-/// you would declare such a module using the `decl_module!` macro:
+/// A Substrate module can be built such that multiple instances of the same module can be used
+/// within a single runtime. For example, the [Balances module](../pallet_balances/index.html) can
+/// be added multiple times to your runtime in order to support multiple, independent currencies for
+/// your blockchain. Here is an example of how you would declare such a module using the
+/// `decl_module!` macro:
 ///
 /// ```
 /// # #[macro_use]
@@ -251,10 +255,10 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 ///
 /// ## Where clause
 ///
-/// Besides the default `origin: T::Origin`, you can also pass other bounds to the module declaration.
-/// This where bound will be replicated to all types generated by this macro. The chaining of multiple
-/// trait bounds with `+` is not supported. If multiple bounds for one type are required, it needs to
-/// be split up into multiple bounds.
+/// Besides the default `origin: T::Origin`, you can also pass other bounds to the module
+/// declaration. This where bound will be replicated to all types generated by this macro. The
+/// chaining of multiple trait bounds with `+` is not supported. If multiple bounds for one type are
+/// required, it needs to be split up into multiple bounds.
 ///
 /// ```
 /// # #[macro_use]
@@ -276,16 +280,18 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 /// The following are reserved function signatures:
 ///
 /// * `deposit_event`: Helper function for depositing an [event](https://docs.substrate.dev/docs/event-enum).
-/// The default behavior is to call `deposit_event` from the [System module](../frame_system/index.html).
-/// However, you can write your own implementation for events in your runtime. To use the default behavior,
-/// add `fn deposit_event() = default;` to your `Module`.
+/// The default behavior is to call `deposit_event` from the [System
+/// module](../frame_system/index.html). However, you can write your own implementation for events
+/// in your runtime. To use the default behavior, add `fn deposit_event() = default;` to your
+/// `Module`.
 ///
-/// The following reserved functions also take the block number (with type `T::BlockNumber`) as an optional input:
+/// The following reserved functions also take the block number (with type `T::BlockNumber`) as an
+/// optional input:
 ///
 /// * `on_runtime_upgrade`: Executes at the beginning of a block prior to on_initialize when there
-/// is a runtime upgrade. This allows each module to upgrade its storage before the storage items are used.
-/// As such, **calling other modules must be avoided**!! Using this function will implement the
-/// [`OnRuntimeUpgrade`](../sp_runtime/traits/trait.OnRuntimeUpgrade.html) trait.
+/// is a runtime upgrade. This allows each module to upgrade its storage before the storage items
+/// are used. As such, **calling other modules must be avoided**!! Using this function will
+/// implement the [`OnRuntimeUpgrade`](../sp_runtime/traits/trait.OnRuntimeUpgrade.html) trait.
 /// Function signature must be `fn on_runtime_upgrade() -> frame_support::weights::Weight`.
 ///
 /// * `on_initialize`: Executes at the beginning of a block. Using this function will
@@ -300,11 +306,11 @@ impl<T> Parameter for T where T: Codec + EncodeLike + Clone + Eq + fmt::Debug {}
 ///   * `fn on_finalize(n: BlockNumber) -> frame_support::weights::Weight` or
 ///   * `fn on_finalize() -> frame_support::weights::Weight`
 ///
-/// * `offchain_worker`: Executes at the beginning of a block and produces extrinsics for a future block
-///   upon completion. Using this function will implement the
+/// * `offchain_worker`: Executes at the beginning of a block and produces extrinsics for a future
+///   block upon completion. Using this function will implement the
 ///   [`OffchainWorker`](./traits/trait.OffchainWorker.html) trait.
-/// * `integrity_test`: Executes in a test generated by `construct_runtime`, note it doesn't
-///   execute in an externalities-provided environment. Implement
+/// * `integrity_test`: Executes in a test generated by `construct_runtime`, note it doesn't execute
+///   in an externalities-provided environment. Implement
 ///   [`IntegrityTest`](./trait.IntegrityTest.html) trait.
 #[macro_export]
 macro_rules! decl_module {
@@ -1325,13 +1331,27 @@ macro_rules! decl_module {
 				$crate::sp_tracing::enter_span!($crate::sp_tracing::trace_span!("on_runtime_upgrade"));
 				let result: $return = (|| { $( $impl )* })();
 
-				$crate::crate_to_pallet_version!()
+				let new_storage_version = $crate::crate_to_pallet_version!();
+				new_storage_version
 					.put_into_storage::<<$trait_instance as $system::Config>::PalletInfo, Self>();
 
 				let additional_write = <
 					<$trait_instance as $system::Config>::DbWeight as $crate::traits::Get<_>
 				>::get().writes(1);
 
+				let pallet_name = <<
+					$trait_instance
+					as
+					$system::Config
+				>::PalletInfo as $crate::traits::PalletInfo>::name::<Self>().expect("pallet will have name in the runtime; qed");
+
+				$crate::debug::info!(
+					target: $crate::LOG_TARGET,
+					"⚠️ running migration for {} and setting new storage version to {:?}",
+					pallet_name,
+					new_storage_version,
+				);
+
 				result.saturating_add(additional_write)
 			}
 
@@ -1359,9 +1379,23 @@ macro_rules! decl_module {
 			fn on_runtime_upgrade() -> $crate::dispatch::Weight {
 				$crate::sp_tracing::enter_span!($crate::sp_tracing::trace_span!("on_runtime_upgrade"));
 
-				$crate::crate_to_pallet_version!()
+				let new_storage_version = $crate::crate_to_pallet_version!();
+				new_storage_version
 					.put_into_storage::<<$trait_instance as $system::Config>::PalletInfo, Self>();
 
+				let pallet_name = <<
+					$trait_instance
+					as
+					$system::Config
+				>::PalletInfo as $crate::traits::PalletInfo>::name::<Self>().expect("pallet will have name in the runtime; qed");
+
+				$crate::debug::info!(
+					target: $crate::LOG_TARGET,
+					"✅ no migration for '{}' and setting new storage version to {:?}",
+					pallet_name,
+					new_storage_version,
+				);
+
 				<
 					<$trait_instance as $system::Config>::DbWeight as $crate::traits::Get<_>
 				>::get().writes(1)

frame/support/src/lib.rs

@@ -80,6 +80,9 @@ pub use self::storage::{
 pub use self::dispatch::{Parameter, Callable};
 pub use sp_runtime::{self, ConsensusEngineId, print, traits::Printable};
 
+/// A unified log target for support operations.
+pub const LOG_TARGET: &'static str = "runtime::frame-support";
+
 /// A type that cannot be instantiated.
 #[derive(Debug, PartialEq, Eq, Clone)]
 pub enum Never {}

frame/support/src/traits.rs

@@ -1553,6 +1553,54 @@ pub trait OnGenesis {
 	fn on_genesis() {}
 }
 
+/// Prefix to be used (optionally) for implementing [`OnRuntimeUpgrade::storage_key`].
+#[cfg(feature = "try-runtime")]
+pub const ON_RUNTIME_UPGRADE_PREFIX: &[u8] = b"__ON_RUNTIME_UPGRADE__";
+
+/// Some helper functions for [`OnRuntimeUpgrade`] during `try-runtime` testing.
+#[cfg(feature = "try-runtime")]
+pub trait OnRuntimeUpgradeHelpersExt {
+	/// Generate a storage key unique to this runtime upgrade.
+	///
+	/// This can be used to communicate data from pre-upgrade to post-upgrade state and check
+	/// them. See [`set_temp_storage`] and [`get_temp_storage`].
+	#[cfg(feature = "try-runtime")]
+	fn storage_key(ident: &str) -> [u8; 32] {
+		let prefix = sp_io::hashing::twox_128(ON_RUNTIME_UPGRADE_PREFIX);
+		let ident = sp_io::hashing::twox_128(ident.as_bytes());
+
+		let mut final_key = [0u8; 32];
+		final_key[..16].copy_from_slice(&prefix);
+		final_key[16..].copy_from_slice(&ident);
+
+		final_key
+	}
+
+	/// Get temporary storage data written by [`set_temp_storage`].
+	///
+	/// Returns `None` if either the data is unavailable or un-decodable.
+	///
+	/// A `at` storage identifier must be provided to indicate where the storage is being read from.
+	#[cfg(feature = "try-runtime")]
+	fn get_temp_storage<T: Decode>(at: &str) -> Option<T> {
+		sp_io::storage::get(&Self::storage_key(at))
+			.and_then(|bytes| Decode::decode(&mut &*bytes).ok())
+	}
+
+	/// Write some temporary data to a specific storage that can be read (potentially in
+	/// post-upgrade hook) via [`get_temp_storage`].
+	///
+	/// A `at` storage identifier must be provided to indicate where the storage is being written
+	/// to.
+	#[cfg(feature = "try-runtime")]
+	fn set_temp_storage<T: Encode>(data: T, at: &str) {
+		sp_io::storage::set(&Self::storage_key(at), &data.encode());
+	}
+}
+
+#[cfg(feature = "try-runtime")]
+impl<U: OnRuntimeUpgrade> OnRuntimeUpgradeHelpersExt for U {}
+
 /// The runtime upgrade trait.
 ///
 /// Implementing this lets you express what should happen when the runtime upgrades,

primitives/storage/src/lib.rs

@@ -29,7 +29,7 @@ use codec::{Encode, Decode};
 
 /// Storage key.
 #[derive(PartialEq, Eq, RuntimeDebug)]
-#[cfg_attr(feature = "std", derive(Serialize, Deserialize, Hash, PartialOrd, Ord, Clone))]
+#[cfg_attr(feature = "std", derive(Serialize, Deserialize, Hash, PartialOrd, Ord, Clone, Encode, Decode))]
 pub struct StorageKey(
 	#[cfg_attr(feature = "std", serde(with = "impl_serde::serialize"))] pub Vec<u8>,
 );
@@ -107,7 +107,7 @@ impl PrefixedStorageKey {
 
 /// Storage data associated to a [`StorageKey`].
 #[derive(PartialEq, Eq, RuntimeDebug)]
-#[cfg_attr(feature = "std", derive(Serialize, Deserialize, Hash, PartialOrd, Ord, Clone))]
+#[cfg_attr(feature = "std", derive(Serialize, Deserialize, Hash, PartialOrd, Ord, Clone, Encode, Decode))]
 pub struct StorageData(
 	#[cfg_attr(feature = "std", serde(with="impl_serde::serialize"))]
 	pub Vec<u8>,

utils/frame/remote-externalities/Cargo.toml

@@ -16,12 +16,12 @@ targets = ["x86_64-unknown-linux-gnu"]
 jsonrpc-core-client = { version = "15.1.0", features = ["http"] }
 sc-rpc-api = { version = "0.9.0", path = "../../../client/rpc-api" }
 sc-rpc = { version = "3.0.0", path = "../../../client/rpc" }
-futures = "0.1.29"
+futures = "0.3"
 
 hex-literal = "0.3.1"
 env_logger = "0.8.2"
 log = "0.4.11"
-bincode = "1.3.1"
+codec = { package = "parity-scale-codec", version = "2.0.0" }
 tokio = "0.1.22"
 
 sp-io = { version = "3.0.0", path = "../../../primitives/io" }