search

Mrnt / OctoPrint-FlashForge

OctoPrint plugin to support closed source printers from FlashForge, PowerSpec, Dremel
GNU General Public License v3.0
86 stars 12 forks source link

0.2.4 can't process simplify3d gcode file when printing from SD Card #55

Open devslashlol opened 3 years ago

devslashlol commented 3 years ago

Hi, I used Upload to SD card, then printed from that - I get these kinds of messages in the log 2020-09-25 14:43:37,492 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): dropping command 2020-09-25 14:43:37,493 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:G1, cmd:G1 X1.482 Y-9.400 E1.5032

The extruder sounds like it's grinding or skipping steps or something. I also see this: 2020-09-25 16:23:46,385 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:46,387 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,389 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:46,391 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:46,392 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:46,394 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:46,395 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:46,398 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,400 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,402 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,403 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:47,364 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:47,364 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:47,366 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:47,367 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:47,376 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:47,377 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,380 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:47,382 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:47,383 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:47,384 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:47,384 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:47,386 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,387 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,388 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,388 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:48,359 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M105, cmd:M105 2020-09-25 16:23:48,360 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:48,363 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:48,364 - octoprint.plugins.flashforge - DEBUG - write() M105 2020-09-25 16:23:48,367 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:48,369 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:48,374 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M105 Received. | T0:28 /0 B:0/0 | ok | 2020-09-25 16:23:48,374 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M105 Received. 2020-09-25 16:23:48,376 - octoprint.plugins.flashforge - DEBUG - buffering: T0:28 /0 B:0/0 2020-09-25 16:23:48,377 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:48,380 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,383 - octoprint.util.comm - INFO - Externally triggered heatup detected 2020-09-25 16:23:48,395 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,397 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,399 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:48,400 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:48,401 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:48,411 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:48,412 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,414 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:48,417 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:48,418 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:48,420 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:48,421 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:48,423 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,426 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,429 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,430 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:49,371 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:49,373 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:49,376 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:49,378 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:49,386 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:49,388 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,389 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:49,392 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:49,393 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:49,394 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:49,396 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:49,402 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,408 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,411 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,413 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:50,375 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:50,376 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:50,378 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:50,380 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:50,389 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:50,390 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,392 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:50,395 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:50,396 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:50,398 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:50,399 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:50,402 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,404 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,407 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,407 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:51,378 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:51,379 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:51,382 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:51,387 - octoprint.plugins.flashforge - DEBUG - write() M119

I use Simplify 3D to slice, and the gcode files directly out of that always work if I load them via a usb flash drive at the unit directly.

devslashlol commented 3 years ago

any tinkering with timeouts? the auto reports seem to work fine if there is no print job going, but once the print job gets going, the reports seem ... slow.

Mrnt commented 3 years ago

Do you mean the print status when printing from the SD card? That looks to be set at a default of 1s using the "SD status interval (polling)" setting.

devslashlol commented 3 years ago

Yes, I'm just saying that it stops auto updating after a while. In the case of the print I am running right now, the update stopped happening before the temp even got to 200C (the print is well under way at this point) image

devslashlol commented 3 years ago

image

devslashlol commented 3 years ago

I hit the 'print' button after it appeared to have stalled out to see if it would unstick, but to no avail My guess is that the connection stealthily died due to something, because I have to power cycle the printer to get it to reconnect.

Mrnt commented 3 years ago

Did the printer actually stop or is it OctoPrint no longer getting updates?

devslashlol commented 3 years ago

Octoprint is no longer getting updates. The printer goes along happily once I do the Upload to SD card (with your latest refactor of the directory)

Mrnt commented 3 years ago

Can you upload the complete log that you have right now so I can see the whole context?

devslashlol commented 3 years ago

octoprint (6).log

Mrnt commented 3 years ago

The printer seems to stop responding but the weird thing is the plugin does not generate a timeout waiting for a response from the printer.

Mrnt commented 3 years ago

I did see this:

2020-10-01 07:28:19,469 - octoprint.plugins.pi_support - WARNING - This Raspberry Pi is reporting problems that might lead to bad performance or errors caused by overheating or insufficient power.
!!! FREQUENCY CAPPING DUE TO OVERHEATING REPORTED !!! Improve cooling on the Pi's CPU and GPU.

which may or may not be relevant

devslashlol commented 3 years ago

Aye - I've seen that. I'm not sure if it is significant or not. I had no issues with my Creality that took commands right from the unit. I can't imagine octoprint being a hard-hidding application. Still something to look into, I suppose.

devslashlol commented 3 years ago

One thing is that the icon only blinks when there is an ongoing issue. It is not blinking - so for a temp issue (vs undervoltage issue), I am not seeing this when printing. That notification is from 7am in the morning, not now. But I did go and move the Pi so that there is less of a 'heat pocket' underneath it and so that the natural convection can clear a little easier. I do have fins on the chips.

devslashlol commented 3 years ago

ok, I will admit that since I power cycled the Pi, and turned it a little so that natural convection works a little better, so far no hang ups. So you might be onto something with your notification of the warning. I never said I was a Good User!

edit - it quit around 125/1000. The screen saver/lock screen had also come up, not sure if that matters (I can't imagine it would, it shouldn't stop sending queries...)

devslashlol commented 3 years ago

Can we change the M27 polling frequency to something more reasonable like once every 30 seconds? 1/s seems excessive for something that takes hours... edit: I see this parameter. Any reason not to change this to 30 or so?

Mrnt commented 3 years ago

Sure - you can change M27 polling to whatever you want. The plugin is not setting those - they are the default for OctoPrint and certainly if your prints are typically hours long then an update every 30s makes more sense. I don't think it will affect the issue you are seeing where the connection between OctoPrint and the printer is effectively stalling.

Do you have the pi running a Linux desktop connected to a monitor? I know if I run OctoPrint on my Mac it tries to put the USB connections to sleep when the Mac tries to go to sleep causing the connection to the printer to drop, though it is pretty obvious in the log when that happens. So yes, if you have it running a desktop OS with power saving enabled I think there is a chance it will try to put the USB connections to sleep if it is trying to go into a low power or sleep state.