[cpu] Add relevant details to event messages (mainly for debugging).

Author: youngman-g

cpu/src/control.rs

@@ -246,46 +246,65 @@ fn test_sequence_flags_current_flag_state() {
     assert_eq!(flags.drain_flag_changes(), vec![u6!(0o52)]);
 }
 
+/// ControlRegisterDiagnostics is only for generating debug
+/// information.  They must not be used for control/execution
+/// purposes.
+#[derive(Debug)]
+pub struct CurrentInstructionDiagnostics {
+    pub current_instruction: Instruction,
+    pub instruction_address: Address,
+}
+
 #[derive(Debug)]
 pub struct ControlRegisters {
+    pub diagnostic_only: CurrentInstructionDiagnostics,
+
     // Arithmetic Element registers (A-E) are actually in V-memory.
+    /// Contents of the simulated N register.
     pub n: Instruction,
     pub n_sym: Option<SymbolicInstruction>,
+
+    /// The P register is the program counter for the current sequence.
     pub p: Address,
+
+    /// Contents of the simulaterd Q register.
     pub q: Address,
 
-    // The k register (User guide 4-3.1) holds the current sequence
-    // number (User guide 5-24).  k is Option<SequenceNumber> in order
-    // to allow the (emulated) control unit to recognise a CODABO
-    // button as indicating a need to change sequence from the control
-    // unit's initial state to sequence 0.
-    //
-    // This likely doesn't reflect the actual operation of the TX-2
-    // very well, and better understanding of the real operation of
-    // the machine will likely change this.
-    //
-    // I think that perhaps section 12-2.6.2 of Volume 2 of the
-    // technical manual may explain how the real TX-2 avoided this
-    // problem, but I don't think I understand what that section says.
-    // The text is:
-    //
-    // """12-2.6.2 XPS FLIP-FLOP LOGIC.  This flip-floop inhibits the
-    // X Memory strobe pulse into X when the register selected has the
-    // same address or the current program counter, is not register 0,
-    // and this is the first reference to this register since the last
-    // sequence change.  In this case all the cores of the register
-    // are clearered and only "junk" (with a 50-50 chance of a bad
-    // parity) would be strobed into X.  If XPS¹, then a clear pulse
-    // is substituted for the strobe pulse.
-    //
-    // The flip-flop is set whenever a sequence change occurs, and is
-    // cleared the first time thereafter that the program counter
-    // register is referenced during a PK cycle (if ever).  See Fig
-    // 12-8."""
+    /// The k register (User guide 4-3.1) holds the current sequence
+    /// number (User guide 5-24).  k is Option<SequenceNumber> in order
+    /// to allow the (emulated) control unit to recognise a CODABO
+    /// button as indicating a need to change sequence from the control
+    /// unit's initial state to sequence 0.
+    ///
+    /// This likely doesn't reflect the actual operation of the TX-2
+    /// very well, and better understanding of the real operation of
+    /// the machine will likely change this.
+    ///
+    /// I think that perhaps section 12-2.6.2 of Volume 2 of the
+    /// technical manual may explain how the real TX-2 avoided this
+    /// problem, but I don't think I understand what that section says.
+    /// The text is:
+    ///
+    /// """12-2.6.2 XPS FLIP-FLOP LOGIC.  This flip-floop inhibits the
+    /// X Memory strobe pulse into X when the register selected has the
+    /// same address or the current program counter, is not register 0,
+    /// and this is the first reference to this register since the last
+    /// sequence change.  In this case all the cores of the register
+    /// are clearered and only "junk" (with a 50-50 chance of a bad
+    /// parity) would be strobed into X.  If XPS¹, then a clear pulse
+    /// is substituted for the strobe pulse.
+    ///
+    /// The flip-flop is set whenever a sequence change occurs, and is
+    /// cleared the first time thereafter that the program counter
+    /// register is referenced during a PK cycle (if ever).  See Fig
+    /// 12-8."""
     pub k: Option<SequenceNumber>,
 
-    spr: Address, // Start Point Register
+    /// Start Point Register
+    spr: Address,
 
+    /// Index registers.
+    ///
     /// Index register 0 is the Toggle Start point.
     /// Index registers 40-77 are program counters for the sequences.
     ///
@@ -294,14 +313,21 @@ pub struct ControlRegisters {
     /// 3-68 of the User Handbook (section 3-3.1) as being signed
     /// integers.
     pub index_regs: [Signed18Bit; 0o100], // AKA the X memory
-    f_memory: [SystemConfiguration; 32], // the F memory
+
+    /// the F memory
+    f_memory: [SystemConfiguration; 32],
+
+    /// The flags; these indicate which sequences are runnable.
     flags: SequenceFlags,
     current_sequence_is_runnable: bool,
+
+    /// prev_hold is set when the instruction we most previously
+    /// executed had the "hold" bit set.
+    prev_hold: bool,
     // TODO: we may be able to eliminate prev_hold by moving the logic
     // that's currently at the beginning of fetch_instruction() so
     // that it occurs at the end of execute_instruction() instead.
     // See the comment at the top of fetch_instruction().
-    prev_hold: bool,
 }
 
 impl ControlRegisters {
@@ -317,6 +343,10 @@ impl ControlRegisters {
         };
 
         let mut result = ControlRegisters {
+            diagnostic_only: CurrentInstructionDiagnostics {
+                current_instruction: Instruction::invalid(),
+                instruction_address: Address::from(u18!(0o777_777)),
+            },
             n: Instruction::invalid(), // not a valid instruction
             n_sym: None,
             p: Address::default(),
@@ -921,6 +951,7 @@ impl ControlUnit {
         // Calculate the address from which we will fetch the
         // instruction, and the increment the program counter.
         let p_physical_address = Address::from(self.regs.p.split().0);
+        self.regs.diagnostic_only.instruction_address = p_physical_address;
         event!(
             Level::TRACE,
             "Fetching instruction from physical address {p_physical_address:>012o}"
@@ -931,7 +962,7 @@ impl ControlUnit {
         } else {
             MetaBitChange::None
         };
-        let instruction_word = match mem.fetch(ctx, &p_physical_address, &meta_op) {
+        let instruction_word: Unsigned36Bit = match mem.fetch(ctx, &p_physical_address, &meta_op) {
             Ok((inst, extra_bits)) => {
                 if extra_bits.meta && self.trap.trap_on_marked_instruction() {
                     self.raise_trap();
@@ -975,6 +1006,10 @@ impl ControlUnit {
                 p_physical_address
             );
         }
+        // Several things update the N register, so we update
+        // `current_instruction` directly here instead of inside
+        // update_n_register().
+        self.regs.diagnostic_only.current_instruction = Instruction::from(instruction_word);
         self.update_n_register(instruction_word)?;
         Ok(())
     }
@@ -1632,8 +1667,8 @@ impl ControlUnit {
         if let Some(current_seq) = self.regs.k {
             event!(
                 Level::DEBUG,
-                "dismissing current sequence (reason: {})",
-                reason
+                "dismissing current sequence {current_seq:o} (reason: {reason}) while executing instruction from {:o}",
+                self.regs.diagnostic_only.instruction_address,
             );
             self.regs.flags.lower(&current_seq);
             self.regs.current_sequence_is_runnable = false;

cpu/src/control/op_io.rs

@@ -162,8 +162,12 @@ impl ControlUnit {
             }
             _ => devices.connect(ctx, regs.k, &unit, mode, alarm_unit)?,
         };
-        if let Some(FlagChange::Raise) = maybe_flag_change {
-            regs.flags.raise(&unit);
+        match maybe_flag_change {
+            Some(FlagChange::Raise(reason)) => {
+                event!(Level::DEBUG, "unit {unit:o} raised its flag: {reason}");
+                regs.flags.raise(&unit);
+            }
+            None => (),
         }
         Ok(())
     }

cpu/src/io.rs

@@ -191,7 +191,7 @@ fn make_unit_report_word(
         report = report | IO_MASK_AVAIL;
     }
     // A unit can raise but not lower its flag.
-    if current_flag || status.change_flag == Some(FlagChange::Raise) {
+    if current_flag || matches!(&status.change_flag, Some(FlagChange::Raise(_))) {
         report = report | IO_MASK_FLAG;
     }
     report | Unsigned36Bit::from(unit).shl(18) | Unsigned36Bit::from(status.special).shl(24)
@@ -456,7 +456,7 @@ impl DeviceManager {
         let (extended_unit_status, flag): (Option<ExtendedConnectedUnitStatus>, bool) =
             if unit.connected {
                 let unit_status = unit.poll(ctx, alarmer)?;
-                let flag: bool = matches!(unit_status.change_flag, Some(FlagChange::Raise));
+                let flag: bool = matches!(unit_status.change_flag, Some(FlagChange::Raise(_)));
                 let ext_status = ExtendedConnectedUnitStatus {
                     buffer_available_to_cpu: unit_status.buffer_available_to_cpu,
                     inability: unit_status.inability,
@@ -609,6 +609,7 @@ impl DeviceManager {
         let mut alarm: Option<Alarm> = None;
         let mut next_poll: Option<Duration> = None;
 
+        event!(Level::DEBUG, "poll_queue is: {:?}", &self.poll_queue);
         loop {
             match self.poll_queue.peek() {
                 None => {
@@ -642,8 +643,8 @@ impl DeviceManager {
                     self.mark_device_changed(devno);
 
                     event!(
-                        Level::TRACE,
-                        "poll: next poll is now due; due={:?}, now={:?}",
+                        Level::DEBUG,
+                        "poll: next poll is now due  for unit {devno:o}; due={:?}, now={:?}",
                         poll_time,
                         system_time
                     );
@@ -673,8 +674,11 @@ impl DeviceManager {
                     let unit_status = attached.poll(ctx, alarm_unit)?;
                     event!(Level::TRACE, "unit {devno:02o} status is {unit_status:?}");
                     self.poll_queue.push(devno, unit_status.poll_after);
-                    if let Some(FlagChange::Raise) = unit_status.change_flag {
-                        event!(Level::DEBUG, "unit {devno:02o} has raised its flag");
+                    if let Some(FlagChange::Raise(reason)) = unit_status.change_flag {
+                        event!(
+                            Level::DEBUG,
+                            "unit {devno:02o} has raised its flag: {reason}"
+                        );
                         raised_flags |= 1 << u8::from(devno);
                     }
                     if alarm.is_none() {
@@ -777,6 +781,10 @@ impl DeviceManager {
         match self.devices.get_mut(device) {
             Some(attached) => {
                 if attached.in_maintenance {
+                    event!(
+                        Level::INFO,
+                        "attempt to connect in-maintenance unit {device:o}, raising IOSAL"
+                    );
                     Err(Alarm {
                         sequence: Some(*device),
                         details: AlarmDetails::IOSAL {
@@ -786,8 +794,18 @@ impl DeviceManager {
                         },
                     })
                 } else {
+                    event!(Level::DEBUG, "connecting unit {device:o}");
+                    // If the unit being connected is an OUTPUT unit,
+                    // and the unit was not already connected, then
+                    // its flag is raised (Users Handbook page 4-7).
                     let flag_change = if attached.is_disconnected_output_unit() {
-                        Some(FlagChange::Raise)
+                        event!(
+                            Level::DEBUG,
+                            "Connecting previously-unconnected output unit {device:o}, so raising its flag"
+                        );
+                        Some(FlagChange::Raise(
+                            "attaching a previously-disconnected output unit",
+                        ))
                     } else {
                         None
                     };
@@ -797,6 +815,10 @@ impl DeviceManager {
                 }
             }
             None => {
+                event!(
+                    Level::WARN,
+                    "attempt to connect nonexistent unit {device:o}"
+                );
                 alarm_unit.fire_if_not_masked(Alarm {
                     sequence: calling_sequence, // NOTE: not the same as *device.
                     details: AlarmDetails::IOSAL {

cpu/src/io/dev_lincoln_writer.rs

@@ -98,7 +98,9 @@ impl Unit for LincolnWriterOutput {
         let change_flag = if !self.connected || transmitting {
             None
         } else {
-            Some(FlagChange::Raise)
+            Some(FlagChange::Raise(
+                "(still or newly) connected and not already transmitting",
+            ))
         };
         event!(
             Level::TRACE,
@@ -414,7 +416,7 @@ impl Unit for LincolnWriterInput {
                     "LW input {:o}: connected and data is ready; raising flag",
                     self.unit
                 );
-                Some(FlagChange::Raise) // data is ready, raise flag
+                Some(FlagChange::Raise("keyboard data is ready")) // data is ready, raise flag
             } else {
                 event!(
                     Level::TRACE,

cpu/src/io/dev_petr.rs

@@ -336,7 +336,7 @@ impl Unit for Petr {
         UnitStatus {
             special: Unsigned12Bit::ZERO,
             change_flag: if data_ready {
-                Some(FlagChange::Raise)
+                Some(FlagChange::Raise("data is ready"))
             } else {
                 None
             },

cpu/src/types.rs

@@ -6,7 +6,7 @@ use base::prelude::*;
 
 #[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)]
 pub enum FlagChange {
-    Raise,
+    Raise(&'static str),
 }
 
 /// A value of which bits 0..width are significant (0 being the least significant bit).