TMC2208 extruder driver shuts itself off in spreadcycle mode with pressure advance enabled

[lekv]

I installed TMC2208 drivers and configured pressure advance (pressure_advance = 0.5). Sometimes during a print the extruder stepper disables itself and stops extruding. When trying again without any changes to the settings, the same print would then succeed.

My retraction speed is set to 40mm/s and therefore I picked 41mm/s as the stealthchop_threshold. In addition I tried setting stealthchop_threshold to 0 to force the driver into spreadcycle mode permanently, but some prints still failed. I have not had any issues with pressure advance disabled.

The printer is an Ender 3 pro with an MKS Gen L mainboard. The drivers are v1.1 from MKS in UART mode (single wire).

At first this looked like #196, but after a brief discussion there, @KevinOConnor suggested that this could be a different issue and to open a new one.

I'm attaching my klippy.log which has the full configuration. For easier reading I'm also pasting the extruder config and DUMP_TMC output below.

Thanks for any help. I'm happy to provide more information if I forgot anything.

[extruder]
max_extrude_only_distance = 100.0
step_pin = ar26
dir_pin = !ar28
enable_pin = !ar24
step_distance = 0.01030927835
nozzle_diameter = 0.400
filament_diameter = 1.75
heater_pin = ar10
sensor_type = EPCOS 100K B57560G104F
sensor_pin = analog13
control = pid
pid_kp = 21.527
pid_ki = 1.063
pid_kd = 108.982
min_extrude_temp = 0
min_temp = 0
max_temp = 250
pressure_advance = 0.5
pressure_advance_lookahead_time = 0.010

[tmc2208 extruder]
uart_pin = ar65
microsteps = 16
stealthchop_threshold = 41
run_current = 0.709

This is the DUMP_TMC output after the print finished:

DUMP_TMC extruder
========== Write-only registers ==========
IHOLD_IRUN: 00081616 IHOLD=22 IRUN=22 IHOLDDELAY=8
TPWMTHRS:   000000bd TPWMTHRS=189
TPOWERDOWN: 00000014 TPOWERDOWN=20
========== Queried registers ==========
GCONF:      00000101 I_scale_analog=1(ExtVREF) multistep_filt=1
GSTAT:      00000003 reset=1 drv_err=1(ErrorShutdown!)
IFCNT:      00000000
OTP_READ:   00000010 OTP_FCLKTRIM=16
IOIN@TMC220x: 2000034d ENN=1 MS1=1 MS2=1 PDN_UART=1 SEL_A=1(TMC220x) DIR=1 VERSION=0x20
Stats 2450334.2: gcodein=2881324 mcu: mcu_awake=0.008 mcu_task_avg=0.000091 mcu_task_stddev=0.000074 bytes_write=8711751 bytes_read=4560366 bytes_retransmit=9 bytes_invalid=0 send_seq=209593 receive_seq=209592 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=19 stalled_bytes=0 freq=16000506  heater_bed: target=0 temp=40.2 pwm=0.000 print_time=1220128.728 buffer_time=0.000 print_stall=0 extruder: target=0 temp=39.2 pwm=0.000
FACTORY_CONF: 00000010 FCLKTRIM=16
TSTEP:      000fffff TSTEP=1048575
MSCNT:      00000138 MSCNT=312
MSCURACT:   01ac00e8 CUR_A=232 CUR_B=-84
CHOPCONF:   14010053 toff=3 hstrt=5 TBL=2 MRES=4(16usteps) intpol=1
DRV_STATUS: c01f0000 CS_ACTUAL=31 stealth=1 stst=1
PWMCONF:    c80d0e24 PWM_OFS=36 PWM_GRAD=14 pwm_freq=1 pwm_autoscale=1 pwm_autograd=1 PWM_REG=8 PWM_LIM=12
PWM_SCALE:  00000022 PWM_SCALE_SUM=34
PWM_AUTO:   001a0022 PWM_OFS_AUTO=34 PWM_GRAD_AUTO=26

klippy.log

[zwnk]

i'm using pressure advance value of 0.3 on my ender 3 with a tmc2208 in spreadcycle mode and have no issues. the issues arise when changing to stealthchop.
what motor do you use? 0.7a do look a little low for an extruder.

[lekv]

The motor is a Creality 42-40 (the stock one on the Ender 3 Pro). From what I could find online (e.g. here) its I_max is 1.0A, then I converted it to I_RMS by dividing by sqrt(2) and rounding up, ending with 0.7A.

