Red channel remains ON between Steps in attached Protocol

[EtalumaSupport]

BF and 3 channels of Fl in a 6-well in which I delete all Steps except the four each in A1 and A2. I then added a 4 channel location. Running it results in the red channel remaining on from Step 8 to Step 9.

api.log
camera.log
gui_interactions.log
lumaviewpro.log
lumaviewpro_errors.log
metrics.log
RedStaysOn.tsv
serial.log

[ericweiner]

Triage findings (2026-05-20 session 9)

Cluster context

#671 is a third instance of the LED-state-hygiene-at-transition cluster previously addressed by:

• Protocol channel brightness changes based on starting conditions of Protocol #666 -- protocol scan-start LED leak (shipped LVP a35a1e3)
• If a channel LED is ON and one changes to another channel, it remains ON until the new channel is Enabled #659 -- Live-mode accordion-switch LED leak (shipped LVP 308186b)

Both prior fixes ARE present in the user's build (4.0.0-beta12, built 2026-05-18 18:06). Confirmed via git branch --contains -- the user's reported behavior is NOT covered by either prior fix.

Architectural convention: led_on is purely additive at the API + driver layers; the codebase enforces "leds_off before led_on at every layer switch" by convention. This issue is a third site where the convention is violated.

Confirmed bug signature (from attached api.log)

Scan #2 step transitions trace cleanly for the 7 within-TSV transitions:

07:33:13.757 led_on ch=2 (A1_Red)
07:33:14.958 leds_off              <-- leds_off BEFORE move
07:33:14.990 move_abs X=58510.0    <-- move to next position
07:33:16.457 led_on ch=3 (A2_BF)   <-- led_on for next step

But the transition from the LAST TSV step (A2_Red) to the FIRST step of the user-added 4-channel location BREAKS the pattern:

07:33:17.895 led_on ch=2 mA=350.0 owner='protocol'   <-- Step 8: A2_Red
07:33:19.090 move_abs X=19856.9um                     <-- NEW location move, NO leds_off!
07:33:19.150 move_abs Y=57899.3um                     <-- Red LED still on during well-to-well motion
07:33:19.231 move_abs Z=6247.4um wait
07:33:20.920 leds_off                                 <-- Finally leds_off, AFTER the move (~1.7s late)
07:33:20.952 move_abs X=19856.9um                     <-- DUPLICATE move to same X/Y
07:33:21.001 move_abs Y=57899.3um
07:33:21.073 move_abs Z=6247.4um wait
07:33:21.109 set_exposure 1.0ms
07:33:21.171 led_on ch=0 mA=250.0 owner='protocol'    <-- Step 9: Blue (first ch of added location)

Two structural anomalies vs the canonical pattern:

1. leds_off fires AFTER move, not before -- Red LED stays on during the X/Y motion from A2 to the new location
2. Duplicate move to (19856.9, 57899.3) -- two distinct code paths both targeting the same XY/Z, separated by ~1.7s and the leds_off

The duplicate move is the smoking gun: two code paths converge on the same target position, suggesting the user-added-location code path runs alongside (not instead of) the standard protocol step iteration.

Hypotheses (not yet falsified -- Rule 44 budget engaged)

H1: User-added locations append to a separate list that protocol.num_steps() doesn't include, so scan_iterate.go_to_step doesn't fire for them. A separate code path inside sequenced_capture_runner then processes them with its own move-first / led-on-second ordering that lacks the per-step if not keep_led_on: self._leds_off() end-of-step cleanup from protocol_image_writer.capture().

H2: The last-step's end-of-capture leds_off is being skipped for the last TSV step specifically (boundary condition in protocol_step_runner.scan_iterate.scan_iterate lines 230-237 _keep_led logic), with the leds_off then deferred until some end-of-scan cleanup that fires after the position move has begun.

Both hypotheses predict the SAME log signature, so the log alone can't disambiguate. Needs deeper code-trace of the user-added-location path.

Sub-finding (separate concern, worth filing as own issue)

The user's added 4-channel location only ran 3 channels (Blue, Green, BF) in a different order than the TSV-loaded locations (TSV order: BF, Blue, Green, Red). Red is missing entirely from the added location's execution. Either:

• The added-location code stores channels in enable-order at add-time and Red wasn't enabled
• A scan-end / time-budget cutoff truncated the scan before Red ran
• The added location was actually 3-channel not 4-channel

Worth a separate ticket if the user can reproduce.

Repro signature for the next investigator

