search

moggieuk / Happy-Hare

MMU software driver for Klipper (ERCF, Tradrack, Prusa)
GNU General Public License v3.0
482 stars 121 forks source link

Servo is not moved to 'up' position when doing a filametrix toolchange #159

Closed jwhite closed 1 month ago

jwhite commented 9 months ago

Reproduction Steps:

1) Reboot printer 2) Raise nozzle temperature 3) Observe that servo position in in 'move' and filament locked 3) Issue a toolchange command (my first macro in START_PRINT) 4) Tip is cut and reverse extrusion occurs

Result :

Either the ECAS fitting is popped off or something else catastrophically fails as the filament is essentially locked in the servo 'move' position while the reverse extrude after the cut occurs.

A possible solution is to put the servo in the 'up' position during a cut tip toolchange.

moggieuk commented 9 months ago

That's strange. The tip forming (inside happy hare) always adjusts servo position prior to the tip forming macro (form or cut). It depends on the "sync_form_tip" setting. If sync is enabled servo will be down, it not it should be moved up.

I'll test but it's not clear to me what you are seeing. The mmu.log would be helpful.

jwhite commented 9 months ago

sync_form_tip: 0 # Synchronize during standalone tip formation (initial part of unload)

Interesting. I have been able to repro this a few time now. I will wait until it happens again and include logs.

