MCU 'mcu' shutdown:

[engineer-50]

Basic Information:

Printer Model: Retrofitted Guider 2
MCU / Printerboard: MKS SKIPR + MKS THR36 via CAN
Host / SBC: On board (MKS SKIPR)
klippy.log
klippy.log (4.4 MB)

Fill out above information and in all cases attach your klippy.log file (use zip to compress it, if too big). Pasting your printer.cfg is not needed
Be sure to check our “Knowledge Base” Category first. Most relevant items, e.g. error messages, are covered there

Describe your issue:

I had the printer working just fine, printing parts. Was running the same print that had just finished for the 3rd time, and got the following:

klipper has shutdown MCU 'mcu' shutdown: Missed scheduling of next digital out event. This is generally indicative of an intermittent communication failure between micro-controller and host.

After searching the web and reading some similar posts I decided to do an update (klipper + fluidd + mainsail + klipper screen). The update was successful, but it didn’t solve the problem. In fact I am getting intermittently either the above error or the following:

MCU 'mcu' shutdown: Timer too close This often indicates the host computer is overloaded. Check for other processes consuming excessive CPU time, high swap usage, disk errors, overheating, unstable voltage, or similar system problems on the host computer.

This is a 5 (or so) hour print and the error occurs in the first 30-50 minutes. I am using Orca slicer. I did slice an arbitrary part, 1:20 hours long print, and ran it once and it did finish with no error.

On this printer I have already replaced the CAN cable with a proper shielded one, I grounded it at the printerboard side, crimped all wires and connected properly.

Please help with this. I am not a Linux nor programmer person, so please be gentle.

Thanks!!!

[mykepredko]

Thank you for starting a new thread here.

Going over your klippy.log, the first order of business is that your version of Klipper is “dirty”:

Starting Klippy...
Args: ['/home/mks/klipper/klippy/klippy.py', '/home/mks/printer_data/config/printer.cfg', '-I', '/home/mks/printer_data/comms/klippy.serial', '-l', '/home/mks/printer_data/logs/klippy.log', '-a', '/home/mks/printer_data/comms/klippy.sock']
Git version: 'v0.12.0-379-gf2e69a370-dirty'

The first order of business is to go to the “MACHINE” page in your Mainsail web page and do updates to get rid of the “dirty” status.

Then run again and see if the problem persists.

I should point out that this is a “Timer Too Close” error. If, after getting rid of the “dirty” status problems persist, then read through and look for situations that affect your printer:

Timer too close

Background A “Timer too close” error occurs when the MCU attempts to schedule a timer for a target time that is in the past. It almost always occurs as a result of a message from the host requesting an action at a time that is now in the past. It is important to understand that Klipper essentially knows which command was scheduled in the past, but not why it happened. For example, a message is delayed because the webcam is blocking the USB port: The message contains a command whose target time …

[engineer-50]

Hi,

Thank you for your response! Actually I did a complete update of everything apart of “system”. Why? Because I have a custom Armbian build (not by me), that allows me to use a physical button to power off the machine - when the host shuts down it sends a signal to a gpio pin which I then use to turn off a relay. I noticed that if I do a system update I then have 2 problems: klipper screen stops working (just black screen) and the power off function stops working. So I reverted back to the original image and did update all but “system”.

I also noticed, by the way, that if I changed the CAN bitrate, the above functions stopped working.

[mykepredko]

Sorry, this is confusing. Can you explain exactly what the status of the printer is right now?

Is it what I saw with the posted klippy.log?

If so, then follow the instructions above, first clear out the “dirty” warning and then run to test if the problem persists. If it does, look through the Knowledge Base article.

[engineer-50]

@mykepredko

Is it what I saw with the posted klippy.log?

Basically, yes, but since you asked it made me hesitant as to whether that was the correct log LOL. I will reset the log and start a print and will upload a new log.

[engineer-50]

klippy0112_A.log (1.6 MB)
This is a fresh log. 20 minutes into the print, it crashed. I still can see the “dirty” inthere, but here us the update status (just refreshed it and seems that klipper has a new version since my last update a couple of days ago):

[engineer-50]

Updated klipper to the latest:

But the log still says “dirty”

[engineer-50]

I fully updated it:

But it still says “dirty”:

Starting Klippy...
Args: ['/home/mks/klipper/klippy/klippy.py', '/home/mks/printer_data/config/printer.cfg', '-I', '/home/mks/printer_data/comms/klippy.serial', '-l', '/home/mks/printer_data/logs/klippy.log', '-a', '/home/mks/printer_data/comms/klippy.sock']
Git version: 'v0.12.0-391-g2165c9001-dirty'

And as usual this did break the screen again, which just stays off now. And the power off doesn’t work anymore. Will have to revert to previous image again.

[mykepredko]

Can you create a new OS image and start again (save your printer.cfg before doing this)?

You have something fundamentally wrong with the OS and that needs to be fixed (and is probably the cause of the issues).

Where are you getting the OS image that you are using?

[engineer-50]

@mykepredko

Where are you getting the OS image that you are using?

The image was created by a guy over on discord. As I said, the uniqueness of this image is that it enables me to shutdown the printer from a physical button. I have a shutdown macro which is being executed when I press the physical button, then when the host shuts down, it changes the state of a gpio pin, which I am using with a relay board to then cut power to the printer.

Being not a Linux person, I have no idea how this image was created and how it actually does what it does, but I really love the functionality and I specifically designed this printer as such, so wouldn’t want to sacrifice it. It had been working just fine for an extended period of time, so I know it’s not something fundamentally wrong with the image that cannot work.

[mykepredko]

Sorry. The only thing I can suggest is to go back to the guy on Discord.

It appears that you were given a modified version of Klipper along with the OS image and we really can’t support you here.

[engineer-50]

Hmm… Ok, will do that.
Have you ever encountered a an OS image that does what I described or know how to create one like this?

[mykepredko]

I have no idea - I’ve played around with the SKIPR but not in any kind of depth.

Sorry. I wish I had a better answer for you.

[engineer-50]

So with the help of that guy I was able to get rid of the “dirty” flag. But the problem still persists.
Here is the log after the recent crash:
klippy0212_A.log (2.9 MB)

Any ideas?

[mykepredko]

Looking at your klippy.log (thank you for that), the last two print attempts ended in “Timer Too Close”.

Timer too close

Background A “Timer too close” error occurs when the MCU attempts to schedule a timer for a target time that is in the past. It almost always occurs as a result of a message from the host requesting an action at a time that is now in the past. It is important to understand that Klipper essentially knows which command was scheduled in the past, but not why it happened. For example, a message is delayed because the webcam is blocking the USB port: The message contains a command whose target time …

You’re pretty aggressive when it comes to microsteps (which adds to the workload on the MCU).

My suggestion would be to lower the microsteps to 16 for all your steppers and see if you can run without getting “Timer Too Close” errors. If that seems to be the problem them increase them to 32 and then 64 to see if that is the cause of your problem.

If not, we’ll discuss next steps.

[engineer-50]

OK, thanks. Will do and report back. Although, shouldn’t the load be reflected on the monitoring screen:

[mykepredko]

I don’t know for sure (somebody with more knowledge of the internals of Klipper could answer this) but I suspect that the load does go up when the problem happens.

If you look at your klippy.log, you can see where one of the “Timer Too Close” events takes place by what happens with the “bytes_retransmit” value and how it climbs:

