[BUG] Gcode sliced with PrusaSlicer 2.7.1 causes single beep when switching filament with MMU3

[Kevman323]

Printer type - MK3S+ Printer firmware version - 3.13.2

MMU upgrade - MMU3 MMU upgrade firmware version - 3.0.1

SD card or USB/Octoprint - Octoprint

Describe the bug When a filament change occurs while printing a multimaterial print using the MMU3, the printer makes a single loud beep right before changing the filament. This doesn't happen when the same model is sliced with Prusaslicer 2.6.1, and only started happening when I downloaded 2.7.1. I've read online that this also happens with 2.7

This may seem like an issue with PrusaSlicer, and not the firmware, but there is only a single difference in generated gcode for the two files, and no lines that indicate something that would cause the beep. In any case, there's also an issue open on the PrusaSlicer page as well: https://github.com/prusa3d/PrusaSlicer/issues/11786

Ignoring progress messages, the only difference between the filament change sections of the gcode files is that in PrusaSlicer 2.6.1, this single line precedes the T[0-4] command:

G1 Z1.8 F720

The Z value varies, depending on the nozzle height. PrusaSlicer 2.7.1 does not add this extra nozzle hop line before the T[0-4] command. Seemingly the absence of this extra line causes the firmware to beep for a filament change, even though it should be silent and automatic.

To Reproduce Slice a multimaterial print for MMU3 on PrusaSlicer 2.7.1. The printer will beep on every automatic filament change. Slice on 2.6.1 to see the difference in behavior.

Expected behavior A loud beep should only happen in the case of a manual filament change, to get the user's attention. MMU changes should be silent

G-code The only gcode I've sliced with the new PrusaSlicer doesn't have it's first filament change until an hour in. If needed, I can make some quick test prints to show off the issue.

Once my current print is done, I plan on manually sending gcode commands to try and replicate the issue.

[gudnimg]

Sounds like a filament runout event. Have you checked the printer’s serial logs?

When a filament change occurs while printing a multimaterial print using the MMU3, the printer makes a single loud beep right before changing the filament.

does the printer raise a filament change screen?

[Kevman323]

Nope, not a filament runout, since it happens before it switches to the next needed filament. The beep happens when the nozzle is over the wipe tower, right as the filament starts unloading, then it just loads the next filament, purges to the wipe tower, and continues normally. Here's a video of it happening:

https://github.com/prusa3d/Prusa-Firmware/assets/20585337/af9a00e4-8d04-471e-aec2-a74049531c32

Looking at the serial output, there is an "LCD status changed" message, right after the T[0-4] command is sent, which I think is right when the beep happens, but it doesn't bring up an error screen of any kind. The beep happens when the printer starts doing it's side of the unload, before it even sends MMU2:>U0 to the MMU to finish pulling it out.

[gudnimg]

I’ll try reproducing this on my side tomorrow.

For reference, what is the Sound setting set to on your printer? ( is it “Loud”?)

[Kevman323]

Yep, it's set to Loud

[Kevman323]

I was able to do my tests. First of all, here's some test gcode. Apparently I can't upload gcode files, so I've renamed them .txt. These are all set up for PLA in slots 0 and 1.

First, sliced with PrusaSlicer 2.6.1, no beep: multicolor test PS 2.6.1_0.4n_0.2mm_PLA,PLA_MK3SMMU3_8m.txt Then, sliced with 2.7.1, same model and settings, beep: Multicolortest PS 2.7.1_0.4n_0.2mm_PLA,PLA_MK3SMMU3_7m.txt

Then to the 2.7.1 version, I added the G1 Z.6 F720 line back in before the first T1 filament swap, no beep: Multicolortest PS 2.7.1_G1_added_0.4n_0.2mm_PLA,PLA_MK3SMMU3_7m.txt Lastly, to the 2.7.1 version, I removed the G4 S0 line before the first T1 filament swap, no beep: Multicolortest PS 2.7.1_G4_removed_0.4n_0.2mm_PLA,PLA_MK3SMMU3_7m.txt

I looked through the code a bit, and I think the issue might lie here: https://github.com/prusa3d/Prusa-Firmware/blob/45d70b195d95db9151a34bef725d47e797bc54af/Firmware/mmu2.cpp#L371-L377 If !marlin_printingIsActive() passes, the unload() function has a contains WaitForHotendTargetTempBeep(); My guess is that the G4 S0 command might be causing printingIsActive() to return false, and trigger the extra unload function, and the extra G1 command after the G4 command in the 2.6.1 version might make printingIsActive() return true again before the T1. I could be completely wrong though, trying to wrap my head around the firmware has been quite a process, lol

[gudnimg]

I've tested the following files on both 3.13.2 and latest MK3 branch.

First, sliced with PrusaSlicer 2.6.1, no beep: multicolor test PS 2.6.1_0.4n_0.2mm_PLA,PLA_MK3SMMU3_8m.txt Then, sliced with 2.7.1, same model and settings, beep: Multicolortest PS 2.7.1_0.4n_0.2mm_PLA,PLA_MK3SMMU3_7m.txt

On my end I cannot reproduce the beep on either prints. 🤔 I have the sound setting set to Loud.

@Kevman323 Could you share a very verbose log from your printer? Preferably from the boot-up and until the beep appears. Since you use Octoprint it should just be some setting you have to enable to log to a file.

Meanwhile I will look a bit into the code.

Edit: By the way thank you for this detailed report. Since I cannot reproduce this, the issue smells a bit like it's timing related.

