Jyers / Marlin

Marlin is an optimized firmware for RepRap 3D printers based on the Arduino platform. | Many commercial 3D printers come with Marlin installed. Check with your vendor if you need source code for your specific machine.
http://marlinfw.org
GNU General Public License v3.0
2.14k stars 387 forks source link

Preheat After Cancel Print (from SD Card) with OctoPrint connected #702

Closed rollyceballos closed 3 years ago

rollyceballos commented 3 years ago

Description

When Octoprint is connected to the printer, and cancelling the print the printer beeps this cue as if it's a change filament sequence. Doing anything after that pre-heat, or starting a new print will be cut off by a Reheat Timeout error.

This is related to a discussion #594

Used E3V2-UBL-BLTouch-10x10-HS-v4.2.2.bin of v1.3.1 release

This never happened on the main MarlinFW branch with similar configuration that I customized myself, and this is the first time I noticed the printer (or Octoprint) sends M25 (see logs) on cancelled print. There is no custom Gcode scripts inserted to do this - followed the same Gcode scripts from the wiki for this firmware.

Steps to Reproduce

  1. OctoPrint on Raspi 3 connected to printer
  2. Print from SD Card from Ender 3 V2 controls
  3. Cancel the print
  4. Do something like Pre-Heat to PETG or Print a new gcode

Expected behavior: [What you expect to happen]

Print stops - all temp set to 0 Can continue any other selected actions, as normal

Actual behavior: [What actually happens]

Printer attempts a 'Reheating' step and shows a timeout error with the only option to 'Continue' and retry reheating to target temp (usually 180C) Any action done after cancel is interrupted by this timeout error. Usually recovers if left alone for a few minutes, a restart and Octoprint disconnected.

Additional Information

Log from Octoprint during the event

Recv: //action:cancel
Cancelling on request of the printer...
Changing monitoring state from "Printing from SD" to "Cancelling"
Send: M108
Recv: //action:notification Print Aborted
Recv: File deleted:PLR
[...]
Recv: X:0.00 Y:0.00 Z:8.84 E:1032.63 Count X:0 Y:0 Z:3536
Recv: ok
Recv: ok
Send: M25
Recv: //action:paused
Printer signalled that it paused, switching state...
[...]
Recv: 
Recv: DWIN handshake echo:busy: processing
[...]
Recv: X:10.00 Y:220.00 Z:20.00 E:1030.63 Count X:800 Y:17600 Z:8000
Recv: Writing to file: /PLR
Recv: echo:Send M108 to resume
Recv: //action:prompt_end
Recv: //action:prompt_begin Nozzle Parked
Recv: //action:prompt_button Continue
Recv: //action:prompt_show
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
Recv: 
Recv: DWIN handshake  T:170.00 /0.00 B:65.00 /0.00 @:0 B@:0
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:Send M108 to heat nozzle
Recv: //action:prompt_end
Recv: //action:prompt_begin Heater Timeout
Recv: //action:prompt_button Reheat
Recv: //action:prompt_show
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: //action:prompt_end
Recv: //action:prompt_begin Reheating...
Recv: //action:prompt_show
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]

IMG_0269 LCD Menu after selecting Pre-heat PETG (to 230C Hotend) after a cancelled print

IMG_0268 Pre-heat interrupted by this Timeout error

IMG_0267 Reheating 'Completed'

gothcha commented 3 years ago

Is it related to enabling Emergency Parser? The M108 interacts with this apparently, check the Marlin wiki. Previous versions of the firmware did not have this enabled.

gothcha commented 3 years ago

I do not use Octoprint but from the logs, Octoprint appears to be sending a pause M25 which the printer responds with a park to bed centre and then the reheat cycle.

So question is why is the Pause being sent from Pi after the cancel?

rollyceballos commented 3 years ago

I do not use Octoprint but from the logs, Octoprint appears to be sending a pause M25 which the printer responds with a park to bed centre and then the reheat cycle.

So question is why is the Pause being sent from Pi after the cancel?

That’s what I was wondering as well. I just started with Jyer’s firmware in 1.3.0 and have been switching between my own compiled version. The firmware I built doesn’t do this with the same octoprint running on my raspi. I’ve been able to isolate it only to happen on Jyer’s firmware.

gothcha commented 3 years ago

The pre-compiled binaries are now enabling the Emergency Parser by default.

define EMERGENCY_PARSER in configuration_adv.h

If this is the issue then compile a version yourself with this commented out and check if this fixes the issue.

rollyceballos commented 3 years ago

The pre-compiled binaries are now enabling the Emergency Parser by default.

define EMERGENCY_PARSER in configuration_adv.h

If this is the issue then compile a version yourself with this commented out and check if this fixes the issue.

