Spurious warnings logged every couple of seconds (Prusa XL)

[smurfix]

The problem

1. Connect a Prusa XL
2. Receive T:6.00/0.00 B:23.04/0.00 C:-30.00/0.00 X5:6.00/36.00 A:32.35/0.00 T0:22.00/0.00 T1:27.00/0.00 T2:39.00/0.00 T3:19.00/0.00 T4:21.00/0.00 T5:6.00/0.00 @:0 B@:0 HBR@:0 @0:0 @1:0 @2:0 @3:0 @4:0 @5:0 B_0_0:23.50/0.00 B_1_0:24.00/0.00 B_2_0:23.30/0.00 B_3_0:22.30/0.00 B_0_1:23.50/0.00 B_1_1:24.00/0.00 B_2_1:23.60/0.00 B_3_1:22.50/0.00 B_0_2:23.10/0.00 B_1_2:23.60/0.00 B_2_2:23.10/0.00 B_3_2:21.90/0.00 B_0_3:22.80/0.00 B_1_3:22.90/0.00 B_2_3:22.60/0.00 B_3_3:21.80/0.00 messages
3. Observe the C: in there
4. … which triggers a warning every time it's received because of line 360 in src/octoprint/util/comm.py:
   RESERVED_IDENTIFIER_REGEX = re.compile(r"B|C|T\d*")?

Did the issue persist even in safe mode?

Yes, it did persist

If you could not test in safe mode, please state why ("currently printing" is NOT an excuse!)

No response

Version of OctoPrint

git

Operating system running OctoPrint

Debian

Printer model & used firmware incl. version

Prusa XL

Browser and version of browser, operating system running browser

No response

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

octoprint-systeminfo-20240322100439.zip

[foosel]

Could you please share the warning? I'm not sure I'm on the same page after looking at the logs.

[foosel]

In any case this looks like a really low reported chamber temperature and thus a firmware bug.

[smurfix]

The chamber temperature sensor doesn't exist (yet … Prusa says they're working on adding one), so it's disconnected, so you get -30°.

Yes the printer should not report a chamber temperature if it doesn't have the sensor, and I'll open a bug with the Prusa people shortly. In the meantime (who knows when they'll get around to fixing this), it does it anyway, so in line 2220+ of src/octoprint/util/comm.py you don't drop the "C", thus we get the warning.

Suggested diff:

diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py
index 14adb72cc..f4ccb5e05 100644
--- a/src/octoprint/util/comm.py
+++ b/src/octoprint/util/comm.py
@@ -2218,13 +2218,13 @@ class MachineCom:
             self.last_temperature.set_bed(actual=actual, target=target)

         # chamber temperature
-        if "C" in parsedTemps and (
-            self._capability_supported(self.CAPABILITY_CHAMBER_TEMP)
-            or self._printerProfileManager.get_current_or_default()["heatedChamber"]
-        ):
-            actual, target = parsedTemps["C"]
+        if "C" in parsedTemps:
+            if ( self._capability_supported(self.CAPABILITY_CHAMBER_TEMP)
+                  or self._printerProfileManager.get_current_or_default()["heatedChamber"]
+            ):
+                actual, target = parsedTemps["C"]
+                self.last_temperature.set_chamber(actual=actual, target=target)
             del parsedTemps["C"]
-            self.last_temperature.set_chamber(actual=actual, target=target)

         # all other injected temperatures or temperature-like entries
         for key, data in parsedTemps.items():

If you don't want to do that, please emit the warning once, not every bunch of seconds.

[smurfix]

The warning is emitted here, in line 384:

    def set_custom(self, identifier, actual=None, target=None):
        if self.RESERVED_IDENTIFIER_REGEX.fullmatch(identifier):
            raise ValueError(f"{identifier} is a reserved identifier")

[smurfix]

prusa3d/Prusa-Firmware-Buddy#3848

[jneilliii]

Did you enable the chamber temp option in OctoPrint's printer profile?

[smurfix]

No I did not. I don't have a chamber.

I know that I could enable this option to make the warnings go away, but most users won't even notice the problem until they stumble on the fact that their log files get kind of large, and/or their SD card breaks because of the constant writes.

[jneilliii]

Kind of lame Prusa is reporting something that doesn't exist, but a quick fix would be a single file plugin. Here's one that should work, that basically removes the C temperature from the report.

https://gist.github.com/jneilliii/b6206ffa48a52e2904d551d9c1484567

[foosel]

To be honest, I never expected any company to ship firmware broken in this way, let alone THIS one. Live and learn I guess. This whole warning was supposed to help regular people tinkering around with their firmware to understand when they made an error.

I'll look into only logging the warning once instead of every time an invalid temperature key is sent by the firmware. Scheduling this for 1.11.0 though, 1.10.0 is already frozen and close to the finish line. In the meantime the above quick fix should work, and I can also look into pushing out a warning via the FirmwareCheck plugin should this become a larger issue.

[smurfix]

Yeah, Prusa seems to have some growing pains with their firmware. We'll see when somebody gets around to looking at this.

NB sorry about the grumpiness, it was meant as a more-or-less-factual statement but got mixed with more general annoyance about the state of things, not directed at you/Octoprint specifically. Yes I tend to do that too much. 🤔

[foosel]

I just pushed the above commit that will fix that (and another potentially spammy location in that code part).

For now it's targeting 1.11.0 but I might also backport this into a future bugfix release for 1.10.0. I want to first get this out of the door in its current frozen state though (and not turn another RC round).

[foosel]

Backported to 1.10.x, to be included in 1.10.1 as promised.