search

Klipper3d / klipper

Klipper is a 3d-printer firmware
GNU General Public License v3.0
9.4k stars 5.3k forks source link

communications dropouts #5216

Closed tommorox2345 closed 2 years ago

tommorox2345 commented 2 years ago

so i have been enjoing klipper for a few months now with no issues whatsoever and all of a sudden i get the issue of printing fine until it just randomly looses communication with the mcu. creality 4.2.7 board and a pi 4 4gb. the text below is 2 snippets of the log when it goes wrong

i have heard it can be power related but i am running the official pi power supply so i dont believe thats the case

things i have tried: new cable increased pi cooling increased mainboard cooling restarted everything

im all ears if anyone has a suggestion

Stats 96219.8: gcodein=456845 mcu: mcu_awake=0.021 mcu_task_avg=0.000036 mcu_task_stddev=0.000033 bytes_write=1295804 bytes_read=195540 bytes_retransmit=9 bytes_invalid=0 send_seq=22755 receive_seq=22755 retransmit_seq=2 srtt=0.002 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=11609 freq=72000291 heater_bed: target=110 temp=110.0 pwm=0.627 sysload=0.26 cputime=1719.914 memavail=3103360 print_time=753.796 buffer_time=0.000 print_stall=0 extruder: target=260 temp=259.8 pwm=0.591 Stats 96220.8: gcodein=456845 mcu: mcu_awake=0.021 mcu_task_avg=0.000036 mcu_task_stddev=0.000033 bytes_write=1295804 bytes_read=195540 bytes_retransmit=9 bytes_invalid=0 send_seq=22755 receive_seq=22755 retransmit_seq=2 srtt=0.002 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=11610 freq=72000291 heater_bed: target=110 temp=110.0 pwm=0.627 sysload=0.26 cputime=1719.916 memavail=3102580 print_time=753.796 buffer_time=0.000 print_stall=0 extruder: target=260 temp=259.8 pwm=0.591 Stats 96221.8: gcodein=456901 mcu: mcu_awake=0.021 mcu_task_avg=0.000036 mcu_task_stddev=0.000033 bytes_write=1295804 bytes_read=195540 bytes_retransmit=9 bytes_invalid=0 send_seq=22755 receive_seq=22755 retransmit_seq=2 srtt=0.002 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=11611 freq=72000291 heater_bed: target=110 temp=110.0 pwm=0.627 sysload=0.26 cputime=1719.919 memavail=3102964 print_time=753.796 buffer_time=0.000 print_stall=0 extruder: target=260 temp=259.8 pwm=0.591 Lost communication with MCU 'mcu' Once the underlying issue is corrected, use the "FIRMWARE_RESTART" command to reset the firmware, reload the config, and restart the host software. Printer is shutdown

Read 95780.181291: 'N12514 G1 X140.662 Y49.256 E0.3678585\n' Read 95780.183910: 'N12515 G1 X142.259 Y50.854 E0.4447894\n' Read 95780.186527: 'N12516 G1 X142.259 Y51.45 E0.46506110\n' Read 95780.189127: 'N12517 G1 X140.277 Y49.467 E0.5605594\n' Read 95780.191773: 'N12518 G1 X139.851 Y49.636 E0.5761687\n' Read 95780.194961: 'N12519 G1 X142.26 Y52.045 E0.6921699\n' Read 95780.198528: 'N12520 G1 X142.26 Y52.641 E0.71244101\n' Read 95780.201254: 'N12521 G1 X139.415 Y49.796 E0.8494593\n' Read 95780.203865: 'N12522 G1 X138.903 Y49.88 E0.867181\n' Read 95780.206470: 'N12523 G1 X142.26 Y53.237 E1.02875111\n' gcode state: absolute_coord=True absolute_extrude=True base_position=[0.0, 0.0, 0.0, 742.7718800000002] last_position=[142.26, 53.237, 1.0, 743.8006300000002] homing_position=[0.0, 0.0, 0.0, 0.0] speed_factor=0.0166666666667 extrude_factor=1.0 speed=130.267235 Reactor garbage collection: (95408.422541298, 0.0, 0.0) Stats 95780.3: gcodein=445395 mcu: mcu_awake=0.021 mcu_task_avg=0.000036 mcu_task_stddev=0.000033 bytes_write=1295804 bytes_read=195540 bytes_retransmit=9 bytes_invalid=0 send_seq=22755 receive_seq=22755 retransmit_seq=2 srtt=0.002 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=10806 freq=72000291 heater_bed: target=110 temp=110.0 pwm=0.627 sysload=0.35 cputime=1718.473 memavail=3110540 print_time=753.776 buffer_time=2.583 print_stall=0 extruder: target=260 temp=259.8 pwm=0.591 Lost communication with MCU 'mcu' Once the underlying issue is corrected, use the "FIRMWARE_RESTART" command to reset the firmware, reload the config, and restart the host software. Printer is shutdown

