Sudden MCU Shutdown During Print

General Discussion
1

Basic Information:

Printer Model: Modded Ender 3 Max
MCU / Printerboard: BTT SKR E3 Mini V3
klippy.zip (4.4 MB)

Describe your issue:

I let my printer run overnight, to find it halted mid-print in the morning. Tried to find the error in the log, but couldn’t make sense of it this time. The only thing I noticed in the log was that these lines:

Stats 130848.1: gcodein=27  mcu: mcu_awake=0.083 mcu_task_avg=0.000043 mcu_task_stddev=0.000056 bytes_write=38506225 bytes_read=5049971 bytes_retransmit=9 bytes_invalid=0 send_seq=653160 receive_seq=653160 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=15 upcoming_bytes=6716 freq=64001024 sd_pos=4794813 heater_bed: target=60 temp=60.0 pwm=0.312 sysload=0.17 cputime=531.214 memavail=2646392 print_time=5936.987 buffer_time=2.051 print_stall=0 extruder: target=225 temp=225.1 pwm=0.772
Stats 130849.1: gcodein=27  mcu: mcu_awake=0.083 mcu_task_avg=0.000043 mcu_task_stddev=0.000056 bytes_write=38506225 bytes_read=5049971 bytes_retransmit=9 bytes_invalid=0 send_seq=653160 receive_seq=653160 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=15 upcoming_bytes=9501 freq=64001024 sd_pos=4794842 heater_bed: target=0 temp=60.0 pwm=0.312 sysload=0.17 cputime=531.225 memavail=2642748 print_time=5938.065 buffer_time=2.129 print_stall=0 extruder: target=0 temp=225.1 pwm=0.772

These are the lines before the error section. The temp. targets go from 225/60 to 0/0. Could this be it, and why?

As this is the second time the print halts during the same print and I am not very experienced with klippy logs, I was hoping that the kind people of this forum would help me troubleshoot. :slight_smile:

Thanks in advance!

2

On which basis did you decide, which parts of the log are “unnecessary”?
Post a complete klippy.log and we will have a look.

3

On the basis that this was the only error present in the log and that the file was 50 MB. But for the sake of completeness, I have replaced the old log with a zip file, containing the whole thing. My apologies and thank you!

4

Your log in inconclusive as to what error you are reporting, since there are quite a few.
In addition you are using unofficial modifications to the original Klipper that may or may not contribute to your issues.

Most likely the error that killed your print is:

b'Got EOF when reading from device'
Stats 6255.1: gcodein=0  mcu: mcu_awake=0.002 mcu_task_avg=0.000011 mcu_task_stddev=0.000010 bytes_write=25248848 bytes_read=3708161 bytes_retransmit=9 bytes_invalid=0 send_seq=434526 receive_seq=434526 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=63999891  heater_bed: target=0 temp=50.0 pwm=0.000 sysload=0.29 cputime=287.389 memavail=2652776 print_time=5248.318 buffer_time=0.000 print_stall=8 extruder: target=0 temp=77.5 pwm=0.000
Stats 6256.1: gcodein=0  mcu: mcu_awake=0.002 mcu_task_avg=0.000011 mcu_task_stddev=0.000010 bytes_write=25248848 bytes_read=3708161 bytes_retransmit=9 bytes_invalid=0 send_seq=434526 receive_seq=434526 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=1 freq=63999891  heater_bed: target=0 temp=50.0 pwm=0.000 sysload=0.29 cputime=287.394 memavail=2653812 print_time=5248.318 buffer_time=0.000 print_stall=8 extruder: target=0 temp=77.5 pwm=0.000
Stats 6257.1: gcodein=0  mcu: mcu_awake=0.002 mcu_task_avg=0.000011 mcu_task_stddev=0.000010 bytes_write=25248848 bytes_read=3708161 bytes_retransmit=9 bytes_invalid=0 send_seq=434526 receive_seq=434526 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=2 freq=63999891  heater_bed: target=0 temp=50.0 pwm=0.000 sysload=0.29 cputime=287.399 memavail=2653696 print_time=5248.318 buffer_time=0.000 print_stall=8 extruder: target=0 temp=77.5 pwm=0.000
Stats 6258.1: gcodein=0  mcu: mcu_awake=0.002 mcu_task_avg=0.000011 mcu_task_stddev=0.000010 bytes_write=25248848 bytes_read=3708161 bytes_retransmit=9 bytes_invalid=0 send_seq=434526 receive_seq=434526 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=3 freq=63999891  heater_bed: target=0 temp=50.0 pwm=0.000 sysload=0.29 cputime=287.404 memavail=2653444 print_time=5248.318 buffer_time=0.000 print_stall=8 extruder: target=0 temp=77.5 pwm=0.000
Stats 6259.1: gcodein=0  mcu: mcu_awake=0.002 mcu_task_avg=0.000011 mcu_task_stddev=0.000010 bytes_write=25248848 bytes_read=3708161 bytes_retransmit=9 bytes_invalid=0 send_seq=434526 receive_seq=434526 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=4 freq=63999891  heater_bed: target=0 temp=50.0 pwm=0.000 sysload=0.29 cputime=287.409 memavail=2652184 print_time=5248.318 buffer_time=0.000 print_stall=8 extruder: target=0 temp=77.5 pwm=0.000
Timeout with MCU 'mcu' (eventtime=6260.132126)
Transition to shutdown state: Lost communication with MCU 'mcu'

