Improve Latency Counting Error Reports

multiply_add.sus

@@ -495,6 +495,24 @@ module bad_cycle : int a -> int r {
 	r = new_test;
 }
 
+module module_taking_time : int data_in'0 -> int data_out'3 {
+	data_out = data_in;
+}
+
+module bad_cycle2 : int a -> int r {
+	state int test;
+	initial test = 0;
+
+	test = module_taking_time(test+a);
+
+	r = test;
+}
+
+module module_taking_a_lot_of_time : int data_in'0 -> int data_out'300 {
+	data_out = data_in;
+}
+
+
 module good_cycle : int a -> int r {
 	state int test;
 	initial test = 0;

src/flattening/mod.rs

@@ -154,6 +154,11 @@ impl Instruction {
         let Self::SubModule(sm) = self else {panic!("extract_wire on not a SubModule! Found {self:?}")};
         sm
     }
+    #[track_caller]
+    pub fn extract_write(&self) -> &Write {
+        let Self::Write(sm) = self else {panic!("extract_write on not a Write! Found {self:?}")};
+        sm
+    }
 
     pub fn for_each_embedded_type<F : FnMut(&Type, Span)>(&self, f : &mut F) {
         match self {

src/instantiation/latency_algorithm.rs

@@ -1,13 +1,36 @@
 use crate::list_of_lists::ListOfLists;
 
 
+#[derive(Debug, Clone, Copy)]
+pub struct SpecifiedLatency {
+    pub wire : usize,
+    pub latency : i64
+}
+
 #[derive(Debug)]
 pub enum LatencyCountingError {
-    ConflictingSpecifiedLatencies{conflict_path : Vec<usize>, path_latency : i64},
-    NetPositiveLatencyCycle{conflict_path : Vec<usize>, net_positive_latency_amount : i64},
+    ConflictingSpecifiedLatencies{conflict_path : Vec<SpecifiedLatency>},
+    NetPositiveLatencyCycle{conflict_path : Vec<SpecifiedLatency>, net_roundtrip_latency : i64},
     IndeterminablePortLatency{bad_ports : Vec<(usize, i64, i64)>}
 }
 
+fn invert_lc_error(err : LatencyCountingError) -> LatencyCountingError {
+    match err {
+        LatencyCountingError::ConflictingSpecifiedLatencies { conflict_path:_} => {
+            unreachable!("LatencyCountingError::ConflictingSpecifiedLatencies should not appear in backwards exploration, because port conflicts should have been found in the forward pass already");
+            // conflict_path.reverse();
+            // for c in &mut conflict_path {c.latency = -c.latency;}
+            // LatencyCountingError::ConflictingSpecifiedLatencies { conflict_path, path_latency }
+        }
+        LatencyCountingError::NetPositiveLatencyCycle { mut conflict_path, net_roundtrip_latency } => {
+            conflict_path.reverse();
+            for c in &mut conflict_path {c.latency = -c.latency;}
+            LatencyCountingError::NetPositiveLatencyCycle { conflict_path, net_roundtrip_latency } 
+        }
+        other => other
+    }
+}
+
 #[derive(Debug, Clone, Copy)]
 pub struct FanInOut {
     pub other : usize,
@@ -49,11 +72,11 @@ fn count_latency<'d>(is_latency_pinned : &mut [bool], absolute_latency : &mut [i
                 if is_latency_pinned[other] {
                     // Positive latency cycle error detected!
                     return Err(if let Some(conflict_begin) = stack.iter().position(|elem| elem.node_idx == other) {
-                        let conflict_path = stack[conflict_begin..].iter().map(|elem| elem.node_idx).collect();
-                        LatencyCountingError::NetPositiveLatencyCycle { conflict_path, net_positive_latency_amount : to_node_min_latency - absolute_latency[other] }
+                        let conflict_path = stack[conflict_begin..].iter().map(|elem| SpecifiedLatency{wire : elem.node_idx, latency : absolute_latency[elem.node_idx]}).collect();
+                        LatencyCountingError::NetPositiveLatencyCycle { conflict_path, net_roundtrip_latency : to_node_min_latency - absolute_latency[start_node] }
                     } else {
-                        let conflict_path = stack.iter().map(|elem| elem.node_idx).chain(std::iter::once(other)).collect();
-                        LatencyCountingError::ConflictingSpecifiedLatencies { conflict_path, path_latency : to_node_min_latency - absolute_latency[start_node] }
+                        let conflict_path = stack.iter().map(|elem| SpecifiedLatency{wire : elem.node_idx, latency : absolute_latency[elem.node_idx]}).chain(std::iter::once(SpecifiedLatency{wire : other, latency : to_node_min_latency})).collect();
+                        LatencyCountingError::ConflictingSpecifiedLatencies { conflict_path }
                     });
                 } else {
                     absolute_latency[other] = to_node_min_latency;
@@ -78,11 +101,6 @@ fn invert_latency(latencies : &mut [i64]) {
     }
 }
 
-pub struct SpecifiedLatency {
-    pub wire : usize,
-    pub latency : i64
-}
-
 struct PortData {
     wire : usize,
     already_covered : bool,
@@ -212,11 +230,11 @@ pub fn solve_latencies<'d>(fanins : &'d ListOfLists<FanInOut>, fanouts : &'d Lis
     for l in &mut specified_latencies {
         l.latency = -l.latency;
     }
-    found_new_ports |= output_side.init_with_given_latencies(&specified_latencies, &mut input_side, &mut is_latency_pinned, &mut stack)?;
+    found_new_ports |= output_side.init_with_given_latencies(&specified_latencies, &mut input_side, &mut is_latency_pinned, &mut stack).map_err(invert_lc_error)?;
 
     while found_new_ports {
         found_new_ports = input_side.discover_connected_ports(&mut output_side, &mut temporary_buffer, &mut is_latency_pinned, &mut stack)?;
-        found_new_ports |= output_side.discover_connected_ports(&mut input_side, &mut temporary_buffer, &mut is_latency_pinned, &mut stack)?;
+        found_new_ports |= output_side.discover_connected_ports(&mut input_side, &mut temporary_buffer, &mut is_latency_pinned, &mut stack).map_err(invert_lc_error)?;
     }
 
     let mut resulting_forward_latencies = input_side.precomputed_seed_nodes;
@@ -480,7 +498,9 @@ mod tests {
         let should_be_err = solve_latencies_infer_ports(&fanins, vec![SpecifiedLatency{wire: 0, latency : 0}, SpecifiedLatency{wire: 3, latency : 1}]);
 
         println!("{should_be_err:?}");
-        assert!(matches!(should_be_err, Err(LatencyCountingError::ConflictingSpecifiedLatencies{conflict_path: _, path_latency : 2})))
+        let Err(LatencyCountingError::ConflictingSpecifiedLatencies{conflict_path}) = should_be_err else {unreachable!()};
+        let path_latency = conflict_path.last().unwrap().latency - conflict_path.first().unwrap().latency;
+        assert_eq!(path_latency, 2);
     }
 
     #[test]
@@ -498,7 +518,9 @@ mod tests {
 
         let should_be_err = solve_latencies_infer_ports(&fanins, vec![SpecifiedLatency{wire: 1, latency : 0}, SpecifiedLatency{wire: 5, latency : 0}]);
 
-        assert!(matches!(should_be_err, Err(LatencyCountingError::ConflictingSpecifiedLatencies{conflict_path: _, path_latency : 1})))
+        let Err(LatencyCountingError::ConflictingSpecifiedLatencies{conflict_path}) = should_be_err else {unreachable!()};
+        let path_latency = conflict_path.last().unwrap().latency - conflict_path.first().unwrap().latency;
+        assert_eq!(path_latency, 1);
     }
 
     #[test]
@@ -513,11 +535,14 @@ mod tests {
         let should_be_err = solve_latencies_infer_ports(&fanins, vec![SpecifiedLatency{wire: 0, latency : 0}, SpecifiedLatency{wire: 1, latency : 1}]);
         println!("{should_be_err:?}");
 
-        if let Err(LatencyCountingError::ConflictingSpecifiedLatencies{conflict_path, path_latency : 2}) = should_be_err {
-            assert_eq!(conflict_path, [0,2,1])
-        } else {
-            assert!(false);
-        }
+
+        let Err(LatencyCountingError::ConflictingSpecifiedLatencies{conflict_path}) = should_be_err else {unreachable!()};
+        let path_latency = conflict_path.last().unwrap().latency - conflict_path.first().unwrap().latency;
+        assert_eq!(path_latency, 2);
+
+        assert_eq!(conflict_path[0].wire, 0);
+        assert_eq!(conflict_path[1].wire, 2);
+        assert_eq!(conflict_path[2].wire, 1);
     }
 
     #[test]
@@ -551,7 +576,8 @@ mod tests {
 
         let should_be_err = solve_latencies_infer_ports(&fanins, Vec::new());
 
-        assert!(matches!(should_be_err, Err(LatencyCountingError::NetPositiveLatencyCycle{conflict_path: _, net_positive_latency_amount: 1})))
+        let Err(LatencyCountingError::NetPositiveLatencyCycle{conflict_path, net_roundtrip_latency}) = should_be_err else {unreachable!()};
+        assert_eq!(net_roundtrip_latency, 1);
     }
 }
 

src/instantiation/mod.rs

@@ -26,7 +26,7 @@ pub struct ConnectFrom {
     pub num_regs : i64,
     pub from : WireID,
     pub condition : Option<WireID>,
-    pub original_wire : FlatID
+    pub original_connection : FlatID
 }
 
 #[derive(Debug)]
@@ -41,6 +41,18 @@ pub struct MultiplexerSource {
     pub from : ConnectFrom
 }
 
+impl MultiplexerSource {
+    pub fn for_each_source<F : FnMut(WireID)>(&self, mut f : F) {
+        f(self.from.from);
+        for path_elem in &self.path {
+            match path_elem {
+                ConnectToPathElem::MuxArrayWrite { idx_wire } => {f(*idx_wire)}
+                ConnectToPathElem::ConstArrayWrite { idx:_ } => {}
+            }
+        }
+    }
+}
+
 #[derive(Debug)]
 pub enum RealWireDataSource {
     ReadOnly,
@@ -254,7 +266,7 @@ impl<'fl, 'l> InstantiationContext<'fl, 'l> {
         }
         Some(result)
     }
-    fn process_connection(&mut self, conn : &Write, original_wire : FlatID, condition : Option<WireID>) -> Option<()> {
+    fn process_connection(&mut self, conn : &Write, original_connection : FlatID, condition : Option<WireID>) -> Option<()> {
         match conn.write_type {
             WriteType::Connection{num_regs, regs_span : _} => {
                 match &self.generation_state[conn.to.root] {
@@ -268,7 +280,7 @@ impl<'fl, 'l> InstantiationContext<'fl, 'l> {
                             num_regs,
                             from,
                             condition,
-                            original_wire
+                            original_connection
                         };
 
                         self.process_connection_to_wire(&conn.to.path, conn_from, deref_w)?;
@@ -590,10 +602,33 @@ impl<'fl, 'l> InstantiationContext<'fl, 'l> {
             }
             Err(err) => {
                 match err {
-                    LatencyCountingError::NetPositiveLatencyCycle { conflict_path, net_positive_latency_amount } => {
-                        for n in conflict_path {
-                            if let Some(source_location) = self.flattened.instructions[self.wires[WireID::from_hidden_value(n)].original_wire].get_location_of_module_part() {
-                                self.errors.error_basic(source_location, format!("This operation is part of a net-positive latency cycle of {net_positive_latency_amount}"));
+                    LatencyCountingError::NetPositiveLatencyCycle { conflict_path, net_roundtrip_latency } => {
+                        let writes_involved = gather_all_mux_inputs(&self.wires, &conflict_path);
+                        assert!(!writes_involved.is_empty());
+                        let (first_write, later_writes) = writes_involved.split_first().unwrap();
+                        let first_write_desired_latency = first_write.to_latency + net_roundtrip_latency;
+                        let mut path_message = make_path_info_string(later_writes, first_write.to_latency, &first_write.to_wire.name);
+                        write_path_elem_to_string(&mut path_message, &first_write.to_wire.name, first_write_desired_latency, writes_involved.last().unwrap().to_latency);
+                        let unique_write_instructions = filter_unique_write_flats(&writes_involved, &self.flattened.instructions);
+                        let rest_of_message = format!(" part of a net-positive latency cycle of +{net_roundtrip_latency}\n\n{path_message}\nWhich conflicts with the starting latency");
+
+                        let mut did_place_error = false;
+                        for wr in &unique_write_instructions {
+                            match wr.write_type {
+                                WriteType::Connection { num_regs, regs_span } => {
+                                    if num_regs >= 1 {
+                                        did_place_error = true;
+                                        let this_register_plural = if num_regs == 1 {"This register is"} else {"These registers are"};
+                                        self.errors.error_basic(regs_span.unwrap(), format!("{this_register_plural}{rest_of_message}"));
+                                    }
+                                }
+                                WriteType::Initial => {unreachable!("Initial assignment can only be from compile-time constant. Cannot be part of latency loop. ")}
+                            }
+                        }
+                        // Fallback if no register annotations used
+                        if !did_place_error {
+                            for wr in unique_write_instructions {
+                                self.errors.error_basic(wr.to.span, format!("This write is{rest_of_message}"));
                             }
                         }
                     }
@@ -603,20 +638,22 @@ impl<'fl, 'l> InstantiationContext<'fl, 'l> {
                             self.errors.error_basic(Span::new_single_token(port_decl.name_token), format!("Cannot determine port latency. Options are {} and {}\nTry specifying an explicit latency or rework the module to remove this ambiguity", port.1, port.2));
                         }
                     }
-                    LatencyCountingError::ConflictingSpecifiedLatencies { conflict_path, path_latency } => {
-                        let start_wire = &self.wires[WireID::from_hidden_value(*conflict_path.first().unwrap())];
-                        let end_wire = &self.wires[WireID::from_hidden_value(*conflict_path.last().unwrap())];
+                    LatencyCountingError::ConflictingSpecifiedLatencies { conflict_path } => {
+                        let start_wire = &self.wires[WireID::from_hidden_value(conflict_path.first().unwrap().wire)];
+                        let end_wire = &self.wires[WireID::from_hidden_value(conflict_path.last().unwrap().wire)];
                         let start_decl = self.flattened.instructions[start_wire.original_wire].extract_wire_declaration();
                         let end_decl = self.flattened.instructions[end_wire.original_wire].extract_wire_declaration();
                         let end_latency_decl = self.flattened.instructions[end_decl.latency_specifier.unwrap()].extract_wire();
-                        let reason = format!("Conflicting specified latency. The specified latency is {}, but the path from {} (specified at absolute latency {}) is at least {path_latency}", end_wire.absolute_latency, start_decl.name, start_wire.absolute_latency);
+
+
+                        let writes_involved = gather_all_mux_inputs(&self.wires, &conflict_path);
+                        let path_message = make_path_info_string(&writes_involved, start_wire.absolute_latency, &start_wire.name);
+                        //assert!(!writes_involved.is_empty());
+
+                        let end_name = &end_wire.name;
+                        let specified_end_latency = end_wire.absolute_latency;
+                        let reason = format!("Conflicting specified latency\n\n{path_message}\nBut this was specified as {end_name}'{specified_end_latency}");
                         self.errors.error_with_info(end_latency_decl.span, reason, vec![start_decl.make_declared_here(self.errors.file)]);
-                        /*for wire in conflict_path {
-                            let bad_wire = &self.wires[WireID::from_hidden_value(wire.0)];
-                            let decl = self.flattened.instructions[bad_wire.original_wire].extract_wire_declaration();
-                            let latency_decl = self.flattened.instructions[decl.latency_specifier.unwrap()].extract_wire();
-                            
-                        }*/
                     }
                 }
                 None
@@ -683,6 +720,76 @@ impl<'fl, 'l> InstantiationContext<'fl, 'l> {
 }
 
 
+struct PathMuxSource<'s> {
+    to_wire : &'s RealWire,
+    to_latency : i64,
+    mux_input : &'s MultiplexerSource
+}
+fn gather_all_mux_inputs<'w>(wires : &'w FlatAlloc<RealWire, WireIDMarker>, conflict_iter : &[SpecifiedLatency]) -> Vec<PathMuxSource<'w>> {
+    let mut connection_list = Vec::new();
+    for window in conflict_iter.windows(2) {
+        let [from, to] = window else {unreachable!()};
+        let from_wire_id = WireID::from_hidden_value(from.wire);
+        //let from_wire = &self.wires[from_wire_id];
+        let to_wire_id = WireID::from_hidden_value(to.wire);
+        let to_wire = &wires[to_wire_id];
+        let RealWireDataSource::Multiplexer { is_state:_, sources } = &to_wire.source else {continue}; // We can only name multiplexers
+
+        //let decl_id = to_wire.original_wire;
+        //let Instruction::Declaration(decl) = &self.flattened.instructions[decl_id] else {unreachable!()};
+
+        for s in sources {
+            let mut predecessor_found = false;
+            s.for_each_source(|source| {
+                if source == from_wire_id {
+                    predecessor_found = true;
+                }
+            });
+            if predecessor_found {
+                connection_list.push(PathMuxSource{to_wire, mux_input : s, to_latency : to.latency});
+            }
+        }
+    }
+    connection_list
+}
+
+fn write_path_elem_to_string(result : &mut String, decl_name : &str, to_absolute_latency : i64, prev_absolute_latency : i64) {
+    use std::fmt::Write;
+
+    let delta_latency = to_absolute_latency - prev_absolute_latency;
+
+    let plus_sign = if delta_latency >= 0 {"+"} else {""};
+
+    writeln!(result, "-> {decl_name}'{to_absolute_latency} ({plus_sign}{delta_latency})").unwrap();
+}
+fn make_path_info_string(writes : &[PathMuxSource<'_>], from_latency : i64, from_name : &str) -> String {
+   let mut prev_decl_absolute_latency = from_latency;
+    let mut result = format!("{from_name}'{prev_decl_absolute_latency}\n");
+
+    for wr in writes {
+        let decl_name = &wr.to_wire.name;
+
+        let to_absolute_latency = wr.to_latency;
+
+        write_path_elem_to_string(&mut result, &decl_name, to_absolute_latency, prev_decl_absolute_latency);
+
+        prev_decl_absolute_latency = to_absolute_latency;
+    }
+
+    result
+}
+
+fn filter_unique_write_flats<'w>(writes : &'w [PathMuxSource<'w>], instructions : &'w FlatAlloc<Instruction, FlatIDMarker>) -> Vec<&'w crate::flattening::Write> {
+    let mut result : Vec<&'w crate::flattening::Write> = Vec::new();
+    for w in writes {
+        let original_write = instructions[w.mux_input.from.original_connection].extract_write();
+
+        if !result.iter().any(|found_write| std::ptr::eq(*found_write, original_write)) {result.push(original_write)}
+    }
+    result
+}
+
+
 
 #[derive(Debug)]
 pub struct InstantiationList {