search

moggieuk / Happy-Hare

MMU software driver for Klipper (ERCF, Tradrack, Box Turtle, Night Owl, Angry Beaver, 3MS, ...)
GNU General Public License v3.0
503 stars 128 forks source link

Problems with Restore Position since update to v2.7.1 #444

Open weuzor opened 1 month ago

weuzor commented 1 month ago

Hi, I am running happy hare with a custom park (user_pre_unload_extension), cut (form_tip_macro) and purge/prime/return (user_post_load_extension) macro. The latter „steals“ the nextpos coordinates from the happy hare park macro and moves the toolhead where it needs to be to continue the print after doing its stuff. This worked fine for the last couple of months but since the latest update happy hare would move the toolhead back to where the tool change started making a dot in the wrong color and return to the correct (next) position before continuing the print, although the _MMU_RESTORE_POSITION macro would not suggest to do so. When returning after parking it is the same except the toolhead returns to where it was parked, do some z move and return to where it already was. (I have variable_enable_park_printing , variable_enable_park_standalone and variable_enable_park_disabled empty, so happy hare parking should be disabled as it used to be pre 2.7.1.) Is there anything I can do to stop this from happening?

moggieuk commented 1 month ago

Ok, so you have turned off parking correctly -- setting those three params will do that (and I assume you haven't set any of the other parking extensions). The only other thing is that Happy Hare itself provides an overall safe guard to prevent printing in the wrong location. Without it folks were blaming for crashing into the bed for example. This fail-safe move uses restore_xy_pos to decide what to do...

Either ensure the toolhead is at last position, or next position if available, or the current x,y position if set to none.

If you can read the python, search for the comment:

# Paranoia: no matter what macros do ensure position and state is good. Either last, next or none (current x,y)

Let me know if setting this variable doesn't allow you to do what you need. I think it should (at least that was my intention).

weuzor commented 1 month ago

Thanks for your reply.

(and I assume you haven't set any of the other parking extensions)

I am not sure which other parking extensions you mean but my relevant settings are the following:

Movement section: variable_enable_park_printing : '' ; Empty '' to disable parking variable_enable_park_standalone : '' ; Empty '' to disable parking variable_enable_park_disabled : '' ; Empty '' to disable parking variable_min_toolchange_z : 0.0 ; The absolute minimum saftey floor (z-height) for ALL parking moves variable_park_toolchange : -1, -1, 0, 0, 0 ; x,y,z-hop,z_hop_ramp,retract for "toolchange" operations (toolchange,load,unload) variable_park_runout : -1, -1, 0, 0, 0 ; x,y,z-hop,z_hop_ramp,retract variable_park_pause : -1, -1, 0, 0, 0 ; x,y,z-hop,z_hop_ramp,retract (park position when mmu error occurs) variable_park_cancel : -1, -1, 0, 0, 0 ; x,y,z-hop,z_hop_ramp,retract variable_park_complete : -1, -1, 0, 0, 0 ; x,y,z-hop,z_hop_ramp,retract variable_pre_unload_position : -1, -1, 0 ; x,y,z-hop position before unloading starts variable_post_form_tip_position : -1, -1, 0 ; x,y,z-hop position after form/cut tip on unload variable_pre_load_position : -1, -1, 0 ; x,y,z-hop position before loading starts variable_restore_xy_pos : "next" ; last|next|none - What x,y position the toolhead should travel to after a "toolchange" variable_user_park_move_macro : '' ; Executed instead of default 'G1 X Y move' to park position

Extensions: variable_user_pre_unload_extension : '_PURGINATOR_HAPPY_PRE_UNLOAD' ; Executed after default logic form_tip_macro : _PURGINATOR_HAPPY_FORM_TIP_MACRO variable_user_post_form_tip_extension : '_PURGINATOR_HAPPY_POST_FORM_TIP' ; Executed after default logic variable_user_post_unload_extension : '_PURGINATOR_HAPPY_POST_UNLOAD' ; Executed after default logic variable_user_pre_load_extension : '_PURGINATOR_HAPPY_PRE_LOAD' ; Executed after default logic variable_user_post_load_extension : '_PURGINATOR_HAPPY_POST_LOAD' ; Executed after default logic but before restoring toolhead position variable_user_pause_extension : '_PURGINATOR_HAPPY_PAUSE' ; Executed after the klipper base pause variable_user_resume_extension : '_PURGINATOR_HAPPY_RESUME' ; Executed before the klipper base resume variable_user_cancel_extension : '_PURGINATOR_HAPPY_CANCEL' ; Executed before the klipper base cancel_print

Either ensure the toolhead is at last position, or next position if available, or the current x,y position if set to none.

My user_post_load_extension macro moves the printhead to the next_pos stored in the happy hare park macro. So after the user_post_load_extension ends the toolhead already is at happy hares next_pos correlating with variable_restore_xy_pos.

However, after that, the happy hare still would: -After initial tool change move the toolhead from print start position (next_pos) back to start (park) position and once again to print start position (next_pos). -After all other tool changes move from next pos to the position where the tool change started and the back to next pos. -When resuming after pause, in which my user_resume_extension uses its own stored coordinates for returning, the toolhead moves back to park pos and once again to the print. I wonder where happy hare would get that park pos coordinates from, as my parking position is nowhere configured in happy hare.

Let me know if setting this variable doesn't allow you to do what you need. I think it should (at least that was my intention).

Unfortunately not :-(

moggieuk commented 1 month ago

Hmmm, you really are fighting some pretty challenging logic here because there are so many combination of events. However, I think one missing piece is that you need to call:

_MMU_CLEAR_POSITION

perhaps in your post_load macro. That will ensure that when _MMU_RESTORE_POSITION is called it will do nothing.

You will also need to set restore_xy to next or none otherwise the failsafe in HH itself will "correct" you. none is probably safer because it will essentially set the gcode state restoration to the current x/y coordinates.

On the pause case, Happy Hare will doctor the saved PAUSE_STATE so that the base RESUME will always return to the expected position. This is necessary to prevent back-and-forth movement on resume. Could that be the missing info you are looking for?

Finally can you validate you are on a late patch of v2.7.1 -- if not force and update because a bug was fixed in the parking logic.

weuzor commented 1 month ago

Thank you for this tip which sounds very promising. Unfortunately I cannot give it a try at the moment as my mmu servo died. Will report the outcome after replacing the servo.

moggieuk commented 1 month ago

Ok.

I wondered, given the extensive parking and movement logic that now exists why you would need to handle all the movement in extension macros?

weuzor commented 1 month ago

Curiosity made me change the servo in record time and I am happy to report putting _MMU_CLEAR_POSITION at the end of my return macro was the decisive hint and solved my issues for the tool changes. Thanks a lot!

However, resume after park is more resilient and still shows the described behavior although my user_resume_extension calls the very same return macro with the _MMU_CLEAR_POSITION command at its end. And the happy hare client resume macro (which I use) also calls _MMU_RESTORE_POSITION which then should do nothing. Even putting _MMU_CLEAR_POSITION in the user_pause_extension does not change that. Is there another mechanic besides _MMU_RESTORE_POSITION which moves the toolhead after user_resume_extension?

I wondered, given the extensive parking and movement logic that now exists why you would need to handle all the movement in extension macros?

Because I run these macros since times when happy hare did not have this functionality. They are very much optimized for the purge station I built. We talked about it briefly quite a while ago if you remember. It changed a lot since then. If you want to have a look: github.com/weuzor/purginator But it is definitely on my to do list to look into the new functions of happy hare more deeply and see if I can offload stuff to happy hare :-)

moggieuk commented 1 month ago

Oh, I remember you now! Sorry, just so many conversations.... The purginator is pretty cool - I need to take another look at it.

So, a little more detail on movement. The _MMU_CLEAR_POSITION does reset the macros completely (as you have discovered) which is where almost all the logic is now. It does not change what HH does internally and there are two things to note:

  1. As described, HH has built in protection and will restore toolhead position no matter what. It does respect the restore_xy_pos setting. So while it will always restore the z-height, the x,y restoration can be last/next/none. You will see a log message "Ensuring toolhead position..." when this logic runs. With my new park macros this will be a no-op.
  2. HH manipulates the toolhead postion that is recorded by the BASE klipper pause. Essentially on resume I intercept the call and change the recorded BASE pause toolhead position to be current position, so the movement part of restoring state will do nothing. Finally I run HH's restore position logic that will run macro _MMU_RESTORE_POSITION and then the sanity check in 1 above.

So I think setting restore_xy_pos: none will turn off x,y toolhead restoration by HH (but z will always be corrected).

weuzor commented 1 month ago

To completely rule out any involvement of _MMU_RESTORE_POSITION I changed it temporarily to

[gcode_macro _MMU_RESTORE_POSITION] description: Restore saved toolhead position gcode: _MMU_CLEAR_POSITION

.. which also had no effect so I assumed it must have to do with the built in protection. However, setting restore_xy_pos to „none“ also has no effect so I set it back to next :-(

I do have entries in my log: 20:37:59   DEBUG: Ensuring correct gcode state and position (X:48.9 Y:300.5 Z:0.4 E:191.7) after toolchange after which all is good, toolhead is not moved

20:39:33   DEBUG: Ensuring correct gcode state and position (X:86.0 Y:301.5 Z:0.4 E:411.6) after resume after which the toohead still moves from X:86.0 Y:301.5 Z:0.4 back to park position producing an impressive string and then move again to X:86.0 Y:301.5 Z:0.4 to smear it onto the print.

As mentioned before the park location the toolhead moves to is nowhere configured in happy hare so it must be stored somehow after the user_pause_extension and before the user_resume_extension. Looking at the log entries the only difference I see is the „mmu pause wrapper“ and the „mmu resume wrapper“ Could the unwanted move be associated with one of them? Sorry to bother you so much with this.

Log: Pause/resume 19:39:28   DEBUG: MMU PAUSE wrapper called 19:39:28   DEBUG: Saving toolhead gcode state and position (X:55.5 Y:266.9 Z:0.4 E:51.2) for pause 19:39:28 > mmu_sync_gear_motor 19:39:35 > RESUME 19:39:35   DEBUG: MMU RESUME wrapper called 19:39:35 > mmu_sync_gear_motor 19:39:39 > mmu_sync_gear_motor 19:39:40   DEBUG: Continuing from printing state after resume 19:39:42   DEBUG: Ensuring correct gcode state and position (X:55.5 Y:266.9 Z:0.4 E:468.8) after resume

Toolchange 20:42:58 > MMU_CHANGE_TOOL TOOL=3 NEXT_POS="48.903,300.503" ; T3 20:42:58   DEBUG: Tool change initiated with standalone MMU tip forming 20:42:58 Tool change requested, from T1 to T3 20:42:58   DEBUG: Saving toolhead gcode state and position (X:65.0 Y:308.9 Z:0.8 E:25.7) for toolchange 20:42:58 Restoring MMU gear stepper run current to 100% configured 20:43:00 Unsynced MMU from extruder 20:43:00   DEBUG: Unloading tool T1 20:43:00 > mmu_sync_gear_motor 20:43:00 Modifying MMU gear stepper run current to 70% for extruder syncing 20:43:00 Synced MMU to extruder 20:43:03 Unloading filament... 20:43:03 [T1] < En <<<<<<<<< () << [Ex << () << Nz] LOADED 0.0mm (e:0.0mm) 20:43:04 Restoring MMU gear stepper run current to 100% configured 20:43:04   DEBUG: Setting pressure advance for tip forming: 0.000000 20:43:04 Forming tip... 20:43:08   DEBUG: Restoring pressure advance: 0.000000 20:43:08 [T1] < En <<<<<<<<< () << [Ex << () <. Nz] -7.0mm (e:6.6mm) 20:43:09   DEBUG: Extracting filament from extruder 20:43:09   DEBUG: Reverse homing up to 83.0mm to extruder sensor (synced) to exit extruder 20:43:09 Unsynced MMU from extruder 20:43:12 [T1] < En <<<<<<<<<|(e) .. [Ex .. (t) .. Nz] -54.1mm (e:53.1mm) 20:43:12   DEBUG: Filament should be out of extruder 20:43:12   DEBUG: Unloading bowden tube 20:43:12   DEBUG: Performing bowden pre-unload test 20:43:13 [T1] < En <<<<<.... (e) .. [Ex .. (t) .. Nz] -95.0mm (e:67.3mm) 20:43:20 [T1] < En <........ (e) .. [Ex .. (t) .. Nz] -1078.1mm (e:1051.2mm) 20:43:20   DEBUG: Slow unload of the encoder 20:43:22 Warning: Possible encoder malfunction (free-spinning) during final filament parking 20:43:22 [T1] < En ......... (e) .. [Ex .. (t) .. Nz] UNLOADED -1128.6mm (e:1101.4mm) 20:43:22   DEBUG: Setting servo to up (filament released) position at angle: 30 20:43:23 Unload of -1128.6mm filament successful (encoder measured 1101.4mm) 20:43:23   DEBUG: Autotune: bowden move ratio: 1.000799, Extra homing movement: 0.0mm 20:43:23   DEBUG: Loading tool T3... 20:43:24   DEBUG: Selecting tool T3 on Gate 3... 20:43:24   DEBUG: Setting servo to move (filament hold) position at angle: 30 20:43:24 Tool T3 enabled 20:43:24 Loading filament... 20:43:24 [T3] > En ......... (e) .. [Ex .. (t) .. Nz] UNLOADED 0.0mm (e:0.0mm) 20:43:24   DEBUG: Setting servo to down (filament drive) position at angle: 140 20:43:25 > MMU_STATS COUNTER=servo_down INCR=1 20:43:27 [T3] > En >........ (e) .. [Ex .. (t) .. Nz] 79.2mm (e:79.6mm) 20:43:27   DEBUG: Loading bowden tube 20:43:34 [T3] > En >>>>>>>>> (e) .. [Ex .. (t) .. Nz] 1059.1mm (e:1061.6mm) 20:43:34   DEBUG: Loading filament into extruder 20:43:34   DEBUG: Homing up to 40.0mm to toolhead sensor (synced) 20:43:37 [T3] > En >>>>>>>>> () >> [Ex >>|() .. Nz] 1085.8mm (e:1088.2mm) 20:43:37   DEBUG: Loading last 55.0mm to the nozzle... 20:43:40 [T3] > En >>>>>>>>> () >> [Ex >> () >> Nz] LOADED 1140.8mm (e:1143.1mm) 20:43:40   DEBUG: Filament should loaded to nozzle 20:43:40 Load of 1140.8mm filament successful (encoder measured 1143.1mm) 20:43:40   DEBUG: Autotune: bowden move ratio: 1.002181, Extra homing movement: 16.7mm 20:43:40 > MMU_SLICER_TOOL_MAP PURGE_MAP=1 20:43:40 > mmu_sync_gear_motor 20:43:40 Modifying MMU gear stepper run current to 70% for extruder syncing 20:43:40 Synced MMU to extruder 20:44:04 > mmu_sync_gear_motor 20:44:06 MMU Statistics: 20:44:06   DEBUG: Continuing from printing state after toolchange 20:44:06   DEBUG: Ensuring correct gcode state and position (X:48.9 Y:300.5 Z:0.8 E:598.9) after toolchange 20:44:06 > __MMU_EXTRUDER_RUNOUT

moggieuk commented 1 month ago

Hmmm My logic for the "Ensuring correct gcode state and position..." is: (and this is all in mmu.py and not in the macros since as the comment suggests it is paranoia and a final precaution):

# Allow resume to restore position if in mmu error/paused state
if not (self._is_mmu_paused() or self._is_printer_paused()) or (operation == "resume" and (self._is_mmu_paused() or self._is_printer_paused())):
    # Controlled by the RESTORE=0 flag to MMU_LOAD, MMU_EJECT, MMU_CHANGE_TOOL (only real use case is final eject)
    if restore:
        self._wrap_gcode_command(self.restore_position_macro) # Restore macro position and clear saved

        # Paranoia: no matter what macros do ensure position and state is good. Either last, next or none (current x,y)
        sequence_vars_macro = self.printer.lookup_object("gcode_macro _MMU_SEQUENCE_VARS", None)
        if sequence_vars_macro and sequence_vars_macro.variables.get('restore_xy_pos', 'last') == 'none' and self.saved_toolhead_operation in ['toolchange']:
            # Don't change x,y position on toolchange
            current_pos = self.gcode_move.get_status(eventtime)['gcode_position']
            self.gcode_move.saved_states[self.TOOLHEAD_POSITION_STATE]['last_position'][:2] = current_pos[:2]
        gcode_pos = self.gcode_move.saved_states[self.TOOLHEAD_POSITION_STATE]['last_position']
        display_gcode_pos = " ".join(["%s:%.1f" % (a, v) for a, v in zip("XYZE", gcode_pos)])
        self.gcode.run_script_from_command("M204 S%d" % self.saved_toolhead_max_accel)
        self.gcode.run_script_from_command("RESTORE_GCODE_STATE NAME=%s MOVE=1 MOVE_SPEED=%.1f" % (self.TOOLHEAD_POSITION_STATE, self.saved_toolhead_speed))
        self.log_debug("Ensuring correct gcode state and position (%s) after %s" % (display_gcode_pos, operation))
        self._clear_saved_toolhead_position()
        return

The resume wrapper does this before calling your resume:

# Prevent BASE_RESUME from moving toolhead
if self.TOOLHEAD_POSITION_STATE in self.gcode_move.saved_states:
    gcode_pos = self.gcode_move.get_status(self.reactor.monotonic())['gcode_position']
    self.gcode_move.saved_states['PAUSE_STATE']['last_position'][:3] = gcode_pos[:3]

which always "edits" the base resume restore position so that it doesn't move.

All of this to say:

moggieuk commented 1 month ago

I know I tweaked this logic so first can you double check this still occurs with the latest Happy Hare. I pushed my v2.7.2 work to main now. If you still have this problem I will fix, but I can't see how it is happening with current logic.

EDIT: In wondering if it is because the "initiating" operation is "pause" rather than "toolchange" and thus the "none" logic isn't occurring... I.e. you pause first, then restore will be incorrect for "none". If you toolchange, then have pause, it will be ok. The problem is that if the first parking action is "pause", I can't allow next/none logic to apply because that is intended for in print where the next line of gcode will fix.

What is your use case for pause / resume not restoring to "last" position?

Also, can you share your "RESTORE" macro

weuzor commented 1 month ago

I know I tweaked this logic so first can you double check this still occurs with the latest Happy Hare. I pushed my v2.7.2 work to main now. If you still have this problem I will fix, but I can't see how it is happening with current logic.

I updated to Happy Hare v2.7.2-20-gd70ff209 but the unwanted move still persists.

The resume wrapper does this before calling your resume: Prevent BASE_RESUME from moving toolhead if self.TOOLHEAD_POSITION_STATE in self.gcode_move.saved_states: gcode_pos = self.gcode_move.get_status(self.reactor.monotonic())['gcode_position'] self.gcode_move.saved_states['PAUSE_STATE']['last_position'][:3] = gcode_pos[:3]

Unfortunately I don’t speak python but If the resume wrapper does this before my return macro is called the toolhead is at that time at the position the unwanted back and forth move is directed to (y, y and z).

What is your use case for pause / resume not restoring to "last" position?

I am not quite sure what you mean. After pause/resume my restore macro moves the toolhead to the position which my park macro saved before moving the toolhead. So I guess this is „last“ position.

Also, can you share your "RESTORE" macro

Hereafter are pause and resume extensions and the return macro. All other macros are also on the GitHub.

[gcode_macro _PURGINATOR_HAPPY_PAUSE]
description: Happy Hare User Pause Extension
gcode:
    _PURGINATOR_PARK

[gcode_macro _PURGINATOR_HAPPY_RESUME]
description: Happy Hare User Resume Extension
gcode:
    ## purge if a return position is set (prevents purging and errors if the print is paused before actual printing began)
    {% if printer['gcode_macro _PURGINATOR_RETURN'].return_pos_stored %}
        ## execute purge sequence, optionally retracting filament and descending gantry during servo waittimes
        _PURGINATOR_PURGE RETRACTSPEED={printer['gcode_macro _PURGINATOR_VARS'].return_retract_speed } DESCENDSPEED={printer['gcode_macro _PURGINATOR_VARS'].return_descend_speed}
        ## return to print suppressing the use of happy hare nextpos
        _PURGINATOR_RETURN NEXTPOS=0
    {% endif %}

[gcode_macro _PURGINATOR_RETURN]
description:  Return toolhead to print
variable_return_pos_stored:    False
variable_return_pos_x:         0
variable_return_pos_y:         0
variable_return_pos_z:         2
variable_return_travel_height: 2
gcode:
    ## respond macroname incl. parameters for debugging
    {% if printer['gcode_macro _PURGINATOR_VARS'].show_issued_commands %}
        RESPOND TYPE=command MSG="_PURGINATOR_RETURN {rawparams}"
    {% endif %}
    ## save gcode state
    SAVE_GCODE_STATE NAME=_PURGINATOR_RETURN
    ## set parameters
    {% set printing = params.PRINTING | default ( printer.mmu.print_state == 'printing' ) %}
    {% set retractspeed = printer['gcode_macro _PURGINATOR_VARS'].return_retract_speed | float %}
    {% set descendspeed = printer['gcode_macro _PURGINATOR_VARS'].return_descend_speed | float %}
    ## sync gear motor
    mmu_sync_gear_motor
    ## return to print if return pos is stored
    {% if return_pos_stored and printing %}
        ## update return pos to happy hare next_pos if available and not prohibited by parameter NEXTPOS=0 (for resume after pause)
        {% if printer['gcode_macro _MMU_PARK'].next_pos and params.NEXTPOS | default ( 1 ) | int == 1 %}
            ## get next pos from happy hare park macro
            {% set nx,ny = printer['gcode_macro _MMU_PARK'].next_xy|map('float') %}
            {% set return_pos_x = nx %}
            {% set return_pos_y = ny %}
            ## respond begin of return sequence
            {% if params.RESPOND|default(printer['gcode_macro _PURGINATOR_VARS'].respond_detail_level)|int >= 1 %}
                RESPOND TYPE=command MSG="❇️ Returning toolhead to happy hare nextpos x: "{return_pos_x | round(2)}" y: "{return_pos_y | round(2)}" z: "{return_pos_z | round(2)}" ..."
            {% endif %}
        {% else %}
            ## respond begin of return sequence
            {% if params.RESPOND|default(printer['gcode_macro _PURGINATOR_VARS'].respond_detail_level)|int >= 1 %}
                RESPOND TYPE=command MSG="❇️ Returning toolhead to x: "{return_pos_x | round(2)}" y: "{return_pos_y | round(2)}" z: "{return_pos_z | round(2)}" ..."
            {% endif %}
        {% endif %}
        ## ensure not hitting print or bed if gantry was moved for some reason
        {% if printer.gcode_move.gcode_position.z < return_travel_height %}
            _purginator_travel Z={return_travel_height}
        {% endif %}     
        ## undock with nozzle wipe
        _PURGINATOR_UNDOCK WIPE=True {rawparams}
        ## if enabled, brush nozzle before returning to print
        {% if printer['gcode_macro _PURGINATOR_VARS'].brush_during_return %}
            {% set wipes = printer['gcode_macro _PURGINATOR_VARS'].return_brush_wipes|int %}
            {% set zigzags = printer['gcode_macro _PURGINATOR_VARS'].return_brush_zigzags|int %}
            {% set start_y_depth = printer['gcode_macro _PURGINATOR_VARS'].return_brush_start_y_depth|int %}
            _PURGINATOR_BRUSH_NOZZLE WIPES={wipes} ZIGZAGS={zigzags} DEPTH={start_y_depth} RETRACTSPEED={retractspeed} DESCENDSPEED={descendspeed}
        {% endif  %}
        ## travel to park_z_hop above return position, optionally retracting filament
        _purginator_travel X={return_pos_x} Y={return_pos_y} Z={return_travel_height} RETRACTSPEED={retractspeed}
        ## lower nozzle to print level, optionally retracting filament
        _purginator_travel Z={return_pos_z} RETRACTSPEED={retractspeed}
        ## unretract filament
        _purginator_filament_unretract SPEED={printer['gcode_macro _PURGINATOR_VARS'].return_unretract_speed}
        ## clear return position
        _purginator_clear_return_position
        ## clear mmu position to prevent happy hare from moving the toolhead beyond this point
        _MMU_CLEAR_POSITION
        ## respond end of return sequence
        {% if params.RESPOND|default(printer['gcode_macro _PURGINATOR_VARS'].respond_detail_level)|int >= 1 %}
            RESPOND TYPE=command MSG="❇️ Toolhead returned"
        {% endif %}   
    ## not printing or no return position 
    {% else %}
        ## undock with nozzle wipe
        _PURGINATOR_UNDOCK WIPE=True {rawparams}
        ## unretract any accumulated retraction
        _purginator_filament_unretract SPEED={printer['gcode_macro _PURGINATOR_VARS'].return_unretract_speed}
    {% endif %}
    ## restore gcode state
    RESTORE_GCODE_STATE NAME=_PURGINATOR_RETURN
weuzor commented 1 month ago

After changes to my print start sequence I noticed that the first toolchange is also an occasion where unexpected toolhead moves happen. Before the print starts the toolhead would rise to the z height the gantry was at when the toolchange started and then move back down to the printed and start printing (https://youtu.be/Xf8zcAJq_CM). This was previously unnoticed, as in my old print start sequence the first toolchange was initiated at 1 mm height, now at 20. Strange, that there is only z movement as opposed to pause/resume (https://youtu.be/HVXZDi0NL_g) where there is also x y movement.

Below is the MMU Log of such toolchange (no idea why all entries are double).

> MMU_CHANGE_TOOL TOOL=5 NEXT_POS="103.187,150.431" ; T5
18:45:30   DEBUG: Tool change initiated with standalone MMU tip forming
18:45:30 Tool change requested: T5
18:45:30 > MMU_CHANGE_TOOL TOOL=5 NEXT_POS="103.187,150.431" ; T5
18:45:30   DEBUG: Saving toolhead gcode state and position (X:2.8 Y:358.0 Z:20.0 E:11.8) for toolchange
18:45:30   DEBUG: Tool change initiated with standalone MMU tip forming
18:45:30 Tool change requested: T5
18:45:30   DEBUG: Saving toolhead gcode state and position (X:2.8 Y:358.0 Z:20.0 E:11.8) for toolchange
18:45:30 Saving toolhead position (x:2.8, y:358.0, z:20.0)
18:45:30 Saving toolhead position (x:2.8, y:358.0, z:20.0)
18:45:30 Restoring MMU gear stepper run current to 100% configured
18:45:30 Restoring MMU gear stepper run current to 100% configured
18:45:30 Unsynced MMU from extruder
18:45:30 Unsynced MMU from extruder
18:45:30   DEBUG: Loading tool T5...
18:45:30   DEBUG: Loading tool T5...
18:45:30   DEBUG: Selecting tool T5 on Gate 5...
18:45:30   DEBUG: Selecting tool T5 on Gate 5...
18:45:30   DEBUG: Setting servo to move (filament hold) position at angle: 30
18:45:30   DEBUG: Setting servo to move (filament hold) position at angle: 30
18:45:31 Tool T5 enabled
18:45:31 Tool T5 enabled
18:45:32 Loading filament...
18:45:32 Loading filament...
18:45:32 [T5] > En ......... (e) .. [Ex .. (t) .. Nz] UNLOADED 0.0mm (e:0.0mm)
18:45:32 [T5] > En ......... (e) .. [Ex .. (t) .. Nz] UNLOADED 0.0mm (e:0.0mm)
18:45:32   DEBUG: Setting servo to down (filament drive) position at angle: 140
18:45:32   DEBUG: Setting servo to down (filament drive) position at angle: 140
18:45:33 > MMU_STATS COUNTER=servo_down INCR=1
18:45:33 > MMU_STATS COUNTER=servo_down INCR=1
18:45:35 [T5] > En >........ (e) .. [Ex .. (t) .. Nz] 65.0mm (e:65.4mm)
18:45:35 [T5] > En >........ (e) .. [Ex .. (t) .. Nz] 65.0mm (e:65.4mm)
18:45:35   DEBUG: Loading bowden tube
18:45:35   DEBUG: Loading bowden tube
18:45:43 [T5] > En >>>>>>>>> (*) .. [Ex .. (t) .. Nz] 1059.1mm (e:1084.4mm)
18:45:43 [T5] > En >>>>>>>>> (*) .. [Ex .. (t) .. Nz] 1059.1mm (e:1084.4mm)
18:45:43   DEBUG: Loading filament into extruder
18:45:43   DEBUG: Homing up to 40.0mm to toolhead sensor (synced)
18:45:43   DEBUG: Loading filament into extruder
18:45:43   DEBUG: Homing up to 40.0mm to toolhead sensor (synced)
18:45:44 [T5] > En >>>>>>>>> (*) >> [Ex >>|(*) .. Nz] 1066.8mm (e:1091.9mm)
18:45:44 [T5] > En >>>>>>>>> (*) >> [Ex >>|(*) .. Nz] 1066.8mm (e:1091.9mm)
18:45:44   DEBUG: Loading last 55.0mm to the nozzle...
18:45:44   DEBUG: Loading last 55.0mm to the nozzle...
18:45:47 [T5] > En >>>>>>>>> (*) >> [Ex >> (*) >> Nz] LOADED 1121.8mm (e:1146.0mm)
18:45:47 [T5] > En >>>>>>>>> (*) >> [Ex >> (*) >> Nz] LOADED 1121.8mm (e:1146.0mm)
18:45:47   DEBUG: Filament should loaded to nozzle
18:45:47 Load of 1121.8mm filament successful (encoder measured 1146.0mm)
18:45:47   DEBUG: Autotune: bowden move ratio: 1.025034, Extra homing movement: 0.0mm
18:45:47   DEBUG: Filament should loaded to nozzle
18:45:47 Load of 1121.8mm filament successful (encoder measured 1146.0mm)
18:45:47   DEBUG: Autotune: bowden move ratio: 1.025034, Extra homing movement: 0.0mm
18:45:47 > MMU_SLICER_TOOL_MAP PURGE_MAP=1
18:45:47 --------- Slicer MMU Tool Summary ---------
         Single color print
         T5 (Gate 5, ABS, 21ff06, 230°C)
         Initial Tool: T5
         -------------------------------------------
         Purge Volume Map (mm^3):
         To -> T0   T1   T2   T3   T4   T5   T6   T7 
         T0    -    60  561  569  404  553  307  646
         T1    60   -   561  569  404  553  307  646
         T2    82   82   -   228  255  235  272  207
         T3   112  112  403   -   165  231  255  238
         T4    89   89  577  379   -   461  236  529
         T5   110  110  429  311  241   -   253  361
         T6    80   80  664  567  395  547   -   654
         T7   127  127  278   89  244  210  266   - 
18:45:47 > MMU_SLICER_TOOL_MAP PURGE_MAP=1
18:45:47 --------- Slicer MMU Tool Summary ---------
         Single color print
         T5 (Gate 5, ABS, 21ff06, 230°C)
         Initial Tool: T5
         -------------------------------------------
         Purge Volume Map (mm^3):
         To -> T0   T1   T2   T3   T4   T5   T6   T7 
         T0    -    60  561  569  404  553  307  646
         T1    60   -   561  569  404  553  307  646
         T2    82   82   -   228  255  235  272  207
         T3   112  112  403   -   165  231  255  238
         T4    89   89  577  379   -   461  236  529
         T5   110  110  429  311  241   -   253  361
         T6    80   80  664  567  395  547   -   654
         T7   127  127  278   89  244  210  266   - 
18:45:47 > mmu_sync_gear_motor
18:45:47 Modifying MMU gear stepper run current to 70% for extruder syncing
18:45:47 > mmu_sync_gear_motor
18:45:47 Modifying MMU gear stepper run current to 70% for extruder syncing
18:45:48 Synced MMU to extruder
18:45:48 Synced MMU to extruder
18:45:51 > mmu_sync_gear_motor
18:45:51 > mmu_sync_gear_motor
18:45:54 MMU Statistics:
         +-----------+--------------------------+---------------------------+----------+
         |  3104(1)  |        unloading         |          loading          | complete |
         |   swaps   |  pre  |    -     |  post | pre  |    -     |   post  |   swap   |
         +-----------+-------+----------+-------+------+----------+---------+----------+
         |    total  | 58:36 | 18:39:57 | 32:14 | 6:14 | 14:10:47 | 6:31:51 | 28:56:07 |
         |     └ avg |  1.13 |     21.6 |  0.62 | 0.12 |     16.4 |    7.57 |     33.6 |
         | this job  |     - |        - |     - | 1.02 |     14.8 |    5.98 |     22.9 |
         |     └ avg |     - |        - |     - | 1.02 |     14.8 |    5.98 |     22.9 |
         |      last |     - |        - |     - | 1.02 |     14.8 |    5.98 |     22.9 |
         +-----------+-------+----------+-------+------+----------+---------+----------+

         15:11:45 spent paused over 41 pauses (All time)
         0.00 spent paused over 0 pauses (This job)
         Number of swaps since last incident: 62 (Record: 348)

         Gate Statistics:
         0:😎, 1:😎, 2:😎, 3:😎, 4:😎, 5:😎, 6:😎, 7:😎
18:45:54 MMU Statistics:
         +-----------+--------------------------+---------------------------+----------+
         |  3104(1)  |        unloading         |          loading          | complete |
         |   swaps   |  pre  |    -     |  post | pre  |    -     |   post  |   swap   |
         +-----------+-------+----------+-------+------+----------+---------+----------+
         |    total  | 58:36 | 18:39:57 | 32:14 | 6:14 | 14:10:47 | 6:31:51 | 28:56:07 |
         |     └ avg |  1.13 |     21.6 |  0.62 | 0.12 |     16.4 |    7.57 |     33.6 |
         | this job  |     - |        - |     - | 1.02 |     14.8 |    5.98 |     22.9 |
         |     └ avg |     - |        - |     - | 1.02 |     14.8 |    5.98 |     22.9 |
         |      last |     - |        - |     - | 1.02 |     14.8 |    5.98 |     22.9 |
         +-----------+-------+----------+-------+------+----------+---------+----------+

         15:11:45 spent paused over 41 pauses (All time)
         0.00 spent paused over 0 pauses (This job)
         Number of swaps since last incident: 62 (Record: 348)

         Gate Statistics:
         0:😎, 1:😎, 2:😎, 3:😎, 4:😎, 5:😎, 6:😎, 7:😎
18:45:54   DEBUG: Continuing from printing state after toolchange
18:45:54   DEBUG: Continuing from printing state after toolchange
18:45:54   DEBUG: Ensuring correct gcode state and position (X:103.2 Y:150.4 Z:20.0 E:2724.9) after toolchange
18:45:54   DEBUG: Ensuring correct gcode state and position (X:103.2 Y:150.4 Z:20.0 E:2724.9) after toolchange
18:45:54 > __MMU_EXTRUDER_INSERT
18:45:54 > __MMU_EXTRUDER_INSERT
18:45:54   DEBUG: Ignoring extruder insertion because bypass not selected
18:45:54   DEBUG: Ignoring extruder insertion because bypass not selected
18:45:54   DEBUG: Setting toolchange height floor to 20.0
18:45:54   DEBUG: Setting toolchange height floor to 20.0
github-actions[bot] commented 1 week ago

This issue is stale because it has been open for over 30 days with no activity. It will be closed in 14 days automatically unless there is activity.

weuzor commented 1 week ago

showing life sign to prevent going stale

TTom1088 commented 1 week ago

I have the same problem, but at first I suspected a configuration error on my part. Then I came across this report. In my case the error is a bit meaner, as it can destroy the entire printer. In my case the printer moves to the last corner after the break and then to Z4.5 to get to the brush, after cleaning it moves up to the previously saved Z coordinate and only then starts printing again. If an error occurs during cleaning (e.g. low extruder temperature) The happy hare then moves directly to the print, diagonally in the Z coordinate, so the gantry then moves against the print. Normally it would simply do nothing and I could intervene and then press resume again.

I have of course also done my "research" to prevent pointless back and forth travel. I have found an "unclean solution" for this. I simply commented out my own "RESTORE_GCODE_STATE" in my resume macro.

[gcode_macro PAUSE]
rename_existing: BASE_PAUSE
variable_extruder_temp: 0
variable_fan_drehzahl: 0

gcode:
    G90
    Licht_hell
    Gate_Abfrage_ES    #Fehler verhindern
    SET_GCODE_VARIABLE MACRO=hotend_fan_check_status VARIABLE=check_an VALUE=0 # schaltet Hotend Lüfter Überwachung aus
    SET_GCODE_VARIABLE MACRO=CANCEL_PRINT VARIABLE=stop_von_pause VALUE=1  # für cancel print
    #_MMU_PARK
    TASTER_Pause_process_pause
    RESPOND PREFIX=tgalarm MSG="Drucker ist wegen einer Störung auf Pause gegangen, bitte überprüfen"
    #ERCF_Fehler_Status
    G1 F96000
    SET_GCODE_VARIABLE MACRO=PAUSE VARIABLE=extruder_temp VALUE={printer.extruder.target} # Nozzle Temperatur speichern
    SET_GCODE_VARIABLE MACRO=PAUSE VARIABLE=fan_drehzahl VALUE={printer['fan'].speed}
    M106 S0
    M117 Pause
    G1 F96000
    G90
    SAVE_GCODE_STATE NAME=PAUSE_Position
    BASE_PAUSE
    G91
    G1 E-3 F2100
    G1 Z5
    G90
    G1 X31 Y350 F96000    
    G92 E0
    SAVE_GCODE_STATE NAME=RESUME_OBEN
    G1 F2400 E-20            
    G92 E0   
    SET_IDLE_TIMEOUT TIMEOUT=86400
    SET_HEATER_TEMPERATURE HEATER=extruder TARGET=0
    SET_GCODE_VARIABLE MACRO=_TASTER_VARIABEL VARIABLE=drucker_status VALUE=2
    _TASTEN_LED_ABFRAGE
    MMU_ENCODER ENABLE=0
    MMU_LED_Abfrage

#######################################

[gcode_macro RESUME]
rename_existing: BASE_RESUME
variable_start_error: 0

gcode: 

    SET_GCODE_VARIABLE MACRO=CANCEL_PRINT VARIABLE=stop_von_pause VALUE=0 # für cancel print
    SET_GCODE_VARIABLE MACRO=_TASTER_VARIABEL VARIABLE=drucker_status VALUE=1
    _TASTEN_LED_ABFRAGE
    TASTER_Resume_process_pause
    G90
    M117 Fortsetzung
    G1 F96000
    SET_HEATER_TEMPERATURE HEATER=extruder TARGET={printer["gcode_macro PAUSE"].extruder_temp}   
    G1 X31 Y350 F96000
    G1 Z4.5
    #test
    M109 S{printer["gcode_macro PAUSE"].extruder_temp}
    G92 E0
    G1 F2400 E20             
    G92 E0   
    G91
    G1 E3 F2100
    G90
    G1 F24000
    G10
    NOZZLE_WISCHEN
    RESTORE_GCODE_STATE NAME=RESUME_OBEN MOVE=1
    G1 F96000
    SET_IDLE_TIMEOUT TIMEOUT=600
    #RESTORE_GCODE_STATE NAME=PAUSE_Position MOVE=1 MOVE_SPEED=300      #deaktiviert wegen mmu auto 
    M106 S{printer["gcode_macro PAUSE"].fan_drehzahl*255}
    Licht_dunkel
    LED_Drucken
    SET_GCODE_VARIABLE MACRO=_TASTER_VARIABEL VARIABLE=drucker_status VALUE=1
    _TASTEN_LED_ABFRAGE
    SET_GCODE_VARIABLE MACRO=hotend_fan_check_status VARIABLE=check_an VALUE=1 # schaltet Hotend Lüfter Überwachung an
    G11
    MMU_ENCODER ENABLE=1
    BASE_RESUME
    MMU_LED_Abfrage