ok, will be able to test that 'workaround' after I finish this 1-day print.

if I get to confirm this it seems like an Octoprint issue, or the main MarlinFW branch?

Jyers commented 3 years ago

This is very strange. My firmware is doing what it's supposed to and handling the M25, but why is there an M25 in the first place. I have never noticed this behavior. Have you tried disabling all your plugins to see if maybe one is doing something weird.

rollyceballos commented 3 years ago

This is very strange. My firmware is doing what it's supposed to and handling the M25, but why is there an M25 in the first place. I have never noticed this behavior. Have you tried disabling all your plugins to see if maybe one is doing something weird.

will try that too later today.

Jyers commented 3 years ago

Just checked and you can disable M108 sends on octoprint cancel from the octoprint settings. I might give it a try to see if that helps

rollyceballos commented 3 years ago

Is this the default ‘Emergency Commands’ in ‘Protocol Fine Tuning’? This may be related to the enabled ‘Emergency Parser’ that’s enabled by default mentioned by @gothcha ?

rollyceballos commented 3 years ago

Just checked and you can disable M108 sends on octoprint cancel from the octoprint settings. I might give it a try to see if that helps

I haven't figured this one out where this setting was so wasn't able to test. I tried removing it from the Protocol Fine Tuning but I don't think that was it as it still sends M108 and M25.

I have tried disabling 'EMERGENCY_PARSER' like @gothcha suggested but made no difference.

Jyers commented 3 years ago

@rollyceballos Hmmmm, I really though emergency parser would do it. In that case this might be an upstream marlin bug, I'll pull from upstream and see if I see any change.

Jyers commented 3 years ago

I've merged from upstream so now would be a good time to test if this is still happening.

rollyceballos commented 3 years ago

I've merged from upstream so now would be a good time to test if this is still happening.

will report back once I've done more testing. Have long running prints in queue so might take a while to get back.

rollyceballos commented 3 years ago

@Jyers I'm getting this error from the Ender_3_V2_Extensible_UI branch

Compiling .pio/build/STM32F103RET6_creality/src/src/libs/vector_3.cpp.o
Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp: In member function 'void CrealityDWINClass::Menu_Item_Handler(uint8_t, uint8_t, bool)':
Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:3416:82: error: no matching function for call to 'Modify_Value(int8_t&, int, uint16_t, int)'
                   Modify_Value(ubl.storage_slot, 0, settings.calc_num_meshes(), 1);
                                                                                  ^
In file included from Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:32:0:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:343:8: note: candidate: void CrealityDWINClass::Modify_Value(float&, float, float, float, void (*)()) <near match>
   void Modify_Value(float &value, float min, float max, float unit, void (*f)()=NULL);
        ^~~~~~~~~~~~
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:343:8: note:   conversion of argument 1 would be ill-formed:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:3416:82: error: cannot bind non-const lvalue reference of type 'float&' to an rvalue of type 'float'
                   Modify_Value(ubl.storage_slot, 0, settings.calc_num_meshes(), 1);
                                                                                  ^
In file included from Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:32:0:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:344:8: note: candidate: void CrealityDWINClass::Modify_Value(uint8_t&, float, float, float, void (*)()) <near match>
   void Modify_Value(uint8_t &value, float min, float max, float unit, void (*f)()=NULL);
        ^~~~~~~~~~~~
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:344:8: note:   conversion of argument 1 would be ill-formed:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:3416:82: error: cannot bind non-const lvalue reference of type 'uint8_t& {aka unsigned char&}' to an rvalue of type 'uint8_t {aka unsigned char}'
                   Modify_Value(ubl.storage_slot, 0, settings.calc_num_meshes(), 1);
                                                                                  ^
In file included from Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:32:0:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:345:8: note: candidate: void CrealityDWINClass::Modify_Value(uint16_t&, float, float, float, void (*)()) <near match>
   void Modify_Value(uint16_t &value, float min, float max, float unit, void (*f)()=NULL);
        ^~~~~~~~~~~~
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:345:8: note:   conversion of argument 1 would be ill-formed:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:3416:82: error: cannot bind non-const lvalue reference of type 'uint16_t& {aka short unsigned int&}' to an rvalue of type 'uint16_t {aka short unsigned int}'
                   Modify_Value(ubl.storage_slot, 0, settings.calc_num_meshes(), 1);
                                                                                  ^
