Duet3 6CH + 3CH expansion board - Missing steps.

evomotors

@dc42 I added M112 & M112 B1 to the end of my start GCode in slicer then power cycle the printer and started print job.

These are all console enrties in chronological order:

1/16/2021, 4:25:51 PM
Connection established

1/16/2021, 4:35:56 PM	
M32 "0:/gcodes/2ZR_BearingTopMount_FR.gcode"
File 0:/gcodes/2ZR_BearingTopMount_FR.gcode selected for printing

1/16/2021, 4:40:20 PM	
Leadscrew adjustments made: 0.196 0.148 0.149 0.184, points used 4, (mean, deviation) before (0.167, 0.017) after (0.000, 0.000)

1/16/2021, 4:40:20 PM	
Bed Leveling Cycle: 1 - Difference was 0.017mm

1/16/2021, 4:40:20 PM	
Leadscrew adjustments made: 0.005 -0.005 -0.005 -0.007, points used 4, (mean, deviation) before (-0.003, 0.003) after (0.000, 0.000)

1/16/2021, 4:40:20 PM	
Bed Tramming Cycle: 2 - Difference was 0.003mm

1/16/2021, 4:40:20 PM	
Height map loaded from file heightmap.csv

1/16/2021, 4:40:46 PM	
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.3beta running on Duet 3 MB6HC v1.01 or later (SBC mode)
Board ID: 08DJM-956L2-G43S8-6JKDL-3SJ6L-1802G
Used output buffers: 1 of 40 (10 max)
=== RTOS ===
Static ram: 149772
Dynamic ram: 64248 of which 104 recycled
Never used RAM 140548, free system stack 126 words
Tasks: Linux(ready,111) HEAT(blocked,299) CanReceiv(blocked,893) CanSender(blocked,354) CanClock(blocked,326) TMC(blocked,52) MAIN(running,615) IDLE(ready,19)
Owned mutexes: File(MAIN)
=== Platform ===
Last reset 00:15:28 ago, cause: power up
Last software reset details not available
Error status: 0x00
Aux0 errors 0,0,0
Aux1 errors 0,0,0
MCU temperature: min 29.0, current 36.6, max 36.9
Supply voltage: min 24.1, current 24.3, max 24.5, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.2, under voltage events: 0
Driver 0: position 39840, standstill, reads 53659, writes 18 timeouts 0, SG min/max 0/237
Driver 1: position 37920, standstill, reads 53659, writes 18 timeouts 0, SG min/max 0/235
Driver 2: position 64, standstill, reads 53659, writes 18 timeouts 0, SG min/max 0/235
Driver 3: position 0, standstill, reads 53659, writes 18 timeouts 0, SG min/max 0/255
Driver 4: position 0, standstill, reads 53666, writes 11 timeouts 0, SG min/max 0/0
Driver 5: position 0, standstill, reads 53666, writes 11 timeouts 0, SG min/max 0/0
Date/time: 2021-01-16 21:40:45
Slowest loop: 203.63ms; fastest: 0.04ms
=== 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, maxWait 677116ms, bed compensation in use: mesh, comp offset 0.000
=== MainDDARing ===
Scheduled moves 94, completed moves 89, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 2], CDDA state 3
=== AuxDDARing ===
Scheduled moves 0, completed moves 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, chamberHeaters = -1 -1 -1 -1
Heater 0 is on, I-accum = 0.4
Heater 1 is on, I-accum = 0.3
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP* is idle in state(s) 0
Telnet is idle in state(s) 0
File* is doing "M122" 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
Code queue is empty.
=== CAN ===
Messages queued 3723, send timeouts 0, received 32, lost 0, longest wait 1ms for reply type 6018, peak Tx sync delay 354, free buffers 48
=== SBC interface ===
State: 0, failed transfers: 0
Last transfer: 31ms ago
RX/TX seq numbers: 32108/32108
SPI underruns 0, overruns 0
Number of disconnects: 0, IAP RAM available 0x2c478
Buffer RX/TX: 504/1744-0

