markniu / Bed_Distance_sensor

Auto bed level with High resolution distance sensor
281 stars 28 forks source link

MCU shutdown with HEAD #127

Closed heinrichWeichert closed 6 months ago

heinrichWeichert commented 6 months ago

I encounter shutdowns each time i home Z with the latest head commit. MainsailOS and all components are update-to-date. This happens on an SKR Pico.

Excerpt from klippy.log:

current z:5.000000
Stats 614.9: gcodein=0  mcu: mcu_awake=0.001 mcu_task_avg=0.000006 mcu_task_stddev=0.000005 bytes_write=3244 bytes_read=15583 bytes_retransmit=9 bytes_invalid=0 send_seq=284 receive_seq=284 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=28.4 sysload=0.32 cputime=11.746 memavail=3379468 print_time=60.024 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 615.9: gcodein=0  mcu: mcu_awake=0.005 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=4474 bytes_read=16813 bytes_retransmit=9 bytes_invalid=0 send_seq=352 receive_seq=352 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=29.7 mcu_temp: temp=28.3 sysload=0.29 cputime=11.865 memavail=3380844 print_time=60.974 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 616.9: gcodein=0  mcu: mcu_awake=0.005 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=5065 bytes_read=17426 bytes_retransmit=9 bytes_invalid=0 send_seq=385 receive_seq=385 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=28.2 sysload=0.29 cputime=11.923 memavail=3382144 print_time=61.974 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.8 pwm=0.000
Stats 617.9: gcodein=0  mcu: mcu_awake=0.005 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=5668 bytes_read=18043 bytes_retransmit=9 bytes_invalid=0 send_seq=419 receive_seq=419 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=28.0 sysload=0.29 cputime=11.982 memavail=3381248 print_time=62.974 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 618.9: gcodein=0  mcu: mcu_awake=0.005 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=6264 bytes_read=18675 bytes_retransmit=9 bytes_invalid=0 send_seq=453 receive_seq=453 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=28.1 sysload=0.29 cputime=12.043 memavail=3382444 print_time=63.974 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 619.9: gcodein=0  mcu: mcu_awake=0.005 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=7154 bytes_read=19561 bytes_retransmit=9 bytes_invalid=0 send_seq=503 receive_seq=503 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000204  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=28.0 sysload=0.29 cputime=12.115 memavail=3382944 print_time=64.994 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 620.9: gcodein=0  mcu: mcu_awake=0.008 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=7745 bytes_read=20173 bytes_retransmit=9 bytes_invalid=0 send_seq=536 receive_seq=536 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=28.0 sysload=0.35 cputime=12.149 memavail=3380480 print_time=65.994 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 621.9: gcodein=0  mcu: mcu_awake=0.008 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=8348 bytes_read=20819 bytes_retransmit=9 bytes_invalid=0 send_seq=570 receive_seq=570 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000204  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=27.9 sysload=0.35 cputime=12.182 memavail=3380480 print_time=66.994 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 622.9: gcodein=0  mcu: mcu_awake=0.008 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=8944 bytes_read=21437 bytes_retransmit=9 bytes_invalid=0 send_seq=604 receive_seq=604 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.2 mcu_temp: temp=27.9 sysload=0.35 cputime=12.214 memavail=3380228 print_time=67.994 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.8 pwm=0.000
Stats 623.9: gcodein=0  mcu: mcu_awake=0.008 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=9535 bytes_read=22035 bytes_retransmit=9 bytes_invalid=0 send_seq=637 receive_seq=637 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000203  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=29.7 mcu_temp: temp=27.9 sysload=0.35 cputime=12.246 memavail=3378976 print_time=68.994 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
BDsensorVer:V1.2 pandapi3d.com  ,switch_mode=0,collision_homing=1,collision_cal=1
Stats 624.9: gcodein=0  mcu: mcu_awake=0.008 mcu_task_avg=0.000007 mcu_task_stddev=0.000006 bytes_write=10927 bytes_read=23062 bytes_retransmit=9 bytes_invalid=0 send_seq=703 receive_seq=703 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000204  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=27.9 sysload=0.35 cputime=12.332 memavail=3378236 print_time=74.501 buffer_time=4.704 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 625.9: gcodein=0  mcu: mcu_awake=0.032 mcu_task_avg=0.000032 mcu_task_stddev=0.000180 bytes_write=11017 bytes_read=23378 bytes_retransmit=9 bytes_invalid=0 send_seq=710 receive_seq=710 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000204  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=27.7 sysload=0.32 cputime=12.370 memavail=3378236 print_time=74.501 buffer_time=3.703 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 626.9: gcodein=0  mcu: mcu_awake=0.032 mcu_task_avg=0.000032 mcu_task_stddev=0.000180 bytes_write=11107 bytes_read=23664 bytes_retransmit=9 bytes_invalid=0 send_seq=717 receive_seq=717 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000205  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.2 mcu_temp: temp=27.9 sysload=0.32 cputime=12.408 memavail=3378236 print_time=74.501 buffer_time=2.702 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 627.9: gcodein=0  mcu: mcu_awake=0.032 mcu_task_avg=0.000032 mcu_task_stddev=0.000180 bytes_write=11197 bytes_read=23979 bytes_retransmit=9 bytes_invalid=0 send_seq=724 receive_seq=724 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000207  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=27.9 sysload=0.32 cputime=12.446 memavail=3378236 print_time=74.521 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.8 pwm=0.000
Stats 628.9: gcodein=0  mcu: mcu_awake=0.032 mcu_task_avg=0.000032 mcu_task_stddev=0.000180 bytes_write=11287 bytes_read=24280 bytes_retransmit=9 bytes_invalid=0 send_seq=731 receive_seq=731 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000207  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=27.6 sysload=0.32 cputime=12.481 memavail=3377744 print_time=74.521 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 629.9: gcodein=0  mcu: mcu_awake=0.032 mcu_task_avg=0.000032 mcu_task_stddev=0.000180 bytes_write=11534 bytes_read=24691 bytes_retransmit=9 bytes_invalid=0 send_seq=749 receive_seq=749 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=7 upcoming_bytes=0 freq=12000206  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=27.6 sysload=0.32 cputime=12.508 memavail=3377744 print_time=74.971 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 630.9: gcodein=0  mcu: mcu_awake=0.010 mcu_task_avg=0.000017 mcu_task_stddev=0.000098 bytes_write=12011 bytes_read=25361 bytes_retransmit=9 bytes_invalid=0 send_seq=784 receive_seq=784 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000205  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=27.7 sysload=0.37 cputime=12.540 memavail=3377744 print_time=75.971 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 631.9: gcodein=0  mcu: mcu_awake=0.010 mcu_task_avg=0.000017 mcu_task_stddev=0.000098 bytes_write=12474 bytes_read=25979 bytes_retransmit=9 bytes_invalid=0 send_seq=818 receive_seq=818 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000205  heater_bed: target=0 temp=22.8 pwm=0.000 raspberry_pi: temp=29.2 mcu_temp: temp=27.5 sysload=0.37 cputime=12.571 memavail=3377744 print_time=77.021 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 632.9: gcodein=0  mcu: mcu_awake=0.010 mcu_task_avg=0.000017 mcu_task_stddev=0.000098 bytes_write=12938 bytes_read=26545 bytes_retransmit=9 bytes_invalid=0 send_seq=847 receive_seq=847 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000205  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=27.7 sysload=0.37 cputime=12.602 memavail=3377744 print_time=78.687 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 633.9: gcodein=0  mcu: mcu_awake=0.010 mcu_task_avg=0.000017 mcu_task_stddev=0.000098 bytes_write=13111 bytes_read=26923 bytes_retransmit=9 bytes_invalid=0 send_seq=861 receive_seq=861 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000205  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.7 mcu_temp: temp=27.6 sysload=0.37 cputime=12.624 memavail=3377744 print_time=78.987 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 634.9: gcodein=0  mcu: mcu_awake=0.010 mcu_task_avg=0.000017 mcu_task_stddev=0.000098 bytes_write=13573 bytes_read=27573 bytes_retransmit=9 bytes_invalid=0 send_seq=897 receive_seq=897 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000204  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=29.7 mcu_temp: temp=27.6 sysload=0.37 cputime=12.664 memavail=3377392 print_time=79.987 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
Stats 635.9: gcodein=0  mcu: mcu_awake=0.030 mcu_task_avg=0.000034 mcu_task_stddev=0.000154 bytes_write=14023 bytes_read=28214 bytes_retransmit=9 bytes_invalid=0 send_seq=932 receive_seq=932 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000216  heater_bed: target=0 temp=22.9 pwm=0.000 raspberry_pi: temp=28.2 mcu_temp: temp=27.6 sysload=0.34 cputime=12.696 memavail=3377392 print_time=80.987 buffer_time=0.000 print_stall=0 extruder: target=0 temp=22.9 pwm=0.000
MCU 'mcu' shutdown: Rescheduled timer in the past
clocksync state: mcu_freq=12000000 last_clock=963082111 clock_est=(608.750 643666087 12000216.004) min_half_rtt=0.000066 min_rtt_time=630.444 time_avg=608.750(534.981) clock_avg=643666087.966(6419889074.459) pred_variance=8924246.854
Dumping serial stats: bytes_write=14080 bytes_read=28311 bytes_retransmit=9 bytes_invalid=0 send_seq=936 receive_seq=936 retransmit_seq=2 srtt=0.000 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0
Dumping send queue 100 messages
Sent 0 632.313138 632.313138 21: seq: 14, queue_step oid=11 interval=1799 count=1 add=0, trsync_set_timeout oid=3 clock=929402716, trsync_trigger oid=3 reason=3
Sent 1 632.313524 632.313524 15: seq: 15, BDendstop_home oid=1 clock=0 sample_ticks=0 sample_count=0 rest_ticks=0 pin_value=0 trsync_oid=0 trigger_reason=0 endstop_pin=gpio22
Sent 2 632.313729 632.313729 8: seq: 16, trsync_trigger oid=3 reason=3
Sent 3 632.314370 632.314370 7: seq: 17, stepper_get_position oid=11
Sent 4 632.314983 632.314983 14: seq: 18, tmcuart_send oid=0 write=b'\xea\x0bH-\x8e' read=10
Sent 5 632.319546 632.319546 8: seq: 19, reset_step_clock oid=11 clock=0
Sent 6 632.320019 632.320019 12: seq: 1a, I2C_BD_send oid=2 data=b'1018'
Sent 7 632.320703 632.320703 38: seq: 1b, set_next_step_dir oid=11 dir=1, queue_step oid=11 interval=931479511 count=1 add=0, queue_step oid=11 interval=5390 count=3 add=-1206, queue_step oid=11 interval=2646 count=8 add=-161, queue_step oid=11 interval=1500 count=4214 add=0
Sent 8 632.321616 632.321616 40: seq: 1c, I2C_BD_send oid=2 data=b'1018', queue_step oid=11 interval=1500 count=3627 add=0, queue_step oid=11 interval=1502 count=137 add=0, queue_step oid=11 interval=1720 count=7 add=147, queue_step oid=11 interval=3022 count=3 add=1180
Sent 9 632.321749 632.321749 10: seq: 1d, I2C_BD_receive oid=1 data=b'32'
Sent 10 632.413169 632.413169 45: seq: 1e, get_clock, trsync_start oid=3 report_clock=943991764 report_ticks=900000 expire_reason=2, stepper_stop_on_trigger oid=11 trsync_oid=3, trsync_set_timeout oid=3 clock=946991764, BDendstop_home oid=1 clock=943991764 sample_ticks=360000 sample_count=1 rest_ticks=360000 pin_value=1 trsync_oid=3 trigger_reason=1 endstop_pin=gpio22
Sent 11 632.946815 632.946815 14: seq: 1f, tmcuart_send oid=0 write=b'\xea\x0b\xe8\xad\xba' read=10
Sent 12 632.951334 632.951334 14: seq: 10, tmcuart_send oid=0 write=b'\xea\x0b( \x98' read=10
Sent 13 633.147603 633.147603 14: seq: 11, tmcuart_send oid=0 write=b'\xea\x13\xe8-\xcc' read=10
Sent 14 633.152385 633.152385 14: seq: 12, tmcuart_send oid=0 write=b'\xea\x03\xe8\xad\xe1' read=10
Sent 15 633.156911 633.156911 14: seq: 13, tmcuart_send oid=0 write=b'\xea\x13(\xa0\xee' read=10
Sent 16 633.161636 633.161636 14: seq: 14, tmcuart_send oid=0 write=b'\xea\x03( \xc3' read=10
Sent 17 633.397879 633.397879 6: seq: 15, get_clock

Please let me know if you need further information, I will supply them.

markniu commented 6 months ago

could you update it again with the latest commit that I just update 1 one hour ago that I found this happens on some low speed of mcu too.

heinrichWeichert commented 6 months ago

will do i also encountered https://github.com/markniu/Bed_Distance_sensor/issues/128 which was fixed by flashing the mcu again with the latest klipper version this also fixed this bug

you can close it, but i'll try the commit anyway