Is that wrong? Which motor do you have and what value for I_max do you use?

[zwnk]

i use 0.9 on the extruder. no heat issue so far.

[KevinOConnor]

The results from your DUMP_TMC output doesn't look sane. Make sure you always apply motor power before starting up klipper, and make sure to never remove motor power while klipper is running. (If motor power is interrupted at any point then it is required to run the klipper RESTART command to reinitialize the tmc drivers.) If this is not done, then the tmc drivers can go into a corrupted state and very odd things can happen.

I don't think it would make sense to run the extruder in stealthchop mode if you've got a retraction speed of 40mm/s. I'd say you should just exclusively use spreadcycle mode.

If you've got a failure when running exclusively in spreadcycle mode, then I think the klipper log from that may help. Please also include the DUMP_TMC output before the failure and after the failure.

-Kevin

[terrorhai]

TMC2208 are too weak to run the fast PA commands, the problem will occur on StealthChop too. Run 2130 (if you want to waste money) or A4988 for your E's. In this specific case, the "dumb" A4988 works the best. Ran into the same problems some months ago ;)

[lekv]

Thanks for the feedback. I added DUMP_TMC for the extruder to the starting G-code for every print and will update this issue when it happens again.

[lekv]

This has happened to me again, I'm attaching the log file of the failed print.

This is the TMC status when the print started:

DUMP_TMC extruder
========== Write-only registers ==========
IHOLD_IRUN: 00081616 IHOLD=22 IRUN=22 IHOLDDELAY=8
TPWMTHRS:   00000000
TPOWERDOWN: 00000014 TPOWERDOWN=20
========== Queried registers ==========
GCONF:      00000101 I_scale_analog=1(ExtVREF) multistep_filt=1
GSTAT:      00000001 reset=1
IFCNT:      00000000
OTP_READ:   00000010 OTP_FCLKTRIM=16
IOIN@TMC220x: 2000014d ENN=1 MS1=1 MS2=1 PDN_UART=1 SEL_A=1(TMC220x) VERSION=0x20
FACTORY_CONF: 00000010 FCLKTRIM=16
TSTEP:      000fffff TSTEP=1048575
MSCNT:      00000008 MSCNT=8
MSCURACT:   00f7000c CUR_A=12 CUR_B=247
CHOPCONF:   14010053 toff=3 hstrt=5 TBL=2 MRES=4(16usteps) intpol=1
DRV_STATUS: c01e0000 CS_ACTUAL=30 stealth=1 stst=1
PWMCONF:    c80d0e24 PWM_OFS=36 PWM_GRAD=14 pwm_freq=1 pwm_autoscale=1 pwm_autograd=1 PWM_REG=8 PWM_LIM=12
PWM_SCALE:  00000024 PWM_SCALE_SUM=36
Stats 187612.4: gcodein=2931477 mcu: mcu_awake=0.015 mcu_task_avg=0.000108 mcu_task_stddev=0.000077 bytes_write=8522584 bytes_read=2333001 bytes_retransmit=0 bytes_invalid=0 send_seq=193012 receive_seq=193011 retransmit_seq=0 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=16000502  heater_bed: target=60 temp=60.7 pwm=0.000 print_time=12761.008 buffer_time=14.005 print_stall=0 extruder: target=210 temp=210.1 pwm=0.422
PWM_AUTO:   000e0024 PWM_OFS_AUTO=36 PWM_GRAD_AUTO=14

This is the status after the error:

DUMP_TMC extruder
========== Write-only registers ==========
IHOLD_IRUN: 00081616 IHOLD=22 IRUN=22 IHOLDDELAY=8
TPWMTHRS:   00000000
TPOWERDOWN: 00000014 TPOWERDOWN=20
========== Queried registers ==========
GCONF:      00000101 I_scale_analog=1(ExtVREF) multistep_filt=1
GSTAT:      00000003 reset=1 drv_err=1(ErrorShutdown!)
Stats 188520.2: gcodein=3129365 mcu: mcu_awake=0.009 mcu_task_avg=0.000094 mcu_task_stddev=0.000072 bytes_write=9266518 bytes_read=2515031 bytes_retransmit=0 bytes_invalid=0 send_seq=209961 receive_seq=209960 retransmit_seq=0 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=
28 stalled_bytes=0 freq=16000499  heater_bed: target=0 temp=53.7 pwm=0.000 print_time=13654.982 buffer_time=0.125 print_stall=0 extruder: target=0 temp=177.8 pwm=0.000
IFCNT:      00000000
OTP_READ:   00000010 OTP_FCLKTRIM=16
IOIN@TMC220x: 2000034d ENN=1 MS1=1 MS2=1 PDN_UART=1 SEL_A=1(TMC220x) DIR=1 VERSION=0x20
FACTORY_CONF: 00000010 FCLKTRIM=16
TSTEP:      000fffff TSTEP=1048575
MSCNT:      000001c8 MSCNT=456
MSCURACT:   01160052 CUR_A=82 CUR_B=-234
CHOPCONF:   14010053 toff=3 hstrt=5 TBL=2 MRES=4(16usteps) intpol=1
DRV_STATUS: c01f0000 CS_ACTUAL=31 stealth=1 stst=1
PWMCONF:    c80d0e24 PWM_OFS=36 PWM_GRAD=14 pwm_freq=1 pwm_autoscale=1 pwm_autograd=1 PWM_REG=8 PWM_LIM=12
PWM_SCALE:  00000024 PWM_SCALE_SUM=36
PWM_AUTO:   001e0024 PWM_OFS_AUTO=36 PWM_GRAD_AUTO=30

Full log file:

klippy.log

[lekv]

Apologies for accidentally closing this, and thanks for any help!

[andrico21]

My two cents: updated Klipper yesterday and my extruder 5160 begin to suddenly shut down during the print. As far as I can remember - previously updated about two weeks ago... So I suspect there was some change in the code which leads to unexpected shutdown. Anyway I'm going to create issue for that, but maybe it's due the same reason as this issue.

[KevinOConnor]

The GCONF report is showing bad values - it should look something like:

GCONF:      000001c4 en_spreadCycle=1 pdn_disable=1 mstep_reg_select=1 multistep_filt=1

(The en_spreadCycle may or may not be present, but the rest of the line should match the above.)

The only reason I can think of that would lead to a corrupted GCONF is if motor power was removed after a Klipper start.

I recommend you upgrade to the latest software and verify that you can obtain a correct GCONF setting.

-Kevin

[lekv]

This just happened again after updating to the latest version of klipper (TODO). Here's the DUMP_TMC output at the start of the print:

DUMP_TMC extruder
========== Write-only registers ==========
IHOLD_IRUN: 00081919 IHOLD=25 IRUN=25 IHOLDDELAY=8
TPOWERDOWN: 00000014 TPOWERDOWN=20
========== Queried registers ==========
GCONF:      00000101 I_scale_analog=1(ExtVREF) multistep_filt=1
GSTAT:      00000001 reset=1
IFCNT:      00000000
OTP_READ:   00000010 OTP_FCLKTRIM=16
IOIN@TMC220x: 2000014d ENN=1 MS1=1 MS2=1 PDN_UART=1 SEL_A=1(TMC220x) VERSION=0x20
FACTORY_CONF: 00000010 FCLKTRIM=16
TSTEP:      000fffff TSTEP=1048575
MSCNT:      00000008 MSCNT=8
MSCURACT:   00f7000c CUR_A=12 CUR_B=247
CHOPCONF:   14010053 toff=3 hstrt=5 TBL=2 MRES=4(16usteps) intpol=1
DRV_STATUS: c01f0000 CS_ACTUAL=31 stealth=1 stst=1
PWMCONF:    c80d0e24 PWM_OFS=36 PWM_GRAD=14 pwm_freq=1 pwm_autoscale=1 pwm_autograd=1 PWM_REG=8 PWM_LIM=12
PWM_SCALE:  00000021 PWM_SCALE_SUM=33
PWM_AUTO:   000e0024 PWM_OFS_AUTO=36 PWM_GRAD_AUTO=14

Here's the one at the end:

DUMP_TMC extruder
========== Write-only registers ==========
IHOLD_IRUN: 00081919 IHOLD=25 IRUN=25 IHOLDDELAY=8
TPOWERDOWN: 00000014 TPOWERDOWN=20
========== Queried registers ==========
GCONF:      00000101 I_scale_analog=1(ExtVREF) multistep_filt=1
GSTAT:      00000003 reset=1 drv_err=1(ErrorShutdown!)
IFCNT:      00000000
OTP_READ:   00000010 OTP_FCLKTRIM=16
IOIN@TMC220x: 2000034d ENN=1 MS1=1 MS2=1 PDN_UART=1 SEL_A=1(TMC220x) DIR=1 VERSION=0x20
FACTORY_CONF: 00000010 FCLKTRIM=16
TSTEP:      000fffff TSTEP=1048575
MSCNT:      00000238 MSCNT=568
MSCURACT:   011701ac CUR_A=-84 CUR_B=-233
CHOPCONF:   14010053 toff=3 hstrt=5 TBL=2 MRES=4(16usteps) intpol=1
DRV_STATUS: c01e0000 CS_ACTUAL=30 stealth=1 stst=1
PWMCONF:    c80d0e24 PWM_OFS=36 PWM_GRAD=14 pwm_freq=1 pwm_autoscale=1 pwm_autograd=1 PWM_REG=8 PWM_LIM=12
PWM_SCALE:  00000023 PWM_SCALE_SUM=35
PWM_AUTO:   00190023 PWM_OFS_AUTO=35 PWM_GRAD_AUTO=25

I verified that all other steppers return the same GCONF value (00000101).

Then I stopped klipper, powered off the printer, unplugged the USB connection to make sure everything shuts down, then plugged USB back in, powered the printer on, and restarted klipper and sure enough, the output of all steppers now looks like this:

DUMP_TMC extruder
========== Write-only registers ==========
IHOLD_IRUN: 00081919 IHOLD=25 IRUN=25 IHOLDDELAY=8
TPOWERDOWN: 00000014 TPOWERDOWN=20
========== Queried registers ==========
GCONF:      000001c4 en_spreadCycle=1 pdn_disable=1 mstep_reg_select=1 multistep_filt=1
GSTAT:      00000001 reset=1
IFCNT:      00000005 IFCNT=5
OTP_READ:   00000010 OTP_FCLKTRIM=16
IOIN@TMC220x: 2000014d ENN=1 MS1=1 MS2=1 PDN_UART=1 SEL_A=1(TMC220x) VERSION=0x20
FACTORY_CONF: 00000010 FCLKTRIM=16
TSTEP:      000fffff TSTEP=1048575
MSCNT:      00000008 MSCNT=8
MSCURACT:   00f7000c CUR_A=12 CUR_B=247
CHOPCONF:   14030053 toff=3 hstrt=5 TBL=2 vsense=1 MRES=4(16usteps) intpol=1
DRV_STATUS: 80190000 CS_ACTUAL=25 stst=1
PWMCONF:    c80d0e24 PWM_OFS=36 PWM_GRAD=14 pwm_freq=1 pwm_autoscale=1 pwm_autograd=1 PWM_REG=8 PWM_LIM=12
PWM_SCALE:  0000001d PWM_SCALE_SUM=29
PWM_AUTO:   000e0024 PWM_OFS_AUTO=36 PWM_GRAD_AUTO=14

I will keep an eye on the GCONF value and will try to observe if/how/when it changes. I'll report back with my findings, thanks so far for the help!

[lekv]

After observing this for a while, I think that the stepper gets into that state after powering on the printer without doing a firmware restart (board is always on through raspberry pi). The GCONF value shows 00000101, and restarting the firmware gets it back to the known good 000001c4. With that I can prevent this issue by restarting the firmware every time I power on the printer.

I think it would be good to either automate this (detect a broken config in Klipper, then restart it, or refuse to start a print), or at least warn about it. I think it would also be good to add it to FAQ. It's unfortunate that the prints would still start and even succeed most of the times, and only fail sometimes.

@KevinOConnor - Thanks for the help! Let me know if you prefer any of the suggestions and I'll try to implement it or send a PR to add to the FAQ.

[KevinOConnor]

Okay - it sounds like this issue is solved then. As mentioned at the start of this issue, it is not valid to remove motor power from TMC drivers.

-Kevin

[lekv]

I agree, thanks again for helping me sort this out. Would you like me to send a PR with an entry to the FAQ to make this stand out for people? Looks like #1797 could be similar, I'll leave a comment there pointing here for now.

[KevinOConnor]

Documentation would be helpful. FWIW, I think maybe a new docs/TMC_Drivers.md with overall info on the configuration of Trinamic drivers may be easier for users than an entry in the FAQ.

-Kevin

[KevinOConnor]

Okay, lets close this issue as it appears a solution was found for the original problem.

-Kevin