Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Wrong line resent after resend request without ok #2285

Closed
jm2069872 opened this issue Dec 14, 2017 · 41 comments
Closed

Wrong line resent after resend request without ok #2285

jm2069872 opened this issue Dec 14, 2017 · 41 comments
Labels
done Done but not yet released improvement Improving functionality, behaviour, UX, ... not octoprint Issue is not on OctoPrint's end
Milestone

Comments

@jm2069872
Copy link

What were you doing?

The issue occurred during a print after starting/heating/leveling and during the actual printing phase.

What did you expect to happen?

The print should have continued normally.

What happened instead?

The print head suddenly stopped. Extrusion stopped but the heated bed and hotend remained on. The OctoPrint web interface became partially unresponsive; canceling did nothing, and the temperature graph did not update.

In one case, the print failed after only a couple layers. In the second case it failed after roughly 60 layers.

It looks like OctoPrint may have been re-sending the wrong line. Note that in the Terminal log (pasted below) lines up to 66557 were sent and the last line was 66555. Although the logs say "Resend: 66556", the actual line that is resent contains "N66555" which was already received.

In both cases, I reset the Pi and started the print again using the exact same gcode, without reuploading it or changing any settings. In the first case, the print continued and finished successfully. In the second case, the print is in progress and has printed past the point of initial failure.

Did the same happen when running OctoPrint in safe mode?

I have not tried safe mode. Since the issue is intermittent it is difficult to reliably reproduce.

Version of OctoPrint

OctoPrint 1.3.5 (master branch)

Operating System running OctoPrint

OctoPi 0.14.0

Printer model & used firmware incl. version

Prusa i3 MK3, latest firmware as shipped (currently beta, the latest version on the site is older).

Browser and Version of Browser, Operating System running Browser

N/A

Link to octoprint.log

Excerpt log: https://gist.github.com/justinmrkva/22288e9b5e7df2e0999e6c229f9fe960

Link to contents of terminal tab or serial.log

Terminal tab: https://gist.github.com/justinmrkva/03f869d34e85691c59195ca5258b70c2

Excerpt provided here for clarity:

Send: N66554 G1 X130.897 Y133.148 E0.0085*83
Recv: ok
Send: N66555 G1 X131.338 Y133.349 E0.0091*91
Recv: ok
Send: N66556 G1 X131.574 Y133.428 E0.0046*92
Recv: ok
Send: N66557 G1 X131.715 Y133.287 E0.0037*93
Recv: Error:checksum mismatch, Last Line: 66555
Recv: Resend: 66556
Recv: Error:Line Number is not Last Line Number+1, Last Line: 66555
Recv: Resend: 66556
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N66555 G1 X131.338 Y133.349 E0.0091*91
Recv: Error:Line Number is not Last Line Number+1, Last Line: 66555
Recv: Resend: 66556
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
Send: N66555 G1 X131.338 Y133.349 E0.0091*91
Recv: Error:Line Number is not Last Line Number+1, Last Line: 66555
Recv: Resend: 66556

Link to contents of Javascript console in the browser

N/A

Screenshot(s)/video(s) showing the problem:

N/A

@foosel
Copy link
Member

foosel commented Dec 14, 2017

Your firmware has a specific bug leading to an ok after the resend request missing. While that still shouldn't cause this line to be sent, it is what makes this issue manifest in the first place. You should set Settings > Serial communication > Advanced options > Simulate an additional ok for resend requests to work around that firmware bug.

@jm2069872
Copy link
Author

Thanks! I'll watch out for any other odd behavior after enabling it, but it sounds like you're familiar with this particular issue. I came across a lot of similar cases while searching but I hadn't seen any where the line number was off by one.

Closing the issue, and maybe this'll pop up in the search results and help someone else who has a similar problem in the future. :)

@foosel
Copy link
Member

foosel commented Dec 18, 2017

FWIW, I've opened a ticket at prusa3d/Prusa-Firmware#331 about this.

@foosel
Copy link
Member

foosel commented Dec 18, 2017

Reopening. I'll have to take a look in January if I can somehow get OctoPrint to not send the wrong line when that happens (but it might not be possible to differ between this firmware bug and something like an actual communication timeout during a resend).

