Klipper3d / klipper

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

Klipper shutting down shortly after boot on 2 different boards [Errno 16] #3219

Closed definitely-not-a-t-rex closed 4 years ago

definitely-not-a-t-rex commented 4 years ago

klippy.log Hi, I recently set up and started using klipper on my ender 5 pro using an skr 1.4 turbo but after a couple days of almost flawless prints (once calibrated pressure advance) it started not being able to boot for enough time to even home x/y and then z, looking through the log there seem to be many [Errno16] Unable to open port: [Errno 16] could not open port /dev/serial/by-id/, I thought it could be a board problem and since I have an skr 1.2 pro laying around I also tried it with that other board (after changing the config to one that would work for the pro and compiling the firmware for it using stm32f407 and 32kib bootloader) and it gives me the same result and that leads me to believe that the problem doesn't lie on the 1.4t but it probably depends probably on klipper. The log includes both boards with their config and all the errors. A typical episode of this is like this one:

Recv: // Klipper state: Ready
Send: M105
Recv: ok B:0.0 /0.0 T0:0.0 /0.0
Send: M105
Recv: ok B:29.7 /0.0 T0:37.4 /0.0
Send: M105
Recv: ok B:29.7 /0.0 T0:37.2 /0.0
Recv: // Klipper state: Shutdown

and what shows in the log after it resembles

Extruder max_extrude_ratio=0.266081
Starting serial connect
got {u'count': 247, '#receive_time': 4855.599921698, u'sum': 240761, u'sumsq': 1714225, '#name': u'stats', '#sent_time': 4855.560394402}
Loaded MCU 'mcu' 77 commands (v0.8.0-721-g560d48db-20200820_193026-raspberrypi / gcc: (15:7-2018-q2-6) 7.3.1 20180622 (release) [ARM/embedded-7-branch revision 261907] binutils: (2.31.1-11+rpi1+11) 2.31.1)
MCU 'mcu' config: BUS_PINS_i2c1=PB6,PB7 BUS_PINS_i2c2=PB10,PB11 BUS_PINS_spi3a=PC11,PC12,PC10 BUS_PINS_spi2a=PC2,PC3,PB10 STEP_DELAY=2 BUS_PINS_spi3=PB4,PB5,PB3 ADC_MAX=4095 RESERVE_PINS_crystal=PH0,PH1 CLOCK_FREQ=168000000 BUS_PINS_spi1=PA6,PA7,PA5 RESERVE_PINS_USB=PA11,PA12 MCU=stm32f407xx STATS_SUMSQ_BASE=256 BUS_PINS_spi1a=PB4,PB5,PB3 BUS_PINS_spi2=PB14,PB15,PB13
Sending MCU 'mcu' printer configuration...
Configured MCU 'mcu' (1024 moves)
Starting heater checks for heater_bed
Starting heater checks for extruder
Got error -1 in read: (11)Resource temporarily unavailable
Timeout with MCU 'mcu' (eventtime=4869.947329)
Transition to shutdown state: Lost communication with MCU 'mcu'
Dumping gcode input 3 blocks
Read 4855.584186: 'M105\n'
Read 4860.588053: 'M105\n'
Read 4865.596333: 'M105\n'
gcode state: absolute_coord=True absolute_extrude=True base_position=[0.0, 0.0, 0.0, 0.0] last_position=[0.0, 0.0, 0.0, 0.0] homing_position=[0.0, 0.0, 0.0, 0.0] speed_factor=0.0166666666667 extrude_factor=1.0 speed=25.0

or

