mariner icon indicating copy to clipboard operation
mariner copied to clipboard

Unexpected Printer Response while printing from web interface

Open dmnkhhn opened this issue 4 years ago • 25 comments

Hello!

I have mariner3d_0.1.1-1_armhf.deb running on a fresh Pi Zero (2020-12-02-raspios-buster-armhf-lite.img) and so far everything seems to be running fine.

However, when I try to print from the web interface I get an Unexpected Printer Response:

The printer returned an unexpected response: 'ok N:0\r\n'

Traceback (most recent call last):
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/server/api.py", line 45, in print_status
    selected_file = elegoo_mars.get_selected_file()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 102, in get_selected_file
    self._extract_response_with_regex("ok '([^']+)'\r\n", data).group(1)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 39, in _extract_response_with_regex
    raise UnexpectedPrinterResponse(data)
mariner.exceptions.UnexpectedPrinterResponse: ok N:0

I don't know what other printer responses there might be, but it might be a fix to change the regular expression to:

ok '?([^']+)'?\r\n

to make the single quotes in the response optional.

The printer:

  • Mars 2 Pro
  • EL3D-3.0.2
  • V4.3.13_LCDC /1620x2560 /F2.23

Edit: I've used minicom to debug it further and amongst a lot of simple "ok" responses there a some responses like

ok '/lenkrad-v1.ctb'

and

ok 'lenkrad-v1.ctb'

where lenkrad-v1.ctb is the only uploaded file right now.

dmnkhhn avatar Jan 02 '21 12:01 dmnkhhn

Hey! Thanks for posting about this. I've noticed this myself too.

This is actually because the printer sends ok responses periodically. Updating the regex will likely work, but it feels a bit hacky.

We should probably flush the read buffers before sending any commands to the printer but, even then, I believe there's no guarantee that an ok won't come back between sending the command and getting the response to the command (not sure how the printer work internally).

