Mrnt / OctoPrint-FlashForge

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

Dremel 3D20: Timeouts while Connecting w/M27 #40

Closed eduncan911 closed 3 years ago

eduncan911 commented 3 years ago

New install (on an x64 device, no RPi). First time using OctoPrint, and this plugin.

Wiped and installed twice now; however, I've been unable to connect to the printer. Sometimes it does connect, but I am unable to send any commands - and it Times Out.

$ lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 0424:2530 Microchip Technology, Inc. (formerly SMSC) BOSCH Dremel 3D Printer
Bus 001 Device 002: ID 0424:4603 Microchip Technology, Inc. (formerly SMSC)
Bus 001 Device 004: ID 2a89:8889 BOSCH BOSCH Dremel 3D Printer

Yep, that's all this device has connected via USB. ;)

I am installing per README, and followed the master zip file approach, as well as just searching Get more and installing that way.

Tried to restart the octoprint service and checked the logs (this is outputted from systemd logs that I have setup):

Aug 18 02:00:29 up-printer-1 python3[1282]: 2020-08-18 02:00:29,649 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
Aug 18 02:00:30 up-printer-1 python3[1282]: 2020-08-18 02:00:30,001 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
Aug 18 02:00:35 up-printer-1 python3[1282]: 2020-08-18 02:00:35,041 - octoprint.server.preemptive_cache - INFO - ... done in 5.42s
Aug 18 02:00:39 up-printer-1 python3[1282]: 2020-08-18 02:00:39,910 - octoprint.plugins.flashforge - INFO - Found a Dremel Dremel IdeaBuilder 3D20
Aug 18 02:00:39 up-printer-1 python3[1282]: 2020-08-18 02:00:39,955 - octoprint.plugins.flashforge - INFO - Found a Dremel Dremel IdeaBuilder 3D20
Aug 18 02:00:40 up-printer-1 python3[1282]: 2020-08-18 02:00:40,172 - octoprint.plugins.flashforge - INFO - Found a Dremel Dremel IdeaBuilder 3D20

I found the logs to this Octoprint instance and saw this:

2020-08-18 02:00:54,001 - octoprint.util.comm - ERROR - Unexpected error while connecting to serial port unknown, baudrate 250000 from hook flashforge: FlashForgeError: '>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Unable to connect to FlashForge printer - permission error.

If you are using OctoPi/Linux add permission to access this device by editing file:
 /etc/udev/rules.d/99-octoprint.rules

and adding the line:
SUBSYSTEM=="usb", ATTR{idVendor}=="2a89", MODE="0666"

You can do this as follows:
1) Connect to your OctoPi/Octoprint device using ssh
2) Type the following to open a text editor:
sudo nano /etc/udev/rules.d/99-octoprint.rules
3) Add the following line:
SUBSYSTEM=="usb", ATTR{idVendor}=="2a89", MODE="0666"
4) Save the file and close the editor
5) Verify the file permissions are set to "rw-r--r--" by typing:
ls /etc/udev/rules.d/99-octoprint.rules
6) Reboot your system for the rule to take effect.

<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

Easy enough. Did the above, and I was able to connect!

However, I ran into more errors:

2020-08-18 02:28:50,625 - octoprint.util.comm - ERROR - Unexpected error while connecting to serial port /dev/ttyS0, baudrate 250000 from hook default: SerialException: '[Errno 13] could not open port /dev/ttyS0: [Errno 13] Permission denied: '/dev/ttyS0'' @ comm.py:_open_serial:2781
Traceback (most recent call last):
  File "/home/eric/.virtualenvs/octoprint/lib/python3.8/site-packages/serial/serialposix.py", line 265, in open
    self.fd = os.open(self.portstr, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK)
