Print Start issues 3.5 Beta1+

[Alex.cr]

Error reporting for 3.5B1+
Continuing the theme of print start errors. Even with the new release with fixes in the + firmware I am still having issues with print starts. All of this code is pretty much unmodified from 3.4.x and worked well.

The details, Voron2.4 6HC+3HC+1HCL(x2)+1LC+SBC. On Print start the order of subroutines is not being respected. Similar to issues surrounding G32 with the other posts. I am assuming this might be a SBC issues if the + firmware fixed the problem for others, but that is just pure conjecture at this point.

It is not solely based around G32 in my case. I have replaced the G32 with a G28 in the start code from my slicer and the same thing happens.

So what's the problem; the system is hanging around the autoz.g and bed.g programs. The console on DWC is reporting the "abort" command that can occur in autoz.g slightly before the echo command in bed.g (echo "G32 leveling start"). This occurs while the machining is still processing code in bed.g.
The system then hangs after completing everything in bed.g. No errors reported.

Relevant code below.

Start G code from the slicer

M104 S180
M190 S[first_layer_bed_temperature]
G10 P0 S[temperature]  R180;
M116 ; wait for tool temp
 
G32 ; home and level gantry 
M98 P"/macros/print_scripts/nozzle_purge_wipe.g"
M98 P"autoz.g"
 
echo "cycle start"

bed.g code

; bed.g
; Called to perform automatic bed compensation via G32
echo "G32 leveling start"
 
; If the printer hasn't been homed, home it
if !move.axes[0].homed || !move.axes[1].homed || !move.axes[2].homed
	echo "Homeing"
	G28
else
	M98 P"/sys/homez.g"   			  ; Home Z
  
 
G54   												      ; normal coordinate system 
M561                                                      ; Clear any bed transform 
;G31 K1 													  ; select height probe 
M401 ;Deploy Probe
 
G1 X310 Y310 Z15.0 F20000                               ; move to an inital location
M98 P"/macros/print_scripts/speed_homing.g"   			  ; Setup low speed & accel
M290 R0 S0 ; clear babystepping
G90;
echo "Leveling"
M558 H10.0 ;dive height for probing
while iterations <=1                                      ; Do minimum of 2 passes
	G30 P0 X320 Y300 Z-99999
	G30 P1 X320 Y40 Z-99999
	G30 P2 X30 Y40 Z-99999
	G30 P3 X30 Y300 Z-99999 S4
	M558 H3.0 ;lower dive height
 
while move.calibration.initial.deviation >= 0.01         ; perform additional tramming if previous deviation was over 0.01mm 
   if iterations = 5                                      ; Perform 5 checks
      M300 S3000 P500                                     ; Sound alert, required deviation could not be achieved
      abort "!!! ABORTED !!! Failed to achieve < 0.01 deviation within 5 movements. Current deviation is " ^ move.calibration.initial.deviation ^ "mm."
   G30 P0 X320 Y300 Z-99999
   G30 P1 X320 Y40 Z-99999
   G30 P2 X30 Y40 Z-99999
   G30 P3 X30 Y300 Z-99999 S4
 
echo "Gantry deviation of " ^ move.calibration.initial.deviation ^ "mm obtained."
set global.gantryLevel=1; 
;set global.gantrylevel=1 ; set variable to true
G1 Z{sensors.probes[0].diveHeight+10.0}; lift head
 
M402     ;Retract probe
M98 P"homez.g"
 
 
M98 P"/macros/print_scripts/speed_normal.g"   			  ; Setup normal speed & accel
G1 Z20.0
M98 P"/macros/print_scripts/goto_bucket.g"   			  ; Go to park position
G54
G4 P50

The top couple of lines of code from "autoZ.g"

;program for calculating the zaxis offset for the klicky probe
set global.klickyOffset = 0.80 ; measured value of the switch on the probe to the probe body ; larger values here means nozzle closer to the bed after autoz (0.59)
G90
echo "AutoZ qual"
if global.gantryLevel != 1
	abort "gantry not level, abort"
 
M98 P"/sys/homez.g"   			  ; Home Z

[Alex.cr]

Additional info:
Here is a screen shot showing an echo command present in autoz.g appearing before the G32 commands were completed.

Also here is an M122 report while the machine is hanging.