So there's a few things we could do:

  1. Flush the buffers like I said above.
  2. Be smarter about reading the responses from the printer. If there's an unexpected ok, just ignore it and move on to the next line.
  3. Remove race conditions between different commands that are sent by the printer by moving communication with the printer to its own thread (see #75).

I'm not sure if 2/ comes with any tradeoffs but it's likely worth a try. 3/ would most likely not help here unless you're taking a lot of different actions around the same time on the app. 1/ should be somewhat simple to implement.

luizribeiro avatar Jan 02 '21 22:01 luizribeiro

Similar Issue?

The printer returned an unexpected response: ''

  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/server/api.py", line 45, in print_status
    selected_file = elegoo_mars.get_selected_file()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 102, in get_selected_file
    self._extract_response_with_regex("ok '([^']+)'\r\n", data).group(1)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 39, in _extract_response_with_regex
    raise UnexpectedPrinterResponse(data)
mariner.exceptions.UnexpectedPrinterResponse

Hypertoken avatar Feb 14 '21 06:02 Hypertoken

Yup, you can ignore it.

luizribeiro avatar Feb 14 '21 15:02 luizribeiro

Not sure if I have the same issue as I haven't saved the error info to compare, but the home page said "status: printer ready" and i was able to upload a file to print and start the print from the Web interface. Upon starting the print I saw the first "in print" status with layer info, time remaining etc, then received an http 500 error and could not then get back to a working status dialog. New Zero W, Raspberry Pi OS lite and mariner installed as per the instructions as of Saturday 27th and installed on a Phrozen Sonic Mini 4K. The 8hr print completed without issue so not the biggest of problems. Great work BTW 👌

AndyRap avatar Mar 29 '21 21:03 AndyRap

Okay, going to play with this issue a bit. Have added the basic buffer flush ( self._serial_port.read(size=1024) )to the mars serial send() function. I get this issue super frequently, so it should be easy enough to test how effective a flush is.

Zenroth avatar Apr 19 '21 00:04 Zenroth

So adding the flush helps quite a bit, but isn't a 100% solution as expected.

This was with just leaving the web display up during prints, and not issuing additional commands. So no race conditions, etc.

It probably reduced the issue on my end by 50-70% though.

Zenroth avatar Apr 28 '21 19:04 Zenroth

I also still get this, but it is quite reduced. Sonic Mini and Mighty 4K.

proffrink avatar Apr 28 '21 19:04 proffrink

Getting this on the Sonic Mini 4K as well. If I clear the error, it's back again the next time I check.

Traceback (most recent call last):
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/server/api.py", line 46, in print_status
    selected_file = elegoo_mars.get_selected_file()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 102, in get_selected_file
    self._extract_response_with_regex("ok '([^']+)'\r\n", data).group(1)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 39, in _extract_response_with_regex
    raise UnexpectedPrinterResponse(data)
mariner.exceptions.UnexpectedPrinterResponse

juicyroots avatar Apr 30 '21 23:04 juicyroots

So I'm not sure how to solve this issue. It seems to only ever really be a problem with PrintStatus from what I've seen. Flushing the buffer before command helps a lot, however..

Sometimes you get a blank line back.. Sometimes the response comes back to slow.. Sometimes you get multiple output back in the wait period.. Sometimes the response had extra quotes, etc. Sometimes even after a print has finished the printers continue to send something like ok '\filename' over and over. Sometimes you get an actual strange error output, which doesn't seem to cause any print problems, but happens never the less.

Given the wide variety of issues around this, and the fact that we don't have specs on the internal printer communication flow/etc.. I'm not sure there is a good way to 100% fix this.

So for my own testing, I've decided to commit a programming sin, and just try/catch the read response call in PrintStatus. This is quite dirty of course, yet it does handle all the problematic cases above more or less. One thing I would be tempted to do here, is add an error counter that gets cleared on handling a good response. If it instead increments and hits some set threshold than a full error dialog pops up. (AKA something has clearly gone very wrong with the printer or the serial communication.)

Zenroth avatar May 02 '21 18:05 Zenroth

not sure what have i did wrong:

Traceback (most recent call last):
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/server/api.py", line 220, in printer_command
    elegoo_mars.start_printing(filename)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 132, in start_printing
    self.select_file(filename)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 111, in select_file
    raise UnexpectedPrinterResponse(response)
mariner.exceptions.UnexpectedPrinterResponse: //Disk init fail!

I get this when i want to start a print.

Later Edit: i changed my data cable, the one i uses was only able to charge.

prukeremanuel avatar May 12 '21 23:05 prukeremanuel

I made some good progress on this bug today by making these changes:

  1. Adding retries (5b5c5b2046175f8aa5a9feb7981a8d8bc5ec0cba). Fetching print status is idempotent so it's fine for us to execute it a few times until it works.
  2. Adding a delay between retries (2455d9f19fa9ef81b6ceb2249ca2165323a6ec87). This helps a bunch because the printer doesn't seem to handle multiple commands close to each other in a row for whatever reason. We might also want to try making the delay between retries use an exponential backoff, but I didn't try that.
  3. Ending commands with \r\n (599f4b06a5a988cfb2b27be51bf947a88a224508). I was a bit surprised this worked at all without ending the commands with a new line. Turns out the printer probably waits a bit for a few milliseconds when there's no new line on the end of the command. If the input looks like a command, it runs it. Otherwise, it just errors out. This helped a bunch too.
  4. Flushing input/output buffers (f9847d323e6123d069730258775041e88e019b9a).

Overall after these changes I can only reproduce this bug if I refresh the page multiple times quickly. This makes sense though: we're probably processing multiple requests at the same time and spamming the printer with commands and running into race conditions. But at that point, #75 becomes more important than any more tweaks to this.

If you would like to try a build with these fixes, download the .deb that is attached to this CI run as an artifact: https://github.com/luizribeiro/mariner/actions/runs/894169954

luizribeiro avatar Jun 01 '21 02:06 luizribeiro

Those look like solid steps, one thing though, you'll probably want to add the retry logic to get_selected_file as well. As part of print_status I had the exceptions rising out of that as well.

Zenroth avatar Jun 01 '21 02:06 Zenroth

Right, 3c9185a34e243a343c6a51e857e681331cba7e80 did that :)

luizribeiro avatar Jun 01 '21 03:06 luizribeiro

Man, that is so cool. Great work!!

daxliniere avatar Jun 01 '21 09:06 daxliniere

I give the linked build a shot, and ... wow is it much more responsive, even just sitting and not doing anything. File uploads are SIGNIFICANTLY faster. So, great improvements, keep it up!

Edit: Using it, the random notifications while printing are gone. It's nice and silent. Though, still get HTTP 400 errors when attempting to upload, periodically.
Much improved!

drashna avatar Jun 05 '21 05:06 drashna

Sounds awesome. I'm happy to test as well. Noob question: how do I update this from CLI? I tried apt-get update/upgrade, but I guess since it's not an official release yet, I'm not getting this new version.

daxliniere avatar Jun 05 '21 21:06 daxliniere

@daxliniere, see #415 for how to update it manually from a CI build

luizribeiro avatar Jun 06 '21 00:06 luizribeiro

I made some good progress on this bug today by making these changes:

  1. Adding retries (5b5c5b2). Fetching print status is idempotent so it's fine for us to execute it a few times until it works.
  2. Adding a delay between retries (2455d9f). This helps a bunch because the printer doesn't seem to handle multiple commands close to each other in a row for whatever reason. We might also want to try making the delay between retries use an exponential backoff, but I didn't try that.
  3. Ending commands with \r\n (599f4b0). I was a bit surprised this worked at all without ending the commands with a new line. Turns out the printer probably waits a bit for a few milliseconds when there's no new line on the end of the command. If the input looks like a command, it runs it. Otherwise, it just errors out. This helped a bunch too.
  4. Flushing input/output buffers (f9847d3).

