[3.6.0-rc.3] sticky probe with 1HCL board

dc42

@ironhydroxide do you mean that it failed to trigger when it made contact, but when you broke and remade contact then it did trigger?

dc42

@ironhydroxide please try this EXP1HCL binary, which has debouncing enabled. After installation, M115 B50 should report the build date/time as 2025-05-13 11:05:26.

Duet3Firmware_EXP1HCL.bin

The debouncing in this build adds a latency of about 250us to the trigger detection. If this build fixes the issue then i can try reducing the latency.

ironhydroxide

@dc42 said in [3.6.0-rc.3] sticky probe with 1HCL board:

do you mean that it failed to trigger when it made contact, but when you broke and remade contact then it did trigger?

that it remained triggered after a probe was completed, and my script went through 5 instances of probe, seeing the probe triggered and backing off more from the tube. then it aborts the print if the probe points aren't close enough together.

So, probe success,
probe stays triggered,
probe commanded but errors due to already contacted,
backs off the tube a bit,
Probe commanded but errors due to already contacted
repeat 4x more.
Abort print,

I find probe in triggered state after abort
confirm voltage at pin is high (~3v)
manually ground the pin and watch the green light on 1HCL show up.
unground the pin and watch the green light go out, as well as probe status in DWC go from 1000 to 0.

I'll test that bin and let you know.

ironhydroxide

@dc42 said in [3.6.0-rc.3] sticky probe with 1HCL board:

M115 B50 should report the build date/time as 2025-05-13 11:05:26.

I'm getting
Duet EXP1HCL rev 1.0a or earlier firmware version 3.6.0-rc.3+1 (2025-05-14 08:29:27)

Downloaded twice, and loaded rc1, then this download just to make sure it's loaded correct.

dc42

@ironhydroxide I'm sorry, that was the correct firmware but I sent the M115 to the wrong board to check it, also the build date was being updated but not the build time. Here's another one, this time with build date 2025-05-15 08:01:41.

Duet3Firmware_EXP1HCL.bin

ironhydroxide

@dc42 Ah, no worries.

Loaded the latest, 5/15 build date,
Almost immediately the same symptoms.
Probe is good, then probe remains triggered,
next probe errors for already triggered,

Stays triggered until I manually trigger the probe and it resets.

Ran this 3x, symptoms the same each time.

and subjectively felt the occurrence to be much earlier in the run.

dc42

@ironhydroxide thanks. It looks like there were two issues:

Interrupt system getting locked up so that it doesn't detect further state changes. The last few builds have fixed this.
The remaining issue is that t doesn't detect a transition (i.e. probe contact) so you have to break contact, then it will detect the next contact. I think I have worked out what causes this, and how to fix it. I expect to have another firmware build to test this afternoon.

dc42

@ironhydroxide please try this build. The build time is 09:23 today.

Duet3Firmware_EXP1HCL.bin

dc42

@ironhydroxide did you have a chance to try this build? We plan to release 3.6.0-stable this week and I would like to include a fix for this issue in it.

ironhydroxide

@dc42 Sorry, been out the last 4 days on holiday. I'll test that build today and let you know asap.

ironhydroxide

@dc42
I am tentatively calling this one fixed.
A complete run of my test and no sticky probe. 5810 probes in succession, not a single "Probe already triggered" error as well.

I have started another run, but all things point to the sticky probe issue being fixed.

Z drift on the other hand.... seems to potentially be a further issue. I will address that in the other post, to keep things clean.

ironhydroxide

@dc42 Ran a second test through,
Finished without sticky probe making it now 11,656 probes without "Probe already triggered"

Though however in this run I did get a single instance of "failed to enable probe" directly after a Can Response timeout.
Below is the eventlog of that section.
luckily my macro calls M122 B50.0 just after probing, so it did just that and the result is logged

that said, still didn't have a problem, so... fixed, unless you feel the failed to enable probe could be indicative of a larger problem.