@foosel foosel reopened this Dec 18, 2017
@foosel foosel added improvement Improving functionality, behaviour, UX, ... not octoprint Issue is not on OctoPrint's end labels Dec 18, 2017
@foosel foosel added this to the 1.3.7 milestone Dec 18, 2017
@foosel foosel changed the title Wrong Line Resent after Checksum Mismatch Wrong line resent after resend request without ok Dec 18, 2017
@sbts
Copy link

sbts commented Dec 23, 2017

@foosel I've updated the prusa issue with a note about this, but as I read and understand the log, the firmware is also reporting the incorrect Last Line and Resend Line numbers

  • Last Line 66555 when I believe it should be 66556
  • Resend Line 66556 when I believe it should be 66557

This is probably caused by the same root bug, but if the fix it in the wrong way the numbering will still be incorrect.

@rnldnkp
Copy link

rnldnkp commented Dec 29, 2017

I have exact the same problem since 1.3.6 only. Have printed dozens of STL's for 6 months in the same setup, no new plugins, no recent firmware upgrades to my printer. The one giving problems is connected to my MK2S.

First print after 1.3.6 upgrade gave me these problems.

Again I did not change printer firmware, I did however upgrade Octoprint just before the first failure.

I can fix it though when I notice the error. Just force an acknowledgement in de advanced terminal view. You can see the communication is stuck somehow.

Error in terminal

Send: N24777 G1 X121.235 Y122.062 E0.01711*102
Recv: Error:checksum mismatch, Last Line: 24775
Recv: Resend: 24776
Recv: Error:Line Number is not Last Line Number+1, Last Line: 24775
Recv: Resend: 24776
Communication timeout during an active resend, resending same line again to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.

After I fake the acknowledgement the print finishes just fine as far as I currently tested on 4 prints.

@Firebug24k
Copy link

I think I'm suffering from the same issue (Prusa MK2s and latest version of Octoprint).

Had a couple of failed prints, here's the output from the last one:

Send: N245945 G1 X73.662 Y61.664 E0.0166790
Recv: ok
Send: N245946 G1 X73.280 Y61.837 E0.01667
89
Recv: ok
Send: N245947 G1 X72.934 Y62.063 E0.0164785
Recv: ok
Send: N245948 G1 X72.632 Y62.332 E0.01608
95
Recv: ok
Send: N245949 G1 X72.381 Y62.633 E0.0155794
Recv: Error:Line Number is not Last Line Number+1, Last Line: 245945
Recv: Resend: 245946
Send: N245946 G1 X73.280 Y61.837 E0.01667
89
Recv: ok
Send: N245947 G1 X72.934 Y62.063 E0.0164785
Recv: ok
Send: N245948 G1 X72.632 Y62.332 E0.01608
95
Recv: Error:No Line Number with checksum, Last Line: 245945
Send: N245949 G1 X72.381 Y62.633 E0.0155794
Recv: ok
Send: N245950 G1 X72.169 Y62.979 E0.01611
82
Recv: Full RX Buffer
Recv: ok
Send: N245951 G1 X72.009 Y63.358 E0.0163689
Recv: Error:checksum mismatch, Last Line: 245948
Recv: Resend: 245949
Send: N245949 G1 X72.381 Y62.633 E0.01557
94
Recv: ok
Send: N245950 G1 X72.169 Y62.979 E0.0161182
Recv: ok
Send: N245951 G1 X72.009 Y63.358 E0.01636
89
Recv: Error:Line Number is not Last Line Number+1, Last Line: 245948
Recv: Resend: 245949
Send: N245949 G1 X72.381 Y62.633 E0.0155794
Recv: ok
Send: N245950 G1 X72.169 Y62.979 E0.01611
82
Recv: ok
Send: N245951 G1 X72.009 Y63.358 E0.0163689
Recv: Error:No Line Number with checksum, Last Line: 245948
Send: N245952 G1 X71.907 Y63.762 E0.01660
80
Recv: ok
Send: N245953 G1 X71.868 Y64.180 E0.0166783
Recv: Full RX Buffer
Recv: ok
Send: N245954 G1 X71.893 Y64.598 E0.01667
93
Recv: Error:Line Number is not Last Line Number+1, Last Line: 245951
Recv: Resend: 245952
Send: N245952 G1 X71.907 Y63.762 E0.0166080
Recv: ok
Send: N245953 G1 X71.868 Y64.180 E0.01667
83
Recv: echo: cold extrusion prevented
Recv: ok
Send: N245954 G1 X71.893 Y64.598 E0.0166793
Recv: Error:Line Number is not Last Line Number+1, Last Line: 245951
Recv: Resend: 245952
Send: N245952 G1 X71.907 Y63.762 E0.01660
80
Recv: ok
Send: N245953 G1 X71.868 Y64.180 E0.01667*83
Recv: start
Printer sent 'start' while printing. External reset? Aborting job since printer lost state.
Changing monitoring state from 'Printing' to 'Operational'
Recv: echo:echo: Last Updated: Oct 30 2017 10:24:26 | Author: (none, default config)
Recv: Compiled: Oct 30 2017
Recv: echo: Free Memory: 2217 PlannerBufferBytes: 1360
Recv: echo:Stored settings retrieved
Recv: echo:SD init fail
Recv: Error:Line Number is not Last Line Number+1, Last Line: 0
Recv: Resend: 1
Printer requested line 1 but no sufficient history is available, can't resend
Recv: echo:SD init fail
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: Too many consecutive timeouts, printer still connected and alive?'
Connection closed, closing down monitor

