Description
The problem
I was attempting to do a SD Card Upload of a GCode file. It fails with a repeating:
Recv: Error:checksum mismatch, Last Line: 0
Recv: Resend: 1
octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1, current line = 2
In looking at the OctoPrint log file and terminal dump, the problem seems to be in https://github.com/OctoPrint/OctoPrint/blob/master/src/octoprint/util/comm.py and how it processes the gcode lines that it is sending.
The source code seems to strip comments that use the ';' symbol, but not CNC-style paren-comments, which can be enabled in the printer's firmware and is used in this gcode file. If the paren-comments are on lines with actual gcode comments, there is no issue, as it sends the comment to the printer right along with the rest of the gcode command line. But, if a paren-comment appears on a line by itself, it seems that OctoPrint doesn't properly send the line number and checksum as it should, which causes the printer to rerequest the line and the two sides get out of sync.
The first few lines of the gcode file are:
;Generated with Cura_SteamEngine 15.05
(**** start.gcode for The OctoForge ****)
M75 (start print job)
M73 P0 (enable build progress)
G21 (set units to mm)
The first line gets tossed completely by OctoPrint as a comment. However, the second line gets sent as-is, but without the proper line-number and checksum, since it contains no actual gcode command. That is, gcode_command_for_cmd
returns nothing for it.
This is what is seen in the OctoPrint log file:
2022-06-06 21:06:27,251 - octoprint.filemanager.analysis - INFO - Starting analysis of local:FilamentSensorPlug_octoforge.gcode
2022-06-06 21:06:27,271 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python3 -m octoprin
t analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --bed-z=0.0 --offset 0.0 0.0 /home/pi/
.octoprint/uploads/FilamentSensorPlug_octoforge.gcode
2022-06-06 21:06:27,557 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2022-06-06 21:06:27,845 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Sending file to SD"
2022-06-06 21:06:27,989 - octoprint.plugins.action_command_notification - INFO - Got a notification: filame~1.gco
2022-06-06 21:06:28,005 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1, current line = 2
| Last lines in terminal:
| Recv: T:25.35 /0.00 B:19.03 /0.00 C:19.60 /0.00 T0:25.35 /0.00 T1:-15.00 /0.00 @:0 B@:0 @0:0 @1:0
| Recv: Not SD printing
| Recv: Not SD printing
| Send: M20 L
| Recv: Begin file list
| Recv: End file list
| Recv: ok
| Send: N0 M110 N0*125
| Recv: ok
| Send: M28 /filame~1.gco
| Recv: echo:Now fresh file: /filame~1.gco
| Recv: Writing to file: filame~1.gco
| Changing monitoring state from "Operational" to "Sending file to SD"
| Recv: //action:notification filame~1.gco
| Recv: ok
| Recv: Not SD printing
| Send: (**** start.gcode for The OctoForge ****)
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
2022-06-06 21:06:28,026 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1, current line = 2
| Last lines in terminal:
| Recv: Begin file list
| Recv: End file list
| Recv: ok
| Send: N0 M110 N0*125
| Recv: ok
| Send: M28 /filame~1.gco
| Recv: echo:Now fresh file: /filame~1.gco
| Recv: Writing to file: filame~1.gco
| Changing monitoring state from "Operational" to "Sending file to SD"
| Recv: //action:notification filame~1.gco
| Recv: ok
| Recv: Not SD printing
| Send: (**** start.gcode for The OctoForge ****)
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
| Recv: ok
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
2022-06-06 21:06:28,053 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1, current line = 2
| Last lines in terminal:
| Recv: ok
| Send: M28 /filame~1.gco
| Recv: echo:Now fresh file: /filame~1.gco
| Recv: Writing to file: filame~1.gco
| Changing monitoring state from "Operational" to "Sending file to SD"
| Recv: //action:notification filame~1.gco
| Recv: ok
| Recv: Not SD printing
| Send: (**** start.gcode for The OctoForge ****)
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
| Recv: ok
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
| Recv: ok
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
2022-06-06 21:06:28,072 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1, current line = 2
| Last lines in terminal:
| Changing monitoring state from "Operational" to "Sending file to SD"
| Recv: //action:notification filame~1.gco
That continues to repeat for a bit until it realizes it's stuck and tries to abort:
2022-06-06 21:06:28,232 - octoprint.util.comm - WARNING - Printer keeps requesting line 1 again and again, communication stuck
2022-06-06 21:06:28,233 - octoprint.util.comm - INFO - Changing monitoring state from "Sending file to SD" to "Error"
2022-06-06 21:06:28,253 - octoprint.util.comm - INFO - Force-sending M112 to the printer
2022-06-06 21:06:28,253 - octoprint.filemanager.analysis - INFO - Starting analysis of local:FilamentSensorPlug_octoforge.gcode
2022-06-06 21:06:28,299 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python3 -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 --bed-z=0.0 --offset 0.0 0.0 /home/pi/.octoprint/uploads/FilamentSensorPlug_octoforge.gcode
2022-06-06 21:06:28,366 - octoprint.util.comm - INFO - Changing monitoring state from "Error" to "Offline after error"
2022-06-06 21:06:28,400 - octoprint.plugins.action_command_notification - INFO - Notifications cleared
2022-06-06 21:06:28,909 - octoprint.util.comm - INFO - Firmware didn't send an 'ok' with their resend request. That's a known bug with some firmware variants out there. Simulating an ok to continue...
2022-06-06 21:06:37,252 - octoprint.filemanager.analysis - INFO - Analysis of entry local:FilamentSensorPlug_octoforge.gcode finished, needed 9.00s
Then, for whatever reason, the printer and OctoPrint can't seem to get resynchronized until I reboot the printer board and reconnect with OctoPrint...
I think the problem is right here:
| Send: (**** start.gcode for The OctoForge ****)
| Send: N1 M75 (start print job)*71
| Recv: Error:checksum mismatch, Last Line: 0
| Recv: Resend: 1
| Recv: ok
Where OctoPrint sends the (**** start.gcode for The OctoForge ****)
text without a line number or checksum and without stripping it as a pure comment line.
Now arguably, paren-comment-only lines are a bit outside of gcode standard, even for CNC format, but the printer itself, if you copy this file directly to the SD card, interprets it just fine. So, there's a definite bug in OctoPrint's reading and sending the file.
My workaround, of course, is to just change the start.gcode segment to use the ';' symbol for comment-only lines and let OctoPrint just strip them. But I wanted to open this issue so that it can eventually get fixed in OctoPrint.
Did the issue persist even in safe mode?
Yes, it did persist
If you could not test in safe mode, please state why
No response
Version of OctoPrint
1.8.1
Operating system running OctoPrint
octopi_version: 0.18.0, octopiuptodate_build: 0.18.0-1.7.3-20220323100241
Printer model & used firmware incl. version
Custom rebuild of FFCP using BTT Octopus (i.e. an "OctoForge"). Firmware: "Marlin bugfix-2.0.x (Jun 5 2022 20:21:01)"
Browser and version of browser, operating system running browser
Firefox 100.0.2 on Xubuntu (but not related to problem)
Checklist of files to include below
- Systeminfo Bundle (always include!)
- Contents of the JavaScript browser console (always include in cases of issues with the user interface)
- Screenshots and/or videos showing the problem (always include in case of issues with the user interface)
- GCODE file with which to reproduce (always include in case of issues with GCODE analysis or printing behaviour)
Additional information & file uploads
Systeminfo Bundle:
octoprint-systeminfo-20220609124913.zip
GCode file in question:
FilamentSensorPlug_octoforge.gcode.zip
Full Log file from OctoPrint:
octoprint.log.2022-06-06.zip
Metadata
Metadata
Assignees
Labels
Type
Projects
Status
Done