Flo-Kra commented 2 years ago

I have exactly the same issue since I updated Klipper and switched from Octoprint to Moonraker/Mainsail some weeks ago.

Some prints work fine, and then occasionally i get a Klipper shutdown error - log file see below. Sometimes it happened after some minutes, sometimes after many hours of printing. 


Got EOF when reading from device
...
Timeout with MCU 'mcu' (eventtime=22619.089863)
Transition to shutdown state: Lost communication with MCU 'mcu'

For me it looks like the MCU firmware hangs up or resets for some reason. I also had to restart the entire system in some (not all) cases as the USB serial port was gone, so no firmware restart possible any more. I tried different good quality USB cables, improved RPi cooling, but all with no success. I don´t suspect it is caused by an USB port reset from RPi side as the webcam still works when the issue occurs.

Used Klipper for 3 months with Octo and had no such problems ever. Not a single unexpected lost print in that time. I don´t know exactly which build i had, but since I started with Klipper in october 21 it must have been release v0.10.0 or a commit shortly after. Before that I have been using the printer with Octoprint and Marlin firmware for a year - without any USB/MCU connectivity issues.

My printer and system:

First time the error occured with v0.10.0-237 (28b568a6). Updated Klipper/Klippy to v0.10.0-244 (15ffa859) but got the same issue (from my perception more often since then, but I am not sure).

I will now try again with v0.10.0 (2a964a46), both MCU and Klippy, hoping that it will then work as before. I am relatively sure that it is not caused by Moonraker, nor Mainsail, even given that with Octoprint the approach is very different because it doesn´t use virtual SD card as Moonraker/Mainsail does. Anyhow, the log messages don´t point in that direction.

There is only one more thing that changed: I did not compile the initially used Klipper version with advanced settings for the initial pin states, as I didn´t know about this possibility until I realized that on an emergency stop my extruder fan stopped spinning. But I think this is also not the root cause as this does nothing but initializing/setting some GPIOs on MCU startup.

klippy.log:


