prusa3d / Prusa-Firmware

Firmware for Original Prusa i3 3D printer by PrusaResearch
GNU General Public License v3.0
2.02k stars 1.05k forks source link

[BUG] [3.9.3 / 3.10.0-RC2] OctoPrint 1.6.0rc2 unable to start SD card print due to file name case sensitivity (capitalization) #3115

Closed kazoob closed 12 months ago

kazoob commented 3 years ago

Printer type - MK3S Printer firmware version- 3.9.3, 3.10.0-RC2

MMU Upgrade - N/A

SD card or USB/OctoPrint SD card print initiated from OctoPrint (G-code stored on printer's SD card)

Describe the bug OctoPrint 1.6.0rc2 - initiating an SD card print (load and print) no longer works. OctoPrint 1.5.3 - everything functions as expected.

See https://github.com/OctoPrint/OctoPrint/issues/4102.

In OctoPrint 1.5.3, the file names were converted to lowercase no matter how they were received from the printer's firmware. However the print started successfully. Note the output of M20 and M23 - the file is opened successfully and OctoPrint issues M24:

2021-04-19 15:52:04,189 - Send: M20
2021-04-19 15:52:04,219 - Recv: Begin file list
2021-04-19 15:52:04,256 - Recv: TEST~1.GCO 19691
2021-04-19 15:52:04,257 - Recv: End file list
2021-04-19 15:52:04,258 - Recv: ok
2021-04-19 15:52:09,049 - Send: M23 /test~1.gco
2021-04-19 15:52:09,062 - Recv: echo:Now fresh file: /test~1.gco
2021-04-19 15:52:09,076 - Recv: File opened: /test~1.gco Size: 19691
2021-04-19 15:52:09,077 - Recv: File selected**
2021-04-19 15:52:09,100 - Changing monitoring state from "Operational" to "Starting print from SD"
2021-04-19 15:52:09,173 - Recv: ok
2021-04-19 15:52:09,176 - Send: M105
2021-04-19 15:52:09,191 - Recv: ok T:30.4 /0.0 B:31.3 /0.0 T0:30.4 /0.0 @:0 B@:0 P:29.0 A:32.4
2021-04-19 15:52:09,195 - Send: M23 /test~1.gco
2021-04-19 15:52:09,203 - Recv: echo:Now doing file: /test~1.gco
2021-04-19 15:52:09,224 - Recv: File opened: /test~1.gco Size: 19691
2021-04-19 15:52:09,225 - Recv: File selected
2021-04-19 15:52:09,244 - Recv: ok
2021-04-19 15:52:09,246 - Send: M24
2021-04-19 15:52:09,264 - Recv: ok
2021-04-19 15:52:09,266 - Changing monitoring state from "Starting print from SD" to "Printing from SD"

OctoPrint 1.6.0rc2 now maintains the file name case as received by the printer's firmware. However sending M23 using the same filename case as was received by the printer's firmware no longer properly opens the file. Note the output of M20 and M23 - the file is not opened successfully so OctoPrint does not issue M24:

2021-04-19 15:49:35,333 - Send: M20
2021-04-19 15:49:35,365 - Recv: Begin file list
2021-04-19 15:49:35,401 - Recv: TEST~1.GCO 19691
2021-04-19 15:49:35,403 - Recv: End file list
2021-04-19 15:49:35,404 - Recv: ok
2021-04-19 15:49:40,194 - Send: M105
2021-04-19 15:49:40,205 - Recv: ok T:31.8 /0.0 B:33.2 /0.0 T0:31.8 /0.0 @:0 B@:0 P:28.9 A:32.3
2021-04-19 15:49:40,405 - Send: M23 /TEST~1.GCO
2021-04-19 15:49:40,416 - Recv: ok
2021-04-19 15:49:45,195 - Send: M105
2021-04-19 15:49:45,209 - Recv: ok T:31.7 /0.0 B:32.9 /0.0 T0:31.7 /0.0 @:0 B@:0 P:27.8 A:32.7
2021-04-19 15:49:50,196 - Send: M105
2021-04-19 15:49:50,208 - Recv: ok T:31.6 /0.0 B:33.0 /0.0 T0:31.6 /0.0 @:0 B@:0 P:27.8 A:32.2

Even though a change in OctoPrint from 1.5.3 to 1.6.0rc2 has brought the issue to light, it still seems to be a bug in the Prusa firmware.

Additionally some output from Pronterface:

Connecting...
start
Printer is now online.
echo: 3.9.3-3556
echo: Last Updated: Jan  7 2021 12:57:03 | Author: (none, default config)
Compiled: Jan  7 2021
echo: Free Memory: 1746  PlannerBufferBytes: 1760
echo:Stored settings retrieved
adc_init
Extruder fan type:
NOCTUA
CrashDetect ENABLED!
Command not found!
FSensor ENABLED (sensor board revision: 0.3 or older)
Sending 0xFF
echo:SD card ok
echo:busy: processing
>>>M20
SENDING:M20
Begin file list
TEST~1.GCO 19691
End file list
MMU not responding - DISABLED
>>>M23 /TEST~1.GCO
SENDING:M23 /TEST~1.GCO
>>>M23 /test~1.gco
SENDING:M23 /test~1.gco
echo:Now fresh file: /test~1.gco
File opened: /test~1.gco Size: 19691
File selected

G-code

test.gcode.txt

Serial Log

Prusa MK3S firmware 3.9.3: serial_1.5.3.log serial_1.6.0rc2.log

Prusa MK3S firmware 3.10.0-RC2: *serial_1.6.0rc2_3.10.0-RC2.log

foosel commented 3 years ago

Judging by the serial output it never actually even makes it past the cardOk check or into the actual file open routine, otherwise there should at least be a echo:Now fresh file or echo:Now doing file output as far as I understand the code.

Only change on OctoPrint's side, as mentioned, was to no longer lower case the SD card file names (which was actually a bug) but rather to refer to them the exact way the firmware reports them in the M20 output. Related ticket is here: OctoPrint/OctoPrint#3994. For some reason, the firmware doesn't like that though and refuses to do anything with the file like that.

I'll add a config setting to OctoPrint to restore the old behaviour and see if I can tie it into PrusaFirmware being detected (both to not have this issue block the pending 1.6.0 release and also for better user experience), but this should definitely be fixed firmware-side as well, the current behaviour is broken.

leptun commented 3 years ago

Prusa firmware requires that all filenames passed to gcodes are lowercase. Otherwise, the actual filename might be interpreted as a gcode. Example:

M23 /ABCD.gco ; might work
M23 /ABCD.GCO ; will not work. Interpreted as unknown G command
M23 /G1.gco ; will be interpreted as G1
M23 /filename.gco ; will be interpreted correctly

We can patch the M20 output to be lowercase, but wouldn't all the previous versions of the firmware suddenly stop working with octoprint?

foosel commented 3 years ago
M23 /G1.gco ; will be interpreted as G1

I'm sorry, but why? That sounds like a bug in your parser then. Multiple commands in the same line should be separated by a : if anything. I'm not aware of any such limitations on other firmware variants (though happy to be updated).

We can patch the M20 output to be lowercase, but wouldn't all the previous versions of the firmware suddenly stop working with octoprint?

Previous versions of OctoPrint would just lower case an already lower cased filename before using it. OctoPrint 1.6 would use the filename as is, so also lower case. OctoPrint has no issues with other firmware variants that already report the file names in lower case. Any line between a Begin file list and End file list will be parsed as a 8.3 file name, or 8.3 file name + size in bytes, or 8.3. file name + size in bytes + long name. So far OctoPrint then went case insensitive and converted stuff to all lower case. That has caused issues with certain firmwares however, so now OctoPrint will use the 8.3 file name for all SD card commands as provided in M20.

awenelo commented 3 years ago

I'm sorry, but why? That sounds like a bug in your parser then. Multiple commands in the same line should be separated by a : if anything. I'm not aware of any such limitations on other firmware variants (though happy to be updated).

As far as I understand, it's because the parser is checking for PRUSA and G's existence before checking for M in process_commands()(not caring about location in the string, if I understand correctly). M117 gets around this by being put above the PRUSA and G sections. @leptun, is there a reason M23 and M30, or even the entire M block can't be moved up to where M117 is?

No matter what change is made to M20 or M23 before the 3.10 firmware release, running a pre-3.10 version of firmware with post-1.6 OctoPrint and capitalized files wouldn't work, as the interaction will be the same as reported above (capitalized files not working).

foosel commented 3 years ago

No matter what change is made to M20 or M23 before the 3.10 firmware release, running a pre-3.10 version of firmware with post-1.6 OctoPrint and capitalized files wouldn't work, as the interaction will be the same as reported above (capitalized files not working).

Don't worry, I'm aware, and I'm building a flag in to work around that as we speak ;)

leptun commented 3 years ago

One can assume that the M block was put after the G block for performance reasons. From the current parsing perspective, M should go before G, but gcode files are mostly composed of G commands, so that might slow down things even further. With the way the current parser is structured, it would mean adding two more exceptions before the G block like it was done for M117, which is undesirable at best and just ads more spaghetti on top of the current code.

foosel commented 3 years ago

But why are you even checking for multiple commands on the same line in a line based protocol without the presence of a line separator (\n, or : if there absolutely needs to be more than one command be put on one line)?

leptun commented 3 years ago

Well, we are not searching for multiple gcodes in one single line. A gcode line in this firmware is defined as a string terminated by the newline (on either SD or USB). There is no : splitting implemented. The reason uppercase filenames break everything is because of how we parse a gcode command. Instead of doing it properly, it is done like this (simplified):

 if ("PRUSA" is in the string)
   execute a PRUSA command
 else if ('G' is in the string)
   execute the G command
 else if ('M' is in the string)
   execute the M command
 ...
 else
   unknown command

This is why a 'G' in the filename will take precedence over a M23 G.GCO. Actually, even M23 PRUSA.GCO will parse incorrectly since PRUSA takes precedence over M. It's stupid parsing gcode like this, but I don't think that's going to change any time soon. There are ways to work around this, but nobody tried fixing it yet.

foosel commented 3 years ago

That explains that then, thank you for the insight.

DRracer commented 3 years ago

@foosel unfortunately "fixing" the parody of a parser used in our 8bit FW since its very beginning has only one correct but costly solution - implementing a real lexer and a grammar on top of it. It would have definitely been an efficient and stable solution, but it would also break everything (esp. the hacked edge cases over the years). Thus we are not touching this part of code unless absolutely necessary. Thank you for your understanding...

github-actions[bot] commented 1 year ago

This issue has been flagged as stale because it has been open for 60 days with no activity. The issue will be closed in 7 days unless someone removes the "stale" label or adds a comment.

github-actions[bot] commented 12 months ago

This issue has been closed due to lack of recent activity.