Extruder max_extrude_ratio=0.266081
Starting serial connect
Unable to open port: [Errno 16] could not open port /dev/serial/by-id/usb-Klipper_lpc1769_1F20001722813AAFF63A6A5CC62000F5-if00: [Errno 16] Device or resource busy: '/dev/serial/by-id/usb-Klipper_lpc1769_1F20001722813AAFF63A6A5CC62000F5-if00'
Unable to open port: [Errno 16] could not open port /dev/serial/by-id/usb-Klipper_lpc1769_1F20001722813AAFF63A6A5CC62000F5-if00: [Errno 16] Device or resource busy: '/dev/serial/by-id/usb-Klipper_lpc1769_1F20001722813AAFF63A6A5CC62000F5-if00'
Loaded MCU 'mcu' 77 commands (v0.8.0-721-g560d48db-20200820_174702-raspberrypi / gcc: (15:7-2018-q2-6) 7.3.1 20180622 (release) [ARM/embedded-7-branch revision 261907] binutils: (2.31.1-11+rpi1+11) 2.31.1)
MCU 'mcu' config: BUS_PINS_i2c1=P0.1,P0.0 BUS_PINS_i2c0=P0.28,P0.27 BUS_PINS_i2c2=P0.11,P0.10 BUS_PINS_i2c1a=P0.20,P0.19 BUS_PINS_ssp1=P0.8,P0.9,P0.7 INITIAL_PINS=!P1.30 STEP_DELAY=2 ADC_MAX=4095 BUS_PINS_ssp0=P0.17,P0.18,P0.15 RESERVE_PINS_USB=P0.30,P0.29,P2.9 CLOCK_FREQ=120000000 MCU=lpc1769 STATS_SUMSQ_BASE=256
Sending MCU 'mcu' printer configuration...
Configured MCU 'mcu' (1024 moves)
Starting heater checks for heater_bed
Starting heater checks for extruder
Stats 1087.8: gcodein=71 mcu: mcu_awake=0.000 mcu_task_avg=0.000000 mcu_task_stddev=0.000000 bytes_write=4286 bytes_read=4622 bytes_retransmit=9 bytes_invalid=0 send_seq=221 receive_seq=206 retransmit_seq=2 srtt=0.003 rttvar=0.004 rto=0.025 ready_bytes=461 stalled_bytes=40 freq=120020670 heater_bed: target=0 temp=0.0 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=0.0 pwm=0.000 sysload=2.26 cputime=1.369 memavail=3338176
Stats 1088.8: gcodein=71 mcu: mcu_awake=0.000 mcu_task_avg=0.000000 mcu_task_stddev=0.000000 bytes_write=4882 bytes_read=4878 bytes_retransmit=9 bytes_invalid=0 send_seq=235 receive_seq=235 retransmit_seq=2 srtt=0.003 rttvar=0.004 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120005348 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.4 pwm=0.000 sysload=2.26 cputime=1.382 memavail=3388168
Stats 1089.8: gcodein=76 mcu: mcu_awake=0.000 mcu_task_avg=0.000000 mcu_task_stddev=0.000000 bytes_write=4888 bytes_read=4984 bytes_retransmit=9 bytes_invalid=0 send_seq=236 receive_seq=236 retransmit_seq=2 srtt=0.002 rttvar=0.003 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120004150 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.8 pwm=0.000 sysload=2.26 cputime=1.395 memavail=3388184
Stats 1090.8: gcodein=76 mcu: mcu_awake=0.051 mcu_task_avg=0.000059 mcu_task_stddev=0.000197 bytes_write=4903 bytes_read=5127 bytes_retransmit=9 bytes_invalid=0 send_seq=238 receive_seq=238 retransmit_seq=2 srtt=0.002 rttvar=0.003 rto=0.025 ready_bytes=7 stalled_bytes=0 freq=120002513 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=31.8 pwm=0.000 sysload=2.26 cputime=1.408 memavail=3388220
Stats 1091.8: gcodein=76 mcu: mcu_awake=0.051 mcu_task_avg=0.000059 mcu_task_stddev=0.000197 bytes_write=4942 bytes_read=5263 bytes_retransmit=9 bytes_invalid=0 send_seq=242 receive_seq=242 retransmit_seq=2 srtt=0.001 rttvar=0.002 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120002079 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.9 pwm=0.000 sysload=2.26 cputime=1.422 memavail=3389092
Stats 1092.8: gcodein=76 mcu: mcu_awake=0.051 mcu_task_avg=0.000059 mcu_task_stddev=0.000197 bytes_write=4948 bytes_read=5369 bytes_retransmit=9 bytes_invalid=0 send_seq=243 receive_seq=243 retransmit_seq=2 srtt=0.001 rttvar=0.002 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120002148 heater_bed: target=0 temp=29.4 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.9 pwm=0.000 sysload=2.32 cputime=1.430 memavail=3388016
Stats 1093.8: gcodein=76 mcu: mcu_awake=0.051 mcu_task_avg=0.000059 mcu_task_stddev=0.000197 bytes_write=4970 bytes_read=5495 bytes_retransmit=9 bytes_invalid=0 send_seq=245 receive_seq=245 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001748 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.9 pwm=0.000 sysload=2.32 cputime=1.438 memavail=3413240
Stats 1094.8: gcodein=81 mcu: mcu_awake=0.051 mcu_task_avg=0.000059 mcu_task_stddev=0.000197 bytes_write=4976 bytes_read=5616 bytes_retransmit=9 bytes_invalid=0 send_seq=246 receive_seq=246 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001771 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.3 pwm=0.000 sysload=2.32 cputime=1.450 memavail=3413660
Stats 1095.8: gcodein=81 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=4998 bytes_read=5731 bytes_retransmit=9 bytes_invalid=0 send_seq=248 receive_seq=247 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=11 stalled_bytes=0 freq=120001699 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=33.1 pwm=0.000 sysload=2.32 cputime=1.463 memavail=3413840
Stats 1096.8: gcodein=81 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5042 bytes_read=5874 bytes_retransmit=9 bytes_invalid=0 send_seq=252 receive_seq=252 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001625 heater_bed: target=0 temp=29.4 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.4 pwm=0.000 sysload=2.32 cputime=1.473 memavail=3414440
Stats 1097.8: gcodein=81 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5048 bytes_read=5993 bytes_retransmit=9 bytes_invalid=0 send_seq=253 receive_seq=253 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001613 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=30.5 pwm=0.000 sysload=2.21 cputime=1.484 memavail=3413852
Stats 1098.8: gcodein=81 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5054 bytes_read=6099 bytes_retransmit=9 bytes_invalid=0 send_seq=254 receive_seq=254 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001523 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.7 pwm=0.000 sysload=2.21 cputime=1.492 memavail=3435200
Stats 1099.8: gcodein=86 mcu: mcu_awake=0.001 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5076 bytes_read=6225 bytes_retransmit=9 bytes_invalid=0 send_seq=256 receive_seq=256 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001628 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.6 pwm=0.000 sysload=2.21 cputime=1.502 memavail=3435092
Stats 1100.8: gcodein=86 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000023 bytes_write=5082 bytes_read=6361 bytes_retransmit=9 bytes_invalid=0 send_seq=257 receive_seq=257 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001587 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.4 pwm=0.000 sysload=2.21 cputime=1.515 memavail=3435076
Stats 1101.8: gcodein=86 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000023 bytes_write=5088 bytes_read=6467 bytes_retransmit=9 bytes_invalid=0 send_seq=258 receive_seq=258 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001574 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.0 pwm=0.000 sysload=2.21 cputime=1.527 memavail=3436056
Stats 1102.8: gcodein=86 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000023 bytes_write=5126 bytes_read=6598 bytes_retransmit=9 bytes_invalid=0 send_seq=261 receive_seq=261 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001555 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.1 pwm=0.000 sysload=2.04 cputime=1.540 memavail=3436064
Stats 1103.8: gcodein=86 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000023 bytes_write=5169 bytes_read=6734 bytes_retransmit=9 bytes_invalid=0 send_seq=265 receive_seq=265 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001532 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.7 pwm=0.000 sysload=2.04 cputime=1.554 memavail=3435940
Stats 1104.8: gcodein=91 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000023 bytes_write=5175 bytes_read=6840 bytes_retransmit=9 bytes_invalid=0 send_seq=266 receive_seq=266 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001489 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.9 pwm=0.000 sysload=2.04 cputime=1.565 memavail=3414852
Stats 1105.8: gcodein=91 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000021 bytes_write=5197 bytes_read=6981 bytes_retransmit=9 bytes_invalid=0 send_seq=268 receive_seq=268 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001475 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.8 pwm=0.000 sysload=2.04 cputime=1.577 memavail=3415084
Stats 1106.8: gcodein=91 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000021 bytes_write=5203 bytes_read=7102 bytes_retransmit=9 bytes_invalid=0 send_seq=269 receive_seq=269 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001448 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.8 pwm=0.000 sysload=2.04 cputime=1.587 memavail=3380944
Stats 1107.8: gcodein=91 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000021 bytes_write=5225 bytes_read=7213 bytes_retransmit=9 bytes_invalid=0 send_seq=271 receive_seq=271 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001414 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.7 pwm=0.000 sysload=2.19 cputime=1.594 memavail=3362368
Stats 1108.8: gcodein=91 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000021 bytes_write=5247 bytes_read=7339 bytes_retransmit=9 bytes_invalid=0 send_seq=273 receive_seq=273 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001400 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.8 pwm=0.000 sysload=2.19 cputime=1.602 memavail=3411364
Stats 1109.8: gcodein=96 mcu: mcu_awake=0.002 mcu_task_avg=0.000009 mcu_task_stddev=0.000021 bytes_write=5253 bytes_read=7460 bytes_retransmit=9 bytes_invalid=0 send_seq=274 receive_seq=274 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001401 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.3 pwm=0.000 sysload=2.19 cputime=1.613 memavail=3384596
Stats 1110.8: gcodein=96 mcu: mcu_awake=0.002 mcu_task_avg=0.000010 mcu_task_stddev=0.000025 bytes_write=5291 bytes_read=7591 bytes_retransmit=9 bytes_invalid=0 send_seq=277 receive_seq=277 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001386 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.1 pwm=0.000 sysload=2.19 cputime=1.621 memavail=3372312
Stats 1111.8: gcodein=96 mcu: mcu_awake=0.002 mcu_task_avg=0.000010 mcu_task_stddev=0.000025 bytes_write=5329 bytes_read=7732 bytes_retransmit=33 bytes_invalid=0 send_seq=280 receive_seq=280 retransmit_seq=280 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001386 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.7 pwm=0.000 sysload=2.19 cputime=1.630 memavail=3366008
Stats 1112.8: gcodein=96 mcu: mcu_awake=0.002 mcu_task_avg=0.000010 mcu_task_stddev=0.000025 bytes_write=5351 bytes_read=7838 bytes_retransmit=57 bytes_invalid=0 send_seq=282 receive_seq=282 retransmit_seq=282 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001386 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.9 pwm=0.000 sysload=2.02 cputime=1.638 memavail=3380048
Stats 1113.8: gcodein=96 mcu: mcu_awake=0.002 mcu_task_avg=0.000010 mcu_task_stddev=0.000025 bytes_write=5357 bytes_read=7868 bytes_retransmit=57 bytes_invalid=0 send_seq=283 receive_seq=283 retransmit_seq=282 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001386 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.6 pwm=0.000 sysload=2.02 cputime=1.649 memavail=3391300
Stats 1114.9: gcodein=101 mcu: mcu_awake=0.002 mcu_task_avg=0.000010 mcu_task_stddev=0.000025 bytes_write=5363 bytes_read=7994 bytes_retransmit=64 bytes_invalid=0 send_seq=284 receive_seq=284 retransmit_seq=284 srtt=0.001 rttvar=0.001 rto=0.050 ready_bytes=0 stalled_bytes=0 freq=120001386 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.8 pwm=0.000 sysload=2.02 cputime=1.661 memavail=3391872
Stats 1115.9: gcodein=101 mcu: mcu_awake=0.002 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5385 bytes_read=8140 bytes_retransmit=81 bytes_invalid=0 send_seq=286 receive_seq=286 retransmit_seq=285 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001403 heater_bed: target=0 temp=29.4 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.1 pwm=0.000 sysload=2.02 cputime=1.677 memavail=3392256
Stats 1116.9: gcodein=101 mcu: mcu_awake=0.002 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5391 bytes_read=8231 bytes_retransmit=81 bytes_invalid=0 send_seq=287 receive_seq=287 retransmit_seq=285 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=120001382 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=29.8 pwm=0.000 sysload=2.02 cputime=1.686 memavail=3357620
Stats 1117.9: gcodein=101 mcu: mcu_awake=0.002 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5397 bytes_read=8357 bytes_retransmit=88 bytes_invalid=0 send_seq=288 receive_seq=288 retransmit_seq=288 srtt=0.001 rttvar=0.001 rto=0.050 ready_bytes=0 stalled_bytes=0 freq=120001382 heater_bed: target=0 temp=29.4 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.5 pwm=0.000 sysload=1.94 cputime=1.694 memavail=3386800
Stats 1118.9: gcodein=101 mcu: mcu_awake=0.002 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5419 bytes_read=8472 bytes_retransmit=112 bytes_invalid=0 send_seq=290 receive_seq=290 retransmit_seq=290 srtt=0.001 rttvar=0.001 rto=0.200 ready_bytes=0 stalled_bytes=0 freq=120001382 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=30.0 pwm=0.000 sysload=1.94 cputime=1.706 memavail=3386800
Stats 1119.9: gcodein=106 mcu: mcu_awake=0.002 mcu_task_avg=0.000008 mcu_task_stddev=0.000017 bytes_write=5425 bytes_read=8562 bytes_retransmit=112 bytes_invalid=0 send_seq=291 receive_seq=291 retransmit_seq=290 srtt=0.013 rttvar=0.025 rto=0.113 ready_bytes=0 stalled_bytes=0 freq=120001382 heater_bed: target=0 temp=29.5 pwm=0.000 print_time=0.001 buffer_time=0.000 print_stall=0 extruder: target=0 temp=28.7 pwm=0.000 sysload=1.94 cputime=1.721 memavail=3386804
Got error -1 in read: (11)Resource temporarily unavailable
Timeout with MCU 'mcu' (eventtime=1125.863917)
Transition to shutdown state: Lost communication with MCU 'mcu'
Dumping gcode input 14 blocks
Read 1079.624750: 'N0 M110 N0*125\n'
Read 1079.630399: 'N0 M110 N0*125\n'
Read 1079.655409: 'N0 M110 N0*125\n'
Read 1079.667814: 'N1 M115*39\n'
Read 1079.696893: 'N2 M21*18\n'
Read 1084.632861: 'M105\n'
Read 1089.646235: 'M105\n'
Read 1094.650173: 'M105\n'
Read 1099.655427: 'M105\n'
Read 1104.661699: 'M105\n'
Read 1109.663720: 'M105\n'
Read 1114.666383: 'M105\n'
Read 1119.669592: 'M105\n'
Read 1124.672453: 'M105\n'
gcode state: absolute_coord=True absolute_extrude=True base_position=[0.0, 0.0, 0.0, 0.0] last_position=[0.0, 0.0, 0.0, 0.0] homing_position=[0.0, 0.0, 0.0, 0.0] speed_factor=0.0166666666667 extrude_factor=1.0 speed=25.0
jakep82 commented 4 years ago