Stats 6620.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000175 mcu_task_stddev=0.000173 bytes_write=740593 bytes_read=436265 bytes_retransmit=9 bytes_invalid=0 send_seq=26956 receive_seq=26955 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000214 heater_bed: target=65 temp=65.0 pwm=0.333 sd_pos=80803 sysload=0.52 cputime=91.768 memavail=3490716 print_time=2977.715 buffer_time=3.468 print_stall=0 extruder: target=200 temp=199.8 pwm=0.481
Stats 6621.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000175 mcu_task_stddev=0.000173 bytes_write=740692 bytes_read=436409 bytes_retransmit=9 bytes_invalid=0 send_seq=26963 receive_seq=26962 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=14 stalled_bytes=0 freq=16000214 heater_bed: target=65 temp=65.0 pwm=0.113 sd_pos=80803 sysload=0.52 cputime=91.795 memavail=3490540 print_time=2977.715 buffer_time=2.467 print_stall=0 extruder: target=200 temp=199.8 pwm=0.483
Stats 6622.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000175 mcu_task_stddev=0.000173 bytes_write=741416 bytes_read=436618 bytes_retransmit=9 bytes_invalid=0 send_seq=26983 receive_seq=26982 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.386 sd_pos=80869 sysload=0.52 cputime=91.829 memavail=3490604 print_time=2980.567 buffer_time=4.318 print_stall=0 extruder: target=200 temp=199.9 pwm=0.422
Stats 6623.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000167 mcu_task_stddev=0.000167 bytes_write=741520 bytes_read=436763 bytes_retransmit=9 bytes_invalid=0 send_seq=26990 receive_seq=26989 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000214 heater_bed: target=65 temp=65.0 pwm=0.267 sd_pos=80869 sysload=0.47 cputime=91.856 memavail=3490632 print_time=2980.567 buffer_time=3.317 print_stall=0 extruder: target=200 temp=199.9 pwm=0.409
Stats 6624.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000167 mcu_task_stddev=0.000167 bytes_write=741624 bytes_read=436907 bytes_retransmit=9 bytes_invalid=0 send_seq=26997 receive_seq=26996 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000214 heater_bed: target=65 temp=65.0 pwm=0.235 sd_pos=80869 sysload=0.47 cputime=91.886 memavail=3490612 print_time=2980.567 buffer_time=2.315 print_stall=0 extruder: target=200 temp=200.1 pwm=0.345
Stats 6625.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000167 mcu_task_stddev=0.000167 bytes_write=742308 bytes_read=437106 bytes_retransmit=9 bytes_invalid=0 send_seq=27015 receive_seq=27014 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000214 heater_bed: target=65 temp=65.0 pwm=0.380 sd_pos=80935 sysload=0.47 cputime=91.912 memavail=3490640 print_time=2983.442 buffer_time=4.189 print_stall=0 extruder: target=200 temp=200.1 pwm=0.323
Stats 6626.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000167 mcu_task_stddev=0.000167 bytes_write=742421 bytes_read=437241 bytes_retransmit=9 bytes_invalid=0 send_seq=27023 receive_seq=27022 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=5 stalled_bytes=0 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.286 sd_pos=80935 sysload=0.47 cputime=91.939 memavail=3490620 print_time=2983.442 buffer_time=3.187 print_stall=0 extruder: target=200 temp=200.1 pwm=0.379
Stats 6627.7: gcodein=0 mcu: mcu_awake=0.027 mcu_task_avg=0.000167 mcu_task_stddev=0.000167 bytes_write=742536 bytes_read=437390 bytes_retransmit=9 bytes_invalid=0 send_seq=27031 receive_seq=27030 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.305 sd_pos=80935 sysload=0.47 cputime=91.970 memavail=3490444 print_time=2983.442 buffer_time=2.186 print_stall=0 extruder: target=200 temp=200.2 pwm=0.291
Stats 6628.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743211 bytes_read=437594 bytes_retransmit=9 bytes_invalid=0 send_seq=27047 receive_seq=27046 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=5 stalled_bytes=0 freq=16000212 heater_bed: target=65 temp=65.0 pwm=0.032 sd_pos=81001 sysload=0.44 cputime=92.004 memavail=3490708 print_time=2986.340 buffer_time=4.082 print_stall=0 extruder: target=200 temp=200.0 pwm=0.424
Stats 6629.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743301 bytes_read=437724 bytes_retransmit=9 bytes_invalid=0 send_seq=27054 receive_seq=27053 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000212 heater_bed: target=65 temp=64.9 pwm=0.378 sd_pos=81001 sysload=0.44 cputime=92.033 memavail=3490956 print_time=2986.340 buffer_time=3.080 print_stall=0 extruder: target=200 temp=200.2 pwm=0.325
Stats 6630.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743398 bytes_read=437863 bytes_retransmit=9 bytes_invalid=0 send_seq=27060 receive_seq=27059 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=9 stalled_bytes=0 freq=16000212 heater_bed: target=65 temp=65.0 pwm=0.296 sd_pos=81001 sysload=0.44 cputime=92.062 memavail=3491016 print_time=2986.340 buffer_time=2.079 print_stall=0 extruder: target=200 temp=200.0 pwm=0.495
Got EOF when reading from device
Stats 6631.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=35 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296 sd_pos=81066 sysload=0.44 cputime=92.095 memavail=3490948 print_time=2989.261 buffer_time=3.998 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6632.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=54 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296 sd_pos=81066 sysload=0.44 cputime=92.117 memavail=3490820 print_time=2989.261 buffer_time=2.997 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6633.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=73 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296 sd_pos=81066 sysload=0.40 cputime=92.141 memavail=3490968 print_time=2989.261 buffer_time=1.995 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6634.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=616 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296 sd_pos=81131 sysload=0.40 cputime=92.164 memavail=3490396 print_time=2992.204 buffer_time=3.938 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Timeout with MCU 'mcu' (eventtime=6635.760490)
Transition to shutdown state: Lost communication with MCU 'mcu'
Dumping gcode input 0 blocks
Dumping 20 requests for client 3041826976
Received 3853.793046: {"id": 2799110736, "method": "gcode/help", "params": {}}
Received 3853.801123: {"id": 2797417616, "method": "info", "params": {}}
Received 3853.823031: {"id": 2797398192, "method": "objects/query", "params": {"objects": {"bed_mesh": null, "configfile": null, "display_status": null, "extruder": null, "fan": null, "gcode_move": null, "heater_bed": null, "idle_timeout": null, "pause_resume": null, "print_stats": null, "toolhead": null, "virtual_sdcard": null, "webhooks": null}}}
Received 3853.988880: {"id": 2807796336, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "toolhead": ["position", "print_time", "homed_axes"], "extruder": null, "heater_bed": null, "fan": ["speed"], "display_status": null, "idle_timeout": ["state"], "virtual_sdcard": ["progress", "is_active", "file_position"], "print_stats": null, "filament_switch_sensor FilamentSensor": null, "heater_fan extruder_fan": null, "controller_fan controller_fan": null, "output_pin LIGHT": null, "pause_resume": null}, "response_template": {"method": "process_status_update"}}}
Received 3853.988880: {"id": 2797367952, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "toolhead": ["position", "print_time", "homed_axes"], "extruder": null, "heater_bed": null, "fan": ["speed"], "display_status": null, "idle_timeout": ["state"], "virtual_sdcard": ["progress", "is_active", "file_position"], "print_stats": null, "filament_switch_sensor FilamentSensor": null, "heater_fan extruder_fan": null, "controller_fan controller_fan": null, "output_pin LIGHT": null, "pause_resume": null}, "response_template": {"method": "process_status_update"}}}
Received 3853.991578: {"id": 2799020336, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "toolhead": null, "extruder": null, "heater_bed": null, "fan": null, "display_status": null, "idle_timeout": null, "virtual_sdcard": null, "print_stats": null, "filament_switch_sensor FilamentSensor": null, "heater_fan extruder_fan": null, "controller_fan controller_fan": null, "output_pin LIGHT": null, "pause_resume": null, "configfile": null, "mcu": null, "gcode_macro HELLO_WORLD": null, "output_pin _beeper": null, "gcode_macro M300": null, "gcode_macro M280": null, "gcode_macro G29": null, "gcode_macro HOME_CENTER_BLTOUCH": null, "gcode_macro _SHUTDOWN_SYSTEM": null, "gcode_macro _REBOOT_SYSTEM": null, "gcode_macro _setlightlevel": null, "gcode_macro LIGHT_TOGGLE": null, "gcode_macro LIGHT_ON": null, "gcode_macro LIGHT_DIM_50": null, "gcode_macro LIGHT_DIM_25": null, "gcode_macro LIGHT_DIM_10": null, "gcode_macro LIGHT_DIM_MAX": null, "gcode_macro LIGHT_OFF": null, "gcode_macro M355": null, "gcode_macro M600": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro SCREWS_TILT_CALC": null, "gcode_move": null, "bed_mesh": null, "heaters": null, "probe": null, "motion_report": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}
Received 3854.006297: {"id": 2799021744, "method": "objects/query", "params": {"objects": {"configfile": null}}}
Received 3854.252685: {"id": 2807672304, "method": "list_endpoints", "params": {}}
Received 3854.260510: {"id": 2807763792, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "toolhead": null, "extruder": null, "heater_bed": null, "fan": null, "display_status": null, "idle_timeout": null, "virtual_sdcard": null, "print_stats": null, "filament_switch_sensor FilamentSensor": null, "heater_fan extruder_fan": null, "controller_fan controller_fan": null, "output_pin LIGHT": null, "pause_resume": null, "configfile": null, "mcu": null, "gcode_macro HELLO_WORLD": null, "output_pin _beeper": null, "gcode_macro M300": null, "gcode_macro M280": null, "gcode_macro G29": null, "gcode_macro HOME_CENTER_BLTOUCH": null, "gcode_macro _SHUTDOWN_SYSTEM": null, "gcode_macro _REBOOT_SYSTEM": null, "gcode_macro _setlightlevel": null, "gcode_macro LIGHT_TOGGLE": null, "gcode_macro LIGHT_ON": null, "gcode_macro LIGHT_DIM_50": null, "gcode_macro LIGHT_DIM_25": null, "gcode_macro LIGHT_DIM_10": null, "gcode_macro LIGHT_DIM_MAX": null, "gcode_macro LIGHT_OFF": null, "gcode_macro M355": null, "gcode_macro M600": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro SCREWS_TILT_CALC": null, "gcode_move": null, "bed_mesh": null, "heaters": null, "probe": null, "motion_report": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}
Received 3854.269551: {"id": 2807765872, "method": "objects/query", "params": {"objects": {"bed_mesh": null, "configfile": null, "display_status": null, "extruder": null, "fan": null, "gcode_move": null, "heater_bed": null, "idle_timeout": null, "pause_resume": null, "print_stats": null, "toolhead": null, "virtual_sdcard": null, "webhooks": null, "controller_fan controller_fan": null, "heater_fan extruder_fan": null}}}
Received 3854.593789: {"id": 2797386576, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "toolhead": null, "extruder": null, "heater_bed": null, "fan": null, "display_status": null, "idle_timeout": null, "virtual_sdcard": null, "print_stats": null, "filament_switch_sensor FilamentSensor": null, "heater_fan extruder_fan": null, "controller_fan controller_fan": null, "output_pin LIGHT": null, "pause_resume": null, "configfile": null, "mcu": null, "gcode_macro HELLO_WORLD": null, "output_pin _beeper": null, "gcode_macro M300": null, "gcode_macro M280": null, "gcode_macro G29": null, "gcode_macro HOME_CENTER_BLTOUCH": null, "gcode_macro _SHUTDOWN_SYSTEM": null, "gcode_macro _REBOOT_SYSTEM": null, "gcode_macro _setlightlevel": null, "gcode_macro LIGHT_TOGGLE": null, "gcode_macro LIGHT_ON": null, "gcode_macro LIGHT_DIM_50": null, "gcode_macro LIGHT_DIM_25": null, "gcode_macro LIGHT_DIM_10": null, "gcode_macro LIGHT_DIM_MAX": null, "gcode_macro LIGHT_OFF": null, "gcode_macro M355": null, "gcode_macro M600": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro SCREWS_TILT_CALC": null, "gcode_move": null, "bed_mesh": null, "heaters": null, "probe": null, "motion_report": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}
Received 3855.165864: {"id": 2797345136, "method": "info", "params": {}}
Received 3903.641800: {"id": 2797343728, "method": "gcode/script", "params": {"script": "SET_HEATER_TEMPERATURE HEATER=extruder TARGET=200"}}
Received 3903.643591: {"id": 2797345808, "method": "gcode/script", "params": {"script": "SET_HEATER_TEMPERATURE HEATER=heater_bed TARGET=60"}}
Received 3994.686417: {"id": 2797344976, "method": "objects/query", "params": {"objects": {"print_stats": null}}}
Received 3994.916176: {"id": 2807756016, "method": "info", "params": {}}
Received 3994.916176: {"id": 2797445744, "method": "objects/list", "params": {}}
Received 3994.918603: {"id": 2797446608, "method": "gcode/help", "params": {}}
Received 3995.107766: {"id": 2807669072, "method": "objects/subscribe", "params": {"objects": {"webhooks": null, "toolhead": null, "extruder": null, "heater_bed": null, "fan": null, "display_status": null, "idle_timeout": null, "virtual_sdcard": null, "print_stats": null, "filament_switch_sensor FilamentSensor": null, "heater_fan extruder_fan": null, "controller_fan controller_fan": null, "output_pin LIGHT": null, "pause_resume": null, "bed_mesh": null, "configfile": null, "gcode_move": null, "mcu": null, "gcode_macro HELLO_WORLD": null, "output_pin _beeper": null, "gcode_macro M300": null, "gcode_macro M280": null, "gcode_macro G29": null, "gcode_macro HOME_CENTER_BLTOUCH": null, "gcode_macro _SHUTDOWN_SYSTEM": null, "gcode_macro _REBOOT_SYSTEM": null, "gcode_macro _setlightlevel": null, "gcode_macro LIGHT_TOGGLE": null, "gcode_macro LIGHT_ON": null, "gcode_macro LIGHT_DIM_50": null, "gcode_macro LIGHT_DIM_25": null, "gcode_macro LIGHT_DIM_10": null, "gcode_macro LIGHT_DIM_MAX": null, "gcode_macro LIGHT_OFF": null, "gcode_macro M355": null, "gcode_macro M600": null, "gcode_macro CANCEL_PRINT": null, "gcode_macro PAUSE": null, "gcode_macro RESUME": null, "gcode_macro SCREWS_TILT_CALC": null, "heaters": null, "probe": null, "motion_report": null, "query_endstops": null, "system_stats": null}, "response_template": {"method": "process_status_update"}}}
Received 4009.755007: {"id": 2797397616, "method": "gcode/script", "params": {"script": "SDCARD_PRINT_FILE FILENAME=\"CCR10S_Aufsatzbox Unterteil.gcode\""}}
gcode state: absolute_coord=True absolute_extrude=True base_position=[0.0, 0.0, 0.0, 30.0] last_position=[202.185, 185.308, 0.4, 2621.65765] homing_position=[0.0, 0.0, 0.0, 0.0] speed_factor=0.0166666666667 extrude_factor=1.0 speed=35.0
Virtual sdcard (80107): '40.20832\nG0 F9900 X202.185 Y193.793\nG1 F2100 X138.065 Y257.914 E2543.22436\nG0 F9900 X137.499 Y257.914\nG1 F2100 X202.185 Y193.228 E2546.26699\nG0 F9900 X202.185 Y192.662\nG1 F2100 X136.934 Y257.914 E2549.33622\nG0 F9900 X136.368 Y257.914\nG1 F2100 X202.185 Y192.096 E2552.43207\nG0 F9900 X202.185 Y191.531\nG1 F2100 X135.802 Y257.914 E2555.55452\nG0 F9900 X135.237 Y257.914\nG1 F2100 X202.185 Y190.965 E2558.70358\nG0 F9900 X202.185 Y190.399\nG1 F2100 X134.671 Y257.914 E2561.87925\nG0 F9900 X134.105 Y257.914\nG1 F2100 X202.185 Y189.834 E2565.08152\nG0 F9900 X202.185 Y189.268\nG1 F2100 X133.539 Y257.914 E2568.31042\nG0 F9900 X132.974 Y257.914\nG1 F2100 X202.185 Y188.702 E2571.56592\nG0 F9900 X202.185 Y188.137\nG1 F2100 X132.408 Y257.914 E2574.84802\nG0 F9900 X131.842 Y257.914\nG1 F2100 X202.185 Y187.571 E2578.15673\nG0 F9900 X202.185 Y187.005\nG1 F2100 X131.277 Y257.914 E2581.49205\nG0 F9900 X130.711 Y257.914\nG1 F2100 X202.185 Y186.44 E2584.85397\nG0 F9900 X202.185 Y185.874\nG1 F2100 X130.145 Y257.914 E2588.24251\nG0 F9900 X129.58 Y257.914\n'
Upcoming (81131): 'G1 F2100 X202.185 Y185.308 E2591.65765\nG0 F9900 X202.185 Y184.742\nG1 F2100 X129.014 Y257.914 E2595.09941\nG0 F9900 X128.448 Y257.'
Reactor garbage collection: (6614.339483687, 6488.956654576, 0.0)
Stats 6635.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=636 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296 sd_pos=81131 sysload=0.40 cputime=92.185 memavail=3490300 print_time=2992.204 buffer_time=2.936 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Exiting SD card print (position 81170)
Stats 6636.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=656 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.40 cputime=92.214 memavail=3489764 print_time=2992.204 buffer_time=1.934 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6637.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=803 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.40 cputime=92.237 memavail=3489716 print_time=2992.224 buffer_time=0.953 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6638.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=822 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.37 cputime=92.261 memavail=3489776 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6639.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=841 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.37 cputime=92.283 memavail=3489820 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6640.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=860 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.37 cputime=92.306 memavail=3489792 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6641.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=879 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.37 cputime=92.327 memavail=3489688 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6642.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=898 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.37 cputime=92.348 memavail=3489752 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6643.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=917 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.34 cputime=92.369 memavail=3489776 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6644.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=936 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.34 cputime=92.390 memavail=3489672 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6645.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=955 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.34 cputime=92.411 memavail=3489620 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6646.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=974 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.34 cputime=92.433 memavail=3489612 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6647.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=993 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.34 cputime=92.456 memavail=3489580 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6648.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1012 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.31 cputime=92.478 memavail=3489624 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6649.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1033 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.31 cputime=92.500 memavail=3489992 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6650.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1052 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.31 cputime=92.521 memavail=3490092 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6651.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1071 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.31 cputime=92.543 memavail=3490052 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6652.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1090 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.31 cputime=92.565 memavail=3490112 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6653.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1109 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.29 cputime=92.587 memavail=3490008 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6654.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1128 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.29 cputime=92.609 memavail=3490036 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6655.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1147 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.29 cputime=92.632 memavail=3489988 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6656.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1166 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.29 cputime=92.653 memavail=3490132 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6657.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1185 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.29 cputime=92.676 memavail=3489812 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6658.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1204 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.26 cputime=92.700 memavail=3489864 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Stats 6659.8: gcodein=0 mcu: mcu_awake=0.021 mcu_task_avg=0.000150 mcu_task_stddev=0.000142 bytes_write=743908 bytes_read=437943 bytes_retransmit=9 bytes_invalid=0 send_seq=27070 receive_seq=27070 retransmit_seq=2 srtt=0.003 rttvar=0.000 rto=0.025 ready_bytes=58 stalled_bytes=1223 freq=16000213 heater_bed: target=65 temp=65.0 pwm=0.296  sysload=0.26 cputime=92.724 memavail=3490060 print_time=2992.224 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.1 pwm=0.358
Sineos commented 2 years ago

Github is not the intended place for such a support request. Please open a topic on https://klipper.discourse.group and post your respective klippy.log files showing the issue.

github-actions[bot] commented 2 years ago

It looks like this ticket is a request for help (or similar). Many helpful people will not see your message here and you are unlikely to get a useful response. Instead, see the contact directions at: https://www.klipper3d.org/Contact.html

We use github to share the results of work done to improve Klipper. We don't use github for requests. (In particular, we don't use github for feature requests, to answer questions, nor to help diagnose problems with a printer.)

Please follow the directions at: https://www.klipper3d.org/Contact.html

This ticket will be automatically closed.

Best regards, ~ Your friendly GitIssueBot

PS: I'm just an automated script, not a human being.

Flo-Kra commented 2 years ago

Github is not the intended place for such a support request. Please open a topic on https://klipper.discourse.group and post your respective klippy.log files showing the issue.

I can´t speak for the one who initially opened this issue, but my intention was NOT to get support, but as I stated, after analyzing the problem and trying many possible solutions without success, I think it is a bug that leads to stability issues in the AVR firmware. So opening an issue on github (or in this case commenting to an existing one stating the very same problem) was the obvious next step for me. I wrote what I have tried to avoid people thinking this is a support request. :-/

Sineos commented 2 years ago

The general philosophy taken here is to discuss such topics on Discourse and determine if it is a bug, a configuration issue or some hardware issue. In any case a full and unmodified klippy.log showing the issue is needed for further analysis.

On the other hand, if you have already analyzed the behavior and found a bug in the code, then Github is the right place to point it out and to go into the discussion of a potential solution strategy.

Flo-Kra commented 2 years ago

OK I see. I couldn´t track the issue down to an actual bug, so you´re right, I should have asked in the support forum first, but I thought it´s possibly a known bug as someone else had already opened an issue here describing the exact same behaviour.

Lets see - debugging someone else´s code you´ve never worked on is hard, especially on Arduino and when you have an intermittent error that can´t really be reproduced, as you don´t really know what exactly is triggering it... Unfortunately there is really not much in the log that gives me a clue on where to look precisely. As it worked well for me before updating I am now testing with v0.10.0 release tagged commit and unchanged configuration to see if it works as it did before. Will start a discussion on Discourse as you told me as soon as I know more, if needed.

Thank you for your support so far.