See Timeout with MCU / Lost communication with MCU

5

Thank you for your quick reply.

I am not aware of me having modified original Klipper…? How would I go about checking this?

image
image954×1172 82.2 KB

The only thing that I have modified here is the “Line_purge.cfg”, which I changed some gcode lines on, to fit my needs.

All in all, it comes down to a “simple” MCU timeout then? I will have to investigate. Except for the link you sent, do you have any more advice on what I can do?

Cheers.

6

From your log:

Git version: 'v0.12.0-25-g99d7af87-dirty'
Untracked files: klippy/extras/autotune_tmc.py, klippy/extras/motor_constants.py
Branch: master
Remote: origin

Config files should always go into the same folder as your printer.cfg and never in the Klipper program directory.

Yes, but unfortunately, hunting down this one can be tricky. In all cases I know it is hardware related.

7

Alright then. I thank you for your time and commitment!

8

If I can just borrow your expertise once again:

Printed something again just now, and same thing. Checked the klippy.log and found this section right before it shutdown:

Stats 124287.0: gcodein=27  mcu: mcu_awake=0.106 mcu_task_avg=0.000043 mcu_task_stddev=0.000055 bytes_write=62825823 bytes_read=7804481 bytes_retransmit=1746 bytes_invalid=0 send_seq=1058521 receive_seq=1058521 retransmit_seq=1047348 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=21 upcoming_bytes=20796 freq=63999883 sd_pos=1993485 heater_bed: target=65 temp=65.1 pwm=0.133 sysload=0.38 cputime=555.351 memavail=2604684 print_time=8226.477 buffer_time=2.269 print_stall=1 extruder: target=210 temp=209.9 pwm=0.717
Stats 124288.0: gcodein=27  mcu: mcu_awake=0.106 mcu_task_avg=0.000043 mcu_task_stddev=0.000055 bytes_write=62825823 bytes_read=7804481 bytes_retransmit=1746 bytes_invalid=0 send_seq=1058521 receive_seq=1058521 retransmit_seq=1047348 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=21 upcoming_bytes=22301 freq=63999883 sd_pos=1993505 heater_bed: target=0 temp=65.1 pwm=0.133 sysload=0.35 cputime=555.359 memavail=2604452 print_time=8227.310 buffer_time=2.100 print_stall=1 extruder: target=0 temp=209.9 pwm=0.717
Stats 124289.0: gcodein=27  mcu: mcu_awake=0.106 mcu_task_avg=0.000043 mcu_task_stddev=0.000055 bytes_write=62825823 bytes_read=7804481 bytes_retransmit=1746 bytes_invalid=0 send_seq=1058521 receive_seq=1058521 retransmit_seq=1047348 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=21 upcoming_bytes=22303 freq=63999883 sd_pos=1993505 heater_bed: target=0 temp=65.1 pwm=0.133 sysload=0.35 cputime=555.368 memavail=2604228 print_time=8227.310 buffer_time=1.100 print_stall=1 extruder: target=0 temp=209.9 pwm=0.717
Timeout with MCU 'mcu' (eventtime=124290.005940)
Transition to shutdown state: Lost communication with MCU 'mcu'
Write g-code response
Traceback (most recent call last):
  File "/home/klipper/klipper/klippy/gcode.py", line 459, in _respond_raw
    os.write(self.fd, (msg+"\n").encode())
