fix: attempt to send one flashblock if payload deadline is in the past

crates/op-rbuilder/src/builders/flashblocks/payload.rs

@@ -411,7 +411,7 @@ where
 
         info!(
             target: "payload_builder",
-            id = fb_payload.payload_id.to_string(),
+            id = %fb_payload.payload_id,
             "Fallback block built"
         );
 
@@ -456,7 +456,7 @@ where
             FlashblockScheduler::new(&self.config.specific, self.config.block_time, timestamp);
         info!(
             target: "payload_builder",
-            payload_id = ?fb_payload.payload_id,
+            id = %fb_payload.payload_id,
             schedule = ?flashblock_scheduler,
             "Computed flashblock timing schedule"
         );
@@ -534,7 +534,7 @@ where
             if let Ok(new_fb_cancel) = rx.recv() {
                 debug!(
                     target: "payload_builder",
-                    id = ?fb_payload.payload_id,
+                    id = %fb_payload.payload_id,
                     flashblock_index = ctx.flashblock_index(),
                     block_number = ctx.block_number(),
                     "Received signal to build flashblock",
@@ -575,10 +575,11 @@ where
                 Err(err) => {
                     error!(
                         target: "payload_builder",
-                        "Failed to build flashblock {} for block number {}: {}",
-                        ctx.flashblock_index(),
-                        ctx.block_number(),
-                        err
+                        id = %fb_payload.payload_id,
+                        flashblock_index = ctx.flashblock_index(),
+                        block_number = ctx.block_number(),
+                        ?err,
+                        "Failed to build flashblock",
                     );
                     return Err(PayloadBuilderError::Other(err.into()));
                 }
@@ -836,9 +837,10 @@ where
         info!(
             target: "payload_builder",
             event = "build_complete",
-            id = ?ctx.payload_id(),
+            id = %ctx.payload_id(),
             flashblocks_per_block = flashblocks_per_block,
             flashblock_index = ctx.flashblock_index(),
+            "Flashblocks building complete"
         );
 
         span.record("flashblock_count", ctx.flashblock_index());
@@ -1075,14 +1077,14 @@ where
     };
     debug!(
         target: "payload_builder",
-        id = ?ctx.payload_id(),
+        id = %ctx.payload_id(),
         "Executed block created"
     );
 
     let sealed_block = Arc::new(block.seal_slow());
     debug!(
         target: "payload_builder",
-        id = ?ctx.payload_id(),
+        id = %ctx.payload_id(),
         ?sealed_block,
         "Sealed built block"
     );

crates/op-rbuilder/src/builders/flashblocks/timing.rs

@@ -123,24 +123,38 @@ impl FlashblockScheduler {
 }
 
 /// Computes the remaining time until the payload deadline. Calculates remaining
-/// time as `payload_timestamp - now`. The result is capped at `block_time` and
-/// falls back to `block_time` if the timestamp is in the past.
+/// time as `payload_timestamp - now`. The result is capped at `block_time`. If
+/// the timestamp is in the past (late FCU), sets remaining time to 0 to try to
+/// emit one flashblock.
 fn compute_remaining_time(
     block_time: Duration,
     payload_timestamp: u64,
     reference_system: std::time::SystemTime,
 ) -> Duration {
     let target_time = std::time::SystemTime::UNIX_EPOCH + Duration::from_secs(payload_timestamp);
 
-    // Calculate remaining time, with fallback to block_time if:
-    // - target_time is in the past (duration_since returns Err)
-    // - remaining time is 0 or negative
     target_time
         .duration_since(reference_system)
         .ok()
         .filter(|duration| duration.as_millis() > 0)
-        .unwrap_or(block_time)
-        .min(block_time)
+        .map(|d| d.min(block_time))
+        .unwrap_or_else(|| {
+            // If we're here then the payload timestamp is in the past. This
+            // happens when the FCU is really late and it also means we're
+            // expecting a getPayload call basically right away, so we don't
+            // have any time to build.
+            let delay_ms = reference_system
+                .duration_since(target_time)
+                .map(|d| d.as_millis())
+                .unwrap_or(0);
+            warn!(
+                target: "payload_builder",
+                payload_timestamp,
+                delay_ms,
+                "Late FCU: payload timestamp is in the past"
+            );
+            Duration::ZERO
+        })
 }
 
 /// Computes the scheduler send time intervals as durations relative to the
@@ -448,26 +462,26 @@ mod tests {
     struct RemainingTimeTestCase {
         name: &'static str,
         block_time_ms: u64,
-        reference_secs: u64,
+        reference_ms: u64,
         payload_timestamp: u64,
         expected_remaining_ms: u64,
     }
 
     fn check_remaining_time(test_case: RemainingTimeTestCase) {
         let block_time = Duration::from_millis(test_case.block_time_ms);
         let reference_system =
-            std::time::SystemTime::UNIX_EPOCH + Duration::from_secs(test_case.reference_secs);
+            std::time::SystemTime::UNIX_EPOCH + Duration::from_millis(test_case.reference_ms);
 
         let remaining =
             compute_remaining_time(block_time, test_case.payload_timestamp, reference_system);
 
         assert_eq!(
             remaining,
             Duration::from_millis(test_case.expected_remaining_ms),
-            "Failed test case '{}': block_time={}ms, reference={}s, timestamp={}",
+            "Failed test case '{}': block_time={}ms, reference={}ms, timestamp={}",
             test_case.name,
             test_case.block_time_ms,
-            test_case.reference_secs,
+            test_case.reference_ms,
             test_case.payload_timestamp,
         );
     }
@@ -478,23 +492,30 @@ mod tests {
             RemainingTimeTestCase {
                 name: "future timestamp within block time",
                 block_time_ms: 2000,
-                reference_secs: 1000,
+                reference_ms: 1_000_000,
                 payload_timestamp: 1002,
                 expected_remaining_ms: 2000,
             },
             RemainingTimeTestCase {
                 name: "remaining exceeds block time (capped)",
                 block_time_ms: 1000,
-                reference_secs: 1000,
+                reference_ms: 1_000_000,
                 payload_timestamp: 1005,
                 expected_remaining_ms: 1000,
             },
             RemainingTimeTestCase {
-                name: "past timestamp (fallback to block time)",
+                name: "late FCU (844ms past timestamp)",
                 block_time_ms: 1000,
-                reference_secs: 1000,
-                payload_timestamp: 999,
-                expected_remaining_ms: 1000,
+                reference_ms: 1_000_844, // 1000.844 seconds
+                payload_timestamp: 1000,
+                expected_remaining_ms: 0,
+            },
+            RemainingTimeTestCase {
+                name: "late FCU (1ms past timestamp)",
+                block_time_ms: 1000,
+                reference_ms: 1_000_001, // 1000.001 seconds
+                payload_timestamp: 1000,
+                expected_remaining_ms: 0,
             },
         ];