toolhead: max_velocity: 200.000000
max_accel: 5000.000000
minimum_cruise_ratio: 0.500000
square_corner_velocity: 10.000000
Stats 3175.8: gcodein=0  mcu: mcu_awake=0.023 mcu_task_avg=0.000008 mcu_task_stddev=0.000013 bytes_write=1133639 bytes_read=717668 bytes_retransmit=160 bytes_invalid=0 send_seq=38254 receive_seq=38254 retransmit_seq=29552 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=3 upcoming_bytes=0 freq=168004562 MKS_THR: mcu_awake=0.003 mcu_task_avg=0.000011 mcu_task_stddev=0.000018 bytes_write=415076 bytes_read=348904 bytes_retransmit=112 bytes_invalid=0 send_seq=17068 receive_seq=17068 retransmit_seq=14353 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=56 upcoming_bytes=0 freq=12048566 adj=12048313 rpi: mcu_awake=0.000 mcu_task_avg=0.000008 mcu_task_stddev=0.000013 bytes_write=10425 bytes_read=34239 bytes_retransmit=0 bytes_invalid=0 send_seq=1710 receive_seq=1710 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=50000688 adj=49999407 MCU: temp=34.6 heater_bed: target=70 temp=70.2 pwm=0.221 chamber: target=0 temp=28.9 pwm=0.000 sd_pos=96683 sysload=0.19 cputime=185.484 memavail=638856 print_time=1577.462 buffer_time=2.589 print_stall=0 extruder: target=230 temp=229.7 pwm=0.271
Stats 3176.8: gcodein=0  mcu: mcu_awake=0.023 mcu_task_avg=0.000008 mcu_task_stddev=0.000013 bytes_write=1135426 bytes_read=718094 bytes_retransmit=160 bytes_invalid=0 send_seq=38292 receive_seq=38289 retransmit_seq=29552 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=876 upcoming_bytes=0 freq=168004560 MKS_THR: mcu_awake=0.004 mcu_task_avg=0.000011 mcu_task_stddev=0.000018 bytes_write=415514 bytes_read=349046 bytes_retransmit=112 bytes_invalid=0 send_seq=17076 receive_seq=17073 retransmit_seq=14353 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=215 upcoming_bytes=0 freq=12048567 adj=12048321 rpi: mcu_awake=0.000 mcu_task_avg=0.000009 mcu_task_stddev=0.000015 bytes_write=10431 bytes_read=34268 bytes_retransmit=0 bytes_invalid=0 send_seq=1711 receive_seq=1711 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=50000688 adj=49999416 MCU: temp=34.5 heater_bed: target=70 temp=70.0 pwm=0.617 chamber: target=0 temp=28.8 pwm=0.000 sd_pos=97100 sysload=0.19 cputime=185.651 memavail=638856 print_time=1578.307 buffer_time=2.432 print_stall=0 extruder: target=230 temp=229.7 pwm=0.271
Stats 3177.8: gcodein=0  mcu: mcu_awake=0.023 mcu_task_avg=0.000008 mcu_task_stddev=0.000013 bytes_write=1137335 bytes_read=718520 bytes_retransmit=900 bytes_invalid=0 send_seq=38327 receive_seq=38324 retransmit_seq=38327 srtt=0.001 rttvar=0.001 rto=0.400 ready_bytes=739 upcoming_bytes=1336 freq=168004555 MKS_THR: mcu_awake=0.004 mcu_task_avg=0.000011 mcu_task_stddev=0.000018 bytes_write=416136 bytes_read=349151 bytes_retransmit=852 bytes_invalid=0 send_seq=17087 receive_seq=17084 retransmit_seq=17087 srtt=0.002 rttvar=0.002 rto=0.400 ready_bytes=343 upcoming_bytes=658 freq=12048567 adj=12048327 rpi: mcu_awake=0.000 mcu_task_avg=0.000009 mcu_task_stddev=0.000015 bytes_write=10437 bytes_read=34284 bytes_retransmit=0 bytes_invalid=0 send_seq=1712 receive_seq=1712 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=50000687 adj=49999419 MCU: temp=34.5 heater_bed: target=70 temp=70.1 pwm=0.263 chamber: target=0 temp=29.1 pwm=0.000 sd_pos=97435 sysload=0.25 cputime=185.745 memavail=638856 print_time=1579.002 buffer_time=2.126 print_stall=0 extruder: target=230 temp=229.6 pwm=0.271
Stats 3178.8: gcodein=0  mcu: mcu_awake=0.023 mcu_task_avg=0.000008 mcu_task_stddev=0.000013 bytes_write=1137335 bytes_read=718696 bytes_retransmit=1085 bytes_invalid=0 send_seq=38327 receive_seq=38324 retransmit_seq=38327 srtt=0.001 rttvar=0.001 rto=0.800 ready_bytes=739 upcoming_bytes=4026 freq=168004555 MKS_THR: mcu_awake=0.004 mcu_task_avg=0.000011 mcu_task_stddev=0.000018 bytes_write=416136 bytes_read=349151 bytes_retransmit=1037 bytes_invalid=0 send_seq=17087 receive_seq=17084 retransmit_seq=17087 srtt=0.002 rttvar=0.002 rto=0.800 ready_bytes=343 upcoming_bytes=2028 freq=12048567 adj=12048331 rpi: mcu_awake=0.000 mcu_task_avg=0.000009 mcu_task_stddev=0.000015 bytes_write=10443 bytes_read=34300 bytes_retransmit=0 bytes_invalid=0 send_seq=1713 receive_seq=1713 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=50000692 adj=49999422 MCU: temp=34.5 heater_bed: target=70 temp=70.2 pwm=0.144 chamber: target=0 temp=29.0 pwm=0.000 sd_pos=97770 sysload=0.25 cputime=185.867 memavail=638856 print_time=1580.003 buffer_time=2.127 print_stall=0 extruder: target=230 temp=229.6 pwm=0.271
Stats 3179.8: gcodein=0  mcu: mcu_awake=0.023 mcu_task_avg=0.000008 mcu_task_stddev=0.000013 bytes_write=1137335 bytes_read=718828 bytes_retransmit=1270 bytes_invalid=0 send_seq=38327 receive_seq=38324 retransmit_seq=38327 srtt=0.001 rttvar=0.001 rto=1.600 ready_bytes=739 upcoming_bytes=6641 freq=168004555 MKS_THR: mcu_awake=0.004 mcu_task_avg=0.000011 mcu_task_stddev=0.000018 bytes_write=416136 bytes_read=349151 bytes_retransmit=1222 bytes_invalid=0 send_seq=17087 receive_seq=17084 retransmit_seq=17087 srtt=0.002 rttvar=0.002 rto=1.600 ready_bytes=343 upcoming_bytes=3393 freq=12048567 adj=12048315 rpi: mcu_awake=0.000 mcu_task_avg=0.000009 mcu_task_stddev=0.000015 bytes_write=10449 bytes_read=34316 bytes_retransmit=0 bytes_invalid=0 send_seq=1714 receive_seq=1714 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=50000690 adj=49999462 MCU: temp=34.5 heater_bed: target=70 temp=70.2 pwm=0.000 chamber: target=0 temp=29.0 pwm=0.000 sd_pos=98105 sysload=0.25 cputime=185.948 memavail=638856 print_time=1581.307 buffer_time=2.430 print_stall=0 extruder: target=230 temp=229.6 pwm=0.271
Stats 3180.8: gcodein=0  mcu: mcu_awake=0.018 mcu_task_avg=0.000008 mcu_task_stddev=0.000012 bytes_write=1137335 bytes_read=718990 bytes_retransmit=1455 bytes_invalid=0 send_seq=38327 receive_seq=38324 retransmit_seq=38327 srtt=0.001 rttvar=0.001 rto=3.200 ready_bytes=739 upcoming_bytes=8512 freq=168004555 MKS_THR: mcu_awake=0.004 mcu_task_avg=0.000011 mcu_task_stddev=0.000018 bytes_write=416136 bytes_read=349151 bytes_retransmit=1407 bytes_invalid=0 send_seq=17087 receive_seq=17084 retransmit_seq=17087 srtt=0.002 rttvar=0.002 rto=3.200 ready_bytes=343 upcoming_bytes=4323 freq=12048567 adj=12048290 rpi: mcu_awake=0.000 mcu_task_avg=0.000009 mcu_task_stddev=0.000015 bytes_write=10455 bytes_read=34332 bytes_retransmit=0 bytes_invalid=0 send_seq=1715 receive_seq=1715 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=50000688 adj=49999405 MCU: temp=34.5 heater_bed: target=70 temp=70.1 pwm=0.062 chamber: target=0 temp=29.2 pwm=0.000 sd_pos=98328 sysload=0.25 cputime=186.061 memavail=638856 print_time=1582.345 buffer_time=2.466 print_stall=0 extruder: target=230 temp=229.6 pwm=0.271
Transition to shutdown state: MCU shutdown
Dumping gcode input 0 blocks
Dumping 20 requests for client 281473569538976
Received 1605.552658: b'{"id": 281472846572176, "method": "objects/subscribe", "params": {"objects": {"gcode": null, "webhooks": null, "configfile": null, "mcu": null, "mcu MKS_THR": null, "mcu rpi": null, "gcode_macro BED_MESH_CALIBRATE": null, "gcode_macro LINE_PURGE": null, "gcode_macro SMART_PARK": null, "gcode_macro _KAMP_Settings": null, "gcode_macro SHUTDOWN": null, "gcode_macro M300": null, "gcode_macro M141": null, "gcode_macro M191": null, "pause_resume": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PRINT_START": null, "gcode_macro G32": null, "heaters": null, "heater_fan hotend_fan": null, "fan": null, "stepper_enable": null, "tmc2208 extruder": null, "probe": null, "temperature_sensor Printhead MCU": null, "gcode_button poweroffbtn": null, "output_pin beeper": null, "tmc2208 stepper_x": null, "tmc2209 stepper_y": null, "tmc2208 stepper_z": null, "heater_bed": null, "heater_generic chamber": null, "heater_fan chamber_fan": null, "display_status": null, "neopixel fysetc_mini12864": null, "gcode_move": null, "print_stats": null, "virtual_sdcard": null, "firmware_retraction": null, "idle_timeout": null, "bed_mesh": null, "exclude_object": null, "gcode_macro SET_PAUSE_NEXT_LAYER": null, "gcode_macro SET_PAUSE_AT_LAYER": null, "gcode_macro SET_PRINT_STATS_INFO": null, "gcode_macro _TOOLHEAD_PARK_PAUSE_CANCEL": null, "gcode_macro _CLIENT_EXTRUDE": null, "gcode_macro _CLIENT_RETRACT": null, "gcode_macro LOAD_FILAMENT": null, "gcode_macro UNLOAD_FILAMENT": null, "filament_switch_sensor my_sensor": null, "motion_report": null, "query_endstops": null, "system_stats": null, "manual_probe": null, "toolhead": null, "extruder": null, "screws_tilt_adjust": ["results", "error"]}, "response_template": {"method": "process_status_update"}}}'
Received 1605.555011: b'{"id": 281472881594576, "method": "list_endpoints", "params": {}}'
Received 1605.804505: b'{"id": 281472846570880, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "print_stats": null, "bed_mesh": null, "configfile": null, "display_status": null, "fan": null, "gcode_move": null, "idle_timeout": null, "pause_resume": null, "toolhead": null, "virtual_sdcard": null, "firmware_retraction": null, "motion_report": null, "exclude_object": null, "manual_probe": null, "screws_tilt_adjust": ["results", "error"], "extruder": null, "heater_bed": null, "heater_generic chamber": null, "temperature_sensor Printhead MCU": null, "heater_fan hotend_fan": null, "heater_fan chamber_fan": null, "filament_switch_sensor my_sensor": null, "output_pin beeper": null, "neopixel fysetc_mini12864": null, "gcode": null, "mcu": null, "mcu MKS_THR": null, "mcu rpi": null, "gcode_macro BED_MESH_CALIBRATE": null, "gcode_macro LINE_PURGE": null, "gcode_macro SMART_PARK": null, "gcode_macro _KAMP_Settings": null, "gcode_macro SHUTDOWN": null, "gcode_macro M300": null, "gcode_macro M141": null, "gcode_macro M191": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PRINT_START": null, "gcode_macro G32": null, "heaters": null, "stepper_enable": null, "tmc2208 extruder": null, "probe": null, "gcode_button poweroffbtn": null, "tmc2208 stepper_x": null, "tmc2209 stepper_y": null, "tmc2208 stepper_z": null, "gcode_macro SET_PAUSE_NEXT_LAYER": null, "gcode_macro SET_PAUSE_AT_LAYER": null, "gcode_macro SET_PRINT_STATS_INFO": null, "gcode_macro _TOOLHEAD_PARK_PAUSE_CANCEL": null, "gcode_macro _CLIENT_EXTRUDE": null, "gcode_macro _CLIENT_RETRACT": null, "gcode_macro LOAD_FILAMENT": null, "gcode_macro UNLOAD_FILAMENT": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}'
Received 1606.048399: b'{"id": 281472882057568, "method": "objects/list", "params": {}}'
Received 1606.051112: b'{"id": 281472882057568, "method": "objects/query", "params": {"objects": {"configfile": null}}}'
Received 1606.291255: b'{"id": 281472855941712, "method": "register_remote_method", "params": {"response_template": {"method": "shutdown_machine"}, "remote_method": "shutdown_machine"}}'
Received 1606.295009: b'{"id": 281472855943680, "method": "register_remote_method", "params": {"response_template": {"method": "reboot_machine"}, "remote_method": "reboot_machine"}}'
Received 1606.298168: b'{"id": 281472882057568, "method": "register_remote_method", "params": {"response_template": {"method": "pause_job_queue"}, "remote_method": "pause_job_queue"}}'
Received 1606.300718: b'{"id": 281472882057568, "method": "register_remote_method", "params": {"response_template": {"method": "start_job_queue"}, "remote_method": "start_job_queue"}}'
Received 1606.307139: b'{"id": 281472846572320, "method": "objects/query", "params": {"objects": {"heaters": null}}}'
Received 1606.307691: b'{"id": 281472846570784, "method": "objects/query", "params": {"objects": {"heaters": null}}}'
Received 1606.336690: b'{"id": 281472846573472, "method": "objects/query", "params": {"objects": {"extruder": ["can_extrude"]}}}'
Received 1606.408810: b'{"id": 281472846571072, "method": "info", "params": {}}'
Received 1606.409698: b'{"id": 281472846323424, "method": "objects/list", "params": {}}'
Received 1606.409698: b'{"id": 281472846322752, "method": "gcode/help", "params": {}}'
Received 1606.460271: b'{"id": 281472846322752, "method": "objects/subscribe", "params": {"objects": {"gcode": null, "webhooks": null, "configfile": null, "mcu": null, "mcu MKS_THR": null, "mcu rpi": null, "gcode_macro BED_MESH_CALIBRATE": null, "gcode_macro LINE_PURGE": null, "gcode_macro SMART_PARK": null, "gcode_macro _KAMP_Settings": null, "gcode_macro SHUTDOWN": null, "gcode_macro M300": null, "gcode_macro M141": null, "gcode_macro M191": null, "pause_resume": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PRINT_START": null, "gcode_macro G32": null, "heaters": null, "heater_fan hotend_fan": null, "fan": null, "stepper_enable": null, "tmc2208 extruder": null, "probe": null, "temperature_sensor Printhead MCU": null, "gcode_button poweroffbtn": null, "output_pin beeper": null, "tmc2208 stepper_x": null, "tmc2209 stepper_y": null, "tmc2208 stepper_z": null, "heater_bed": null, "heater_generic chamber": null, "heater_fan chamber_fan": null, "display_status": null, "neopixel fysetc_mini12864": null, "gcode_move": null, "print_stats": null, "virtual_sdcard": null, "firmware_retraction": null, "idle_timeout": null, "bed_mesh": null, "exclude_object": null, "gcode_macro SET_PAUSE_NEXT_LAYER": null, "gcode_macro SET_PAUSE_AT_LAYER": null, "gcode_macro SET_PRINT_STATS_INFO": null, "gcode_macro _TOOLHEAD_PARK_PAUSE_CANCEL": null, "gcode_macro _CLIENT_EXTRUDE": null, "gcode_macro _CLIENT_RETRACT": null, "gcode_macro LOAD_FILAMENT": null, "gcode_macro UNLOAD_FILAMENT": null, "filament_switch_sensor my_sensor": null, "motion_report": null, "query_endstops": null, "system_stats": null, "manual_probe": null, "toolhead": null, "extruder": null, "screws_tilt_adjust": ["results", "error"]}, "response_template": {"method": "process_status_update"}}}'
Received 1606.555525: b'{"id": 281472846323088, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "print_stats": null, "temperature_sensor Printhead MCU": null, "heater_bed": null, "heater_generic chamber": null, "extruder": null, "bed_mesh": null, "configfile": null, "display_status": null, "fan": null, "gcode_move": null, "idle_timeout": null, "pause_resume": null, "toolhead": null, "virtual_sdcard": null, "firmware_retraction": null, "motion_report": null, "exclude_object": null, "manual_probe": null, "screws_tilt_adjust": ["results", "error"], "heater_fan hotend_fan": null, "heater_fan chamber_fan": null, "filament_switch_sensor my_sensor": null, "output_pin beeper": null, "neopixel fysetc_mini12864": null, "gcode": null, "mcu": null, "mcu MKS_THR": null, "mcu rpi": null, "gcode_macro BED_MESH_CALIBRATE": null, "gcode_macro LINE_PURGE": null, "gcode_macro SMART_PARK": null, "gcode_macro _KAMP_Settings": null, "gcode_macro SHUTDOWN": null, "gcode_macro M300": null, "gcode_macro M141": null, "gcode_macro M191": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PRINT_START": null, "gcode_macro G32": null, "heaters": null, "stepper_enable": null, "tmc2208 extruder": null, "probe": null, "gcode_button poweroffbtn": null, "tmc2208 stepper_x": null, "tmc2209 stepper_y": null, "tmc2208 stepper_z": null, "gcode_macro SET_PAUSE_NEXT_LAYER": null, "gcode_macro SET_PAUSE_AT_LAYER": null, "gcode_macro SET_PRINT_STATS_INFO": null, "gcode_macro _TOOLHEAD_PARK_PAUSE_CANCEL": null, "gcode_macro _CLIENT_EXTRUDE": null, "gcode_macro _CLIENT_RETRACT": null, "gcode_macro LOAD_FILAMENT": null, "gcode_macro UNLOAD_FILAMENT": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}'
Received 1606.800701: b'{"id": 281472846323616, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "print_stats": null, "temperature_sensor Printhead MCU": null, "heater_bed": null, "heater_generic chamber": null, "extruder": null, "bed_mesh": null, "configfile": null, "display_status": null, "fan": null, "gcode_move": null, "idle_timeout": null, "pause_resume": null, "toolhead": null, "virtual_sdcard": null, "firmware_retraction": null, "motion_report": null, "exclude_object": null, "manual_probe": null, "screws_tilt_adjust": ["results", "error"], "heater_fan hotend_fan": null, "heater_fan chamber_fan": null, "filament_switch_sensor my_sensor": null, "output_pin beeper": null, "neopixel fysetc_mini12864": null, "gcode": null, "mcu": null, "mcu MKS_THR": null, "mcu rpi": null, "gcode_macro BED_MESH_CALIBRATE": null, "gcode_macro LINE_PURGE": null, "gcode_macro SMART_PARK": null, "gcode_macro _KAMP_Settings": null, "gcode_macro SHUTDOWN": null, "gcode_macro M300": null, "gcode_macro M141": null, "gcode_macro M191": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PRINT_START": null, "gcode_macro G32": null, "heaters": null, "stepper_enable": null, "tmc2208 extruder": null, "probe": null, "gcode_button poweroffbtn": null, "tmc2208 stepper_x": null, "tmc2209 stepper_y": null, "tmc2208 stepper_z": null, "gcode_macro SET_PAUSE_NEXT_LAYER": null, "gcode_macro SET_PAUSE_AT_LAYER": null, "gcode_macro SET_PRINT_STATS_INFO": null, "gcode_macro _TOOLHEAD_PARK_PAUSE_CANCEL": null, "gcode_macro _CLIENT_EXTRUDE": null, "gcode_macro _CLIENT_RETRACT": null, "gcode_macro LOAD_FILAMENT": null, "gcode_macro UNLOAD_FILAMENT": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}'
Received 1607.057697: b'{"id": 281472846323472, "method": "objects/query", "params": {"objects": {"extruder": ["can_extrude"]}}}'
Received 1768.964960: b'{"id": 281472846323472, "method": "gcode/script", "params": {"script": "SDCARD_PRINT_FILE FILENAME=\\"CoverBox.gcode\\""}}'
Virtual sdcard (97304): '188 Y60.932 E.01783\nG1 X234.347 Y68.091 E.38563\nG1 X234.347 Y68.739 E.01783\nG1 X226.54 Y60.932 E.42053\nG1 X225.892 Y60.932 E.01783\nG1 X234.347 Y69.386 E.45543\nG1 X234.347 Y70.034 E.01783\nG1 X225.245 Y60.932 E.49033\nG1 X224.597 Y60.932 E.01783\nG1 X234.347 Y70.682 E.52523\nG1 X234.347 Y71.33 E.01783\nG1 X223.949 Y60.932 E.56013\nG1 X223.301 Y60.932 E.01783\nG1 X234.347 Y71.978 E.59503\nG1 X234.347 Y72.626 E.01783\nG1 X222.653 Y60.932 E.62993\nG1 X222.005 Y60.932 E.01783\nG1 X234.347 Y73.274 E.66483\nG1 X234.347 Y73.921 E.01783\nG1 X221.357 Y60.932 E.69973\nG1 X220.71 Y60.932 E.01783\nG1 X234.347 Y74.569 E.73463\nG1 X234.347 Y75.217 E.01783\nG1 X220.062 Y60.932 E.76953\nG1 X219.414 Y60.932 E.01783\nG1 X234.347 Y75.865 E.80443\nG1 X234.347 Y76.513 E.01783\nG1 X218.766 Y60.932 E.83932\nG1 X218.118 Y60.932 E.01783\nG1 X234.347 Y77.161 E.87422\nG1 X234.347 Y77.809 E.01783\nG1 X217.47 Y60.932 E.90912\nG1 X216.822 Y60.932 E.01783\nG1 X234.347 Y78.456 E.94402\nG1 X234.347 Y79.104 E.01783\nG1 X216.175 Y60.932 E.97892\nG1 X215.527 Y60.932 E.01783\n'
Upcoming (98328): 'G1 X234.347 Y79.752 E1.01382\nG1 X234.347 Y80.4 E.01783\nG1 X214.879 Y60.932 E1.04872\nG1 X214.231 Y60.932 E.01783\nG1 X234.347 Y81.'
gcode state: absolute_coord=True absolute_extrude=False base_position=[0.0, 0.0, 0.08246271022209753, 3851.4404194000263] last_position=[234.347, 79.752, 0.7824627102220975, 3926.665461700036] homing_position=[0.0, 0.0, 0.0, 0.0] speed_factor=0.016666666666666666 extrude_factor=0.97 speed=109.14574999999999
Reactor garbage collection: (1906.29566195, 1945.613862635, 0.0)
MCU 'mcu' shutdown: Timer too close