BlockingIOError: [Errno 11] Resource temporarily unavailable
Dumping gcode input 4 blocks
Read 124286.746823: 'RESTART\r\n'
Read 124286.752692: 'RESTART'
Read 124286.752816: '\r\n'
Read 124286.753495: 'RESTART\r\n'
Dumping 20 requests for client 139693978475856
Received 124085.991505: b'{"id": 140299877570240, "method": "objects/query", "params": {"objects": {"virtual_sdcard": null, "print_stats": null, "gcode_move": null}}}'
Received 124086.242136: b'{"id": 140299877565920, "method": "objects/query", "params": {"objects": {"print_stats": null, "gcode_move": null}}}'
Received 124147.892866: b'{"id": 140299877567648, "method": "objects/query", "params": {"objects": {"print_stats": null}}}'
Received 124147.975478: b'{"id": 140299877565104, "method": "objects/query", "params": {"objects": {"print_stats": null}}}'
Received 124148.226369: b'{"id": 140299877577680, "method": "objects/query", "params": {"objects": {"virtual_sdcard": null, "print_stats": null, "gcode_move": null}}}'
Received 124148.479678: b'{"id": 140299877564720, "method": "objects/query", "params": {"objects": {"print_stats": null, "gcode_move": null}}}'
Received 124161.277679: b'{"id": 140299877567888, "method": "gcode/script", "params": {"script": "SET_PRESSURE_ADVANCE EXTRUDER=extruder ADVANCE=0.2"}}'
Received 124210.798065: b'{"id": 140299877570720, "method": "objects/query", "params": {"objects": {"print_stats": null}}}'
Received 124210.959210: b'{"id": 140299877568320, "method": "objects/query", "params": {"objects": {"print_stats": null}}}'
Received 124211.213681: b'{"id": 140299877570864, "method": "objects/query", "params": {"objects": {"virtual_sdcard": null, "print_stats": null, "gcode_move": null}}}'
Received 124211.460330: b'{"id": 140299877565632, "method": "objects/query", "params": {"objects": {"print_stats": null, "gcode_move": null}}}'
Received 124273.170546: b'{"id": 140299877568176, "method": "objects/query", "params": {"objects": {"print_stats": null}}}'
Received 124273.414928: b'{"id": 140299877571776, "method": "objects/query", "params": {"objects": {"print_stats": null}}}'
Received 124273.666238: b'{"id": 140299877574608, "method": "objects/query", "params": {"objects": {"virtual_sdcard": null, "print_stats": null, "gcode_move": null}}}'
Received 124273.916609: b'{"id": 140299877569088, "method": "objects/query", "params": {"objects": {"print_stats": null, "gcode_move": null}}}'
Received 124276.969991: b'{"id": 140299877569904, "method": "info", "params": {}}'
Received 124276.969991: b'{"id": 140299877573600, "method": "objects/list", "params": {}}'
Received 124276.970649: b'{"id": 140299877570864, "method": "gcode/help", "params": {}}'
Received 124277.013146: b'{"id": 140299877576912, "method": "objects/subscribe", "params": {"objects": {"gcode": null, "webhooks": null, "configfile": null, "mcu": null, "gcode_move": null, "probe": null, "bed_mesh": null, "display_status": null, "print_stats": null, "virtual_sdcard": null, "pause_resume": null, "stepper_enable": null, "tmc2209 stepper_x": null, "tmc2209 stepper_y": null, "tmc2209 stepper_z": null, "tmc2209 extruder": null, "firmware_retraction": null, "heaters": null, "heater_bed": null, "fan": null, "heater_fan Heater_fan": null, "temperature_fan Mainboard_Fan": null, "exclude_object": null, "idle_timeout": null, "screws_tilt_adjust": null, "gcode_macro BED_MESH_CALIBRATE": null, "gcode_macro LINE_PURGE": null, "gcode_macro SMART_PARK": null, "gcode_macro _KAMP_Settings": null, "gcode_macro START_PRINT": null, "gcode_macro END_PRINT": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro G28": null, "gcode_macro G28.2": null, "gcode_macro BED_TRAMMING": null, "gcode_macro Level_Gantry_Check": null, "gcode_macro Probe_test": null, "gcode_macro Z_Offset_Setup": null, "gcode_macro PID_EXTRUDER": null, "gcode_macro PID_BED": null, "gcode_macro MECHANICAL_GANTRY_CALIBRATION": null, "gcode_macro Remove_Filament": null, "gcode_macro Insert_Filament": null, "gcode_macro M600": null, "gcode_macro M600.1": null, "gcode_macro M204": null, "gcode_macro POWER_ON": null, "gcode_macro POWER_OFF": null, "gcode_macro TEST_SPEED": null, "gcode_macro _TOOLHEAD_PARK_PAUSE_CANCEL": null, "motion_report": null, "query_endstops": null, "system_stats": null, "manual_probe": null, "toolhead": null, "extruder": null, "history": null}, "response_template": {"method": "process_status_update"}}}'
Received 124277.930900: b'{"id": 140299877575232, "method": "objects/query", "params": {"objects": {"extruder": ["can_extrude"]}}}'
gcode state: absolute_coord=True absolute_extrude=True base_position=[0.0, 0.0, -0.02, 16551.31159999832] last_position=[122.436, 97.364, 15.68, 16551.31159999832] homing_position=[0.0, 0.0, -0.02, 0.0] speed_factor=0.016666666666666666 extrude_factor=1.0 speed=500.0
Virtual sdcard (1992481): 'L=6500 ACCEL_TO_DECEL=3250\nG1 X99.1 Y127.3 F30000\nSET_VELOCITY_LIMIT ACCEL=3400 ACCEL_TO_DECEL=1700\n;TYPE:Inner wall\nG1 F11847.498\nG1 X93.7 Y127.3 E3.27163\nG1 X93.7 Y121.9 E3.52177\nG1 X99.1 Y121.9 E3.7719\nG1 X99.1 Y127.27 E4.02065\nSET_VELOCITY_LIMIT ACCEL=6500 ACCEL_TO_DECEL=3250\n;WIPE_START\nG1 F2400\nG1 X98.8 Y127.272 E2.22065\n;WIPE_END\nG92 E0\nG1 X98.8 Y127.364 F30000\nG1 X98.967 Y121.836\nG1 X99.164 Y97.364\nG1 X99.7 Y97.9\nG1 E1.8 F2100\nSET_VELOCITY_LIMIT ACCEL=3400 ACCEL_TO_DECEL=1700\n;TYPE:Outer wall\nG1 F11847.498\nG1 X93.1 Y97.9 E2.10572\nG1 X93.1 Y91.3 E2.41144\nG1 X99.7 Y91.3 E2.71716\nG1 X99.7 Y97.87 E3.02149\nSET_VELOCITY_LIMIT ACCEL=6500 ACCEL_TO_DECEL=3250\nG1 X99.1 Y97.3 F30000\nSET_VELOCITY_LIMIT ACCEL=3400 ACCEL_TO_DECEL=1700\n;TYPE:Inner wall\nG1 F11847.498\nG1 X93.7 Y97.3 E3.27163\nG1 X93.7 Y91.9 E3.52176\nG1 X99.1 Y91.9 E3.7719\nG1 X99.1 Y97.27 E4.02065\nSET_VELOCITY_LIMIT ACCEL=6500 ACCEL_TO_DECEL=3250\n;WIPE_START\nG1 F2400\nG1 X98.8 Y97.272 E2.22065\n;WIPE_END\nG92 E0\nG1 X98.8 Y97.364 F30000\nG1 X122.436 Y97.364\n'
Upcoming (1993505): 'G1 X121.9 Y97.9\nG1 E1.8 F2100\nSET_VELOCITY_LIMIT ACCEL=3400 ACCEL_TO_DECEL=1700\n;TYPE:Outer wall\nG1 F11847.498\nG1 X121.9 Y91.3 E'
Reactor garbage collection: (124222.243508969, 123263.47254245, 0.0)
Stats 124290.0: gcodein=27  mcu: mcu_awake=0.106 mcu_task_avg=0.000043 mcu_task_stddev=0.000055 bytes_write=62825823 bytes_read=7804481 bytes_retransmit=1746 bytes_invalid=0 send_seq=1058521 receive_seq=1058521 retransmit_seq=1047348 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=21 upcoming_bytes=22304 freq=63999883 sd_pos=1993505 heater_bed: target=0 temp=65.1 pwm=0.133 sysload=0.35 cputime=555.376 memavail=2604228 print_time=8227.310 buffer_time=0.099 print_stall=1 extruder: target=0 temp=209.9 pwm=0.717
webhooks client 139693978475856: Disconnected
Restarting printer
Start printer at Wed Dec 13 20:20:18 2023 (1702495218.4 124291.1)