m122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5beta1+ (2022-12-31 15:22:06) running on Duet 3 MB6HC v1.0 or earlier (SBC mode)
Board ID: 08DJM-956L2-G43S4-6J1FD-3SJ6T-TB6QH
Used output buffers: 1 of 40 (18 max)
=== RTOS ===
Static ram: 151308
Dynamic ram: 77072 of which 0 recycled
Never used RAM 118764, free system stack 140 words
Tasks: SBC(ready,1.0%,444) HEAT(notifyWait,0.0%,321) Move(notifyWait,0.1%,237) CanReceiv(notifyWait,0.1%,769) CanSender(notifyWait,0.0%,325) CanClock(delaying,0.0%,340) TMC(notifyWait,8.4%,56) MAIN(running,90.4%,978) IDLE(ready,0.0%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 25:00:43 ago, cause: software
Last software reset at 2022-12-31 18:39, reason: User, GCodes spinning, available RAM 119516, slot 1
Software reset code 0x6003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a
Error status: 0x00
Step timer max interval 136
MCU temperature: min 23.9, current 24.8, max 25.3
Supply voltage: min 23.3, current 23.8, max 24.1, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.3, under voltage events: 1
Heap OK, handles allocated/used 99/11, heap memory allocated/used/recyclable 2048/1128/956, gc cycles 775
Events: 5 queued, 5 completed
Driver 0: standstill, SG min n/a, mspos 8, reads 814, writes 0 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 814, writes 0 timeouts 0
Driver 2: standstill, SG min 2, mspos 984, reads 757, writes 56 timeouts 0
Driver 3: standstill, SG min 22, mspos 152, reads 757, writes 56 timeouts 0
Driver 4: standstill, SG min 25, mspos 936, reads 757, writes 56 timeouts 0
Driver 5: standstill, SG min 25, mspos 200, reads 757, writes 56 timeouts 0
Date/time: 2023-01-01 19:40:20
Slowest loop: 438.38ms; fastest: 0.03ms
=== Storage ===
Free file entries: 10
SD card 0 not detected, interface speed: 37.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 125, segments created 28, maxWait 2935931ms, bed compensation in use: none, comp offset 0.000
no step interrupt scheduled
=== DDARing 0 ===
Scheduled moves 112, completed 112, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 4], CDDA state -1
=== DDARing 1 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.3
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Movement locks held by null, null
HTTP* is doing "M122" in state(s) 0
Telnet is idle in state(s) 0
File* is idle in state(s) 0
USB is idle in state(s) 0
Aux is idle in state(s) 0
Trigger* is idle in state(s) 0
Queue* is idle in state(s) 0
LCD is idle in state(s) 0
SBC is idle in state(s) 0
Daemon* is idle in state(s) 0
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2* is doing "M0" in state(s) 0, sync state 2
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x1000003
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
Extruder 0: no data received
=== CAN ===
Messages queued 45261, received 250017, lost 0, boc 0
Longest wait 13ms for reply type 6018, peak Tx sync delay 387, free buffers 50 (min 37), ts 22100/22100/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 42295/42295
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x29b74
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-b1 (2022-12-23 20:41:36)
File2+ProcessInternally:
 
File /opt/dsf/sd/gcodes/Shape-Box_Voron_0.2.gcode is selected, processing
File:
Finishing macro bed.g, started by G32 ; home and level gantry 
> Next stack level
File2:
Buffered code: M0 ; end print
==> 24 bytes
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 51.66, max time between full transfers: 75.4ms, max pin wait times: 48.8ms/13.2ms
Codes per second: 64.92
Maximum length of RX/TX data transfers: 4996/2144
 

[dc42]

@Alex-cr thanks for your report. Are you able to run in standalone mode temporarily, to see if these issues still occur?

[chrishamm]

@Alex-cr There seems to be an issue in SBC mode with M0/M1/M2 if it comes from File(2) aka print job. I am working on a fix.
Edit: It's fixed but it will require a new RRF build and possibly a new DSF build, so probably 3.5-b2.

[Alex.cr]

@dc42 Standalone is really difficult for me as I have to have Wi-Fi with my machine at this time. I will see if I can figure something out.

@chrishamm Thanks for the support. Glad a fix is on the way.

Thanks both of you (and the rest of the Duet team) for your hard work. Awesome product. Any idea when b2 will be released?

[dc42]

@Alex-cr if a new DSF build is not needed then I will probably provide new RRF binaries to fix this at the end of this week. If a new DSF release is needed, we will aim to release beta2 next week.