search

AlexVerrico / Octoprint-ThermalRunaway

Octoprint plugin to provide some basic thermal runaway protection
GNU Affero General Public License v3.0
5 stars 1 forks source link

Thermal Runaway when filament runout #33

Open Ranney1 opened 2 years ago

Ranney1 commented 2 years ago

Describe the bug I've got 2 printers on marlin running by octoprint. Both printers have this issue.

Settings Octoprint, see picture. One of the printers is set to the 'new' settings, the other to the 'old' settings (check box bottom page). Thanks for the great plugin!

To Reproduce Steps to reproduce the behavior:

  1. printer is running out of filament.
  2. Printer is pausing print.
  3. Printhead is parking
  4. Filament is unloading.
  5. After timeout, the hotend temp is still 'set' to 200c, but the hotted is cooling down. (after pressing continue, the hotend is reheating). During cooldown, the thermal runaway is triggered and M112 is send to the printer.

Expected behavior When the printer is paused, the 'state' of the printer is changed from 'Printing' to something like 'Paused for user'. When state is not printing, it is ok for me that only the 'maxtemp' is triggering a thermal runaway. Not a cooldown from the hotend. I expect that the thermal runaway for this plugin is triggered because the set temp is still showing 200c.

Screenshots See settings below in picture.

Environment information:

Additional context Add any other context about the problem here.

Schermafbeelding 2022-03-15 om 13 56 56
BobVul commented 2 years ago

Could you send a serial log of what that the printer sends during these pause events? Preferably during a successful one so I can see what it looks like when it resumes too.

Ranney1 commented 2 years ago

Thanks for your help! it is very often. Also during probing (ABL) the hotend is temporary set to 0c. This also triggers a thermal runaway message. The heater is turned of during the probe. This is fixed now by allowing a temp of 250c if heaters are off. At the moment the printer is busy with a big print. I will update when it is ready with 2 seral logs (during pause). Thanks again for help!