Overall after these changes I can only reproduce this bug if I refresh the page multiple times quickly. This makes sense though: we're probably processing multiple requests at the same time and spamming the printer with commands and running into race conditions. But at that point, #75 becomes more important than any more tweaks to this.

If you would like to try a build with these fixes, download the .deb that is attached to this CI run as an artifact: https://github.com/luizribeiro/mariner/actions/runs/894169954

Interesting, so if i had multiple instances of the web UI open on different browsers / computers at the same time, then the error would come up more often since it creates a retry / timing issue on the printer end, since the server handles each browsers refresh request independently ?

That would explain why I had no errors like the above at first, now a after a few days of tinkering they seem to become more frequent - but in the same time I am monitoring from different computer / devices at the same time.

SaKiEQ avatar Jan 02 '22 10:01 SaKiEQ

Hi, I'm running into the same issue except way worse on my Mars 2 pro, everytime I refreach the page the error will pop out, making the webpage unusable. The artifact seems to be expired. Is there a guide to build the software manually or are you close to some kind of release?

ProgrammedSoul avatar Jan 24 '22 07:01 ProgrammedSoul

I have since then switched to OctoPrint with Chitu implementation - which is not supposed to work on latest firmware, yet it does on my Creality LD-002H. I noticed that on the OctoPrint installation the USB Dongle emulation was not configured properly by default install. While the Mariner3D configuration of the same works well. So I used the Mariner3D USB config with the OctoPrint implementation and i am printing now since 2 weeks or so daily / non stop without errors. Granted the system / UI is a bit more sluggish than Mariner3D, does not have Thumbnails, but else supports the full OctoPrint ecosystem of plugins.

SaKiEQ avatar Jan 25 '22 08:01 SaKiEQ

I have since then switched to OctoPrint with Chitu implementation - which is not supposed to work on latest firmware, yet it does on my Creality LD-002H. I noticed that on the OctoPrint installation the USB Dongle emulation was not configured properly by default install. While the Mariner3D configuration of the same works well. So I used the Mariner3D USB config with the OctoPrint implementation and i am printing now since 2 weeks or so daily / non stop without errors. Granted the system / UI is a bit more sluggish than Mariner3D, does not have Thumbnails, but else supports the full OctoPrint ecosystem of plugins.

Thank you for the suggestions. Just read the plugin page, it seems the author acturally referenced Mariner code to make that plugin. OctoPi is really laggy on PiZeroW but I guess I can live with it until Mariner update.

ProgrammedSoul avatar Jan 28 '22 11:01 ProgrammedSoul

I do not think the problem of lagginess is the PiW, it is the printer. I am running on a Pi4 for now (since we can not get anything here are the moment), it still takes a good 30sec until the printer responds to a start command etc... For my self, I have tied all my printers into an overall reporting system via MQTT. So having access to the OctoPrint plugins with MQTT integration was a big factor. Mariner3D offers actually much better performance, thumbnails etc.. than OctoPrint, yet its an island.

I rather see Mariner3D to become a OctoPrint plugin, than a standalone feature.

SaKiEQ avatar Jan 28 '22 11:01 SaKiEQ

Hi, I have similar problems on the Saturn, but everything works regularly

Traceback (most recent call last):
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/server/api.py", line 46, in print_status
    selected_file = elegoo_mars.get_selected_file()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 102, in get_selected_file
    self._extract_response_with_regex("ok '([^']+)'\r\n", data).group(1)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 39, in _extract_response_with_regex
    raise UnexpectedPrinterResponse(data)
mariner.exceptions.UnexpectedPrinterResponse
Traceback (most recent call last):
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/server/api.py", line 47, in print_status
    print_status = elegoo_mars.get_print_status()
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 73, in get_print_status
    match = self._extract_response_with_regex("D:([0-9]+)/([0-9]+)/([0-9]+)", data)
  File "/opt/venvs/mariner3d/lib/python3.7/site-packages/mariner/mars.py", line 39, in _extract_response_with_regex
    raise UnexpectedPrinterResponse(data)
mariner.exceptions.UnexpectedPrinterResponse

antwal avatar Mar 20 '22 10:03 antwal

there is no valid build that is not "expired", so unfortunately, I can try this fix by manually updating the deb. Any pointer beside compiling it myself?

BenjaminVanRyseghem avatar Jul 20 '22 10:07 BenjaminVanRyseghem

Is there any hope on a solution on this? I got this error on both the printer status screen and after uploading. I have a Elegoo Mars 2 Pro with a Raspberry Pi Zero W

mdbijl avatar Jan 22 '23 14:01 mdbijl