jwhite commented 9 months ago 
- - TRACE: _bootup_tasks()
(\_/)
( *,*)
(")_(") Happy Hare Ready
(\_/)
( *,*)
(")_(") Happy Hare Ready
TTG Map:
Gates: |#0 |#1 |#2 |#3 |#4 |#5 |#6 |#7 |#8 |
Tools: |T0 |T1 |T2 |T3 |T4 |T5 |T6 |T7 |T8 |
Avail: | S | B | B | ? | B | S | ? | ? | ? |
Selct: ------------------------------------- NOT HOMED
TTG Map:
Gates: |#0 |#1 |#2 |#3 |#4 |#5 |#6 |#7 |#8 |
Tools: |T0 |T1 |T2 |T3 |T4 |T5 |T6 |T7 |T8 |
Avail: | S | B | B | ? | B | S | ? | ? | ? |
Selct: ------------------------------------- NOT HOMED
- DEBUG: Job State: READY -> INITIALIZED (MMU State: Encoder: Enabled, Synced: False, Paused temp: None, Resume to state: ready, Position saved: None, z_hop @0.0mm, pause_resume: False, Idle timeout: 1800.00s)
- - TRACE: Running macro: _MMU_PRINT_STATE_CHANGED STATE='initialized' OLD_STATE='ready'
- DEBUG: Disabled encoder sensor. Status: {'encoder_pos': 0.0, 'detection_length': 11.0, 'min_headroom': 11.0, 'headroom': 16.0, 'desired_headroom': 5.0, 'detection_mode': 2, 'enabled': True, 'flow_rate': 0}
- DEBUG: Setting servo to move (filament hold) position at angle: 95
- - TRACE: Processing idle_timeout 'printing' event
- DEBUG: Requesting the following gate/spool_id pairs from Spoolman: [(0, 20), (1, 15), (2, 18), (3, 2), (4, 12), (5, 19)]
Stats 183538.0: gcodein=0  mcu: mcu_awake=0.007 mcu_task_avg=0.000008 mcu_task_stddev=0.000049 bytes_write=14624 bytes_read=8207 bytes_retransmit=9 bytes_invalid=0 send_seq=522 receive_seq=521 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180002370 sb2040: mcu_awake=0.017 mcu_task_avg=0.000021 mcu_task_stddev=0.000033 bytes_write=1429 bytes_read=4984 bytes_retransmit=0 bytes_invalid=0 send_seq=149 receive_seq=149 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000103 adj=11999619 mmu: mcu_awake=0.012 mcu_task_avg=0.000020 mcu_task_stddev=0.000032 bytes_write=1474 bytes_read=4910 bytes_retransmit=9 bytes_invalid=0 send_seq=153 receive_seq=153 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=10 upcoming_bytes=8 freq=47993232 adj=47994383  toolhead: temp=34.9 raspberry_pi: temp=68.2 mcu_temp: temp=40.2 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.24 cputime=13008.836 memavail=1534468 print_time=7.608 buffer_time=0.545 print_stall=0 extruder: target=0 temp=37.9 pwm=0.000
- DEBUG: Received gate map update from Spoolman: {0: {'spool_id': 20, 'material': 'PLA+', 'color': '48FF48'}, 1: {'spool_id': 15, 'material': 'PLA+', 'color': '000000'}, 2: {'spool_id': 18, 'material': 'PLA+', 'color': 'E27304'}, 3: {'spool_id': 2, 'material': 'ABS+', 'color': '000000'}, 4: {'spool_id': 12, 'material': 'ABS+', 'color': '86FF4A'}, 5: {'spool_id': 19, 'material': 'PETG', 'color': 'FFFFFF'}}
- - TRACE: Running macro: _MMU_GATE_MAP_CHANGED GATE=-1
Stats 183539.0: gcodein=0  mcu: mcu_awake=0.007 mcu_task_avg=0.000008 mcu_task_stddev=0.000049 bytes_write=17726 bytes_read=8827 bytes_retransmit=9 bytes_invalid=0 send_seq=595 receive_seq=595 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180002189 sb2040: mcu_awake=0.017 mcu_task_avg=0.000021 mcu_task_stddev=0.000033 bytes_write=1435 bytes_read=5080 bytes_retransmit=0 bytes_invalid=0 send_seq=150 receive_seq=150 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000066 adj=11999757 mmu: mcu_awake=0.012 mcu_task_avg=0.000020 mcu_task_stddev=0.000032 bytes_write=1508 bytes_read=5076 bytes_retransmit=9 bytes_invalid=0 send_seq=156 receive_seq=156 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47993061 adj=47992474  toolhead: temp=34.5 raspberry_pi: temp=69.6 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.30 cputime=13008.931 memavail=1538004 print_time=7.608 buffer_time=0.000 print_stall=0 extruder: target=0 temp=37.8 pwm=0.000
- - TRACE: Processing idle_timeout 'ready' event
- DEBUG: Unloading tool unknown
- - TRACE: Running macro: _MMU_PRE_UNLOAD
Attempting to recover filament position...
Attempting to recover filament position...
- - TRACE: (toolhead sensor detects filament)
MMU [T?] <<< [En] <<<<<<< [Ex] << [Ts] << [Nz] LOADED 0.0mm (e:0.0mm)
MMU [T?] <<< [En] <<<<<<< [Ex] << [Ts] << [Nz] LOADED 0.0mm (e:0.0mm)
Unloading filament...
Unloading filament...
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Unloading' OLD_ACTION='Idle'
MMU [T?] <<< [En] <<<<<<< [Ex] << [Ts] << [Nz] LOADED 0.0mm (e:0.0mm)
MMU [T?] <<< [En] <<<<<<< [Ex] << [Ts] << [Nz] LOADED 0.0mm (e:0.0mm)
- - TRACE: (toolhead sensor detects filament)
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Forming Tip' OLD_ACTION='Unloading'
- - TRACE: _ensure_safe_extruder_temperature: current_temp=37.84, paused_extruder_temp=None, current_target_temp=0.0, klipper_minimum_temp=180.0, default_extruder_temp=200.0, source=auto
Warning: Automatically heating extruder to default temp (200.0)
- - TRACE: Processing idle_timeout 'printing' event
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Heating' OLD_ACTION='Forming Tip'
Waiting for extruder to reach target (default) temperature: 200.0
Waiting for extruder to reach target (default) temperature: 200.0
Stats 183569.0: gcodein=0  mcu: mcu_awake=0.156 mcu_task_avg=0.000140 mcu_task_stddev=0.000104 bytes_write=119604 bytes_read=29511 bytes_retransmit=9 bytes_invalid=0 send_seq=3136 receive_seq=3136 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001634 sb2040: mcu_awake=0.003 mcu_task_avg=0.000013 mcu_task_stddev=0.000022 bytes_write=1630 bytes_read=8491 bytes_retransmit=0 bytes_invalid=0 send_seq=181 receive_seq=181 retransmit_seq=0 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=12000012 adj=11999882 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=1694 bytes_read=9814 bytes_retransmit=9 bytes_invalid=0 send_seq=187 receive_seq=187 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992626 adj=47991945  toolhead: temp=34.5 raspberry_pi: temp=68.7 mcu_temp: temp=40.4 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.18 cputime=13011.619 memavail=1534548 print_time=38.110 buffer_time=0.029 print_stall=0 extruder: target=200 temp=37.8 pwm=1.000
Heater extruder approaching new target of 200.000
Heater extruder within range of 200.000
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Forming Tip' OLD_ACTION='Heating'
Forming tip...
Forming tip...
- - TRACE: Running macro: _MMU_CUT_TIP
Stats 183679.1: gcodein=0  mcu: mcu_awake=0.144 mcu_task_avg=0.000144 mcu_task_stddev=0.000115 bytes_write=499864 bytes_read=107555 bytes_retransmit=9 bytes_invalid=0 send_seq=12916 receive_seq=12916 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001423 sb2040: mcu_awake=0.003 mcu_task_avg=0.000013 mcu_task_stddev=0.000021 bytes_write=2982 bytes_read=21282 bytes_retransmit=0 bytes_invalid=0 send_seq=337 receive_seq=337 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=2 freq=11999996 adj=11999898 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2366 bytes_read=27100 bytes_retransmit=9 bytes_invalid=0 send_seq=299 receive_seq=299 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992472 adj=47992731  toolhead: temp=36.2 raspberry_pi: temp=69.1 mcu_temp: temp=40.6 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.14 cputime=13023.059 memavail=1535612 print_time=148.202 buffer_time=0.051 print_stall=0 extruder: target=200 temp=199.4 pwm=0.405
probe: TRIGGERED
toolhead: max_velocity: 500.000000
max_accel: 1000.000000
max_accel_to_decel: 2000.000000
square_corner_velocity: 8.000000
['x']
Stats 183680.1: gcodein=0  mcu: mcu_awake=0.144 mcu_task_avg=0.000144 mcu_task_stddev=0.000115 bytes_write=504857 bytes_read=110556 bytes_retransmit=9 bytes_invalid=0 send_seq=13121 receive_seq=13119 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001418 sb2040: mcu_awake=0.003 mcu_task_avg=0.000013 mcu_task_stddev=0.000021 bytes_write=4135 bytes_read=23173 bytes_retransmit=0 bytes_invalid=0 send_seq=431 receive_seq=431 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999996 adj=11999895 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2372 bytes_read=27256 bytes_retransmit=9 bytes_invalid=0 send_seq=300 receive_seq=300 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992480 adj=47992721  toolhead: temp=36.1 raspberry_pi: temp=68.7 mcu_temp: temp=40.6 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.14 cputime=13023.197 memavail=1535864 print_time=149.332 buffer_time=0.000 print_stall=0 extruder: target=200 temp=199.7 pwm=0.461
Stats 183681.1: gcodein=0  mcu: mcu_awake=0.144 mcu_task_avg=0.000144 mcu_task_stddev=0.000115 bytes_write=510860 bytes_read=113974 bytes_retransmit=9 bytes_invalid=0 send_seq=13352 receive_seq=13352 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001413 sb2040: mcu_awake=0.003 mcu_task_avg=0.000013 mcu_task_stddev=0.000021 bytes_write=5779 bytes_read=25819 bytes_retransmit=0 bytes_invalid=0 send_seq=566 receive_seq=566 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999995 adj=11999899 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2378 bytes_read=27426 bytes_retransmit=9 bytes_invalid=0 send_seq=301 receive_seq=301 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992496 adj=47992693  toolhead: temp=36.3 raspberry_pi: temp=68.2 mcu_temp: temp=40.4 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.14 cputime=13023.339 memavail=1535864 print_time=150.332 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.2 pwm=0.339
['x']
Stats 183682.1: gcodein=0  mcu: mcu_awake=0.157 mcu_task_avg=0.000072 mcu_task_stddev=0.000102 bytes_write=516756 bytes_read=116451 bytes_retransmit=9 bytes_invalid=0 send_seq=13548 receive_seq=13548 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001412 sb2040: mcu_awake=0.039 mcu_task_avg=0.000016 mcu_task_stddev=0.000023 bytes_write=6749 bytes_read=27437 bytes_retransmit=0 bytes_invalid=0 send_seq=647 receive_seq=647 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999899 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2384 bytes_read=27582 bytes_retransmit=9 bytes_invalid=0 send_seq=302 receive_seq=302 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992506 adj=47992795  toolhead: temp=36.1 raspberry_pi: temp=69.1 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.8 pwm=0.000 sysload=0.14 cputime=13023.512 memavail=1537588 print_time=151.303 buffer_time=0.152 print_stall=0 extruder: target=200 temp=200.4 pwm=0.339
['y']
Stats 183683.1: gcodein=0  mcu: mcu_awake=0.157 mcu_task_avg=0.000072 mcu_task_stddev=0.000102 bytes_write=520435 bytes_read=117304 bytes_retransmit=9 bytes_invalid=0 send_seq=13647 receive_seq=13647 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=23 upcoming_bytes=0 freq=180001413 sb2040: mcu_awake=0.039 mcu_task_avg=0.000016 mcu_task_stddev=0.000023 bytes_write=6755 bytes_read=27551 bytes_retransmit=0 bytes_invalid=0 send_seq=648 receive_seq=648 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999995 adj=11999902 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2390 bytes_read=27738 bytes_retransmit=9 bytes_invalid=0 send_seq=303 receive_seq=303 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992517 adj=47992756  toolhead: temp=36.2 raspberry_pi: temp=68.7 mcu_temp: temp=40.6 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.14 cputime=13023.672 memavail=1537588 print_time=152.365 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.6 pwm=0.339
Stats 183684.1: gcodein=0  mcu: mcu_awake=0.157 mcu_task_avg=0.000072 mcu_task_stddev=0.000102 bytes_write=525093 bytes_read=118570 bytes_retransmit=9 bytes_invalid=0 send_seq=13784 receive_seq=13784 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001416 sb2040: mcu_awake=0.039 mcu_task_avg=0.000016 mcu_task_stddev=0.000023 bytes_write=6761 bytes_read=27665 bytes_retransmit=0 bytes_invalid=0 send_seq=649 receive_seq=649 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999995 adj=11999904 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2396 bytes_read=27894 bytes_retransmit=9 bytes_invalid=0 send_seq=304 receive_seq=304 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992527 adj=47992785  toolhead: temp=36.1 raspberry_pi: temp=68.2 mcu_temp: temp=40.6 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.13 cputime=13023.851 memavail=1537588 print_time=153.365 buffer_time=0.000 print_stall=0 extruder: target=200 temp=200.9 pwm=0.339
Stats 183685.1: gcodein=0  mcu: mcu_awake=0.157 mcu_task_avg=0.000072 mcu_task_stddev=0.000102 bytes_write=529711 bytes_read=119833 bytes_retransmit=9 bytes_invalid=0 send_seq=13925 receive_seq=13925 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001462 sb2040: mcu_awake=0.039 mcu_task_avg=0.000016 mcu_task_stddev=0.000023 bytes_write=6767 bytes_read=27765 bytes_retransmit=0 bytes_invalid=0 send_seq=650 receive_seq=650 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999995 adj=11999914 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2402 bytes_read=28050 bytes_retransmit=9 bytes_invalid=0 send_seq=305 receive_seq=305 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992539 adj=47992775  toolhead: temp=36.2 raspberry_pi: temp=68.2 mcu_temp: temp=40.5 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.13 cputime=13024.028 memavail=1537848 print_time=154.365 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.1 pwm=0.339
['y']
Stats 183686.1: gcodein=0  mcu: mcu_awake=0.157 mcu_task_avg=0.000072 mcu_task_stddev=0.000102 bytes_write=532919 bytes_read=120848 bytes_retransmit=9 bytes_invalid=0 send_seq=14026 receive_seq=14026 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001458 sb2040: mcu_awake=0.039 mcu_task_avg=0.000016 mcu_task_stddev=0.000023 bytes_write=6803 bytes_read=27889 bytes_retransmit=0 bytes_invalid=0 send_seq=653 receive_seq=653 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999995 adj=11999862 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000012 bytes_write=2408 bytes_read=28220 bytes_retransmit=9 bytes_invalid=0 send_seq=306 receive_seq=306 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992557 adj=47992602  toolhead: temp=36.2 raspberry_pi: temp=69.1 mcu_temp: temp=40.5 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.13 cputime=13024.192 memavail=1537848 print_time=155.437 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.2 pwm=0.416
probe: TRIGGERED
toolhead: max_velocity: 500.000000
max_accel: 1000.000000
max_accel_to_decel: 2000.000000
square_corner_velocity: 8.000000
toolhead: max_velocity: 500.000000
max_accel: 4000.000000
max_accel_to_decel: 2000.000000
square_corner_velocity: 8.000000
toolhead: max_velocity: 500.000000
max_accel: 4000.000000
max_accel_to_decel: 2000.000000
square_corner_velocity: 8.000000
toolhead: max_velocity: 500.000000
max_accel: 4000.000000
max_accel_to_decel: 2000.000000
square_corner_velocity: 8.000000
toolhead: max_velocity: 500.000000
max_accel: 4000.000000
max_accel_to_decel: 2000.000000
square_corner_velocity: 8.000000
extruder: pressure_advance: 0.000000
pressure_advance_smooth_time: 0.040000
extruder: pressure_advance: 0.055000
pressure_advance_smooth_time: 0.040000
- - TRACE: After tip formation, park_pos reported as: 60.0mm with 34.0mm filament remaining in extruder (extruder moved: 26.0mm, encoder measured 16.8mm)
MMU [T?] <<< [En] <<<<<<< [Ex] << [Ts] <. [Nz] -60.0mm (e:59.9mm)
MMU [T?] <<< [En] <<<<<<< [Ex] << [Ts] <. [Nz] -60.0mm (e:59.9mm)
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Unloading' OLD_ACTION='Forming Tip'
- - TRACE: Running macro: _MMU_POST_FORM_TIP
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Exiting Ext' OLD_ACTION='Unloading'
- DEBUG: Extracting filament from extruder
- - TRACE: _ensure_safe_extruder_temperature: current_temp=201.48, paused_extruder_temp=None, current_target_temp=200.0, klipper_minimum_temp=180.0, default_extruder_temp=200.0, source=auto
- DEBUG: Setting servo to up (filament released) position at angle: 138
Stats 183694.1: gcodein=0  mcu: mcu_awake=0.154 mcu_task_avg=0.000120 mcu_task_stddev=0.000110 bytes_write=565095 bytes_read=128047 bytes_retransmit=9 bytes_invalid=0 send_seq=14884 receive_seq=14884 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001464 sb2040: mcu_awake=0.009 mcu_task_avg=0.000012 mcu_task_stddev=0.000022 bytes_write=9327 bytes_read=29607 bytes_retransmit=0 bytes_invalid=0 send_seq=731 receive_seq=731 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999883 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000013 bytes_write=2456 bytes_read=29728 bytes_retransmit=9 bytes_invalid=0 send_seq=314 receive_seq=314 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992655 adj=47992674  toolhead: temp=36.3 raspberry_pi: temp=67.2 mcu_temp: temp=40.6 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.11 cputime=13025.124 memavail=1536880 print_time=163.315 buffer_time=0.148 print_stall=0 extruder: target=200 temp=201.4 pwm=0.446
- DEBUG: Reverse homing up to 24.0mm to toolhead sensor
['toolhead']
Stats 183695.1: gcodein=0  mcu: mcu_awake=0.154 mcu_task_avg=0.000120 mcu_task_stddev=0.000110 bytes_write=566936 bytes_read=128537 bytes_retransmit=9 bytes_invalid=0 send_seq=14932 receive_seq=14932 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001462 sb2040: mcu_awake=0.009 mcu_task_avg=0.000012 mcu_task_stddev=0.000022 bytes_write=9526 bytes_read=29797 bytes_retransmit=0 bytes_invalid=0 send_seq=740 receive_seq=740 retransmit_seq=0 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999884 mmu: mcu_awake=0.003 mcu_task_avg=0.000014 mcu_task_stddev=0.000013 bytes_write=2516 bytes_read=29939 bytes_retransmit=9 bytes_invalid=0 send_seq=318 receive_seq=318 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992671 adj=47992765  toolhead: temp=36.3 raspberry_pi: temp=69.1 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.11 cputime=13025.267 memavail=1537132 print_time=163.919 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.1 pwm=0.592
Stats 183696.1: gcodein=0  mcu: mcu_awake=0.154 mcu_task_avg=0.000120 mcu_task_stddev=0.000110 bytes_write=571171 bytes_read=129478 bytes_retransmit=9 bytes_invalid=0 send_seq=15042 receive_seq=15042 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001458 sb2040: mcu_awake=0.009 mcu_task_avg=0.000012 mcu_task_stddev=0.000022 bytes_write=11354 bytes_read=32446 bytes_retransmit=0 bytes_invalid=0 send_seq=889 receive_seq=888 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999887 mmu: mcu_awake=0.014 mcu_task_avg=0.000016 mcu_task_stddev=0.000014 bytes_write=4034 bytes_read=32544 bytes_retransmit=9 bytes_invalid=0 send_seq=445 receive_seq=445 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992685 adj=47992878  toolhead: temp=36.0 raspberry_pi: temp=67.7 mcu_temp: temp=40.5 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.11 cputime=13025.539 memavail=1537132 print_time=163.919 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.3 pwm=0.385
- - TRACE: Reverse homing to toolhead sensor. Stepper: 'extruder' homed after moving -17.6mm (of max -24.0mm), encoder measured 18.7mm (delta -1.1mm). Pos: @-77.6, (82.4mm)
MMU [T?] <<< [En] <<<<<<< [Ex] <| [Ts] .. [Nz] -77.6mm (e:82.4mm)
MMU [T?] <<< [En] <<<<<<< [Ex] <| [Ts] .. [Nz] -77.6mm (e:82.4mm)
- DEBUG: Unloading last 16.4mm to exit the extruder
Stats 183697.1: gcodein=0  mcu: mcu_awake=0.141 mcu_task_avg=0.000128 mcu_task_stddev=0.000120 bytes_write=575396 bytes_read=130393 bytes_retransmit=9 bytes_invalid=0 send_seq=15150 receive_seq=15150 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001450 sb2040: mcu_awake=0.027 mcu_task_avg=0.000015 mcu_task_stddev=0.000022 bytes_write=12263 bytes_read=33444 bytes_retransmit=0 bytes_invalid=0 send_seq=944 receive_seq=944 retransmit_seq=0 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999883 mmu: mcu_awake=0.014 mcu_task_avg=0.000016 mcu_task_stddev=0.000014 bytes_write=4493 bytes_read=33443 bytes_retransmit=9 bytes_invalid=0 send_seq=485 receive_seq=485 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992700 adj=47993002  toolhead: temp=36.1 raspberry_pi: temp=68.7 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.11 cputime=13025.705 memavail=1536184 print_time=163.919 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.4 pwm=0.377
- - TRACE: Unloading extruder. Stepper: 'extruder' moved -16.4mm, encoder measured 7.5mm (delta 8.9mm). Pos: @-94.0, (89.9mm)
- DEBUG: Total measured movement: 7.5mm, total delta: 8.9mm
MMU [T?] <<< [En] <<<<<<< [Ex] .. [Ts] .. [Nz] -84.0mm (e:89.9mm)
MMU [T?] <<< [En] <<<<<<< [Ex] .. [Ts] .. [Nz] -84.0mm (e:89.9mm)
- DEBUG: Filament should be out of extruder
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Unloading' OLD_ACTION='Exiting Ext'
- DEBUG: Unloading bowden tube
- DEBUG: Setting servo to down (filament drive) position at angle: 45
Stats 183698.1: gcodein=0  mcu: mcu_awake=0.141 mcu_task_avg=0.000128 mcu_task_stddev=0.000120 bytes_write=577350 bytes_read=130892 bytes_retransmit=9 bytes_invalid=0 send_seq=15199 receive_seq=15199 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001449 sb2040: mcu_awake=0.027 mcu_task_avg=0.000015 mcu_task_stddev=0.000022 bytes_write=12342 bytes_read=33633 bytes_retransmit=0 bytes_invalid=0 send_seq=950 receive_seq=950 retransmit_seq=0 srtt=0.001 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999993 adj=11999891 mmu: mcu_awake=0.014 mcu_task_avg=0.000016 mcu_task_stddev=0.000014 bytes_write=5252 bytes_read=33669 bytes_retransmit=9 bytes_invalid=0 send_seq=498 receive_seq=492 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=23 upcoming_bytes=8 freq=47992714 adj=47993143  toolhead: temp=36.2 raspberry_pi: temp=68.7 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.11 cputime=13025.782 memavail=1536184 print_time=168.067 buffer_time=0.891 print_stall=0 extruder: target=200 temp=201.2 pwm=0.415
Stats 183699.1: gcodein=0  mcu: mcu_awake=0.141 mcu_task_avg=0.000128 mcu_task_stddev=0.000120 bytes_write=581540 bytes_read=131781 bytes_retransmit=9 bytes_invalid=0 send_seq=15300 receive_seq=15300 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001443 sb2040: mcu_awake=0.027 mcu_task_avg=0.000015 mcu_task_stddev=0.000022 bytes_write=12376 bytes_read=33779 bytes_retransmit=0 bytes_invalid=0 send_seq=953 receive_seq=953 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999993 adj=11999887 mmu: mcu_awake=0.014 mcu_task_avg=0.000016 mcu_task_stddev=0.000014 bytes_write=10100 bytes_read=34604 bytes_retransmit=9 bytes_invalid=0 send_seq=592 receive_seq=592 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=48 upcoming_bytes=0 freq=47992730 adj=47993322  toolhead: temp=36.1 raspberry_pi: temp=68.7 mcu_temp: temp=40.6 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.10 cputime=13025.910 memavail=1536192 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.2 pwm=0.415
Stats 183700.1: gcodein=0  mcu: mcu_awake=0.141 mcu_task_avg=0.000128 mcu_task_stddev=0.000120 bytes_write=585391 bytes_read=132597 bytes_retransmit=9 bytes_invalid=0 send_seq=15394 receive_seq=15394 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001438 sb2040: mcu_awake=0.027 mcu_task_avg=0.000015 mcu_task_stddev=0.000022 bytes_write=12425 bytes_read=33930 bytes_retransmit=0 bytes_invalid=0 send_seq=957 receive_seq=957 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999993 adj=11999888 mmu: mcu_awake=0.014 mcu_task_avg=0.000016 mcu_task_stddev=0.000014 bytes_write=10182 bytes_read=34851 bytes_retransmit=9 bytes_invalid=0 send_seq=595 receive_seq=595 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992744 adj=47993525  toolhead: temp=36.2 raspberry_pi: temp=68.7 mcu_temp: temp=40.3 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.10 cputime=13025.985 memavail=1536192 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.1 pwm=0.475
Stats 183701.1: gcodein=0  mcu: mcu_awake=0.141 mcu_task_avg=0.000128 mcu_task_stddev=0.000120 bytes_write=587355 bytes_read=133110 bytes_retransmit=9 bytes_invalid=0 send_seq=15445 receive_seq=15445 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001438 sb2040: mcu_awake=0.027 mcu_task_avg=0.000015 mcu_task_stddev=0.000022 bytes_write=12489 bytes_read=34114 bytes_retransmit=0 bytes_invalid=0 send_seq=962 receive_seq=962 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999993 adj=11999897 mmu: mcu_awake=0.023 mcu_task_avg=0.000030 mcu_task_stddev=0.000041 bytes_write=10216 bytes_read=35118 bytes_retransmit=9 bytes_invalid=0 send_seq=598 receive_seq=598 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992758 adj=47993731  toolhead: temp=36.1 raspberry_pi: temp=69.6 mcu_temp: temp=40.5 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.10 cputime=13026.049 memavail=1536192 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.2 pwm=0.315
Stats 183702.1: gcodein=0  mcu: mcu_awake=0.137 mcu_task_avg=0.000137 mcu_task_stddev=0.000123 bytes_write=591545 bytes_read=134019 bytes_retransmit=9 bytes_invalid=0 send_seq=15546 receive_seq=15546 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001437 sb2040: mcu_awake=0.027 mcu_task_avg=0.000015 mcu_task_stddev=0.000022 bytes_write=12548 bytes_read=34265 bytes_retransmit=0 bytes_invalid=0 send_seq=966 receive_seq=966 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999993 adj=11999895 mmu: mcu_awake=0.023 mcu_task_avg=0.000030 mcu_task_stddev=0.000041 bytes_write=10250 bytes_read=35351 bytes_retransmit=9 bytes_invalid=0 send_seq=601 receive_seq=601 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992772 adj=47993727  toolhead: temp=36.2 raspberry_pi: temp=68.7 mcu_temp: temp=40.5 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.10 cputime=13026.169 memavail=1535296 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.0 pwm=0.505
Stats 183703.1: gcodein=0  mcu: mcu_awake=0.137 mcu_task_avg=0.000137 mcu_task_stddev=0.000123 bytes_write=595762 bytes_read=134928 bytes_retransmit=9 bytes_invalid=0 send_seq=15657 receive_seq=15657 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=23 upcoming_bytes=0 freq=180001461 sb2040: mcu_awake=0.005 mcu_task_avg=0.000014 mcu_task_stddev=0.000023 bytes_write=12597 bytes_read=34430 bytes_retransmit=0 bytes_invalid=0 send_seq=970 receive_seq=970 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999993 adj=11999897 mmu: mcu_awake=0.023 mcu_task_avg=0.000030 mcu_task_stddev=0.000041 bytes_write=10284 bytes_read=35603 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=47992792 adj=47993620  toolhead: temp=36.5 raspberry_pi: temp=69.1 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.10 cputime=13026.327 memavail=1535300 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.1 pwm=0.370
Stats 183704.1: gcodein=0  mcu: mcu_awake=0.137 mcu_task_avg=0.000137 mcu_task_stddev=0.000123 bytes_write=597789 bytes_read=135489 bytes_retransmit=9 bytes_invalid=0 send_seq=15716 receive_seq=15716 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001463 sb2040: mcu_awake=0.005 mcu_task_avg=0.000014 mcu_task_stddev=0.000023 bytes_write=12661 bytes_read=34614 bytes_retransmit=0 bytes_invalid=0 send_seq=975 receive_seq=975 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999872 mmu: mcu_awake=0.023 mcu_task_avg=0.000030 mcu_task_stddev=0.000041 bytes_write=10318 bytes_read=35855 bytes_retransmit=9 bytes_invalid=0 send_seq=607 receive_seq=607 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992807 adj=47993521  toolhead: temp=36.6 raspberry_pi: temp=69.1 mcu_temp: temp=40.4 heater_bed: target=0 temp=29.1 pwm=0.000 sysload=0.09 cputime=13026.461 memavail=1535076 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.1 pwm=0.339
- - TRACE: Course unloading move from bowden. Stepper: 'gear' moved -771.1mm, encoder measured 808.7mm (delta -37.6mm). Pos: @-855.1, (913.6mm)
MMU [T?] <<< [En] <...... [Ex] .. [Ts] .. [Nz] -855.1mm (e:913.6mm)
MMU [T?] <<< [En] <...... [Ex] .. [Ts] .. [Nz] -855.1mm (e:913.6mm)
- DEBUG: Slow unload of the encoder
Stats 183705.1: gcodein=0  mcu: mcu_awake=0.137 mcu_task_avg=0.000137 mcu_task_stddev=0.000123 bytes_write=602064 bytes_read=136457 bytes_retransmit=9 bytes_invalid=0 send_seq=15834 receive_seq=15833 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001470 sb2040: mcu_awake=0.005 mcu_task_avg=0.000014 mcu_task_stddev=0.000023 bytes_write=12710 bytes_read=34765 bytes_retransmit=0 bytes_invalid=0 send_seq=979 receive_seq=979 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999890 mmu: mcu_awake=0.023 mcu_task_avg=0.000030 mcu_task_stddev=0.000041 bytes_write=10867 bytes_read=36152 bytes_retransmit=9 bytes_invalid=0 send_seq=619 receive_seq=619 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=47992825 adj=47993463  toolhead: temp=36.0 raspberry_pi: temp=68.2 mcu_temp: temp=40.3 heater_bed: target=0 temp=29.0 pwm=0.000 sysload=0.09 cputime=13026.642 memavail=1535836 print_time=168.067 buffer_time=0.000 print_stall=0 extruder: target=200 temp=201.0 pwm=0.408
- - TRACE: Unloading step #1 from encoder. Stepper: 'gear' moved -15.0mm, encoder measured 0.0mm (delta 15.0mm). Pos: @-870.1, (913.6mm)
- - TRACE: Final parking. Stepper: 'gear' moved -8.0mm, encoder measured 0.0mm (delta 8.0mm). Pos: @-863.1, (913.6mm)
MMU [T?] <.. [En] ....... [Ex] .. [Ts] .. [Nz] UNLOADED -855.1mm (e:913.6mm)
MMU [T?] <.. [En] ....... [Ex] .. [Ts] .. [Nz] UNLOADED -855.1mm (e:913.6mm)
- DEBUG: Setting servo to up (filament released) position at angle: 138
Stats 183706.1: gcodein=0  mcu: mcu_awake=0.137 mcu_task_avg=0.000137 mcu_task_stddev=0.000123 bytes_write=606132 bytes_read=137359 bytes_retransmit=9 bytes_invalid=0 send_seq=15941 receive_seq=15941 retransmit_seq=2 srtt=0.001 rttvar=0.001 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=180001465 sb2040: mcu_awake=0.005 mcu_task_avg=0.000014 mcu_task_stddev=0.000023 bytes_write=12744 bytes_read=34911 bytes_retransmit=0 bytes_invalid=0 send_seq=982 receive_seq=982 retransmit_seq=0 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=0 freq=11999994 adj=11999887 mmu: mcu_awake=0.008 mcu_task_avg=0.000025 mcu_task_stddev=0.000031 bytes_write=11311 bytes_read=36464 bytes_retransmit=9 bytes_invalid=0 send_seq=631 receive_seq=631 retransmit_seq=2 srtt=0.000 rttvar=0.000 rto=0.025 ready_bytes=0 upcoming_bytes=8 freq=47992836 adj=47993441  toolhead: temp=36.5 raspberry_pi: temp=68.2 mcu_temp: temp=40.4 heater_bed: target=0 temp=28.9 pwm=0.000 sysload=0.09 cputime=13026.817 memavail=1535836 print_time=175.547 buffer_time=0.366 print_stall=0 extruder: target=200 temp=200.9 pwm=0.408
Unload of -855.1mm filament successful (encoder measured 913.6mm)
Unload of -855.1mm filament successful (encoder measured 913.6mm)
- - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Idle' OLD_ACTION='Unloading'
- DEBUG: Deactivating spool ...
- - TRACE: Running macro: _MMU_POST_UNLOAD
- - TRACE: Processing idle_timeout 'ready' event