During ABL probing: Recv: X:10.00 Y:225.00 Z:1.51 E:24.00 Count X:800 Y:18000 Z:607 Recv: S_XYZ:7 Recv: X: 0; Y: 3; Index 3; Icon 3 Recv: X0 Y3 Z0.3040 displayZ: 0.3040 Recv: Probing mesh point 5/16. Recv: echo:busy: processing Recv: X:10.28 Y:225.00 Z:3.07 E:24.00 Count X:823 Y:18000 Z:1228 Recv: S_XYZ:7 Recv: Taring probe Recv: Taring probe Recv: probe_down_to_z: do_blocking_move_to_z Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:3.07 E:24.00 Count X:6533 Y:18000 Z:1228 Recv: S_XYZ:7 Recv: T:117 /0 B:65 /65 @:0 B@:48 Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:1.34 E:24.00 Count X:6533 Y:18000 Z:535 Recv: S_XYZ:7 Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:0.10 E:24.00 Count X:6533 Y:18000 Z:40 Recv: S_XYZ:7 Recv: T:117 /125 B:65 /65 @:74 B@:48 Recv: Taring probe Recv: Taring probe Recv: probe_down_to_z: do_blocking_move_to_z Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:1.87 E:24.00 Count X:6533 Y:18000 Z:748 Recv: S_XYZ:7 Recv: T:117 /0 B:65 /65 @:0 B@:48 Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:1.00 E:24.00 Count X:6533 Y:18000 Z:397 Recv: S_XYZ:7 Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:0.04 E:24.00 Count X:6533 Y:18000 Z:15 Recv: S_XYZ:7 Recv: T:117 /125 B:65 /65 @:0 B@:53 Recv: echo:busy: processing Recv: X:81.66 Y:225.00 Z:1.36 E:24.00 Count X:6533 Y:18000 Z:543 Recv: S_XYZ:7 Recv: X: 1; Y: 3; Index 4; Icon 4 Recv: X1 Y3 Z0.1440 displayZ: 0.1440 Recv: Probing mesh point 6/16. Recv: echo:busy: processing Recv: X:81.66 Y:224.73 Z:2.91 E:24.00 Count X:6533 Y:17977 Z:1164 Recv: S_XYZ:7 Recv: T:117 /125 B:66 /65 @:83 B@:0 Recv: Taring probe Recv: Taring probe Recv: probe_down_to_z: do_blocking_move_to_z Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:2.91 E:24.00 Count X:6533 Y:12267 Z:1164 Recv: S_XYZ:7 Recv: T:117 /0 B:66 /65 @:0 B@:0 Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:1.18 E:24.00 Count X:6533 Y:12267 Z:471 Recv: S_XYZ:7 Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:0.16 E:24.00 Count X:6533 Y:12267 Z:66 Recv: S_XYZ:7 Recv: T:117 /125 B:66 /65 @:77 B@:0 Recv: Taring probe Recv: Taring probe Recv: probe_down_to_z: do_blocking_move_to_z Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:1.82 E:24.00 Count X:6533 Y:12267 Z:729 Recv: S_XYZ:7 Recv: T:117 /0 B:65 /65 @:0 B@:58 Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:0.95 E:24.00 Count X:6533 Y:12267 Z:381 Recv: S_XYZ:7 Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:0.00 E:24.00 Count X:6533 Y:12267 Z:0 Recv: S_XYZ:7 Recv: T:117 /125 B:65 /65 @:76 B@:40 Recv: echo:busy: processing Recv: X:81.66 Y:153.34 Z:1.22 E:24.00 Count X:6533 Y:12267 Z:488 Recv: S_XYZ:7 Recv: X: 1; Y: 2; Index 5; Icon 5 Recv: X1 Y2 Z0.0830 displayZ: 0.0830 Recv: Probing mesh point 7/16. Recv: echo:busy: processing Recv: X:81.66 Y:153.29 Z:2.84 E:24.00 Count X:6533 Y:12263 Z:1136 Recv: S_XYZ:7 Recv: T:117 /125 B:65 /65 @:85 B@:33 Recv: Taring probe Recv: Taring probe Recv: probe_down_to_z: do_blocking_move_to_z Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:2.84 E:24.00 Count X:6533 Y:6533 Z:1136 Recv: S_XYZ:7 Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:1.11 E:24.00 Count X:6533 Y:6533 Z:443 Recv: S_XYZ:7 Recv: T:117 /0 B:65 /65 @:0 B@:27 Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:0.13 E:24.00 Count X:6533 Y:6533 Z:55 Recv: S_XYZ:7 Recv: Taring probe Recv: Taring probe Recv: probe_down_to_z: do_blocking_move_to_z Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:1.77 E:24.00 Count X:6533 Y:6533 Z:709 Recv: S_XYZ:7 Recv: T:117 /0 B:65 /65 @:0 B@:21 Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:0.90 E:24.00 Count X:6533 Y:6533 Z:361 Recv: S_XYZ:7 Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:-0.05 E:24.00 Count X:6533 Y:6533 Z:-20 Recv: S_XYZ:7 Recv: T:117 /0 B:65 /65 @:0 B@:18 Recv: echo:busy: processing Recv: X:81.66 Y:81.66 Z:1.20 E:24.00 Count X:6533 Y:6533 Z:482 Recv: S_XYZ:7 Recv: X: 1; Y: 1; Index 6; Icon 6 Recv: X1 Y1 Z0.0405 displayZ: 0.0405 Recv: Probing mesh point 8/16. Recv: echo:busy: processing Recv: X:81.66 Y:81.58 Z:2.80 E:24.00 Count X:6533 Y:6525 Z:1121 Recv: S_XYZ:7 Recv: T:117 /125 B:65 /65 @:81 B@:1

BobVul commented 2 years ago

Could you enable debug logging? See https://docs.octoprint.org/en/master/bundledplugins/logging.html, set octoprint.plugins.ThermalRunaway to DEBUG.

Then grab the contents of octoprint.log and upload it here. Preferably with the matching serial logs.

Judging by the probe serial output you posted, the set target temperature is changed during this process and should be getting picked up. See the series of T:117 /0? If the printer is reporting a target temperature of 0 but the measured temperature remains at 117 that whole time, that's a problem.

Having the debug logs would confirm that. Not too sure what, if anything, can be done about this from the plugin side though.

Ranney1 commented 2 years ago

Ok, i will try to do that tomorrow. Thank you for your help! Maybe that the plugin can watch just for max temp it the state of the printer is 'paused for user'?

Ranney1 commented 2 years ago

I've turned on logging for this app but whatever i do, I cannot find the log file. Can you help me with this? Trying to find the logging here: http://192.168.1.120//plugin/logging/logs

Settings in log: SC LOG