@rnldnkp
Copy link

rnldnkp commented Dec 29, 2017

Because of this issue where OctoPrint/my printer becomes useless (4 out of 5 prints get stuck), I just downgraded Octoprint to 1.3.5. These were all the same files btw (two different ones), only spool swap in between.

Now printing my second print on 1.3.5, which is stil holding on... Will keep you posted when it fails. If so, I will also be downgrading Prusa firmware, just to be 100% sure since Prusa did change some stuff in 3.1.0 for Octoprint support.

@Firebug24k
Copy link

That's interesting - I can't help answer that question as I just installed Octoprint for the first time w/this version and this version of Prusa firmware - never used it on this printer before now, so nothing to compare to.

@rnldnkp
Copy link

rnldnkp commented Dec 29, 2017

Ok, stuck again, same issue. So downgrading OP 1.3.6 > 1.3.5. does not solve the issue for me.

Will downgrade firmware when this print ends, not sure if I will be able to print something right after since I don't want this issue happening when I'm not around (heatbed and nozzle are both still on while it 'crashes'!!)

@rnldnkp
Copy link

rnldnkp commented Dec 31, 2017

Just a heads-up, after 5 more prints I came to the same conclusion as @foosel.
Must have been lucky for a while on firmware 3.1.0 without issues, didn't print that much for a few weeks.

Tested on both Octoprint 1.3.5 and 1.3.6 to make sure that has nothing to do with it.

Using Prusa firmware 3.1.0, 4 out of 5 prints get stuck, waiting for an OK.
After downgrading to firmware 3.0.12 (final), 5 out of 5 prints finished just fine.

All tests were performed on a Prusa i3 MK2(S) which has never had any issues before.

Happy New Year! (that's what I was printing for anyways 🤣 )

@jm2069872
Copy link
Author

jm2069872 commented Jan 1, 2018

3.1.1 RC4 B143 firmware was just released for Mk3 a couple days ago (https://www.prusa3d.com/drivers/). I haven't verified whether or not it has the same issue, although "Better OctoPrint Reliability" is mentioned in the release notes.

EDIT: Don't upgrade to RC4... it has a serious serial communication issue. You can download the previous firmware at http://prusa3d.com/downloads/firmware/prusa3d_fw_3_1_1_rc3_b138.zip (the Prusa site doesn't link to previous RC firmwares directly). You can go back by flashing RC3 over RC4 and nothing appears to break, although YMMV.

@Firebug24k
Copy link

I'd try it but I don't have a MK3, just 2S.

@Johncoffee2017
Copy link

Same issue here - prints stop since a I've upgraded from my Prusa i3 MK2S to i3 MK2S MMU (multi color option). This means that I had to update the Prusa FW to 3.1.0

Gina - So I should do this here as you suggest above?
-->"You should set Settings > Serial communication > Advanced options > Simulate an additional ok for resend requests to work around that firmware bug."

@Firebug24k
Copy link

Firebug24k commented Jan 4, 2018 via email

@rnldnkp
Copy link

rnldnkp commented Jan 4, 2018

@Johncoffee2017 just downgrade the firmware to 3.0.12 it is compatible with MMU. All my tests were on the mmu :)

