aura/slot_based: Reduce authoring duration of the last produced block

cumulus/client/consensus/aura/src/collators/slot_based/block_builder_task.rs

@@ -399,13 +399,26 @@ where
 				validation_data.max_pov_size * 85 / 100
 			} as usize;
 
-			let adjusted_authoring_duration = match slot_timer.time_until_next_slot() {
-				Ok((duration, _slot)) => std::cmp::min(authoring_duration, duration),
-				Err(_) => authoring_duration,
-			};
-
+			let adjusted_authoring_duration =
+				slot_timer.adjust_authoring_duration(authoring_duration);
 			tracing::debug!(target: crate::LOG_TARGET, duration = ?adjusted_authoring_duration, "Adjusted proposal duration.");
 
+			let Some(adjusted_authoring_duration) = adjusted_authoring_duration else {
+				tracing::debug!(
+					target: crate::LOG_TARGET,
+					unincluded_segment_len = parent.depth,
+					relay_parent = ?relay_parent,
+					relay_parent_num = %relay_parent_header.number(),
+					included_hash = ?included_header_hash,
+					included_num = %included_header.number(),
+					parent = ?parent_hash,
+					slot = ?para_slot.slot,
+					"Not building block due to insufficient authoring duration."
+				);
+
+				continue;
+			};
+
 			let Ok(Some(candidate)) = collator
 				.build_block_and_import(
 					&parent_header,

cumulus/client/consensus/aura/src/collators/slot_based/slot_timer.rs

@@ -37,6 +37,24 @@ use std::{
 /// Defensive mechanism, corresponds to 12 cores at 6 second block time.
 const BLOCK_PRODUCTION_MINIMUM_INTERVAL_MS: Duration = Duration::from_millis(500);
 
+/// Theoretically, the block production is capped at `BLOCK_PRODUCTION_MINIMUM_INTERVAL_MS`.
+/// In practice, there might be slight deviations due to timing inaccuracies and delays.
+///
+/// This constant is taken into account while adjusting the authoring duration to fit into the slot.
+/// Therefore, it will only reduce the authoring duration if we are within the
+/// `BLOCK_PRODUCTION_ADJUSTMENT_MS` threshold of the next slot.
+///
+/// ### 12 cores 500ms blocks
+///
+/// For example, for 12 cores 500ms blocks: the next slot is scheduled in 490ms due to delays.
+/// In that case, we still want to attempt producing the block, as missing the slot would be worse
+/// than producing slightly too fast.
+const BLOCK_PRODUCTION_THRESHOLD_MS: Duration = Duration::from_millis(50);
+
+/// The amount of time the authoring duration of the last block production attempt
+/// should be reduced by to fit into the slot timing.
+const BLOCK_PRODUCTION_ADJUSTMENT_MS: Duration = Duration::from_millis(1000);
+
 #[derive(Debug)]
 pub(crate) struct SlotInfo {
 	pub timestamp: Timestamp,
@@ -46,7 +64,7 @@ pub(crate) struct SlotInfo {
 /// Manages block-production timings based on chain parameters and assigned cores.
 #[derive(Debug)]
 pub(crate) struct SlotTimer<Block, Client, P> {
-	/// Client that is used for runtime calls
+	/// Parachain client that is used for runtime calls
 	client: Arc<Client>,
 	/// Offset the current time by this duration.
 	time_offset: Duration,
@@ -147,7 +165,7 @@ where
 			time_offset,
 			last_reported_core_num: None,
 			relay_slot_duration,
-			last_reported_slot: None,
+			last_reported_slot: Default::default(),
 			_marker: Default::default(),
 		}
 	}
@@ -173,6 +191,115 @@ where
 		))
 	}
 