1/16/2021, 4:40:47 PM	=== Duet Control Server ===
Duet Control Server v3.2.0
File:
Buffered code: M122 B1
Buffered code: M83 ;relative extrusion mode
Buffered code: G10
Buffered code: ;LAYER_COUNT:205
Buffered code: ;LAYER:0
Buffered code: M107
Buffered code: G0 F6000 X239.301 Y214.311 Z0.2
Buffered code: G11
Buffered code: G1 F1200 X239.779 Y213.81 E0.02303
Buffered code: G1 X240.312 Y213.368 E0.02303
Buffered code: G1 X240.892 Y212.99 E0.02303
Buffered code: G1 X241.512 Y212.681 E0.02304
Buffered code: G1 X242.164 Y212.446 E0.02305
Buffered code: G1 X242.838 Y212.288 E0.02303
Buffered code: G1 X243.703 Y212.2 E0.02892
Buffered code: G1 X244.192 Y212.189 E0.01627
Buffered code: G1 X248.16 Y212.189 E0.13198
Buffered code: G1 X248.944 Y212.2 E0.02608
Buffered code: G1 X249.571 Y212.239 E0.02089
Buffered code: G1 X250.221 Y212.326 E0.02181
Buffered code: G1 X250.899 Y212.466 E0.02303
Buffered code: G1 X251.539 Y212.677 E0.02241
Buffered code: G1 X252.018 Y212.865 E0.01711
Buffered code: G1 X252.647 Y213.155 E0.02304
Buffered code: G1 X253.403 Y213.633 E0.02975
Buffered code: G1 X253.852 Y213.968 E0.01863
Buffered code: G1 X253.926 Y214.025 E0.00311
Buffered code: G1 X254.45 Y214.478 E0.02304
==> 1212 bytes
Pending code: G1 X254.842 Y214.899 E0.01913
Pending code: G1 X255.098 Y215.201 E0.01317
Code buffer space: 2352
Configured SPI speed: 8000000 Hz
Full transfers per second: 22.65
Maximum length of RX/TX data transfers: 3468/1236
File /opt/dsf/sd/gcodes/2ZR_BearingTopMount_FR.gcode is selected, processing

1/16/2021, 4:40:47 PM	
Diagnostics for board 1:
Duet EXP3HC firmware version 3.3beta (2021-01-16 08:18:18)
Bootloader ID: not available
Never used RAM 154492, free system stack 166 words
HEAT 92 CanAsync 92 CanRecv 86 TMC 30 MAIN 306 AIN 259
Last reset 00:15:28 ago, cause: power up
Last software reset data not available
Driver 0: position -276160, 160.0 steps/mm,  ok, reads 9067, writes 18 timeouts 0, SG min/max 0/212, steps req 1080640 done 822518
Driver 1: position 53120, 160.0 steps/mm,  ok, reads 9071, writes 18 timeouts 0, SG min/max 0/230, steps req 933120 done 675001
Driver 2: position 3886, 172.0 steps/mm,  ok, reads 9076, writes 18 timeouts 0, SG min/max 0/94, steps req 10750 done 10072
Moves scheduled 29, completed 27, in progress 1, hiccups 0, step errors 0
Peak sync jitter 15, peak Rx sync delay 187, resyncs 0, next step interrupt due in 68 ticks, enabled
VIN: 24.7V, V12: 12.3V
MCU temperature: min 43.8C, current 43.8C, max 44.0C
Ticks since heat task active 155, ADC conversions started 928646, completed 928646, timed out 0
Last sensors broadcast 0x00000000 found 0 159 ticks ago, loop time 0
CAN messages queued 52, send timeouts 0, received 8373, lost 0, free buffers 36, error reg 110054

1/16/2021, 4:46:45 PM	
M25
Printing paused at X246.2 Y236.3 Z0.4