I’m suggesting that you lower the number of microsteps to 16 because it’s easy to do and often fixes the problem.

If it doesn’t solve your problem, then you will need to read through the Knowledge Base article on Timer Too Close I referenced above.

[engineer-50]

@mykepredko

ou can see where one of the “Timer Too Close” events takes place by what happens with the “bytes_retransmit” value and how it climbs

It climbs and then returns to ‘0’.

@mykepredko

I’m suggesting that you lower the number of microsteps to 16 because it’s easy to do and often fixes the problem.

Already set the microstepping to 16 and tested. It has just now failed - around 30 minutes into the print. This time with a different error though:

Lost communication with MCU 'mcu'

Attaching the log:
klippy0312_A.log (2.4 MB)

[mykepredko]

@engineer-50

@mykepredko

I’m suggesting that you lower the number of microsteps to 16 because it’s easy to do and often fixes the problem.

Already set the microstepping to 16 and tested. It has just now failed - around 30 minutes into the print. This time with a different error though:

Lost communication with MCU 'mcu'

Attaching the log:
klippy0312_A.log (2.4 MB)

Sorry, then I suggest you start going through the suggestions here:

Timer too close

Background A “Timer too close” error occurs when the MCU attempts to schedule a timer for a target time that is in the past. It almost always occurs as a result of a message from the host requesting an action at a time that is now in the past. It is important to understand that Klipper essentially knows which command was scheduled in the past, but not why it happened. For example, a message is delayed because the webcam is blocking the USB port: The message contains a command whose target time …

[engineer-50]

OK. Thanks.

EDIT:
But it is for “timer too close” event. My error is now different…