From acbb734ad98fb718516c6e4bb604557d7229c4e7 Mon Sep 17 00:00:00 2001 From: vanminhpe Date: Mon, 28 Sep 2026 16:09:26 +0800 Subject: [PATCH] trigger OVP while RCU moving --- BE-RCU-ovp_test_csv.py | 309 +++++++++++++++++++++++++++++++++++++---- 1 file changed, 284 insertions(+), 25 deletions(-) diff --git a/BE-RCU-ovp_test_csv.py b/BE-RCU-ovp_test_csv.py index 6ccdc7b..f60ce68 100644 --- a/BE-RCU-ovp_test_csv.py +++ b/BE-RCU-ovp_test_csv.py @@ -15,27 +15,33 @@ answers nothing. So the relay is closed and given RELAY_SETTLE_S to boot the RCU before any RCU access anywhere in this script - the link test included - and while the relay is open the RCU telemetry columns are left blank. -Per cycle: - 1. Relay control = 1, then wait RELAY_SETTLE_S for the RCU to power up. +Two scenarios, picked with --scenario. Both establish charging and then cut +the relay; they differ only in when the cut lands. + + static (default), jig optional: + 1. Relay control = 1, wait RELAY_SETTLE_S for the RCU to power up. 2. Jig -> NEAR_POSITION, settle. - 3. RCU charging cmd = 1, then wait for RCU main_state == CHARGING(5) and - output current above the threshold held continuously for the dwell. - Abort the cycle on timeout. + 3. RCU charging cmd = 1, wait for RCU main_state == CHARGING(5) and output + current above the threshold held continuously for the dwell. 4. Relay control = 0 (this also cuts RCU power). 5. Jig -> FAR_POSITION, keep monitoring for FAR_OBSERVE_S. - 6. RCU charging cmd = 0 (best-effort; the RCU is unpowered by now), - settle, next cycle. + 6. RCU charging cmd = 0, settle, next cycle. -A background monitor thread samples RCU and TPU input registers every 5 s for -the whole run (all cycles, including the aborted ones) and appends each sample -to the CSV. + move, jig required - the cut lands while the coupling is still changing: + 1-3. As above, but parked at (0, 0, --move-from). + 4. Jig -> (0, 0, --move-to), relay cut at half the travel time. + 5. RCU charging cmd = 0, settle. + 6. Jig back to (0, 0, --move-from), last, so the whole post-cut window is + observed at a standstill. + +A background monitor thread samples RCU and TPU input registers every +MONITOR_INTERVAL_S for the whole run and appends each sample to the CSV. Usage: - # check the wiring: read registers from all four ports, then exit python BE-RCU-ovp_test_csv.py -r COM4 -t COM10 -l COM13 -j COM9 --link-test - - # run the test (the link test also runs as a pre-flight check) - python BE-RCU-ovp_test_csv.py -r COM4 -t COM10 -l COM13 -j COM9 -n 1 + python BE-RCU-ovp_test_csv.py -r COM4 -t COM10 -l COM13 -n 1 + python BE-RCU-ovp_test_csv.py -r COM4 -t COM10 -l COM13 -j COM9 \ + --scenario move --move-from 20 --move-to 0 -n 1 """ import argparse @@ -131,12 +137,20 @@ FAR_POSITION = (30, 0, 20) # (x, y, z) mm - move-away position JIG_SETTLE_S = 5.0 # after the near move, before the relay CHARGING_TIMEOUT_S = 60.0 # max wait for the charging criteria -CHARGING_DWELL_S = 30.0 # current must stay above threshold this long +CHARGING_DWELL_S = 10.0 # current must stay above threshold this long CHARGING_CURRENT_THRESHOLD_A = 3.0 FAR_OBSERVE_S = 15.0 # keep monitoring after the move-away CYCLE_GAP_S = 5.0 # after charging cmd = 0 MONITOR_INTERVAL_S = 2.0 # telemetry sampling / CSV row period -RELAY_SETTLE_S = 10.0 # time to wait for relay to settle +RELAY_SETTLE_S = 2.0 # time to wait for relay to settle + +# --- Scenario "move": cut the relay midway through a jig move -------------- +MOVE_X_MM = 0 # held for the whole scenario; only Z moves +MOVE_Y_MM = 0 +MOVE_Z_FROM_MM = 20 # where the move starts - the charging spot +MOVE_Z_TO_MM = 0 # where it ends +JIG_SPEED_MM_S = 10.0 # override with --jig-speed +JIG_MOVE_MAX_S = 5.0 # time allowed for one move, in or out RESULTS_DIR = "results" @@ -297,8 +311,15 @@ class RCU(Device): self.write_coil(RCU_CHARGING_CMD_ADDRESS, enable) def read_data(self): + # Probe once: a dead RCU costs 9 x SERIAL_TIMEOUT otherwise. + try: + main_pre_state = self.read_u16(RCU_MAIN_PRE_STATE_ADDRESS) + except Exception as exc: + logger.debug("RCU did not answer: %s", exc) + return dict(BLANK_RCU_DATA) + return { - 'main_pre_state': _safe(self.read_u16, RCU_MAIN_PRE_STATE_ADDRESS), + 'main_pre_state': main_pre_state, 'main_state': _safe(self.read_u16, RCU_MAIN_STATE_ADDRESS), 'output_current': _q128( _safe(self.read_u16, RCU_OUTPUT_CURRENT_ADDRESS)), @@ -378,11 +399,13 @@ class Jig(Device): super().__init__(port, "JIG") def move_to(self, x, y, z): + """Command a move. Returns the perf_counter() of the go command.""" logger.info("JIG move to (%d, %d, %d) mm", x, y, z) self.write_holding(JIG_X_ADDRESS, x) self.write_holding(JIG_Y_ADDRESS, y) self.write_holding(JIG_Z_ADDRESS, z) self.write_coil(JIG_CMD_ADDRESS, True) + return time.perf_counter() # --------------------------------------------------------------------------- @@ -599,6 +622,28 @@ class Monitor(threading.Thread): with self._state_lock: return dict(self._latest) + def write_event(self, phase, note): + """Append one row now, telemetry blank. set_context() only paints the + next periodic sample, which is too late to record an instant.""" + with self._state_lock: + cycle = self._cycle + jig_x, jig_y, jig_z = self._jig + relay_cmd, charging_cmd = self._relay_cmd, self._charging_cmd + powered = self._rcu_powered + + blank = dict(BLANK_RCU_DATA) + self.recorder.write([ + datetime.datetime.now().strftime("%Y-%m-%d %H:%M:%S.%f")[:-3], + round(time.time() - self.t0, 1), cycle, phase, + jig_x, jig_y, jig_z, relay_cmd, charging_cmd, int(powered), + blank['main_pre_state'], blank['main_state'], + blank['output_current'], blank['output_voltage'], + blank['dc_bus_voltage'], blank['error_code'], + blank['shadow_error'], + None, None, None, None, None, '', '', '', + None, 0.0, note, + ]) + def stop(self): self._stop.set() @@ -675,8 +720,30 @@ def _wait(seconds, stop_when=None, poll=0.2): return False +def _cut_relay(relay, retry=True): + """Open the relay, tolerating one lost frame. Returns True if it landed.""" + try: + relay.set_control(False) + return True + except Exception as exc: + logger.warning("Relay cut not acknowledged: %s", exc) + if not retry: + return False + + try: + relay.set_control(False) + logger.info("Relay cut acknowledged on retry.") + return True + except Exception as exc: + logger.error("Relay cut failed twice: %s", exc) + return False + + def run_cycle(cycle, rcu, relay, jig, monitor, cfg): - """Run one OVP cycle. Returns 'PASS' or 'TIMEOUT'.""" + """Run one OVP cycle with the jig standing still. + + Returns 'PASS', 'TIMEOUT' or 'CUT_FAILED'. + """ logger.info("=" * 62) logger.info("CYCLE %d/%d", cycle, cfg['cycles']) @@ -726,8 +793,10 @@ def run_cycle(cycle, rcu, relay, jig, monitor, cfg): # Step 4: open the relay. This also cuts the RCU's power, so from here on # the RCU is dead and its telemetry columns stay blank. - relay.set_control(False) - monitor.set_context(phase="relay_off", relay_cmd=0, rcu_powered=False) + if not _cut_relay(relay): + result = "CUT_FAILED" + monitor.set_context(phase="relay_off", relay_cmd=0, rcu_powered=False, + note=result) # Step 5: move away, keep monitoring. Without a jig there is nothing to # move, so this becomes a plain observation window after the relay opens. @@ -754,6 +823,123 @@ def run_cycle(cycle, rcu, relay, jig, monitor, cfg): return result +def move_timing(cfg): + """(distance_mm, travel_s, trigger_s). --trigger-at only pulls it earlier.""" + distance = abs(cfg['move_from'] - cfg['move_to']) + travel = distance / cfg['jig_speed'] + trigger = travel / 2.0 + if cfg.get('trigger_at') is not None: + trigger = min(trigger, cfg['trigger_at']) + return distance, travel, trigger + + +def run_cycle_move(cycle, rcu, relay, jig, monitor, cfg): + """One OVP cycle with the relay cut midway through a jig move. + + Returns 'PASS', 'TIMEOUT' or 'CUT_FAILED'. + """ + distance, travel_s, trigger_s = move_timing(cfg) + home = (cfg['move_x'], cfg['move_y'], cfg['move_from']) + target = (cfg['move_x'], cfg['move_y'], cfg['move_to']) + + logger.info("=" * 62) + logger.info("CYCLE %d/%d (move scenario)", cycle, cfg['cycles']) + + # Step 1: close the relay and let the RCU boot. + monitor.set_context(cycle=cycle, phase="relay_on", relay_cmd=1, note="") + power_up_rcu(relay) + monitor.set_context(rcu_powered=True) + + # Step 2: park at the charging position. + monitor.set_context(phase="jig_home", jig=home) + jig.move_to(*home) + _wait(JIG_MOVE_MAX_S) + + # Step 3: charge, and wait for it to be established - the cut means + # nothing until then. + monitor.reset_dwell() + monitor.set_context(phase="charging", charging_cmd=1) + rcu.set_charging(True) + + logger.info( + "Waiting for RCU main_state=%d and output current > %.1f A held for " + "%.0fs (timeout %.0fs)...", + RCU_STATE_CHARGING, cfg['current_threshold'], cfg['dwell'], + cfg['timeout']) + + met = _wait(cfg['timeout'], + stop_when=lambda: monitor.dwell_seconds() >= cfg['dwell']) + result = "PASS" if met else "TIMEOUT" + + if met: + logger.info("Cycle %d: criteria met after %.1fs of dwell.", + cycle, monitor.dwell_seconds()) + else: + latest = monitor.latest().get('rcu', {}) + logger.warning( + "Cycle %d: TIMEOUT after %.0fs (last RCU state=%s, current=%s A).", + cycle, cfg['timeout'], latest.get('main_state'), + latest.get('output_current')) + + monitor.set_context(note=result) + + # Step 4: the move, with the relay cut partway through it. + logger.info("Moving %d mm (%.2fs), cutting relay at %.2fs", + distance, travel_s, trigger_s) + monitor.set_context(phase="jig_move", jig=target) + t_go = jig.move_to(*target) + + # Sleep straight through, not via _wait(): its 0.2s poll is far too coarse + # for a sub-second target. + remaining = (t_go + trigger_s) - time.perf_counter() + if remaining > 0: + time.sleep(remaining) + + # write_coil, not set_control(): that helper logs before it writes, and a + # Windows console write blocks while text is selected in the terminal - + # which here would swallow the cut itself. Log afterwards. + try: + relay.write_coil(RELAY_CONTROL_CMD_ADDRESS, False) + achieved = time.perf_counter() - t_go + cut_ok = True + except Exception as exc: + achieved = time.perf_counter() - t_go + logger.warning("Relay cut not acknowledged at %.3fs: %s", achieved, exc) + cut_ok = _cut_relay(relay, retry=False) + + monitor.set_context(phase="relay_cut", relay_cmd=0, rcu_powered=False) + + note = "cut at %.3fs of %.2fs travel" % (achieved, travel_s) + if not cut_ok: + result = "CUT_FAILED" + note = "CUT_FAILED: " + note + logger.info("RELAY %s", note) + + monitor.write_event("relay_cut", note) + monitor.set_context(note=result) + + _wait(max(0.0, JIG_MOVE_MAX_S - achieved)) + + # Step 5: stop charging. Best-effort - the RCU lost power at the cut. + try: + rcu.set_charging(False) + except Exception as exc: + logger.info("Charging cmd = 0 not acknowledged, as expected with the " + "relay open and the RCU unpowered (%s).", exc) + monitor.set_context(phase="charging_off", charging_cmd=0) + _wait(CYCLE_GAP_S) + + # Step 6: back to the charging position, last thing in the cycle, so the + # whole post-cut window is observed at a standstill. + monitor.set_context(phase="jig_return", jig=home) + jig.move_to(*home) + _wait(JIG_MOVE_MAX_S) + monitor.set_context(note="") + + logger.info("Cycle %d finished: %s", cycle, result) + return result + + def ovp_test(rcu_port, tpu_port, relay_port, jig_port, cycles, cfg, stamp): os.makedirs(RESULTS_DIR, exist_ok=True) csv_path = os.path.join(RESULTS_DIR, "ovp_test_%s.csv" % stamp) @@ -807,9 +993,9 @@ def ovp_test(rcu_port, tpu_port, relay_port, jig_port, cycles, cfg, stamp): relay_cmd=1, charging_cmd=0, rcu_powered=True) monitor.start() + runner = run_cycle_move if cfg['scenario'] == 'move' else run_cycle for cycle in range(1, cycles + 1): - results.append( - run_cycle(cycle, rcu, relay, jig, monitor, cfg)) + results.append(runner(cycle, rcu, relay, jig, monitor, cfg)) except KeyboardInterrupt: logger.warning("Interrupted by user.") @@ -844,10 +1030,13 @@ def ovp_test(rcu_port, tpu_port, relay_port, jig_port, cycles, cfg, stamp): # Nothing to summarise if we bailed out before logging started. if recorder is not None: - passed = results.count("PASS") + # CUT_FAILED is counted apart from TIMEOUT: the relay never opened, + # so the cycle proves nothing either way about the RCU. logger.info("=" * 62) - logger.info("Cycles run: %d/%d | PASS: %d | TIMEOUT: %d", - len(results), cycles, passed, len(results) - passed) + logger.info("Cycles run: %d/%d | PASS: %d | TIMEOUT: %d " + "| CUT_FAILED: %d", + len(results), cycles, results.count("PASS"), + results.count("TIMEOUT"), results.count("CUT_FAILED")) for i, res in enumerate(results, start=1): logger.info(" cycle %d: %s", i, res) logger.info("Results saved to: %s", os.path.abspath(csv_path)) @@ -890,6 +1079,37 @@ def main(): parser.add_argument("--interval", type=float, default=MONITOR_INTERVAL_S, help="Telemetry sampling interval in seconds " "(default: %(default)s)") + parser.add_argument("--scenario", choices=("static", "move"), + default="static", + help="static: cut the relay with the jig still. " + "move: cut it partway through a jig move, which " + "needs a jig (default: %(default)s)") + # int, not float: Device.write_holding does `value & 0xFFFF`. + parser.add_argument("--move-x", type=int, default=MOVE_X_MM, metavar="X", + help="Scenario move: X in mm, held for the whole " + "scenario (default: %(default)s)") + parser.add_argument("--move-y", type=int, default=MOVE_Y_MM, metavar="Y", + help="Scenario move: Y in mm, held for the whole " + "scenario (default: %(default)s)") + parser.add_argument("--move-from", type=int, default=MOVE_Z_FROM_MM, + metavar="Z", + help="Scenario move: Z in mm where the move starts, " + "also the charging position " + "(default: %(default)s)") + parser.add_argument("--move-to", type=int, default=MOVE_Z_TO_MM, + metavar="Z", + help="Scenario move: Z in mm where the move ends " + "(default: %(default)s)") + parser.add_argument("--trigger-at", type=float, default=None, + metavar="SECONDS", + help="Scenario move: seconds after the go command to " + "cut the relay (default: half the travel time). " + "Only pulls the cut earlier") + parser.add_argument("--jig-speed", type=float, default=JIG_SPEED_MM_S, + metavar="MM_S", + help="Scenario move: jig speed in mm/s. Decides where " + "the cut lands, and the jig cannot confirm it - " + "measure it (default: %(default)s)") args = parser.parse_args() if not args.link_test: @@ -900,6 +1120,29 @@ def main(): if args.dwell > args.timeout: parser.error("--dwell cannot exceed --timeout") + if args.scenario == "move" and not args.link_test: + if not args.jig: + parser.error("--scenario move needs -j/--jig") + if args.jig_speed <= 0: + parser.error("--jig-speed must be positive") + if args.trigger_at is not None and args.trigger_at <= 0: + parser.error("--trigger-at must be positive") + + distance = abs(args.move_from - args.move_to) + if distance == 0: + parser.error("--move-from and --move-to are the same") + travel = distance / args.jig_speed + + # The whole travel, not half: step 5 re-commands the jig after + # JIG_MOVE_MAX_S, and a new target mid-move is undocumented behaviour. + if travel > JIG_MOVE_MAX_S: + parser.error("%d mm at %.1f mm/s takes %.1fs, over the %.1fs " + "move window (JIG_MOVE_MAX_S)" + % (distance, args.jig_speed, travel, JIG_MOVE_MAX_S)) + if travel / 2.0 < 0.2: + print("WARNING: only %.0f ms before the cut; Modbus latency is " + "15-35 ms" % (travel / 2.0 * 1000), file=sys.stderr) + os.makedirs(RESULTS_DIR, exist_ok=True) # One log per run, stamped like its CSV so the two pair up by name. A @@ -929,7 +1172,23 @@ def main(): 'timeout': args.timeout, 'interval': args.interval, 'link_test': not args.no_link_test, + 'scenario': args.scenario, + 'move_x': args.move_x, + 'move_y': args.move_y, + 'move_from': args.move_from, + 'move_to': args.move_to, + 'jig_speed': args.jig_speed, + 'trigger_at': args.trigger_at, } + + if args.scenario == "move": + distance, travel, trigger = move_timing(cfg) + logger.info("Scenario move: (%d,%d,%d) -> (%d,%d,%d), %d mm at " + "%.1f mm/s = %.2fs travel, cut at %.2fs", + args.move_x, args.move_y, args.move_from, + args.move_x, args.move_y, args.move_to, + distance, args.jig_speed, travel, trigger) + ovp_test(args.rcu, args.tpu, args.relay, args.jig, args.cycles, cfg, stamp)