1/16/2021, 4:46:53 PM	
M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.3beta running on Duet 3 MB6HC v1.01 or later (SBC mode)
Board ID: 08DJM-956L2-G43S8-6JKDL-3SJ6L-1802G
Used output buffers: 1 of 40 (14 max)
=== RTOS ===
Static ram: 149772
Dynamic ram: 64248 of which 104 recycled
Never used RAM 140548, free system stack 126 words
Tasks: Linux(ready,111) HEAT(blocked,299) CanReceiv(blocked,893) CanSender(blocked,346) CanClock(blocked,326) TMC(blocked,52) MAIN(running,615) IDLE(ready,19)
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:21:35 ago, cause: power up
Last software reset details not available
Error status: 0x00
Aux0 errors 0,0,0
Aux1 errors 0,0,0
MCU temperature: min 36.5, current 37.2, max 37.2
Supply voltage: min 24.1, current 24.3, max 24.5, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.2, under voltage events: 0
Driver 0: position 73845, standstill, reads 62142, writes 0 timeouts 0, SG min/max 0/233
Driver 1: position 5906, standstill, reads 62142, writes 0 timeouts 0, SG min/max 0/230
Driver 2: position 1080, standstill, reads 62143, writes 0 timeouts 0, SG min/max 0/231
Driver 3: position 0, standstill, reads 62143, writes 0 timeouts 0, SG min/max 0/250
Driver 4: position 0, standstill, reads 62143, writes 0 timeouts 0, SG min/max not available
Driver 5: position 0, standstill, reads 62143, writes 0 timeouts 0, SG min/max not available
Date/time: 2021-01-16 21:46:52
Slowest loop: 39.49ms; fastest: 0.04ms
=== 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, maxWait 0ms, bed compensation in use: mesh, comp offset 0.000
=== MainDDARing ===
Scheduled moves 4372, completed moves 4372, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== AuxDDARing ===
Scheduled moves 0, completed moves 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, chamberHeaters = -1 -1 -1 -1
Heater 0 is on, I-accum = 0.4
Heater 1 is on, I-accum = 0.3
=== GCodes ===
Segments left: 0
Movement lock held by 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
Code queue is empty.
=== CAN ===
Messages queued 5754, send timeouts 0, received 24, lost 0, longest wait 21ms for reply type 6024, peak Tx sync delay 373, free buffers 48
=== SBC interface ===
State: 4, failed transfers: 0
Last transfer: 1ms ago
RX/TX seq numbers: 47336/47336
SPI underruns 0, overruns 0
Number of disconnects: 0, IAP RAM available 0x2c478
Buffer RX/TX: 0/0-0
=== Duet Control Server ===
Duet Control Server v3.2.0
Code buffer space: 4096
Configured SPI speed: 8000000 Hz
Full transfers per second: 41.53
Maximum length of RX/TX data transfers: 4664/1664
File /opt/dsf/sd/gcodes/2ZR_BearingTopMount_FR.gcode is selected, paused

1/16/2021, 4:47:01 PM	
M122 B1
Diagnostics for board 1:
Duet EXP3HC firmware version 3.3beta (2021-01-16 08:18:18)
Bootloader ID: not available
Never used RAM 154492, free system stack 165 words
HEAT 92 CanAsync 92 CanRecv 86 TMC 30 MAIN 282 AIN 259
Last reset 00:21:43 ago, cause: power up
Last software reset data not available
Driver 0: position -257449, 160.0 steps/mm,  standstill, reads 50071, writes 0 timeouts 0, SG min/max 0/897, steps req 1128627 done 1136804
Driver 1: position 12303, 160.0 steps/mm,  standstill, reads 50071, writes 0 timeouts 0, SG min/max 0/810, steps req 1156019 done 1164193
Driver 2: position 12182, 172.0 steps/mm,  standstill, reads 50069, writes 0 timeouts 0, SG min/max 0/703, steps req 44372 done 45391
Moves scheduled 4269, completed 4269, in progress 0, hiccups 110, step errors 0
Peak sync jitter 15, peak Rx sync delay 47157, resyncs 17, no step interrupt scheduled
VIN: 24.7V, V12: 12.3V
MCU temperature: min 43.8C, current 44.0C, max 44.0C
Ticks since heat task active 80, ADC conversions started 1303072, completed 1303070, timed out 0
Last sensors broadcast 0x00000000 found 0 84 ticks ago, loop time 0
CAN messages queued 24, send timeouts 0, received 7601, lost 56, free buffers 36, error reg 3c

dc42

Thanks for the additoinal data.

I've just run your print up to the 93% finished mark. This is the data:

m122b1
Diagnostics for board 1:
Duet EXP3HC firmware version 3.3beta (2021-01-16 19:11:54)
Bootloader ID: SAME5x bootloader version 2.2 (2021-01-16b1)
Never used RAM 154492, free system stack 142 words
HEAT 92 CanAsync 92 CanRecv 79 TMC 30 MAIN 274 AIN 259
Last reset 03:06:56 ago, cause: power up
Last software reset data not available
Driver 0: position 78458, 160.0 steps/mm,  standstill, reads 11912, writes 2 timeouts 0, SG min/max 0/72, steps req 49298753 done 49298753
Driver 1: position 82701, 160.0 steps/mm,  standstill, reads 11912, writes 2 timeouts 0, SG min/max 0/72, steps req 50413393 done 50413393
Driver 2: position 719839, 172.0 steps/mm,  standstill, reads 11913, writes 2 timeouts 0, SG min/max 0/67, steps req 1793879 done 1791393
Moves scheduled 210097, completed 210097, in progress 0, hiccups 15372, step errors 0
Peak sync jitter 24, peak Rx sync delay 49110, resyncs 200, no step interrupt scheduled
VIN: 24.4V, V12: 12.2V
MCU temperature: min 44.1C, current 44.2C, max 44.4C
Ticks since heat task active 40, ADC conversions started 11216032, completed 11216031, timed out 0
Last sensors broadcast 0x00000000 found 0 44 ticks ago, loop time 0
CAN messages queued 27, send timeouts 0, received 245625, lost 2226, free buffers 36, error reg 0

