Fix skipped-target and cache-hit span timing

rust/conduit/src/bep/router.rs

@@ -501,6 +501,16 @@ impl EventRouter {
                         );
                     }
                 }
+                if let Some(BepPayload::Aborted(a)) = &event.payload {
+                    if let Some(mapper) = &mut self.mapper {
+                        mapper.on_target_skipped(
+                            &t.label,
+                            Some(a.reason().as_str_name()),
+                            Some(a.description.as_str()),
+                            event_time_nanos,
+                        );
+                    }
+                }
                 Ok(())
             }
             BepId::TargetCompleted(t) => {
@@ -574,6 +584,7 @@ impl EventRouter {
                         start_time_nanos: start_nanos,
                         // Internal actions (Symlink, ...) carry no times.
                         end_time_nanos: end_nanos.or(event_time_nanos),
+                        event_time_nanos,
                         cached,
                         runner,
                     });
@@ -975,6 +986,54 @@ mod tests {
         assert_eq!(root.end_time, UNIX_EPOCH + Duration::from_secs(105), "no BuildFinished: root ends on the build clock");
     }
 
+    #[test]
+    fn every_skipped_target_gets_one_span() {
+        use crate::build_event_stream::build_event::Payload;
+        use crate::build_event_stream::build_event_id::{ConfiguredLabelId, Id, TargetConfiguredId};
+        use crate::build_event_stream::aborted::AbortReason;
+        use crate::build_event_stream::{Aborted, BuildEvent, BuildEventId, BuildStarted};
+        use crate::otel::span::{Sink, Tracer};
+        use crate::otel::OtelMapper;
+
+        let event = |id: Id, payload: Payload| BuildEvent {
+            id: Some(BuildEventId { id: Some(id) }),
+            payload: Some(payload),
+            ..Default::default()
+        };
+        let aborted = || {
+            Payload::Aborted(Aborted { reason: AbortReason::AnalysisFailure as i32, ..Default::default() })
+        };
+        let configured = |label: &str| {
+            event(Id::TargetConfigured(TargetConfiguredId { label: label.into(), ..Default::default() }), aborted())
+        };
+        let started = event(
+            Id::Started(Default::default()),
+            Payload::Started(BuildStarted { uuid: "u".into(), command: "build".into(), ..Default::default() }),
+        );
+
+        let (sink, spans) = Sink::memory();
+        let mut router = super::EventRouter::new().with_mapper(OtelMapper::new(Tracer::new(sink), None));
+        // Bazel 9 order for an analysis failure and the target that depends on it.
+        for ev in [
+            started,
+            event(Id::ConfiguredLabel(ConfiguredLabelId { label: "//:broken".into(), ..Default::default() }), aborted()),
+            configured("//:broken"),
+            configured("//:needs_broken"),
+        ] {
+            router.route_build_event(&ev, None).unwrap();
+        }
+        router.finish();
+
+        let mut skipped: Vec<String> = spans
+            .snapshot()
+            .into_iter()
+            .map(|s| s.name.to_string())
+            .filter(|n| n.starts_with("target "))
+            .collect();
+        skipped.sort();
+        assert_eq!(skipped, ["target //:broken", "target //:needs_broken"]);
+    }
+
     #[test]
     fn test_status_names() {
         assert_eq!(test_status_name(1), "PASSED");

rust/conduit/src/otel/mapper.rs

@@ -83,6 +83,8 @@ pub struct ActionCompletedEvent {
     pub stderr_path: Option<String>,
     pub start_time_nanos: Option<i64>,
     pub end_time_nanos: Option<i64>,
+    /// When Bazel reported the action in this build.
+    pub event_time_nanos: Option<i64>,
     pub cached: Option<bool>,
     pub runner: Option<String>,
 }
@@ -290,6 +292,9 @@ pub struct OtelMapper {
     /// Created lazily on first skipped target, ended in [`finish`].
     skipped_context: Option<Context>,
 
+    /// Timestamp shared by every skipped target and the `skipped` span.
+    skipped_at: Option<i64>,
+
     /// Cached configurations: config hash → mnemonic (e.g. `k8-fastbuild`).
     configurations: HashMap<String, String>,
 
@@ -433,6 +438,7 @@ impl OtelMapper {
             target_start_nanos: HashMap::new(),
             closed_targets: HashSet::new(),
             skipped_context: None,
+            skipped_at: None,
             configurations: HashMap::new(),
             cached_command: None,
             cached_patterns: Vec::new(),
@@ -638,11 +644,8 @@ impl OtelMapper {
             let mut builder = tracer
                 .span_builder(name)
                 .with_kind(SpanKind::Internal);
-            // Anchor group spans at the invocation start. They are created
-            // lazily on their first child, which can arrive late (e.g. the
-            // first skipped target on an interrupted build); without an
-            // explicit start the span would begin at "now" and a child whose
-            // event time predates creation would fall outside the parent.
+            // Without an explicit start the span would begin at "now", after
+            // its first child's event time when events are processed late.
             if let Some(nanos) = start_nanos {
                 builder = builder.with_start_time(nanos_to_system_time(nanos));
             }
@@ -764,6 +767,7 @@ impl OtelMapper {
         if let Some(cx) = self.skipped_context.take() {
             cx.span().end();
         }
+        self.skipped_at = None;
         for (_, cx) in self.target_contexts.drain() {
             cx.span().end();
         }
@@ -923,10 +927,10 @@ impl OtelMapper {
         }
         self.configured_targets.clear();
 
-        // End the `skipped targets` parent span.
         if let Some(cx) = self.skipped_context.take() {
             cx.span().set_status(Status::Unset);
-            if let Some(nanos) = effective_end {
+            let end = self.skipped_at.take().or(effective_end);
+            if let Some(nanos) = end {
                 cx.span().end_with_timestamp(nanos_to_system_time(nanos));
             } else {
                 cx.span().end();

rust/conduit/src/otel/mapper/actions.rs

@@ -27,7 +27,7 @@ impl OtelMapper {
             self.emit_action(&ev);
             return;
         }
-        let duration_nanos = match (ev.start_time_nanos, ev.end_time_nanos) {
+        let duration_nanos = match self.action_time_range(&ev) {
             (Some(start), Some(end)) => (end - start).max(0),
             _ => 0,
         };
@@ -54,13 +54,35 @@ impl OtelMapper {
             .into_iter()
             .map(|Reverse(b)| b.event)
             .collect();
-        kept.sort_by_key(|ev| ev.start_time_nanos.or(ev.end_time_nanos));
+        kept.sort_by_key(|ev| {
+            let (start, end) = self.action_time_range(ev);
+            start.or(end)
+        });
         for ev in &kept {
             self.emit_action(ev);
         }
         kept.len()
     }
 
+    /// Bazel reports a cache hit with the timing of the run that filled the
+    /// cache. Such an action took no time in this build, so it is placed at
+    /// the moment Bazel reported it. Before Bazel 10 `cached` is unknown, and
+    /// a start before the build is the only sign of a cache hit.
+    fn action_time_range(&self, ev: &ActionCompletedEvent) -> (Option<i64>, Option<i64>) {
+        let cached = ev.cached.unwrap_or_else(|| {
+            matches!(
+                (ev.start_time_nanos, self.root_span_start_nanos),
+                (Some(start), Some(root_start)) if start < root_start
+            )
+        });
+        if cached {
+            let at = ev.event_time_nanos.or(ev.end_time_nanos);
+            (at, at)
+        } else {
+            (ev.start_time_nanos, ev.end_time_nanos)
+        }
+    }
+
     /// Create the `action {mnemonic} {label}` span. With the compact exec log
     /// enabled the span is kept open so arriving spawns can backfill attrs
     /// onto it; without it the span ends here.
@@ -72,9 +94,10 @@ impl OtelMapper {
 
         // Clamp action timing before creating a synthetic target so its
         // lifecycle can use the same child bounds.
+        let (start, end) = self.action_time_range(ev);
         let (clamped_start, clamped_end) = clamp_time_range(
-            ev.start_time_nanos,
-            ev.end_time_nanos,
+            start,
+            end,
             self.root_span_start_nanos,
             self.root_span_end_from_wall_nanos.or(self.finish_time_nanos),
         );

rust/conduit/src/otel/mapper/lifecycle.rs

@@ -3,11 +3,11 @@
 
 use std::collections::HashMap;
 use std::path::PathBuf;
-use tracing::{debug, info, warn};
+use tracing::{info, warn};
 
 use super::super::attributes::*;
 use super::{ExecLogState, OtelMapper};
-use crate::otel::span::{self, Context, KeyValue, SpanContext, SpanId, SpanKind, Status};
+use crate::otel::span::{self, Context, KeyValue, SpanContext, SpanId, SpanKind};
 
 impl OtelMapper {
     /// BuildStarted -> create root span `bazel.invocation`, starting at the
@@ -188,53 +188,6 @@ impl OtelMapper {
         }
     }
 
-    /// UnconfiguredLabel / ConfiguredLabel with Aborted payload ->
-    /// record as a span under the "skipped" parent (root-cause failure).
-    pub fn on_aborted_label(
-        &mut self,
-        label: &str,
-        reason: Option<&str>,
-        description: Option<&str>,
-        event_time_nanos: Option<i64>,
-    ) {
-        Self::ensure_group_span(
-            &mut self.skipped_context,
-            &self.root_context,
-            &self.tracer,
-            "skipped targets",
-            self.root_span_start_nanos,
-        );
-
-        let Some(parent) = &self.skipped_context else {
-            return;
-        };
-
-        let short = shorten_label(label);
-        let mut attrs = vec![
-            KeyValue::new(BAZEL_TARGET_LABEL, label.to_string()),
-            KeyValue::new(BAZEL_TARGET_SUCCESS, false),
-        ];
-        if let Some(r) = reason {
-            attrs.push(KeyValue::new(BAZEL_TARGET_ABORT_REASON, r.to_string()));
-        }
-        if let Some(d) = description {
-            attrs.push(KeyValue::new(BAZEL_TARGET_ABORT_DESCRIPTION, d.to_string()));
-        }
-
-        self.build_and_end_child_span(
-            parent,
-            format!("target {short}"),
-            SpanKind::Internal,
-            attrs,
-            Status::Error {
-                description: std::borrow::Cow::Owned(description.unwrap_or("aborted").to_string()),
-            },
-            None,
-            event_time_nanos,
-        );
-        debug!("Created aborted-label span for {label}");
-    }
-
     /// Configuration -> cache its mnemonic (e.g. `k8-fastbuild`) for actions.
     pub fn on_configuration(&mut self, config_id: &str, mnemonic: &str) {
         if !mnemonic.is_empty() {

rust/conduit/src/otel/mapper/targets.rs

@@ -303,6 +303,11 @@ impl OtelMapper {
         description: Option<&str>,
         event_time_nanos: Option<i64>,
     ) {
+        // Bazel can report one skipped target twice (ConfiguredLabel and
+        // TargetConfigured). Completed targets only close at finish.
+        if self.closed_targets.contains(label) {
+            return;
+        }
         // Consume the configured metadata (if any).
         let configured = self.configured_targets.remove(label);
         // End any open span from target_contexts to avoid leaks.
@@ -312,12 +317,20 @@ impl OtelMapper {
             debug!("Ended leaked target span for {label} on skip");
         }
 
+        let instant = event_time_nanos.or_else(super::wall_clock_now_nanos);
+        let (instant, _) = self.clamp_to_invocation(instant, instant);
+        // Skipped targets take no time, but Bazel reports them both during
+        // analysis and after execution; one shared instant keeps the group
+        // from spanning the build.
+        let instant = self.skipped_at.or(instant);
+        self.skipped_at = instant;
+
         Self::ensure_group_span(
             &mut self.skipped_context,
             &self.root_context,
             &self.tracer,
             "skipped targets",
-            self.root_span_start_nanos,
+            instant,
         );
 
         let parent = match &self.skipped_context {
@@ -342,8 +355,7 @@ impl OtelMapper {
             attrs.push(KeyValue::new(BAZEL_TARGET_ABORT_DESCRIPTION, d.to_string()));
         }
 
-        let (_, clamped_event) = self.clamp_to_invocation(None, event_time_nanos);
-        let instant = clamped_event
+        let instant = instant
             .map(super::nanos_to_system_time)
             .unwrap_or_else(SystemTime::now);