@Firebug24k
Copy link

Firebug24k commented Jan 4, 2018 via email

@rnldnkp
Copy link

rnldnkp commented Jan 4, 2018

Not liking to downgrade is different than not working at all after a downgrade ;)
I like my printer better working as it always did, than having new features and not being able to control it easily.

By downgrading you loose the new features but you gain Octoprint support.

@Johncoffee2017
Copy link

Thanks for your replies Firebug24k & rnldnkp.
Wondering what Prusa changed on FW 3.1 that this specific part of the code doesn't behave the same any longer...
I will probably try first to work via the SD card.
..and I need to check what the linear advance really improves.. haven't tried it.
Firebug24k - you seem to like it. Where are the improvements for you?
Thanks for elaborating a bit!

@nophead
Copy link
Contributor

nophead commented Jan 4, 2018 via email

@Firebug24k
Copy link

Firebug24k commented Jan 4, 2018 via email

@Firebug24k
Copy link

Ok, as promised I pulled and compiled, haven't tried it out yet but here's the FW (no changes other than that patch).
Firmware.ino.with_bootloader.rambo.hex.zip

@Firebug24k
Copy link

I should say this is for Rambo 1.3a, 1.75mm MK2 with multimaterial.

@Johncoffee2017
Copy link

I'm getting a verification error when trying to flash your FW Firebug24k. Failed twice. Standard Prusa FW3.1 flashes without issues.
Interesting fact: your version is 692kB, where the standard FW has 660kB only.

Did you succeed?

@Firebug24k
Copy link

Firebug24k commented Jan 8, 2018 via email

@Johncoffee2017
Copy link

Ok, thanks for posting a new version. Will try again after my current print has finished. Need to print new Spool holders, the current Prusa version is not good at all. I don't like the approach - and I got the new black molded version.

@Johncoffee2017
Copy link