As you can see on line 21, the servo position is set to 'move' (HOLDING THE FILAMENT IN PLACE) and then the TIP_CUT macro runs, which tries to lift the tip up to the blade against resistance at the servo, blowing off the ECAS or grinding a nice moon into the filament at the encoder.

Unless you see anything different?

moggieuk commented 8 months ago

Catching up on Issues. Thank you for being such an prolific test / issue submitter!!

I'm reviewing all your submissions and I can't see how this can occur now (at least with the latest main branch). When the extruder is unloaded in must (now) set the servo in either the up/down position.

I tried to stage this setup based on what I see and it appears to work correctly and lifted the servo.

So I'm 99% sure this is addressed but I'm appreciate if you can let me know what you find. I'm happy for you to DM me on Discord if you want a more interactive chat.

jwhite commented 8 months ago

Tested case where filament was somewhere between extruder and encoder. This worked with the servo in the correct UP position.

// - DEBUG: Checking for possibility of filament still in extruder gears... 11:37:37 // - - TRACE: _ensure_safe_extruder_temperature: current_temp=219.99, paused_extruder_temp=None, current_target_temp=220.0, klipper_minimum_temp=180.0, default_extruder_temp=200.0, source=auto 11:37:38 // - DEBUG: Setting servo to up (filament released) position at angle: 138