PermissionError: [Errno 13] Permission denied: '/dev/ttyS0'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/eric/.virtualenvs/octoprint/lib/python3.8/site-packages/octoprint/util/comm.py", line 2781, in _open_serial
    serial_obj = factory(self,
  File "/home/eric/.virtualenvs/octoprint/lib/python3.8/site-packages/octoprint/util/comm.py", line 2761, in default
    serial_obj.open()
  File "/home/eric/.virtualenvs/octoprint/lib/python3.8/site-packages/serial/serialposix.py", line 268, in open
    raise SerialException(msg.errno, "could not open port {}: {}".format(self._port, msg))
serial.serialutil.SerialException: [Errno 13] could not open port /dev/ttyS0: [Errno 13] Permission denied: '/dev/ttyS0'
2020-08-18 02:28:50,636 - octoprint.util.comm - INFO - Serial detection: Could not open port /dev/ttyS0, baudrate 250000, skipping
2020-08-18 02:28:50,638 - octoprint.util.comm - INFO - Serial detection: Trying port BOSCH Dremel 3D Printer, baudrate 115200
2020-08-18 02:28:50,653 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2020-08-18 02:28:50,659 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2020-08-18 02:28:50,716 - octoprint.plugins.flashforge - INFO - Found a Dremel Dremel IdeaBuilder 3D20

Checking, there seems to be a special dialout group assigned to these serial ports. So I added my printer user to it:

$ ls -la /dev/ttyS0
crw-rw---- 1 root dialout 4, 64 Aug 18 02:11 /dev/ttyS0

A quick add:

$ sudo gpasswd --add printeruser dialout
Adding user upuser to group dialout
$ sudo gpasswd --add upuser tty
Adding user upuser to group tty
$ sudo reboot

However, I keep seeing the logs show timeout. And I see this in the gcode tab in OctoPrint:

Changing monitoring state from "Offline" to "Opening serial connection"
Connecting to port /dev/ttyS0, baudrate 115200
Changing monitoring state from "Opening serial connection" to "Connecting"
Connected to: Serial<id=0x7f64bc4b9dc0, open=True>(port='/dev/ttyS0', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=10.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
Send: M601 S0
No answer from the printer within the connection timeout, trying another hello
Send: M601 S0

And it will continue that way.

eduncan911 commented 3 years ago

Forgot to put what it looks like when it does connect:

Trying port BOSCH Dremel 3D Printer, baudrate 115200
Handshake attempt #1 with timeout 2.0s
Send: M601 S0
Recv: CMD M601 Received.
Recv: Control Success.
Recv: ok
Changing monitoring state from "Detecting serial connection" to "Operational"
Send: M119
Recv: CMD M119 Received.
Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0
Recv: MachineStatus: READY
Recv: MoveMode: READY
Recv: ok
Send: M27
Recv: CMD M27 Received.
Communication timeout while idle, 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: M115
Communication timeout while idle, 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: M146 r255 g255 b255
No response from printer after 3 consecutive communication timeouts, considering it dead. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Changing monitoring state from "Operational" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
Connection closed, closing down monitor

I am not fast enough to send a simple G28 to see if it's two way.

Mrnt commented 3 years ago

Once you set up the permissions for the USB port you "should" not have to do anything else - ie the plugin connects to the printer as a USB port not as a serial port. In the OctoPrint UI are you seeing (and selecting) "BOSCH Dremel 3D Printer" (or something similar) as the port? Can you upload a clean log (octoprint.log) of a successful connection so I might be able to see what is causing it to timeout?

eduncan911 commented 3 years ago

Thanks for looking!

Once you set up the permissions for the USB port you "should" not have to do anything else - ie the plugin connects to the printer as a USB port not as a serial port.

Yeah, once I set the permissions I haven't seen any issues like that any longer.

In the OctoPrint UI are you seeing (and selecting) "BOSCH Dremel 3D Printer" (or something similar) as the port?

Oh my, I never saw this before! it was at the very bottom of the list.

I just now selected it, and it now connects immediately and issues the first two commands to verify it can talk. But after that, nothing... the Connection just Hangs/stalls. I am never able to issue, say, an G28, and eventually a timeout message appears.

Changing monitoring state from "Offline" to "Opening serial connection"
Connecting to port /dev/ttyS0, baudrate 250000
Changing monitoring state from "Opening serial connection" to "Connecting"
Connected to: Serial<id=0x7f39c818f6d0, open=True>(port='/dev/ttyS0', baudrate=250000, bytesize=8, parity='N', stopbits=1, timeout=10.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
Send: M601 S0
Connection closed, closing down monitor
Changing monitoring state from "Connecting" to "Offline"
Changing monitoring state from "Offline" to "Opening serial connection"
Changing monitoring state from "Opening serial connection" to "Connecting"
Connected to: <octoprint_flashforge.flashforge.FlashForge object at 0x7f39cb565a00>, starting monitor
Send: M601 S0
Recv: CMD M601 Received.
Recv: Control Success.
Recv: ok
Send: M601 S0
Changing monitoring state from "Connecting" to "Operational"
Recv: CMD M601 Received.
Recv: Control Success.
Recv: ok
Send: M119
Recv: CMD M119 Received.
Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0
Recv: MachineStatus: READY
Recv: MoveMode: READY
Recv: ok
Send: M27

   ^- ED: Connection stalls here, upon issuing this M27 command above!
   ^- ED: After 20 or so seconds, the response below finally comes back:

Recv: CMD M27 Received.
Communication timeout while idle, 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: M115
Communication timeout while idle, 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: M146 r255 g255 b255
No response from printer after 3 consecutive communication timeouts, considering it dead. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Changing monitoring state from "Operational" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
Connection closed, closing down monitor

Can you upload a clean log (octoprint.log) of a successful connection so I might be able to see what is causing it to timeout?

See attached for a clear start, connect, stop of the service. It connected and issued the above commands in this post. But, it never would let me issue anything myself via terminal. I've also changed the BAUD to multiple speeds as well: exact sample results.

EDIT:

Something else to note: While multiple commands are sent, and responses received, it always seems to stall on the M27 command for a good 20 to 30 seconds, and then gets back the Recv: CMD M27 Received. response after those 20 to 30 seconds (I wasn't counting). After that, nothing can ever be issued again during this connection.

octoprint.log

I have also removed the SD card. I've also inserted it. Doesn't seem to make a difference with M27.

Lastly, I have also tried three different USB cables. Doesn't make a difference. Doh.


OT: It may be a security issue by logging IPs like this and people posting them online. While this is an unsecure VLAN on my network, that's fine. But you may want to consider no logging IPs, unless in say Debug mode.

Mrnt commented 3 years ago

Can you turn on debugging for the plugin and then make another log? It should provide more granularity:

Turn on debug messages for the plugin (Settings > Logging, under "Logging Levels" set octoprint.plugins.flashforge to "DEBUG" and then click the "+" sign next to it, then click "Save") to help troubleshoot connection issues.

eduncan911 commented 3 years ago

As you requested, see attached for new clean log file with debugging on. :)

octoprint.log

And remember, it always stops and pauses for a long time after M27 issued, waiting for a response.

Mrnt commented 3 years ago

Great, thanks! It looks like it is not getting a complete response when asking for SD print status (M27) during the connection process. I am not sure why, but maybe if we can skip the command we might get to complete the connection process.

If you feel ok using a text editor on the code, can you edit line 231 of octoprint_flashforge/__init.__.py in your installation's plugins folder and change: cmd = [("M119", "status_polling"), ("M27", "sd_status_polling"), (cmd, cmd_type)] to: cmd = [("M119", "status_polling"), (cmd, cmd_type)] You will probably have to restart OctoPrint to get the changes to work.

eduncan911 commented 3 years ago

@Mrnt yep, that fixed it! Removing M27 worked fine and I'm sending gcode commands manually now! woohoo! first time!

however, there were no files in the "Plugin" folder. This plugin was installed via pip, so the file was located at:

~/.virtualenv/octoprint/lib/python3.8/site-packages/octoprint_flashforge/__init__.py

Is this something you'd accept in a PR? Or, is this something I'll have to edit out during each upgrade?


Quick question while I have ya. First time Octoprint user, I am a bit confused at the "Upload to SD" directives. Does that mean to not just upload gcode (and if I understand it, Octoprint has the option to directly send all gcode commands)?

And, does that mean I can't use timelaspe on the camera at certain layer heights / G-commands?

Mrnt commented 3 years ago

It's something I added a few revs back to try to determine if the printer was already printing when OctoPrint connected, so as to change OctoPrint status.

Before doing a PR I would like to determine if the printer just cannot handle the command or if something else is going on - after you have made a connection and with the printer doing nothing except waiting for commands from OctoPrint, can you enter: M27 in the Terminal window of OctoPrint and see what happens? As another test you could do it while the printer is printing something from the SD card.

Re the Upload to SD card - the only way to print via OctoPrint currently is to upload the whole file to the Printer's SD card via that button. As I keep saying to other people ;-) I think I'm close to getting the plugin to support directly sending g-code, it is taking a lot of trial and error (ie time) to test and make sure the connection is not dropped in the middle of a print.

eduncan911 commented 3 years ago

Confirmed, M27 locks up the communications and it "times out" on a 3D20.

Until M27 is issued, the plugin sends a bunch of status checks like every second or two:

Send: M119
Recv: CMD M119 Received.
Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0
Recv: MachineStatus: READY
Recv: MoveMode: READY
Recv: ok
Send: M105
Recv: CMD M105 Received.
Recv: T0:33 /0 B:0 /0
Recv: ok

It idled like this for a few hours actually!

It wasn't until I just now issued M27 that is completely froze, non-responsible. Timed out and disconnected the printer.

Yeah, at least the Dremel 3D20 can't handle it.

I have a couple of 3D45s here as well, that I'll add soon to this plugin.

eduncan911 commented 3 years ago

Re the Upload to SD card - the only way to print via OctoPrint currently is to upload the whole file to the Printer's SD card via that button. As I keep saying to other people ;-) I think I'm close to getting the plugin to support directly sending g-code, it is taking a lot of trial and error (ie time) to test and make sure the connection is not dropped in the middle of a print.

Thanks for all the effort!

As far as making sure the connections are not dropped; just a thought, but couldn't you snag the connection/session tracking code, try/catch error handling, etc from a well known plugin already that already uses serial? Like the Prusa and/or Creality plugins? I'd imagine they have some quite robust session handling there.

Mrnt commented 3 years ago

Great, thanks for the info. Do you have the most up to date firmware on the 3D20?

I would be interested in seeing what happens if you issue M27 during a print from the SD card - even if it locks up it would be helpful to see what is in the log.

I would also be interested in what happens with the 3D45s - I think there are some other users with 3D40 or 3D45 and I think M27 works for them.

Basically the printer responds to the M27 command but the response does not contain what the FF printers typically respond with (ie actual print progress) and is not being terminated with an ok which the plugin is expecting, as a way to indicate that it has read the complete response. The plugin waits for 30s for an ok before timeout by which time the printer thinks the USB connection has gone and ignores subsequent commands from the plugin. The response your printer is giving is more typical of when a FF printer just does not recognize the command as actionable. As a temporary fix you may be able to make the printer not drop the connection for incomplete responses to commands like M27 by changing the communication timeout from 30 to 3:

Screen Shot 2020-08-19 at 10 40 00 AM
eduncan911 commented 3 years ago

Great, thanks for the info. Do you have the most up to date firmware on the 3D20?

Yes, released June 2018 (they do not release firmware updates any longer... The 3D45 however, has as of July 2020).

I would be interested in seeing what happens if you issue M27 during a print from the SD card - even if it locks up it would be helpful to see what is in the log.

I'll try to do this soon and will report back.

I would also be interested in what happens with the 3D45s - I think there are some other users with 3D40 or 3D45 and I think M27 works for them.

Yep, once I solidify this 3D20 setup (this plugin is the whole reason for me to install OctoPrint and remotely monitor our beloved little 3D20), I can move the device (with 6x Octoprint setups) with the 3d20 to join its bigger brothers in the same room - and connect all to the same device.

Can't wait to get off of that cloud crap they have.

As a temporary fix you may be able to make the printer not drop the connection for incomplete responses to commands like M27 by changing the communication timeout from 30 to 3

Will try this as well, and first before a print...

eduncan911 commented 3 years ago

@Mrnt i've completed testing of the M27 command and timeouts.

Testing M27 with short 3 second timeout: Failed

Try M27 while printing: Nothing happened.

Send: M119
Recv: CMD M119 Received.
Recv: Endstop: X-max: 0 Y-max: 0 Z-min: 0
Recv: MachineStatus: BUILDING_FROM_SD
Recv: MoveMode: MOVING
Recv: ok
Send: M105
Recv: CMD M105 Received.
Recv: T0:201 /200 B:0 /0
Recv: ok
Send: M119
Recv: CMD M119 Received.
Recv: Endstop: X-max: 0 Y-max: 0 Z-min: 0
Recv: MachineStatus: BUILDING_FROM_SD
Recv: MoveMode: MOVING
Recv: ok
Send: M27
Recv: CMD M27 Received.
Recv: SD printing byte 11298/113123
Recv: ok

NOTE: I did find that I could enter M27 into the Blocked Commands settings box. Doing this does not allow me to enter M27 anywhere. Not in terminal, not in startup, no where was safe! I didn't check what happens when printing with this in the blocked list.

image

Mrnt commented 3 years ago

I think if you have M27 in the blocked list OctoPrint won't send it during printing and then you won't get any progress updates. The good news is that M27 seems to work fine when it is actually printing, so maybe if I just take it out of the initial connection code you should be fine.

Mrnt commented 3 years ago

@eduncan911 @Fred583 Just made a new release that should address the problem if you want to give it a try

Fred583 commented 3 years ago

Ill go try it real quick

Fred583 commented 3 years ago

It connected to the printer and moved the bed and extruder to the home position, and then threw the same timeout error. octoprint.log

Terminal output:

Changing monitoring state from "Offline" to "Detecting serial connection" Performing autodetection with 0 port/baudrate candidates: Changing monitoring state from "Detecting serial connection" to "Error: No more candidates to test, and no working port/baudrate combination detected." Changing monitoring state from "Error: No more candidates to test, and no working port/baudrate combination detected." to "Offline (Error: No more candidates to test, and no working port/baudrate combination detected.)" Changing monitoring state from "Offline" to "Detecting serial connection" Performing autodetection with 7 port/baudrate candidates: BOSCH Dremel 3D Printer@115200, BOSCH Dremel 3D Printer@250000, BOSCH Dremel 3D Printer@230400, BOSCH Dremel 3D Printer@57600, BOSCH Dremel 3D Printer@38400, BOSCH Dremel 3D Printer@19200, BOSCH Dremel 3D Printer@9600 Trying port BOSCH Dremel 3D Printer, baudrate 115200 Handshake attempt #1 with timeout 2.0s Send: M601 S0 Connected to: <octoprint_flashforge.flashforge.FlashForge object at 0xa9a503b0>, starting monitor Recv: CMD M601 Received. Recv: Control Success. Recv: ok Changing monitoring state from "Detecting serial connection" to "Operational" Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M115 Recv: CMD M115 Received. Recv: Machine Type: dremel 3d idea builder Recv: Machine Name: DREMEL Recv: Firmware: v1.5 20180611 Recv: SN: 320025-33375104-39333735 Recv: X: 230 Y: 150 Z: 140 Recv: Tool Count: 1 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:20 /0 B:0 /0 Recv: ok Send: M146 r255 g255 b255 Recv: CMD M146 Received. Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:20 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:20 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:20 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:20 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Send: M119 Recv: CMD M119 Received. Recv: Endstop: X-max: 1 Y-max: 1 Z-min: 0 Recv: MachineStatus: READY Recv: MoveMode: READY Recv: ok Send: M105 Recv: CMD M105 Received. Recv: T0:21 /0 B:0 /0 Recv: ok Changing monitoring state from "Operational" to "Starting" Send: M104 S220 Recv: CMD M104 Received. Recv: ok Changing monitoring state from "Starting" to "Printing" Send: M109 S220 Recv: CMD M109 Received. Recv: ok Send: G90 Recv: CMD G90 Received. Recv: ok Send: G28 Recv: CMD G28 Received. Recv: ok Send: M132 X Y Z A Recv: CMD M132 Received. Recv: ok Send: M119 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 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. 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. 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. 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. No response from printer after 6 consecutive communication timeouts, considering it dead. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Changing monitoring state from "Printing" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)" Connection closed, closing down monitor

Mrnt commented 3 years ago

@Fred583 I think you were trying to print directly from OctoPrint (vs using the "Upload to SD Card" button)? Right now that won't work because the connection with the printer will timeout while OctoPrint waits for printer actions to complete.

In the above case I think M132 makes the printer complete current actions (in this case homing) before responding to any other command (it did not respond to M119 in a timely fashion). But because OctoPrint Dows not send a command until there has been a response (or timeout) from the previous one the printer thinks that the host is no longer connected and drops the connection, thereby not responding to any subsequent commands.

Fred583 commented 3 years ago

@Mrnt thats exactly what the issue was. In the midst of hoping it would work I forgot about that. Works perfectly, thank you so much!

eduncan911 commented 3 years ago

That's awesome! Sorry for the delay, work and family and all. :+1:

I can confirm version 0.1.22 works, mostly...

However, that nasty M27 bug appeared again, and it disconnected the printer with a Timeout all over again.

I can press Connect and stat all over it seems; polling the printer, and I can upload another file to start printing.

Does the main flashforge.py file have some additional M27 commands or something at the end of the print/gcode that is ran?

Send: M105
Recv: CMD M105 Received.
Recv: T0:194 /0 B:0 /0
Recv: ok
Send: M119
Recv: CMD M119 Received.
Recv: Endstop: X-max: 1 Y-max: 0 Z-min: 0
Recv: MachineStatus: READY
Recv: MoveMode: READY
Recv: ok
Send: M27

************* LONG 20-30 second pause again ****************

Recv: CMD M27 Received.
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: M119
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.
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.
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.
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.
Mrnt commented 3 years ago

@eduncan911 no I don't think there's any additional M27 commands added by the plugin. I suspect that at the end of printing OctoPrint is sending an M27 to verify that the print is finished and then the printer "forgets" how to respond properly.

Can you upload the octoprint.log for that (or a) successful print including where it hung at the end so I can verify the above theory?

eduncan911 commented 3 years ago

Can you upload the octoprint.log for that (or a) successful print including where it hung at the end so I can verify the above theory?

I knew you were going to ask for that. ;) Yeah, give me some time to get setup again and I'll post it soon when i have a break from work.

Mrnt commented 3 years ago

@eduncan911 @Fred583 I just pushed a new release that should help with the M27 timeout problem.

A BIGGER change is that I added support for printing directly from OctoPrint - please give that a test too.

eduncan911 commented 3 years ago

Whoa. Major update!

I should have a little time late this evening to catch up the debugging, and to try this awesome new feature!

Fred583 commented 3 years ago

I worked, but now when I try to connect it says this: Offline (Error: FlashForgeError: 'USB Error write() (LIBUSB_ERROR_IO [-1])' @ comm.py:_do_send_without_checksum:3593)

octoprint.log

Mrnt commented 3 years ago

@Fred583 sorry I broke it!

Can you try:

eduncan911 commented 3 years ago

@Mrnt i can confirm @Fred583 's findings that it's now connecting, issues a couple commands, and times out after 30 seconds again (same original M27 issue). This time though, no M27.

Attached is the debug log.

octoprint.log

Am I reading this right, that the M119 (Read Endstops States) is the one causing the issue this time?


OT: i've contacted Dremel and FlashForge to attempt to get the pinouts for these boards in the 3D20. Zero progress, stone walled. Really want to throw Klipper on it.

I have also opened a long-standing issue that the 3D20 printer does NOT support gcode files (firmware locks up and reboots when loading one to build), only their proprietary g3drem file format (which has been cracked). It's still in progress.

The 3D20's firmware is disappointing me more and more...

Mrnt commented 3 years ago

The M119 is used as a keep alive to the printer so that it knows the host is there even when OctoPrint is waiting for a blocking command to finish (think waiting for extruder to get to temperature, homing, etc), otherwise it drops the connection. I think I made the time interval too long - can you change line 230 in flashforge.py from: if status_time >= 3.5: to if status_time >= 3.0: and then restart OctoPrint.

RE the print files - the PowerSpec and Finder v1 that I have both read vanilla .gcode files. However, one of the issues is that the printers don't understand a lot of the standard Marlin G-Code and in fact will just hang. I am trying to translate some of those commands in the plugin, but I probably have missed a few.

I hear you on the lack of tech support - I've also tried to make contact with the engineering teams at both companies since it would make things sooo much easier. So far nada.

The sad thing is that the machines do seem well made and the Finder with FlashPrint is a great out of the box experience for a newbie. I just wish they provided support for the community so we could integrate them with other tools as we become more advanced (or when they stop supporting a machine - eg PowerSpec)

Mrnt commented 3 years ago

If you look at the log you can see what is happening:

2020-08-24 23:58:11,967 - octoprint.plugins.flashforge - DEBUG - write() M146 r255 g255 b255
2020-08-24 23:58:12,069 - octoprint.plugins.flashforge - DEBUG - readraw() CMD M146 Received. | ok |
2020-08-24 23:58:12,070 - octoprint.plugins.flashforge - DEBUG - readline() returning: CMD M146 Received. | ok |
2020-08-24 23:58:12,071 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor
2020-08-24 23:58:12,073 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor
2020-08-24 23:58:12,073 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 30000

>>> Here is where the connection is dropped. Because the delay before the next command write() is 
too long, the printer has gives up, so that when the M119 is sent at 23:58:15,080 the printer is no longer 
listening and therefore does not respond. The call at 23:58:12,073 above is the OctoPrint listener thread 
that tries to read responses from the printer.

2020-08-24 23:58:15,080 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:15,081 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:18,585 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:18,586 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:22,089 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:22,090 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:25,595 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:25,596 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:29,100 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:29,101 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:32,605 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:32,606 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:36,111 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:36,112 - octoprint.plugins.flashforge - DEBUG - write() M119
2020-08-24 23:58:39,616 - octoprint.plugins.flashforge - DEBUG - FlashForge.write() called by thread FlashForge.Keep_Alive
2020-08-24 23:58:39,617 - octoprint.plugins.flashforge - DEBUG - write() M119

>>> Here is where the OctoPrint listener thread times out because all those write() M119 calls to the printer 
produced no response.

2020-08-24 23:58:42,075 - octoprint.plugins.flashforge - DEBUG - readraw() error: LIBUSB_ERROR_TIMEOUT [-7]
2020-08-24 23:58:42,076 - octoprint.plugins.flashforge - DEBUG - readraw() 
2020-08-24 23:58:42,076 - octoprint.plugins.flashforge - DEBUG - readline() returning: 
eduncan911 commented 3 years ago

@Mrnt I edited the line 230 to lower the timeout to 3.0. However, it did not fix the connection timeout.

Latest log: octoprint.log

if status_time >= 3.0:
  # get status every 3s so printer gets something during long ops
  self.write(b"M119")
  status_time = 0.0

And started a new instance of Octoprint.

If you look at the log you can see what is happening:

Hard to scroll that far to the right on mobile and tablets when I write some of these messages since it is very verbose. ;)

Mrnt commented 3 years ago

Can you try lowering to 2.5 restart and connect again and if that does not work try 2.0

I’m fairly sure 2.0 will work reliably but not sure we want to send messages more often than we need to.

eduncan911 commented 3 years ago

It seems 2.0 seconds mostly worked. While it was trying to load a file I already had in the queue, I saw another timeout. After a moment or two, of where it was stalled loading, I just cancelled the print. Here's the log for that run that had a timeout while loading. I think this may have been related to the "if the file already exists on the SD Card, uploading again cause octoprint to lock up" issue.

octoprint.log

After a power-off and on, it did let me upload a renamed version of the file. And it completed the print and ran my ending gcode.

Log file of a completed print: octoprint.log

However, Octoprint doesn't show any indication that the print is done. Considering I am new to Octoprint, i actually don't know if there is some visual indicator. But this all I have after the printer completed:

image

May be the plugins, maybe there's something else there. But it just sat like this.

eduncan911 commented 3 years ago

I can confirm streaming worked on the 3D20! It shows the progress and looks like the terminal can read it.

However, it didn't run all of my ending gcode I have embedded in the file (e.g. move to max Z height, to move the bed down all the way). The same file and same ending gcode that did run with the SD card option in previous post, that didn't finish its state.

Log for reference: octoprint.log

Mrnt commented 3 years ago

Thanks for the great feedback. While I look at the logs:

However, Octoprint doesn't show any indication that the print is done. Considering I am new to Octoprint, i actually don't know if there is some visual indicator. But this all I have after the printer completed:

image

May be the plugins, maybe there's something else there. But it just sat like this. Yes it should show % progress while printing and 100% progress, total print time, etc at the conclusion of the print. I suspect this is related to partially disabling the M27 command that polls the progress when printing from SD card. So that’s a new issue 😟.

Mrnt commented 3 years ago

btw I have had problems with the printer display plugin in the past and had to do some special casing for it since the plugin injects a command into the stream that the printers do not recognize. You may want to try without the plugin enabled while I'm debugging this...

eduncan911 commented 3 years ago

This was my first actual print from Octo, hence why I didn't know what was supposed to happen. :)

To be clear, when I was streaming and it completed the print, the status indicators all were 100% and it looked about what I'd expect from it completing a streaming print.

You may want to try without the plugin enabled while I'm debugging this...

Yeah, I was overzealous and just loaded up a bunch. Knew I needed to get a basic print first.

eduncan911 commented 3 years ago

@Mrnt I'm thinking this issue can be closed, as soon as the 2 second thing is merged.

Maybe make that timeout configurable in the settings so users of Dremel 3D20 can adjust it? Just a thought.

Mrnt commented 3 years ago

@eduncan911 I am also trying to add a fix for the displaylayers plugin because that highlighted something that is also potentially an issue.

eduncan911 commented 3 years ago

Yeah, I've printed two other things since and that party never showed any layers. Thought it was a broken plugin. :)

Mrnt commented 3 years ago

@eduncan911 Well it is broken in a way (don't tell Olli) - it relies on sending M117 (display text) commands to the printer, which the FF printers do not use (and if I recall causes them to barf). So I have to allow the plugin to send it and then replace it with something harmless right before the command is sent to the printer (if I just do not send it then OctoPrint will stop sending commands because it is expecting a response from the printer for each command, if I filter it out early, like the other commands FF printers don't like then the plugin doesn't see the command in the OctoPrint command queue and just displays 0%). Pain in the ...

Anyhoo, I just uploaded some changes to the devel branch that should address both the timeout and the displaylayer plugin.

If you and @Fred583 want to give it a try before I push it to release: go to Settings > Plugin Manager > click "Get More" > in the box "... from URL" enter: https://github.com/Mrnt/OctoPrint-FlashForge/archive/devel.zip and it should download the latest version of the devel branch. Restart OctoPrint before testing.

Fred583 commented 3 years ago

Ill get on that as soon as I get home

eduncan911 commented 3 years ago

Nice find!

I'm travelling the next couple of days so I won't be able to test it until sometime this weekend.

Fred583 commented 3 years ago

Just updated and started a print. The percent bar is functional now, I seem to be having no issues. I'll upload the log when it's done so you can see if you want. Edit: It worked with no issues. I would also like to know where you got the display plugin? I've never heard of it, but it looks cool

Log: octoprint.log

Mrnt commented 3 years ago

@Fred583 I cannot tell from the log (I don't think you turned on debugging for the plugin - see Troubleshooting in Readme) - was that an "Upload to SD" or a file that you loaded and printed directly from OctoPrint?

Fred583 commented 3 years ago

I loaded and printed directly from octoprint

Mrnt commented 3 years ago

Wow that's awesome

Mrnt commented 3 years ago

The progress plugin eduncan911 is talking about is DisplayLayerProgress Plugin. It should be working now as well. I had to do some hacky stuff to get the it to play nice.

eduncan911 commented 3 years ago

I still don't know what the DisplayLayerProgress plugin does. It was required for the Dashboard plugin, which is what i really wanted with video. :)

Mrnt commented 3 years ago

The plugin displays the little floating blue dialog in the bottom left of the screen shot you uploaded. More usefully, I think it also puts the progress of the print in the title of the browser window, so if you have multiple browser tabs you can see progress without switching back to the tab containing OctoPrint. I personally run a barebones set up as I have a hard enough time making this lot work as it is. But thats just me ;-)

Mrnt commented 3 years ago

Closing with release of 0.2.2