025-05-20 11:22:51 [warn] Error: CAN response timeout: board 50, req type 6061, RID 1051
2025-05-20 11:22:52 [warn] Error: G30: Failed to enable probe
2025-05-20 11:22:52 [warn] Warning: Discarded std reply src=50 RID=1051 exp=1052 ""
2025-05-20 11:22:52 [debug] Diagnostics for board 50:
2025-05-20 11:22:52 [debug] Duet EXP1HCL rev 1.0a or earlier firmware version 3.6.0-rc.3+1 (2025-05-16 09:23:09)
Bootloader ID: SAME5x bootloader version 2.4 (2021-12-10)
All averaging filters OK
2025-05-20 11:22:52 [debug] Never used RAM 51300, free system stack 154 words
Tasks: EncCal(1,nWait 6,0.0%,469) Move(3,nWait 7,0.0%,124) CLSend(3,nWait 6,3.0%,125) TMC(2,nWait 6,65.0%,313) HEAT(2,nWait 6,1.3%,105) CanAsync(5,nWait 4,0.0%,66) CanRecv(3,nWait 1,0.0%,31) CanClock(5,nWait 1,0.0%,63) MAIN(1,running,14.5%,249) IDLE(0,ready,15.3%,29) AIN(2,nWait 2,0.9%,255), total 100.0%
Owned mutexes:
Last reset 05:16:46 ago, cause: software
2025-05-20 11:22:52 [debug] Last software reset time unknown, reason: HardFault zeroDiv, available RAM 51444, slot 2
Software reset code 0x0060 HFSR 0x40000000 CFSR 0x02000000 ICSR 0x00000803 BFAR 0xe000ed38 SP 0x20002cc0 Task TMC Freestk 366 ok
2025-05-20 11:22:52 [debug] Stack: 00000000 20002d2f 00000000 00000000 00000000 00026359 00026368 41000000 0018a715 00024de3 20019948 20019948 00000001 00025d53 00025d3d 2001a874 001ceac9 00027c73 01601008 a0180030 08004d84 41c31e52 05c80021 3a341809 002ad181 2001a7c0 001ceac9
2025-05-20 11:22:52 [debug] Moves scheduled 37991, hiccups 0 (0.00/0.00ms), segs 3, step errors 0 (types 0x0), maxLate 0 maxPrep 12, ebfmin 0.00 max 0.00
Phase step loop runtime (us): min=6, max=102, frequency (Hz): min=5813, max=17857
Sync err accum 91, peak jitter 1/3, peak Rx delay 174, resyncs 0/0, next timer interrupt due in 7 ticks, enabled, next step interrupt due in 4293675087 ticks, disabled
VIN voltage: min 24.4, current 24.4, max 24.4
V12 voltage: min 12.2, current 12.2, max 12.2
MCU temperature: min 32.5C, curr
2025-05-20 11:22:52 [debug] Driver 0: pos -7187, 10060.2 steps/mm, standstill, SG min 0, mspos 888, reads 33820, writes 0 timeouts 0
2025-05-20 11:22:52 [debug] Last sensors broadcast 0x00000000 found 0 57 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 3346, send timeouts 0, received 27, lost 0, ignored 0, errs 0, boc 0, free buffers 38, min 37, error reg 0
dup 0, oos 0/0/0/0, rxMotionDelay 288, adv 36164/37169
2025-05-20 11:22:52 [debug] Closed loop driver 0 mode: open loop, pre-error threshold: 7.50, error threshold: 50.00, encoder type linearComposite, position 1696
Shaft: Encoder reverse polarity: yes, full rotations 2, last angle 9974, minCorrection=-15.4, maxCorrection=10.9, agc 15, mag 4604, no error
Lin: Encoder reverse polarity: no, raw count 1693
Accelerometer: none
I2C bus errors 0, naks 0, contentions 0, other errors 0

dc42

@ironhydroxide thanks! I worked out what was probably causing the original problem and I am confident that the new code has fixed that.

I would like to reduce the debounce latency before we release 3.6.0 stable so I'll probably as you to test another build later today or tomorrow if that's OK with you.

PS - do you have any feel for what probe trigger latency would work best for you? Currently it is 224us but I have it in mind to reduce it to 112us.

ironhydroxide

@dc42 I'll gladly do more testing.

As for trigger latency, I have not had the chance to drag my scope in and connect it, so I don't have enough data to even guess at a range.
I will attempt to get it connected today and get some traces, but no promises there.

dc42

@ironhydroxide the latency due to debouncing is 212 to 244us in this version. ~~This is somewhat lower than the maximum CAN latency so I think I will leave it as-is.~~

The effect of the latency is that the probing move will go a little further; but the amount is small. For example, if you probe at 5mm/sec then the extra 212us latency will cause the probe to descend about another 1um.

dc42

@ironhydroxide I've halved the latency to bring it oto line with the 6HC and 6XD boards. I doubt that this will affect your system, however if you wish to test it you can find new binaries at https://www.dropbox.com/scl/fo/vg4yfqcuk1u7oofsiogd6/AMDAS-LZ44linkaLjtrkCAY?rlkey=ptopknaa5xr4nhtacr94t6mw3&dl=0.

ironhydroxide

@dc42 Sounds good, I'll load this last one in and start the test.

I am probing below 5mm/s, though would like to keep the overshoot less than 1um, so that's a good "limit" value for me as I try and increase the speed of the system.

Thanks again for your hard work in this. It really is amazing what the Duet team is doing.

ironhydroxide

@dc42 Ran a full cycle of my test without a sticky probe.

on the start of the second cycle I had a weird thing happen, where the G30 did not return, I was watching the movement and it seemed to be due to my secondary attempt speeds being too slow and the debounce was ignoring the contact (blade moved down, contacted, blade moved up and started moving down slowly, but the probe never triggered again and the system hit the bottom stop)

I'm still calling this probe sticky issue no longer an issue. Again, thank you very much for your work in this.

While i have your attention though, would it be possible to get the encoder counts from 1HCL boards into the object model? or is that a huge change? (would make my tests of skew much easier)

dc42

@ironhydroxide thanks for your feedback.

Regarding getting encoder counts back from the 1HCL boards, unfortunately it is quite a large change involving all f the 1HCL firmware, the CAN message format and the main board firmware. Firmware 3.6 is too close to release for us to consider adding it before then. Perhaps you would like to create a feature request at https://github.com/Duet3D/RepRapFirmware/issues.