Haven't tested a full unload yet.

jwhite commented 8 months ago

@moggieuk Sorry, still not working.

Reboot printer, MMU_EJECT. Extruder fights against the servo in 'locked' (move) position and bends/breaks.

10:44:06 (_/) ( ,) (")_(") Happy Hare Ready 10:44:06 Gates: | 0 | 1 | 2 | 3 | 4 | 5 | 6 | 7 | 8 | Tools: |T0 |T1 |T2 |T3 |T4 |T5 |T6 |T7 |T8 | Avail: | ? | ? | ? | ? | ? | ? | ? | ? | ? | Selct: ------------------------------------- NOT HOMED 10:44:06 - DEBUG: Job State: READY -> INITIALIZED (MMU State: Encoder: Enabled, Synced: False, Paused temp: None, Resume to state: ready, Position saved: None, z_hop @0.0mm, pause_resume: False, Idle timeout: 1800.00s) 10:44:06 - - TRACE: Running macro: _MMU_PRINT_STATE_CHANGED STATE='initialized' OLD_STATE='ready' 10:44:06 - - TRACE: Disabled runout detection 10:44:06 - DEBUG: Setting servo to move (filament hold) position at angle: 96 10:44:06 - - TRACE: Processing idle_timeout 'printing' event 10:44:07 - - TRACE: Processing idle_timeout 'ready' event 10:44:08 - - TRACE: Processing idle_timeout 'printing' event 10:44:09 - - TRACE: Processing idle_timeout 'ready' event 10:44:18 - - TRACE: Processing idle_timeout 'printing' event 10:44:19 - - TRACE: Processing idle_timeout 'ready' event 10:49:31 MMU is not homed 10:49:38 - DEBUG: Unloading tool unknown 10:49:38 - - TRACE: Running macro: _MMU_PRE_UNLOAD 10:49:38 Attempting to recover filament position... 10:49:38 - - TRACE: (toolhead sensor detects filament) 10:49:38 - - TRACE: (toolhead sensor detects filament) 10:49:38 [T?] < En <<<<<<<<< [Ex << () << Nz] LOADED 0.0mm (e:0.0mm) 10:49:38 Unloading filament... 10:49:38 - - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Unloading' OLD_ACTION='Idle' 10:49:38 - - TRACE: (toolhead sensor detects filament) 10:49:38 [T?] < En <<<<<<<<< [Ex << () << Nz] LOADED 0.0mm (e:0.0mm) 10:49:38 - - TRACE: (toolhead sensor detects filament) 10:49:38 - - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Forming Tip' OLD_ACTION='Unloading' 10:49:38 - - TRACE: _ensure_safe_extruder_temperature: current_temp=219.99, paused_extruder_temp=None, current_target_temp=220.0, klipper_minimum_temp=180.0, default_extruder_temp=200.0, source=auto 10:49:38 - - TRACE: Processing idle_timeout 'printing' event 10:49:39 Forming tip... 10:49:39 - - TRACE: Running macro: _MMU_CUT_TIP_DRAGON 10:49:55 - - TRACE: After tip formation, park_pos reported as: 45.0mm with 2.0mm filament remaining in extruder (extruder moved: 43.0mm, encoder measured 53.4mm) 10:49:55 - - TRACE: (toolhead sensor detects filament) 10:49:55 [T?] < En <<<<<<<<< [Ex << (*) <. Nz] -45.0mm (e:44.9mm) 10:49:55 - - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Unloading' OLD_ACTION='Forming Tip' 10:49:55 - - TRACE: Running macro: _MMU_POST_FORM_TIP 10:49:55 - - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Exiting Ext' OLD_ACTION='Unloading' 10:49:55 - DEBUG: Extracting filament from extruder 10:49:55 - - TRACE: _ensure_safe_extruder_temperature: current_temp=220.1, paused_extruder_temp=None, current_target_temp=220.0, klipper_minimum_temp=180.0, default_extruder_temp=200.0, source=auto 10:49:55 - DEBUG: Setting servo to up (filament released) position at angle: 138 10:49:55 - - TRACE: (toolhead sensor detects filament) 10:49:55 - DEBUG: Reverse homing up to 68.0mm to toolhead sensor 10:50:01 - - TRACE: Reverse homing to toolhead sensor. Stepper: 'extruder' did not home after moving -68.0mm (of max -68.0mm), encoder measured 19.7mm (delta 48.3mm). Pos: @-113.0, (66.5mm) 10:50:01 - - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Unloading' OLD_ACTION='Exiting Ext' 10:50:01 - - TRACE: Running macro: _MMU_ACTION_CHANGED ACTION='Idle' OLD_ACTION='Unloading' 10:50:01 An issue with the MMU has been detected whilst out of a print Reason: Unload sequence failed: Failed to reach toolhead sensor after moving 68.0mm 10:50:01 - DEBUG: Setting servo to move (filament hold) position at angle: 96 10:50:02 - - TRACE: Processing idle_timeout 'ready' event