• Build: 4.0.0-beta12 or later (both If a channel LED is ON and one changes to another channel, it remains ON until the new channel is Enabled #659 + Protocol channel brightness changes based on starting conditions of Protocol #666 fixes are present)
• Protocol: 6-well, BF + Blue + Green + Red, A1 and A2 wells in the TSV
• User action: load the TSV, then add a 4-channel location via the UI
• Run the protocol
• Observe: Red LED stays lit during the move from A2_Red to the added location's first channel

Log bundle archived at Firmware/build/issue671_2026-05-19/.

What I'd dig into next session

• modules/sequenced_capture_runner.py + the UI add-location handler -- where do user-added locations get stored vs TSV-loaded steps?
• Whether protocol.num_steps() includes added locations or not
• Whether the user-added-location code path has its own move/led_on ordering that bypasses protocol_image_writer.capture()

Status: not yet code-side resolved. Two-hypothesis budget engaged per Rule 44 -- next pass should build the instrument before proposing a fix.

[ericweiner]

seems like you have all of the info you need to reproduce this. Try again. or add logging if you need it.

[ericweiner]

Re-triage: simulator can't repro -- production has a different code path

Followup to my earlier triage. Two findings from this pass:

Finding 1: The regression test PASSES on current beta

tests/test_issue_671_added_location_led_ordering.py::TestAddedLocationLedOrdering::test_leds_off_precedes_move_at_added_location_boundary passes against 4.0.0-beta @ 55642ac. The test builds the same 8 TSV + 4 inserted-step protocol and asserts leds_off precedes the first move_abs at the step-8 -> step-9 boundary. It passes -- so the simulator path does the right thing.

Finding 2: Production routes moves through a DIFFERENT thread than leds_off

scan_iterate.go_to_step calls the p._callbacks.go_to_step callback, which is modules/step_navigation.py::go_to_step in production (set in ui/protocol_settings.py:1416,1941). With called_from_protocol=True (the default), the else branch at step_navigation.py:107-113 calls ui_helpers.move_absolute_position(..., protocol=True). That helper at ui_helpers.py:140-147 calls ctx.scope.motion.move_absolute_position(...) DIRECTLY on the calling thread (protocol_thread) -- BYPASSING io_executor.

Meanwhile protocol_image_writer.capture()'s end-of-step leds_off STILL queues through io_executor.protocol_put (protocol_step_runner.py:462-478) and blocks on the future.

Two threads, two ordering paths: io_executor worker fires leds_off; protocol_thread fires direct move_abs. The test doesn't exercise this divergence because the test sets callbacks.go_to_step=None, falling back to default_move which DOES serialize moves through io_executor (protocol_step_runner.py:354,359,365,390-395). Hence the simulator path is correct-by-construction; the production path has a race window the test can't see.

Hypotheses (refined)

H1 -- A non-move_absolute_position caller is firing the FIRST move sequence at 19.090, before the canonical step-transition fires the second move at 20.952. The "duplicate move to identical X/Y/Z" smoking gun supports this -- the same step's coordinates being targeted twice means two distinct call sites converge on the same target.

H2 -- protocol_step_runner.leds_off proceeds past fut.result(timeout=30) early -- either the future raises (caught silently?), the queue rejects the task (PROTOCOL_QUEUE_FULL -> fut=None), or some other path bypasses the wait.

H3 -- The io_executor worker is genuinely behind the protocol_thread by ~1.83s. The leds_off task is queued correctly, blocked on the future correctly, but the io_executor worker is processing something else (maybe a backlog from the still-in-flight Red exposure / save?) and only gets to leds_off at 20.920.

Instrumentation branch ready for bench

Branch: diag/issue-671-led-move-ordering @ e1589dd (LumaViewPro repo)

Adds 4 [DIAG-671]-tagged logger.info lines:

File	Method	What it logs
modules/protocol_step_runner.py	leds_off() ENQUEUE	thread + time
modules/protocol_step_runner.py	leds_off() DONE (post-fut.result)	thread + time + enqueue->done duration ms
modules/lumascope_api/illumination.py	IlluminationAPI.leds_off() ENTER	thread + time
modules/lumascope_api/motion.py	MotionAPI.move_absolute_position() ENTER	axis + pos + thread + caller + time

The caller= field (via sys._getframe(1).f_code.co_name) names the function frame ONE LEVEL ABOVE move_absolute_position. That distinguishes the production callback path ('move_absolute_position' from ui_helpers) from the test path ('_move_axis_through_io' from protocol_step_runner.default_move) from anything else.

To deploy on the bench

cd /path/to/LumaViewPro
git fetch origin
git checkout diag/issue-671-led-move-ordering
# rebuild / restart LVP per usual bench flow

To repro

Same as the original report:

1. Load an 8-step TSV (A1+A2, 4 channels: BF, Blue, Green, Red).
2. Add a 4-channel location at a 3rd X/Y via the UI.
3. Run the protocol.
4. Capture both api.log and lumaviewpro.log.

What to look for

Grep [DIAG-671] in lumaviewpro.log (or api.log -- the lines emit on LVP.api channel). The TSV-step-8 -> added-step-9 boundary should be the focal window. Falsifying signatures:

• H1: MotionAPI.move_absolute_position ENTER ... caller=<X> where X is NOT one of {move_absolute_position, _move_axis_through_io, default_move}. Names a new code path.
• H2: step_runner.leds_off ENQUEUE fires, then MotionAPI.move_absolute_position ENTER fires on the SAME thread, BEFORE IlluminationAPI.leds_off ENTER fires on a different (io_executor worker) thread. Implies the fut.result() wait returned without leds_off completing.
• H3: step_runner.leds_off ENQUEUE ... t=X.X and IlluminationAPI.leds_off ENTER ... t=X.X+1.8. Identical thread sequence but the io_executor worker is genuinely 1.8s behind -- queue backlog.

When you have data

Attach both api.log AND lumaviewpro.log here, or paste the [DIAG-671] lines + the surrounding move_abs / leds_off / led_on lines into a comment. From there the right fix lands on 4.0.0-beta with a regression test that exercises the production callback path (not just the default_move path).

Bench retest signal: none yet; this is the instrument, not the fix.

[ericweiner]

SN12062-2026-06-01-153424.zip
please see these

[ericweiner]

DIAG-671 results: root cause confirmed (cross-thread leds_off / move race)

Analyzed SN12062-2026-06-01-153424.zip. The [DIAG-671] trace shows protocol moves take TWO code paths:

• thread='IO_WORKER' caller='run' -- the move is enqueued as an IOTask and runs on the io_executor worker, SERIALIZED with leds_off (which also runs on IO_WORKER). Safe.
• thread='protocol_thread' caller='move_absolute_position' -- the move runs DIRECTLY on protocol_thread, bypassing the io_executor entirely.

The second path is ui/ui_helpers.py::move_absolute_position(protocol=True) (lines 153-156). Its comment assumes the "caller is already running on the io_executor / protocol thread" -- but the trace proves protocol_thread is a DIFFERENT thread from IO_WORKER. So when a step takes this path, the move (protocol_thread) races the leds_off enqueued on the io_executor (IO_WORKER). When the move wins, the LED stays lit through the well-to-well move -- the reported red-stays-on.

This confirms H2 (cross-thread ordering), with H1 (the go_to_step path selecting the direct-call route) as the mechanism. H3 (queue backlog) is falsified -- no FUT_NONE, and the IO_WORKER path serializes cleanly.

Cluster: the same protocol=True direct-call hazard applies to the turret path in the same function (lines 138-141) -- bundle it.

Proposed fix (behavior-change, pending approval): route the protocol=True move through the io_executor (same IOTask + future pattern as leds_off / _move_axis_through_io) so move and leds_off serialize on the one ordered stream. The "would deadlock" concern only applies if the caller is ON the io_executor worker -- it is on protocol_thread, so enqueuing is safe. Regression test asserts no protocol_thread-direct move path (all protocol moves share the io_executor ordering with leds_off).

Status: root cause confirmed from bench diag data; fix pending implementation on 4.0.0-beta. The diag/issue-671-led-move-ordering branch can be deleted once the fix lands.

[ericweiner]

Ready for bench verification

Root cause: During a protocol run, go_to_step runs on protocol_thread -- a different thread from the io executor's single worker. The protocol-context X/Y/Z moves and turret thome/tmove were calling the motion primitives directly on protocol_thread, racing the leds_off that the capture path queues on the io worker. When a move won the race, the previous step's LED stayed lit through the well-to-well move.

Fix: Routed all four protocol-context sites (X/Y/Z move, turret tmove, turret thome) through io_executor.protocol_put + future-wait, so they serialize behind the step's leds_off on the single worker (ui/ui_helpers.py, ui/vertical_control.py).

Cluster check: 4-site cluster, all fixed in one commit. Confirmed apply_settings(protocol=True) early-returns under a running protocol, so per-step LED/gain already route correctly -- the cluster is exactly these 4 move/turret sites.

SHA: 5820027 on 4.0.0-beta (tip 28a93f9).

Regression test: tests/test_protocol_move_io_ordering.py (move-routing + turret guards; fails-before/passes-after).

Test plan to confirm:

1. Load the attached protocol (the 8-step TSV + added 4-channel location).
2. Run it; watch the Red channel at each step transition.
3. Expected: the LED turns OFF before the well-to-well move begins -- no Red bleed through the move.

Chris, please build the latest beta and verify, then close if resolved or add a note/logs if anything is still off.

[ericweiner]

red LED did NOT turn on on the added steps, as far as I could see.

SN12062-2026-06-01-172236.zip