+	/// Compute the time until the next slot changes.
+	fn compute_time_until_next_slot_change(&mut self) -> Result<(Duration, Slot), ()> {
+		let Ok(slot_duration) = crate::slot_duration(&*self.client) else {
+			tracing::error!(target: LOG_TARGET, "Failed to fetch slot duration from runtime.");
+			return Err(())
+		};
+
+		let now = duration_now();
+		let now = now.as_millis().saturating_sub(self.time_offset.as_millis());
+
+		let last_reported_slot = self.last_reported_slot.unwrap_or_default();
+		let Some(last_slot_timestamp) = last_reported_slot.timestamp(slot_duration) else {
+			tracing::error!(target: LOG_TARGET, "Failed to obtain the last slot timestamp");
+			return Err(())
+		};
+
+		// Compute when the next different slot starts.
+		let next_different_slot_time =
+			last_slot_timestamp.as_millis() + slot_duration.as_millis() as u64;
+		let remaining_millis = next_different_slot_time.saturating_sub(now as u64);
+		let next_aura_slot =
+			Slot::from_timestamp(Timestamp::from(next_different_slot_time as u64), slot_duration);
+
+		Ok((Duration::from_millis(remaining_millis as u64), next_aura_slot))
+	}
+
+	/// Adjust the authoring duration to fit into the slot timing.
+	///
+	/// Returns the adjusted authoring duration and the slot that it corresponds to.
+	pub fn adjust_authoring_duration(
+		&mut self,
+		mut authoring_duration: Duration,
+	) -> Option<Duration> {
+		let Ok((duration, next_slot)) = self.time_until_next_slot() else {
+			tracing::error!(
+				target: LOG_TARGET,
+				"Failed to fetch slot duration from runtime. Using unadjusted authoring duration."
+			);
+			return Some(authoring_duration);
+		};
+
+		let Ok((next_duration_change, next_slot_change)) =
+			self.compute_time_until_next_slot_change()
+		else {
+			tracing::error!(
+				target: LOG_TARGET,
+				"Failed to compute time until next slot change. Using unadjusted authoring duration."
+			);
+			return Some(authoring_duration);
+		};
+
+		// The authoring of blocks must stop 1 second before the slot ends.
+		let deadline = next_duration_change.saturating_sub(BLOCK_PRODUCTION_ADJUSTMENT_MS);
+		tracing::debug!(
+			target: LOG_TARGET,
+			?authoring_duration,
+			?duration,
+			last_reported_slot = ?self.last_reported_slot,
+			?next_slot,
+			?next_duration_change,
+			?next_slot_change,
+			?deadline,
+			"Adjusting authoring duration for slot.",
+		);
+
+		// Ensure no blocks are produced in the last second of the slot,
+		// regardless of authoring duration.
+		if deadline == Duration::ZERO {
+			tracing::debug!(
+				target: LOG_TARGET,
+				?next_duration_change,
+				?next_slot_change,
+				"Not enough time left in the slot to adjust authoring duration. Skipping block production for the slot."
+			);
+
+			return None;
+		}
+
+		// Clamp the authoring duration to fit into the slot deadline.
+		// For most cases, the deadline is farther in the future than the authoring duration.
+		if authoring_duration >= deadline {
+			authoring_duration = deadline;
+
+			// Ensure we are not going below the minimum interval within a reasonable threshold.
+			// For 12 cores, we might have a scenario where the last 3 blocks are skipped:
+			// - Block 10: next slot change in 1.493s:
+			// 	 - After adjusting the deadline: 1.493s - 1s = 0.493s the block could be produced
+			//     without issues.
+			// - Block 11: next slot change in 0.993s - skipped by the deadline
+			// - Block 12: next slot change in 0.493s - skipped by the deadline
+			if authoring_duration <
+				BLOCK_PRODUCTION_MINIMUM_INTERVAL_MS.saturating_sub(BLOCK_PRODUCTION_THRESHOLD_MS)
+			{
+				tracing::debug!(
+					target: LOG_TARGET,
+					?authoring_duration,
+					?next_slot,
+					"Authoring duration is below minimum. Skipping block production for the slot."
+				);
+				return None;
+			}
+		}
+
+		// The `duration` intends to slightly adjust when then block production
+		// attempt happens. This goes slightly below the `BLOCK_PRODUCTION_MINIMUM_INTERVAL_MS`
+		// threshold.
+		Some(authoring_duration.min(duration))
+	}
+
 	/// Returns a future that resolves when the next block production should be attempted.
 	pub async fn wait_until_next_slot(&mut self) -> Result<(), ()> {
 		let Ok(slot_duration) = crate::slot_duration(&*self.client) else {
@@ -210,6 +337,7 @@ where
 		);
 
 		self.last_reported_slot = Some(next_aura_slot);
+
 		Ok(())
 	}
 }

prdoc/pr_10154.prdoc