In file included from Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:32:0:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:346:8: note: candidate: void CrealityDWINClass::Modify_Value(int16_t&, float, float, float, void (*)()) <near match>
   void Modify_Value(int16_t &value, float min, float max, float unit, void (*f)()=NULL);
        ^~~~~~~~~~~~
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:346:8: note:   conversion of argument 1 would be ill-formed:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:3416:82: error: cannot bind non-const lvalue reference of type 'int16_t& {aka short int&}' to an rvalue of type 'int16_t {aka short int}'
                   Modify_Value(ubl.storage_slot, 0, settings.calc_num_meshes(), 1);
                                                                                  ^
In file included from Marlin/src/lcd/extui/creality_dwin/creality_dwin.cpp:32:0:
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:347:8: note: candidate: void CrealityDWINClass::Modify_Value(uint32_t&, float, float, float, void (*)()) <near match>
   void Modify_Value(uint32_t &value, float min, float max, float unit, void (*f)()=NULL);
        ^~~~~~~~~~~~
Marlin/src/lcd/extui/creality_dwin/creality_dwin.h:347:8: note:   conversion of argument 1 would be ill-formed:
compilation terminated due to -fmax-errors=5.
Jyers commented 3 years ago

Let me check, I just added a ton of things so that's to be expected

Jyers commented 3 years ago

Okay, give it a try now

Jyers commented 3 years ago

Any update on this? Haven't printed much lately so I haven't been able to check if the problem is still occurring.

rollyceballos commented 3 years ago

I haven't done testing on this yet. I just finished my long prints and will start testing with your latest updates in the next few days :)

rollyceballos commented 3 years ago

I got the v1.3.3 release tested with a print I cancelled. I think the pop-up may have went away but there's something else that came up. From 'Cancelling' it went to 'printing' again the same file based on the Octoprint log.

Changing monitoring state from "Operational" to "Starting print from SD"
Recv: ok
Recv: X:169.00 Y:145.00 Z:13.33 E:0.00 Count X:13520 Y:11600 Z:5332
[...]
Recv: Writing to file: /PLR
[...]
Recv: echo:busy: processing
[...]
Recv: ok
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
Recv: //action:cancel
Cancelling on request of the printer...
Changing monitoring state from "Starting print from SD" to "Cancelling"
Send: M108
Recv: //action:notification Print Aborted
[...]
Recv: File deleted:PLR
[...]
Recv: 
Recv: DWIN handshake echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:SD card ok
Recv: echo:busy: processing
[...]
Recv: X:0.00 Y:0.00 Z:5.00 E:7.69 Count X:0 Y:0 Z:2000
Recv: ok
Recv: ok
[...]
Recv: ok
Send: M75
Recv: ok
Send: M117 <F>e3v2_g~1.gco
Recv: //action:notification <F>e3v2_g~1.gco
Recv: ok
Changing monitoring state from "Cancelling" to "Printing from SD"
Send: M25
Recv: Writing to file: /PLR
Recv: //action:paused
Printer signalled that it paused, switching state...
Changing monitoring state from "Printing from SD" to "Pausing"
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
Recv: X:10.00 Y:220.00 Z:20.00 E:5.69 Count X:800 Y:17600 Z:8000
Recv: echo:Send M108 to resume
Recv: //action:prompt_end
Recv: //action:prompt_begin Nozzle Parked
Recv: //action:prompt_button Continue
Recv: //action:prompt_show
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
Recv: //action:cancel
Cancelling on request of the printer...
Changing monitoring state from "Pausing" to "Cancelling"
Send: M108
Recv: 
Recv: DWIN handshake  T:180.96 /180.00 B:59.23 /0.00 @:0 B@:0
Recv: //action:prompt_end
Recv: //action:prompt_begin Paused
Recv: //action:prompt_button PurgeMore
Recv: //action:prompt_button Continue
Recv: //action:prompt_show
Recv: echo:busy: paused for user
[...]
Recv: echo:busy: paused for user
Recv: //action:prompt_end
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: //action:notification Print Paused
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
[...]
Recv: echo:busy: processing
Recv: //action:resumed
Printer signalled that it resumed, switching state...
Recv: //action:notification Printing...
Recv: ok
Recv: 
Recv: DWIN handshake ok
[...]

the hotend temp was still set to 180 deg though

IMG_0314

I have Octoprint 1.6.1 and OctoPi 0.17

rollyceballos commented 3 years ago

I may need to log this as a different issue but after I disconnected OctoPi and started a new print it doesn't show the Print State screen but still the SD card menu list. It seems like it's hung up on that too I can't go out and the knob is unresponsive. Only way to recover is a power recycle of the printer. Let me know if I should post this as another issue?

Jyers commented 3 years ago

Just tried disconnecting from OctoPrint for the first time in a while and it seemed to work as expected. Can anyone else verify if maybe this is fixed?

Jyers commented 3 years ago

Closing this due to inactivity, if any more information or updates arise, feel free to post here and I can reopen this.