So I am still not seeing any loss of XY done vs. requested steps, only a loss of 0.14% of E steps. This is with pressure advance set to zero. OTOH there have been 2226 lost CAN messages, presumably mostly movement messages, so moves will have been lost.

My pause.g and resume.g are currently empty. You've provided your pause.g. Please provide your resume.g file too, then I will try again using your files, in case it makes a difference.

I will work on fixing the lost CAN messages tomorrow or Monday.

evomotors

@dc42 said in Duet3 6CH + 3CH expansion board - Missing steps.:

Thanks for the additoinal data.

I've just run your print up to the 93% finished mark. This is the data:
m122b1
Diagnostics for board 1:
Duet EXP3HC firmware version 3.3beta (2021-01-16 19:11:54)
Bootloader ID: SAME5x bootloader version 2.2 (2021-01-16b1)
Never used RAM 154492, free system stack 142 words
HEAT 92 CanAsync 92 CanRecv 79 TMC 30 MAIN 274 AIN 259
Last reset 03:06:56 ago, cause: power up
Last software reset data not available
Driver 0: position 78458, 160.0 steps/mm,  standstill, reads 11912, writes 2 timeouts 0, SG min/max 0/72, steps req 49298753 done 49298753
Driver 1: position 82701, 160.0 steps/mm,  standstill, reads 11912, writes 2 timeouts 0, SG min/max 0/72, steps req 50413393 done 50413393
Driver 2: position 719839, 172.0 steps/mm,  standstill, reads 11913, writes 2 timeouts 0, SG min/max 0/67, steps req 1793879 done 1791393
Moves scheduled 210097, completed 210097, in progress 0, hiccups 15372, step errors 0
Peak sync jitter 24, peak Rx sync delay 49110, resyncs 200, no step interrupt scheduled
VIN: 24.4V, V12: 12.2V
MCU temperature: min 44.1C, current 44.2C, max 44.4C
Ticks since heat task active 40, ADC conversions started 11216032, completed 11216031, timed out 0
Last sensors broadcast 0x00000000 found 0 44 ticks ago, loop time 0
CAN messages queued 27, send timeouts 0, received 245625, lost 2226, free buffers 36, error reg 0
So I am still not seeing any loss of XY done vs. requested steps, only a loss of 0.14% of E steps. This is with pressure advance set to zero. OTOH there have been 2226 lost CAN messages, presumably mostly movement messages, so moves will have been lost.

My pause.g and resume.g are currently empty. You've provided your pause.g. Please provide your resume.g file too, then I will try again using your files, in case it makes a difference.

I will work on fixing the lost CAN messages tomorrow or Monday.

So why it's not working for me? I'm not even talking about diagnostics. It is not printing when motors connected to expansion board. But works flawlessly when connected to Duet3.

All configs are attached. Compressed and renamed to txt
[0_1610838265664_RRF_3.3_Bakcup.zip](Uploading 100%) RRF_3.3_Bakcup.zip.txt

dc42

@evomotors said in Duet3 6CH + 3CH expansion board - Missing steps.:

It is not printing when motors connected to expansion board.

Please explain what you mean by this. I thought it was printing, but the print quality was poor.

evomotors

@dc42 said in Duet3 6CH + 3CH expansion board - Missing steps.:

@evomotors said in Duet3 6CH + 3CH expansion board - Missing steps.:

It is not printing when motors connected to expansion board.

Please explain what you mean by this. I thought it was printing, but the print quality was poor.

I'm taking about stuff that's happening on my videos. I cannot call this printing. Did you actually see the videos?

evomotors

@dc42 There are 2 videos I posted earlier in this thread. One showing motors connected to Duet3 and another then motors connected to expansion board. Please watch

dc42

