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

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.

dc42

@ironhydroxide I'm sorry to bother you again, however I've had to revert one of the earlier changes I made to fix this issue because it had an unfortunate side effect. I think the issue should be fixed without that change; however I would be grateful if you could test the candidate 3.6.0 firmware for the 1HCL which is now at https://www.dropbox.com/scl/fo/etf8gf0vxx8ro102juita/AHzXcQJL_3Io_1C4LuDwpxI?rlkey=1hbgwbogzy1r44y1897a7kqds&dl=0.

ironhydroxide

@dc42 Sorry for the delay, I've been out of town the last 4 days.

I have loaded the provided build and have ran over 10k probes without a sticky probe issue.

I'll continue to test(mostly because of skew i'm seeing), but it looks like you got the sticky probe issue whipped.

Thanks again!!

dc42

@ironhydroxide thanks for the confirmation!