Have you tried replacing the USB cable?

definitely-not-a-t-rex commented 4 years ago

Have you tried replacing the USB cable?

Both blue short ones from the boards and a longer one that I got with probably a printer or a microphone, I printed fine with the 1.4 and the cable that I used for the log just yesterday. The boards do show up using ls /dev/serial/by-id/* on all cables

BlackStump commented 4 years ago

Have you tried a different sdcard on your Pi?

definitely-not-a-t-rex commented 4 years ago

Have you tried a different sdcard on your Pi?

No, do you think the could problem could lie on the sd itself or what's on it? It's the only a2 class that I have not in use elsewhere, I can try only klipper and octo on another one for a test but migrating not from a backup would take me a really long time. I can try but I don't see how it would cause Got error -1 in read: (11)Resource temporarily unavailable orUnable to open port: [Errno 16] could not open port /dev/serial/by-id/usb-Klipper_lpc1769_1F20001722813AAFF63A6A5CC62000F5-if00: [Errno 16] Device or resource busy: '/dev/serial/by-id/usb-Klipper_lpc1769_1F20001722813AAFF63A6A5CC62000F5-if00'

inks007 commented 4 years ago

You could look at the RasPi's kernel log for USB dropouts.

e.g. dmesg | grep 'usb' and look for sequential 'USB disconnect' and 'New USB device' or dmesg -w for a realtime monitoring

definitely-not-a-t-rex commented 4 years ago

You could look at the RasPi's kernel log for USB dropouts.

e.g. dmesg | grep 'usb' and look for sequential 'USB disconnect' and 'New USB device' or dmesg -w for a realtime monitoring

the second one doesn't seems to give me any info about it and dmesg | grep 'usb' gives me the same output when the device becomes shutdown as when it's active so ``` [ 0.128800] usbcore: registered new interface driver usbfs [ 0.128882] usbcore: registered new interface driver hub [ 0.128999] usbcore: registered new device driver usb [ 1.111628] usbcore: registered new interface driver r8152 [ 1.111692] usbcore: registered new interface driver lan78xx [ 1.111760] usbcore: registered new interface driver smsc95xx [ 1.115755] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04 [ 1.115772] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.115787] usb usb1: Product: xHCI Host Controller [ 1.115801] usb usb1: Manufacturer: Linux 5.4.51-v7l+ xhci-hcd [ 1.115814] usb usb1: SerialNumber: 0000:01:00.0 [ 1.117496] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04 [ 1.117512] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.117527] usb usb2: Product: xHCI Host Controller [ 1.117541] usb usb2: Manufacturer: Linux 5.4.51-v7l+ xhci-hcd [ 1.117555] usb usb2: SerialNumber: 0000:01:00.0 [ 1.120361] usbcore: registered new interface driver uas [ 1.120466] usbcore: registered new interface driver usb-storage [ 1.130368] usbcore: registered new interface driver usbhid [ 1.130380] usbhid: USB HID core driver [ 1.480573] usb 1-1: new high-speed USB device number 2 using xhci_hcd [ 1.663193] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 [ 1.663210] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 [ 1.663225] usb 1-1: Product: USB2.0 Hub [ 1.990576] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd [ 2.121765] usb 1-1.3: New USB device found, idVendor=14cd, idProduct=1212, bcdDevice= 1.00 [ 2.121784] usb 1-1.3: New USB device strings: Mfr=1, Product=3, SerialNumber=2 [ 2.121800] usb 1-1.3: Product: Mass Storage Device [ 2.121814] usb 1-1.3: Manufacturer: Generic [ 2.121829] usb 1-1.3: SerialNumber: 121220160204 [ 2.124560] usb-storage 1-1.3:1.0: USB Mass Storage device detected [ 2.125595] scsi host0: usb-storage 1-1.3:1.0 [ 5.953668] usbcore: registered new interface driver brcmfmac [ 257.972726] usb 1-1.4: new full-speed USB device number 4 using xhci_hcd [ 258.114695] usb 1-1.4: New USB device found, idVendor=1d50, idProduct=614e, bcdDevice= 1.00 [ 258.114713] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 258.114726] usb 1-1.4: Product: stm32f407xx [ 258.114740] usb 1-1.4: Manufacturer: Klipper [ 258.114752] usb 1-1.4: SerialNumber: 2F003700065052504B313720 [ 258.173172] usbcore: registered new interface driver cdc_acm


which seems to be fine
inks007 commented 4 years ago

If you've checked your RasPi's USB ports (try different port?), your USB cables, your USB connections, two different boards, then my guesses would be:

How are you powering the RasPi? Hopefully not off the SKRs' 5V supply... Also, check for the RasPi undervolt flags. Also, check that the SKRs are not pulling 5V from the USB (J2 on the SKR Pro, J15 on the SKR 1.4).

Otherwise I don't have any other bright suggestions.

definitely-not-a-t-rex commented 4 years ago

If you've checked your RasPi's USB ports (try different port?), your USB cables, your USB connections, two different boards, then my guesses would be:

  • some rogue process on your RasPi? (perhaps re-image)
  • flaky power supply perhaps affecting the printer boards and/or RasPi
  • a bug in Klipper (unusual, given you've tested both an lpc1768 & an stm32f407, and no-one else is reporting these issues)

How are you powering the RasPi? Hopefully not off the SKRs' 5V supply... Also, check for the RasPi undervolt flags. Also, check that the SKRs are not pulling 5V from the USB (J2 on the SKR Pro, J15 on the SKR 1.4).

Otherwise I don't have any other bright suggestions.

I'm using a 5v 3A psu and vcgencmd get_throttled returns throttled=0x0 which means I should be in the clear for that. I tried reinstalling just octoprint and klipper without any success, in the meantime tho I also noticed that my homeassistant install seems to be dead so I might try reinstalling the whole os and rechecking after that once I have a few hours for it. I wouldn't know how to check for other processes interfering with this but seems to be the most likely explanation. For the pulling you mean the switch from powering the board from either 12/24v and 5v? Both are set to 24v.

KevinOConnor commented 4 years ago

FWIW, the best advice I have is in the FAQ: https://www.klipper3d.org/FAQ.html#i-keep-getting-random-lost-communication-with-mcu-errors

As far as we know, the code works as intended. In similar reports in the past it was ultimately tracked down to loose wires, voltage fluctuations, or similar.

-Kevin

definitely-not-a-t-rex commented 4 years ago

FWIW, the best advice I have is in the FAQ: https://www.klipper3d.org/FAQ.html#i-keep-getting-random-lost-communication-with-mcu-errors

As far as we know, the code works as intended. In similar reports in the past it was ultimately tracked down to loose wires, voltage fluctuations, or similar.

-KevinI'

Hi, following those didn't fix it but reinstalling the os, octoprint, restoring octo backup and klipper did so I don't know what was the issue but it doesn't seem to be klipper's fault, probably some rogue process, I'll close the issue.