I was confusing you with the other guy having a problem with print quality when the extruder is on an expansion board. I searched through the 128 posts in this thread and eventually found your video. It looks like it's printing correctly most of the time, but occasionally there is a big jolt which results in a shift in X and/or Y. That ties in with the lost CAN messages that are reported by M122 B1.

evomotors

@dc42 said in Duet3 6CH + 3CH expansion board - Missing steps.:

I was confusing you with the other guy having a problem with print quality when the extruder is on an expansion board. I searched through the 128 posts in this thread and eventually found your video. It looks like it's printing correctly most of the time, but occasionally there is a big jolt which results in a shift in X and/or Y. That ties in with the lost CAN messages that are reported by M122 B1.

The bottom line is when I connect XY motors to Duet3 board that problem disappears, but E steps still missing or not synchronized with XY movement and that produces bad quality print. Unfortunately I cannot connect extruder to duet3 as well as Duet3 has 6 stepper drivers, but I need 7.

jbarros

@dc42 said in Duet3 6CH + 3CH expansion board - Missing steps.:

I was confusing you with the other guy having a problem with print quality when the extruder is on an expansion board.

If you're refering to a ToolBoard then I'm the guy and this is my thread: https://forum.duet3d.com/topic/20899/duet3d-6hc-toolboard-missing-filament-on-curves

dc42

Yes, it figures that extrusion will be affected as well. Most of the moves in a print involve X, Y and E movement. So even if you move X and Y to the main board, there is still a CAN packet sent for the E movement.

I think the reason we haven't seen this before is that your print uses sequences of tiny movements, smaller than our other tests use. For example:

G0 F12000 X273.288 Y248.054
G1 F4800 X273.303 Y248.082 E0.00106
G1 X273.539 Y248.591 E0.01866
G1 X273.542 Y248.6 E0.00032
G1 X273.603 Y248.759 E0.00566
G1 X273.682 Y248.966 E0.00737
G1 X273.759 Y249.171 E0.00728
G1 X273.763 Y249.184 E0.00045

Here are those moves imported into a spreadsheet. The columns are X, Y, change in X, change in Y, move distance, and move time.

There are really small moves. The fourth one is less than 10 microns long and it will execute in just 120 microseconds. The longest one takes only 7 milliseconds and all the rest are below 3 milliseconds. So the system is having to process a very high rate of moves. Still, I don't see any evidence that the CAN bus is being overloaded, so I expect to resolve the issues with this print by improving the efficiency of processing the incoming move commands on the expansion board.

evomotors

@dc42 Could my issue exists due to faulty Duet board ? I'm dead in the water. I cannot print at all for several weeks already.

Luke'sLaboratory

@evomotors

@dc42 said:

So I am still not seeing any loss of XY done vs. requested steps, only a loss of 0.14% of E steps. This is with pressure advance set to zero. OTOH there have been 2226 lost CAN messages, presumably mostly movement messages, so moves will have been lost.

evomotors

@dc42 do you have any time estimates? I’m wondering when I’ll be able to print.

evomotors

Can I have some updates? Please...

Phaedrux

Still being worked on. Thanks for your patience.

Multisaft

I would like to tell u that ur not alone with this issue. My colleague and myself have exactly the same problem. Connecting xy to the expansion board and we had what u have shown on ur Youtube Video. Switching back to the Mainboard and everything is fine.

Unfortunately we need also 7 motors driven to print. Now we have the extruder on the expansion board and have the issue there.

It's nice to see that dc is working on it now especially because I have this problem since the board was officially released... It's some time now.

Fingers crossed that there is a solution soon.

Best regards.
Multisaft

dc42

@Multisaft, it's likely that the changes already made in 3.3beta will fix the issue for you. The issue I am pinning down now occurs when all of XYE are on the same expansion board and there is a very high rate of very short moves sent to the board. Even if 3.3beta doesn't fix the issue, the improved diagnostics will reveal what is going on.

Multisaft

@dc42 ty, we will try it.

dc42

Good progress today. I had been assuming that the remaining problem seen by @evomotors was caused by the expansion board firmware being too slow, so over the past few days I have been making it more efficient. But additional diagnostics reveal that it's a problem with the way the main board firmware is scheduling CAN moves. With this particular file it's sending the expansion board some moves which are impossible to execute in time. Main board firmware is easier to debug than expansion board firmware, so tracking down why shouldn't take long.

dc42

I've located the problem and tested a provisional fix. It affects systems using CAN expansion boards that have DAA enabled.