@@ -0,0 +1,83 @@
+title: 'aura/slot_based: Reduce authoring duration of the last produced block '
+doc:
+- audience: Node Dev
+  description: "This PR reduces the authoring duration of the last parachain produced\
+    \ block. Effectively ensures that the next author has sufficient time to import\
+    \ the previous block.\n\n- Only the last authoring duration is reduced by 500ms\
+    \ (`BLOCK_PRODUCTION_ADJUSTMENT_MS`)\n- The authorizing duration was already capped\
+    \ at a minimum of 500ms (`BLOCK_PRODUCTION_MINIMUM_INTERVAL_MS`)\n- The number\
+    \ of para blocks that the relay chain can fit is inferred by the `relay slot duration\
+    \ / default authoring time`\n- `SlotInfo` is adjusted to account for the number\
+    \ of para blocks produced so far\n- While at it, have added a few extra trace\
+    \ logs\n\n### Testing Done\n\nTested on top of:\n- https://github.com/paritytech/polkadot-sdk/pull/9880\n\
+    \n```\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain] New block production\
+    \ opportunity. slot_duration=SlotDuration(6000) aura_slot=Slot(293621792)\nDEBUG\
+    \ tokio-runtime-worker aura::cumulus: [Parachain] Parachain slot adjusted to relay\
+    \ chain. timestamp=Timestamp(1761730746000) slot=Slot(293621791)\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Going to claim core relay_parent=0xa486a45c3a10e9ade7d4ddefef7615d4b001d47c962013386b95719d8f37aeae\
+    \ core_selector=CoreSelector(0) claim_queue_offset=ClaimQueueOffset(1)\nDEBUG\
+    \ tokio-runtime-worker aura::cumulus: [Parachain] Building block. unincluded_segment_len=0\
+    \ relay_parent=0xa486\u2026aeae relay_parent_num=61 relay_parent_offset=1 included_hash=0x21c3\u2026\
+    ac1b included_num=84 parent=0x21c3\u2026ac1b slot=Slot(293621791)\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Expected to produce for 3 cores but only have 1 slots.\
+    \ Attempting to produce multiple blocks per slot. block_production_interval=2s\n\
+    DEBUG tokio-runtime-worker aura::cumulus: [Parachain] Adjusting authoring duration\
+    \ for slot. blocks_produced_for_slot=1 blocks_produced_per_relay_slot=3 authoring_duration=2s\
+    \ duration=1.99s\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain] Adjusted\
+    \ proposal duration. duration=1.99s\n\n INFO tokio-runtime-worker sc_basic_authorship::basic_authorship:\
+    \ [Parachain] \U0001F381 Prepared block for proposing at 85 (8 ms) hash: 0x7579638578324c2f7b5b9f8af0f2bb1aa238f665db70dfcd1ddcb77475733e28;\
+    \ parent_hash: 0x21c3\u2026ac1b; end: NoMoreTransactions; extrinsics_count: 2\n\
+    \ INFO tokio-runtime-worker substrate: [Parachain] \U0001F195 Imported #85 (0x21c3\u2026\
+    ac1b \u2192 0x183a\u20265b0d)\n\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain]\
+    \ Expected to produce for 3 cores but only have 1 slots. Attempting to produce\
+    \ multiple blocks per slot. block_production_interval=2s\nTRACE tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Determined next block production opportunity. time_until_next_attempt=1.977s\
+    \ aura_slot=Slot(293621792) last_reported=LastReportedSlot { slot: Some(Slot(293621792)),\
+    \ blocks_produced: 1 }\nTRACE tokio-runtime-worker aura::cumulus: [Parachain]\
+    \ Sleeping until the next slot. time_until_next_attempt=1.977s\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] New block production opportunity. slot_duration=SlotDuration(6000)\
+    \ aura_slot=Slot(293621792)\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain]\
+    \ Parachain slot adjusted to relay chain. timestamp=Timestamp(1761730746000) slot=Slot(293621791)\n\
+    DEBUG tokio-runtime-worker aura::cumulus: [Parachain] Going to claim core relay_parent=0xa486a45c3a10e9ade7d4ddefef7615d4b001d47c962013386b95719d8f37aeae\
+    \ core_selector=CoreSelector(1) claim_queue_offset=ClaimQueueOffset(1)\nDEBUG\
+    \ tokio-runtime-worker aura::cumulus: [Parachain] Building block. unincluded_segment_len=1\
+    \ relay_parent=0xa486\u2026aeae relay_parent_num=61 relay_parent_offset=1 included_hash=0x21c3\u2026\
+    ac1b included_num=84 parent=0x183a\u20265b0d slot=Slot(293621791)\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Expected to produce for 3 cores but only have 1 slots.\
+    \ Attempting to produce multiple blocks per slot. block_production_interval=2s\n\
+    DEBUG tokio-runtime-worker aura::cumulus: [Parachain] Adjusting authoring duration\
+    \ for slot. blocks_produced_for_slot=2 blocks_produced_per_relay_slot=3 authoring_duration=2s\
+    \ duration=1.988s\n\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain] Adjusted\
+    \ proposal duration. duration=1.988s\n INFO tokio-runtime-worker sc_basic_authorship::basic_authorship:\
+    \ [Parachain] \U0001F381 Prepared block for proposing at 86 (232 ms) hash: 0x17b4f3fc6f13a8bad577d3e12f026a8c51b37fecd33551beb32e059fc510c941;\
+    \ parent_hash: 0x183a\u20265b0d; end: NoMoreTransactions; extrinsics_count: 2\n\
+    \ INFO tokio-runtime-worker substrate: [Parachain] \U0001F195 Imported #86 (0x183a\u2026\
+    5b0d \u2192 0x9504\u2026a66d)\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain]\
+    \ Expected to produce for 3 cores but only have 1 slots. Attempting to produce\
+    \ multiple blocks per slot. block_production_interval=2s\nTRACE tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Determined next block production opportunity. time_until_next_attempt=1.751s\
+    \ aura_slot=Slot(293621792) last_reported=LastReportedSlot { slot: Some(Slot(293621792)),\
+    \ blocks_produced: 2 }\nTRACE tokio-runtime-worker aura::cumulus: [Parachain]\
+    \ Sleeping until the next slot. time_until_next_attempt=1.751s\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] New block production opportunity. slot_duration=SlotDuration(6000)\
+    \ aura_slot=Slot(293621792)\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain]\
+    \ Parachain slot adjusted to relay chain. timestamp=Timestamp(1761730746000) slot=Slot(293621791)\n\
+    DEBUG tokio-runtime-worker aura::cumulus: [Parachain] Going to claim core relay_parent=0xa486a45c3a10e9ade7d4ddefef7615d4b001d47c962013386b95719d8f37aeae\
+    \ core_selector=CoreSelector(2) claim_queue_offset=ClaimQueueOffset(1)\nDEBUG\
+    \ tokio-runtime-worker aura::cumulus: [Parachain] Building block. unincluded_segment_len=2\
+    \ relay_parent=0xa486\u2026aeae relay_parent_num=61 relay_parent_offset=1 included_hash=0x21c3\u2026\
+    ac1b included_num=84 parent=0x9504\u2026a66d slot=Slot(293621791)\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Expected to produce for 3 cores but only have 1 slots.\
+    \ Attempting to produce multiple blocks per slot. block_production_interval=2s\n\
+    \nDEBUG tokio-runtime-worker aura::cumulus: [Parachain] Adjusting authoring duration\
+    \ for slot. blocks_produced_for_slot=3 blocks_produced_per_relay_slot=3 authoring_duration=2s\
+    \ duration=1.99s\nDEBUG tokio-runtime-worker aura::cumulus: [Parachain] Adjusted\
+    \ the last block production attempt for the slot. aura_slot=Slot(293621793) blocks_produced_for_slot=3\
+    \ blocks_produced_per_relay_slot=3 authoring_duration=1.49s\nDEBUG tokio-runtime-worker\
+    \ aura::cumulus: [Parachain] Adjusted proposal duration. duration=1.49s\n```\n\
+    \n- The first two blocks are adjusted to `duration=1.99s` and `duration=1.988s`\
+    \ respectively\n- The last block is adjusted to `duration=1.49s` (ie reduced by\
+    \ another 500ms)\n\nPart of: https://github.com/paritytech/polkadot-sdk/issues/9848"
+crates:
+- name: cumulus-client-consensus-aura
+  bump: patch