This is version : 245d33abe3cf74a6623f89b37f2ffb2b52d90cb5

I suggest this fix.

image

jwhite commented 8 months ago

@moggieuk Where do you think the servo should be lifted? Which function? I'm easily reproducing this with tip cutting.

"This happens most of the time, all of the time"

Zephyrus67 commented 7 months ago

I have this issue as well. And in my case it is a constant thing.

I have the following settings in mmu_parameters.: sync_to_extruder: 0 sync_form_tip: 0 sync_feedback_enable: 0

Yet my ERCF 2 now starts every print by setting the servo in POS=MOVE After each toolchange it also sets the ERCF2 into POS=MOVE

My own fix has been to set MMU_SERVO POS=UP in my nozzle scrubber that is run on every print start in my print_start macro. That is fixing the problem for the print start. (The MMU_SERVO POS=UP could probably also just be placed in the end of the print_start macro for the printer).

For the toolchange issue I have a MMU_SERVO POS=UP in the _MMU_POST_LOAD macro in mmu_sequences.

At first I used my purge bucket to prime after a toolchange without a purge/wipe tower but I kept getting strange behaviors when starting printing again. Especially clogging warnings without any clogs when checking it manually.

I am now set on parking disabled. filament cutter and purge/wipe block in the slicer. And the settings I described above.

I DID for a short test try out using FORM_TIP instead of FORM_CUT but I must admit that I did not take any notice of the servor position due to other issues.

Zephyrus67 commented 7 months ago

@moggieuk, @jwhite

I just updated from HH 2.4.?.? to v2.5.0-32-gac57367b

This seems to have fixed the issues. I also had an issue with z_hop_height_toolchange not being used at all but that also seems fixed now.

Good job.

jwhite commented 1 month ago

Belived fixed. Not seeing the issue now.