Here is the new log attached: klippy.zip (909.3 KB)

9

Might be a cabling issue if there is such a sudden loss of the MCU.
What USB cable are you using? A good and as short as possible one?

10

At first, I was using the cable that came with my SKR E3 Mini V3, which was working fine until this happened. I ordered a new 1 m cable from a PZOZ which was also working fine, until yesterday. Maybe it’s the port on the printer’s motherboard?

11

What is your host system?

12

It’s an old laptop running Linux Mint (Ubuntu 22.04).
CPU: Intel Core i5 - Haswell 4th gen with integrated graphics
RAM: 4 GB DDR3
SSD: 128 GB (40 GB free)

Need to know anything else?

13

You might want to try something like a Raspberry Pi at least in the short term.

If you’re going to run with a laptop, you’re going to have to make sure that you understand all the processes running in the system and ensure there’s no way anything can preempt Klipper (which can cause a MCU shutdown because the host system is off doing something else).

Sorry, I don’t think there’s a good guide to configuring a Linux PC to run Klipper on.

14

Hmm, I went this route as: 1. it was sitting collecting dust and 2. it is really difficult to find a Raspberry Pi that isn’t first gen or scalper-priced in Sweden.

Thank you all for the help I’ve received so far!

15

Can you try to get something like BTT CB1:

It’s basically the same as the rPi but a little trickier in getting the network setup (once that’s done it’s identical to a Raspberry Pi).

I wish I had a better answer for you.

16

Personally, I would see no issue in running the Klipper host on a Laptop.

There are enough reports of the same error in conjunction with SBCs / RPis and IMO this error is not host related but hardware related and this make it so elusive.

As detailed in the KB article:

  • Use a good quality USB cable
  • Check your USB port if the cable is properly seated. To my experience, often the printer board side wonky
  • Remove other USB devices to avoid them interfering with the USB communication
  • Use a different port on the Laptop
  • Check dmesg if there are any USB / hardware related errors
  • Check all cables on the printer board for proper seating. Often cables start breaking in the JST connectors, screw terminals become loose because no proper ferrules are used etc
  • Fully heat nozzle and bed and start some printing. Now measure the voltage at your printer boards’ input: Is it stable? Is it 24V? Does it drop occasionally?
  • Inspect all wiring in the printer, especially on the print head. Breakage can occur there by movement etc. Often not really visible because insulation is still intact

Unfortunately, this stupid error has no “sprinkle magic dust on the board and print happily thereafter” solution

17

I’ve been running Klipper on my main laptop for weeks now. With the exception of disabling the auto-sleep when idle, I didn’t do anything special to the OS.

I’m running an openSUSE Leap 15.5 with XFCE and everything works like a charm. And the OS is packed with IDEs, various Docker containers running in the background, even a few pesky Electron apps (for video calls and chat). And when I’ve checked the graphs before deleting the logs, everything looked normal, as far as I could tell.

P.S. At first I played around with process scheduling, but I’ve reverted that scheduling change after some words from Piezo and Sineos.

L.E. And I’ve tripped over the USB cable a couple of times while it was printing, the print continued without any hiccups.

18

I tried, yet again, to print something today, after uninstalling Autotune_TMC and updating Klipper, and this time I got a Timer to close error…

Would it be worth a shot to factory reset Ubuntu on the laptop? The only thing running on it is Klipper. While I’m at it, is Ubuntu the optimal choice for Klipper, or is there a lighter Linux variant?

19

Ok, this is quite strange.
Timer too close in fact is more software related, while to my best knowledge Timeout with MCU / Lost communication with MCU is mainly hardware related.
Please provide a new klippy.log showing the error.

If it is not an ancient laptop that is below the performance of a RPi 3 then it should work. An overloaded host (CPU or memory) can be diagnosed in the klippy.log. See Advanced Trouble-Shooting / Graphing Klipper

20

I know @Sineos has his thoughts on this but I’ve watched multiple people struggle with using PCs and things simply resolve when they go to a Raspberry Pi or clone (note that the Creality Sonic Pad should not be considered as it has some pretty significant issues).

Sorry it’s difficult and expensive to you get a Raspberry Pi but maybe one of the clones will be easy to get and affordable.