New error: ... Recv: ok N1487 P0 B31 Send: N1488 G0 F11250 X107.7 Y127.374 Recv: S_XYZ:5 Recv: T:199 /200 B:51 /50 @:102 B@:0 Recv: S_XYZ:5 Recv: ok N1488 P0 B31 Send: N1489 G1 F1873.9 X107.7 Y107.7 E135.3449138 Recv: S_XYZ:5 Recv: S_XYZ:5 Recv: ok N1489 P0 B31 Send: N1490 G1 X127.3 Y107.7 E135.6056793 Recv: S_XYZ:5 Recv: S_XYZ:5 Recv: ok N1490 P0 B31 Send: N1491 G1 X127.3 Y127.3 E135.8664387 Recv: S_XYZ:5 Recv: S_XYZ:5 Recv: ok N1491 P0 B31 Send: N1492 G1 X107.7 Y127.3 E136.1271982 Recv: S_XYZ:5 Recv: T:200 /200 B:51 /50 @:82 B@:0 Recv: S_XYZ:5 Recv: ok N1492 P0 B31 Send: N1493 G0 F11250 X107.97 Y127.0373 Recv: //action:prompt_end Recv: //action:prompt_begin FilamentRunout T0 Recv: //action:prompt_show Recv: //action:paused filament_runout 0 Printer signalled that it paused, switching state... Changing monitoring state from "Printing" to "Pausing" Recv: T:200 /200 B:51 /50 @:84 B@:0 Recv: T:200 /200 B:51 /50 @:86 B@:0 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Changing monitoring state from "Pausing" to "Paused" Send: M105 Recv: T:200 /200 B:51 /50 @:87 B@:0 Recv: //action:paused Printer signalled that it paused, switching state... Recv: T:200 /200 B:51 /50 @:87 B@:0 Recv: echo:busy: processing Recv: X:107.70 Y:127.30 Z:4.41 E:111.13 Count X:8616 Y:10184 Z:1766 Recv: S_XYZ:5 Recv: T:200 /200 B:51 /50 @:88 B@:0 Recv: echo:busy: processing Recv: X:107.70 Y:127.30 Z:14.09 E:111.13 Count X:8616 Y:10184 Z:5638 Recv: S_XYZ:5 Recv: T:200 /200 B:51 /50 @:88 B@:0 Recv: echo:busy: processing Recv: X:68.41 Y:164.68 Z:20.00 E:111.13 Count X:5466 Y:13181 Z:8000 Recv: S_XYZ:5 Recv: X:5.00 Y:225.00 Z:20.00 E:111.13 Count X:400 Y:18000 Z:8000 Recv: T:200 /200 B:51 /50 @:88 B@:0 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Send: M105 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:111.13 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:73 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:73 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:73 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:72 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:71 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:70 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:201 /200 B:51 /50 @:69 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:200 /200 B:51 /50 @:85 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:200 /200 B:51 /50 @:82 B@:0 Recv: echo:busy: processing Recv: X:5.00 Y:225.00 Z:20.00 E:-288.87 Count X:400 Y:18000 Z:8000 Recv: S_XYZ:5 Recv: T:200 /200 B:51 /50 @:80 B@:0 Recv: echo:Insert filament and send M108 Recv: //action:prompt_end Recv: //action:prompt_begin Load/unload filament Recv: //action:prompt_button Continue Recv: //action:prompt_show Recv: SetNewScreen: 39 Recv: SetNewScreen (saving): 39 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:79 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:79 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:50 /50 @:78 B@:60 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:50 /50 @:78 B@:38 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:78 B@:0 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: S_XYZ:6 Recv: T:200 /200 B:50 /50 @:0 B@:64 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:200 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:199 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:198 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:196 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:194 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:191 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:189 /200 B:48 /50 @:0 B@:127 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:186 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:183 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:180 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:177 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:174 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:171 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:169 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:166 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:163 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:160 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:158 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:155 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:153 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:150 /200 B:49 /50 @:0 B@:127 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:148 /200 B:50 /50 @:0 B@:0 .... Recv: S_XYZ:6 Recv: T:105 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:104 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:102 /200 B:51 /50 @:0 B@:0 Recv: echo:busy: paused for user Recv: S_XYZ:6 Recv: T:100 /200 B:51 /50 @:0 B@:0 Send: M112 Send: N1494 M11225 Send: N1495 M104 T0 S024 Send: N1496 M140 S095 Recv: Error:Printer halted. kill() called! Changing monitoring state from "Paused" to "Error" Send: M112 Closing serial port due to emergency stop M112. Send: N1497 M11226 Send: N1498 M104 T0 S021 Send: N1499 M140 S080 Connection closed, closing down monitor Changing monitoring state from "Error" to "Offline after error"

Thanks for help!

BobVul commented 2 years ago

I've turned on logging for this app but whatever i do, I cannot find the log file. Can you help me with this?

The log entries will be in the main octoprint.log file. There is no separate log file created by this plugin.

As for the serial log, please include a successful run with the thermal runaway plugin disabled. I would like to see what happens upon a successful resume. Detecting when it enters such a paused state isn't very useful if there's no way to detect when it exits that state. If possible, please include one with timestamps from the serial.log file rather than just copied from the terminal tab.