[gudnimg]

@Kevman323 I could reproduce the beep when I used Octoprint! ✅

In my previous comment, the results are from using the SD card only which does not reproduce this beep.

[gudnimg]

I tested the MK3 branch again (3.14.0 unreleased) which at the time of writing has the HEAD at https://github.com/prusa3d/Prusa-Firmware/commit/45d70b195d95db9151a34bef725d47e797bc54af and I can not reproduce the beep.

There are a ton a changes between 3.13.2 and 3.14.0 and we may have accidentally fixed the issue with some other change.

@Kevman323 Is it possible for you to try 3.14.0 to confirm my findings? If you haven't compiled the firmware before I can send you an image if you want. The MMU FW version is still set to 3.0.1 so should cause you no issues (It will likely get bumped to 3.0.2 later).

[Kevman323]

I just built the firmware and flashed, and I still get the beeps on the PS 2.7.1 test gcode file. Firmware on the support screen shows "3.14.0-BETA1-7945"

[gudnimg]

I went back to 3.13.2

I added logs to see the values of everything:

bool __attribute__((noinline)) printer_active() {
    bool res = printJobOngoing()
        || isPrintPaused
        || saved_printing
        || (lcd_commands_type != LcdCommands::Idle)
        || MMU2::mmu2.MMU_PRINT_SAVED()
        || homing_flag
        || mesh_bed_leveling_flag;
    if (!res)
    {
        printf_P(PSTR("IS_SD_PRINTING = %d\n"), (int)IS_SD_PRINTING);
        printf_P(PSTR("usb_timer.running() = %d\n"), (int)usb_timer.running());
        printf_P(PSTR("isPrintPaused = %d\n"), (int)isPrintPaused);
        printf_P(PSTR("saved_printing = %d\n"), (int)saved_printing);
        printf_P(PSTR("(lcd_commands_type != LcdCommands::Idle) = %d\n"), (int)(lcd_commands_type != LcdCommands::Idle));
        printf_P(PSTR("MMU2::mmu2.MMU_PRINT_SAVED() = %d\n"), (int)MMU2::mmu2.MMU_PRINT_SAVED());
        printf_P(PSTR("homing_flag = %d\n"), (int)homing_flag);
        printf_P(PSTR("mesh_bed_leveling_flag = %d\n"), (int)mesh_bed_leveling_flag);
    }

    return res;
}

And this is what I get before toolchange. I suspect the issue is caused by the usb_timer being expired when it clearly should not be. Needs to be investigated further.

Send: N139 T1*48
Recv: IS_SD_PRINTING = 0
Recv: usb_timer.running() = 0
Recv: isPrintPaused = 0
Recv: saved_printing = 0
Recv: (lcd_commands_type != LcdCommands::Idle) = 0
Recv: MMU2::mmu2.MMU_PRINT_SAVED() = 0
Recv: homing_flag = 0
Recv: mesh_bed_leveling_flag = 0
Recv: IS_SD_PRINTING = 0
Recv: usb_timer.running() = 0
Recv: isPrintPaused = 0
Recv: saved_printing = 0
Recv: (lcd_commands_type != LcdCommands::Idle) = 0
Recv: MMU2::mmu2.MMU_PRINT_SAVED() = 0
Recv: homing_flag = 0
Recv: mesh_bed_leveling_flag = 0
Recv: tool_change -> UNLOAD
Recv: LCD status changed

[gudnimg]

I think I've found the issue.

See my comments on the PS 2.7.1 gcode. The wiping in the X-axis takes ~16 seconds!

G1 X93.737 E20.0000 F454    ; Move X axis from 144.167mm to 93.737mm (distance = 50.43mm) at 7.56 mm /s, this will take 6.67 seconds
G1 X144.167 E-20.0000 F303  ; Move X axis from 93.747mm to 144.167mm (distance = 50.43mm) at 5.05 mm/s this will take 9.98 seconds
M73 P12 R6
M73 Q12 S6
G1 E-35.0000 F2000          ; Move E axis by 35mm at 33.3 mm/s (this takes roughly 1 second)
M73 P14 R6
M73 Q14 S6
G1 Y111.422 F2400
M73 P15 R6
M73 Q15 S6
G4 S0                       ; Triggers a blocking call which will wait for all planned moves to be done. Here the USB timer expires! (See st_synchronize(); in the code)
; Filament-specific end gcode
T1                          ; T1 is sent when the USB timer is expired => a unload is triggered
M900 K0.05 ; Filament gcode LA 1.5
M900 K30 ; Filament gcode LA 1.0

The G1 command added in PS 2.6.1 resolves the issue since is will restart the timer.

G1 X93.737 E20.0000 F454
G1 X144.167 E-20.0000 F303
M73 P12 R6
M73 Q12 S6
G1 E-35.0000 F2000
M73 P14 R6
M73 Q14 S6
G1 Y111.422 F2400
G4 S0             ; USB timer expires like in PS 2.7.1
M73 P15 R6
M73 Q15 S6
G1 Z.6 F720       ; A new G command is sent before Toolchange, this will restart the USB timer
; Filament-specific end gcode
T1

To fix this, I'm thinking we can restart the USB timer if the planner is executing moves AND provided the fact that the USB timer was running before. If the USB timer is not running when a planned move is executed, then we don't restart the timer.

Currently, from the way I see it, any long move that takes longer than 10 seconds will make the USB timer expire. This sounds like a bug to me.