Ok, uploaded your new FW build and now testing a 6.5h print. Let's see how it turns out.
(My former print I've just made with FW3.1 ran fine too. Within the print time of 3hrs - there were about 5-6 cases where errors occured)

@Johncoffee2017
Copy link

It didn't work! Found my Printer this morning sitting and waiting on the part without any movement, hotend and bed were still hot, Octoprint unresponsive.

Here are some log data's:

| Recv: Resend: 689
2018-01-07 23:05:32,733 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 721, current line = 723
| Last lines in terminal:
| Recv: ok
| Send: N714 G1 X117.323 Y116.573 E0.01682111
| Recv: ok
| Send: N715 G1 X99.335 Y98.584 E0.79996
100
| Recv: ok
| Send: N716 G1 X99.981 Y98.696 E0.02063109
| Recv: ok
| Send: N717 G1 X117.858 Y116.573 E0.79499
108
| Recv: ok
| Send: N718 G1 X118.393 Y116.573 E0.01682103
| Recv: ok
| Send: N719 G1 X100.508 Y98.688 E0.79534
90
| Recv: ok
| Send: N720 G1 X101.006 Y98.651 E0.0157180
| Recv: ok
| Send: N721 G1 X118.928 Y116.573 E0.79696
109
| Recv: ok
| Send: N722 G1 X119.463 Y116.573 E0.01682103
| Recv: Error:checksum mismatch, Last Line: 720
| Recv: Resend: 721
2018-01-07 23:05:32,744 - octoprint.util.comm - INFO - Ignoring resend request for line 721, that still originates from lines we sent before we got the first resend request
2018-01-07 23:05:32,762 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 721, current line = 724
| Last lines in terminal:
| Recv: ok
| Send: N718 G1 X118.393 Y116.573 E0.01682
103
| Recv: ok
| Send: N719 G1 X100.508 Y98.688 E0.7953490
| Recv: ok
| Send: N720 G1 X101.006 Y98.651 E0.01571
80
| Recv: ok
| Send: N721 G1 X118.928 Y116.573 E0.79696109
| Recv: ok
| Send: N722 G1 X119.463 Y116.573 E0.01682
103
| Recv: Error:checksum mismatch, Last Line: 720
| Recv: Resend: 721
| Send: N721 G1 X118.928 Y116.573 E0.79696109
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 720
| Recv: Resend: 721
| Send: N722 G1 X119.463 Y116.573 E0.01682
103
| Recv: Error:No Line Number with checksum, Last Line: 720
| Send: N723 G1 X101.426 Y98.536 E0.80208*87
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 720
| Recv: Resend: 721
2018-01-07 23:07:09,596 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1605, current line = 1606
| Last lines in terminal:

Going back to FW 3.1 again!

@Firebug24k
Copy link

Firebug24k commented Jan 9, 2018 via email

@Johncoffee2017
Copy link

Firebug24k - Can you give me your private email address?

@Johncoffee2017
Copy link

The reason I’m asking is that i’d like to share some more information with you!

@jm2069872
Copy link
Author

jm2069872 commented Jan 11, 2018

Just wanted to throw this in here: https://shop.prusa3d.com/forum/original-prusa-i3-mk3-f30/octoprint-issues-and-tips-t13156.html

Firmware 143e (on the forum but not yet on the main page) removes a couple features because they were apparently overloading the board and causing serial issues. I haven't yet tried it but I'll give it a shot when I have the time.

@foosel
Copy link
Member

foosel commented Jan 11, 2018

Soo... First day back from a much needed vacation. Happy new year everyone.

@justinmrkva Thanks for the link to this thread. Just from the increase in communication issues and also the fact that someone somewhere reported the printer making funny moves, before I clicked on that thread it sounded suspiciously like a similar issue I had with another vendor firmware on a printer here where they did too much in a interrupt handler, causing the serial connection to get out of sync and causing loads of garbled communication as a result, which made me think this might be a similar case. After reading the thread it sounds like my hunch was pretty much spot on ;)

@Firebug24k You said "Settings > Serial communication > Advanced options > Simulate an additional ok for resend requests" didn't solve this for you. Did you reconnect to the printer after enabling that checkbox? Because this definitely worked when I simulated the problem here against the virtual printer.

@EddyMI3d
Copy link

EddyMI3d commented Jan 18, 2018

So referring to Marlin's considerations to linear advance (http://marlinfw.org/docs/features/lin_advance.html#considerations-before-using-linear-advance), I would try 57600 baud, but the Prusa firmware denies the connection at that speed.
[Another possibility would be to turn off linear advance. I know there is a g-code line in slic3r to set a (somehow) optimal setting for the printer. Is there a g-code to turn LA completely off?] -> found it: just set K = 0 😊

@EvanFei
Copy link

EvanFei commented Jan 26, 2018

Hi, @rnldnkp .
I've met same resend-issue, could you please tell me how to force an acknowledgement?

@EddyMI3d
Copy link

EddyMI3d commented Jan 26, 2018

There is no way to force anything. The issue seems to be in the firmware/rambo board because of not enough time to handle the serial input (as far as I understood).
You just can disable Linear Advance by using "K0" in your filament settings. Works fine for me.

@foosel
Copy link
Member

foosel commented Mar 26, 2018

1.3.7 introduces a dynamic workaround for this by starting a timer after a resend request is received. If no ok is received within the timeout of that timer, one will be simulated. That should avoid this issue more or less reliably. Doesn't fix firmware side serial timing issues, only works around possible results of that plus a specific bug.

@foosel foosel added the done Done but not yet released label Mar 26, 2018
@foosel foosel added this to the 1.3.7 milestone Mar 26, 2018
@foosel
Copy link
Member

foosel commented Apr 9, 2018

Closing as 1.3.7 was just released.

@foosel foosel closed this as completed Apr 9, 2018
@github-actions github-actions bot locked as resolved and limited conversation to collaborators May 29, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
done Done but not yet released improvement Improving functionality, behaviour, UX, ... not octoprint Issue is not on OctoPrint's end
Projects
None yet
Development

No branches or pull requests

9 participants