eyal0 / OctoPrint-PrintTimeGenius

Use a gcode pre-analysis to provide better print time estimation
191 stars 32 forks source link

Update of pip 22.3 to pip 24.1.1 appears to interfere with PrintTimeGenius ETA #317

Open clarkiej opened 1 week ago

clarkiej commented 1 week ago

Before reporting, check if your problem is here: https://github.com/eyal0/OctoPrint-PrintTimeGenius/wiki/Common-problems

Describe the bug After updating pip version 22.3 to version 24.1.1 within Octoprint V1.10.2, all of the PrintTimeGenius print times are now longer by a factor of between 3-5x longer for any new gcode file added to Octoprint and given the yellow star treatment by PrintTimeGenius

To Reproduce Steps to reproduce the behavior:

  1. Slice model in Cura

Example A 7 minute print time, Example B 2rs 46 minutes print time

image image

  1. Load into Octoprint

Example A Yellow Star PTG ETA 32 minutes Example B Yellow Star PTG ETA 8 hrs 47 min

image image

  1. Disable PTG, delete and re-upload the gcode files and ETA times are the print times estimated by Cura and imbeded in the gcode.

Expected behavior The PTG print time has been consistantly around 5% less than the Cura ETA since it was originally added as a plugin and through version 2.3.2 and after updating to 2.3.3

**OctoPrint Version:1.10.2

**PrintTimeGenius Version (if you know):2.3.3

If relevant, upload the PrintTimeGenius log and any problematic gcode files (you might need to rename the files). This is really important. I probably can't help you without this.

Attached are the gcode files of the two sample models above zipped up as a 7z file and addedd.txt to the end

gcode_files.7z.txt

PTG log file form Octoprint : plugin_PrintTimeGenius_engine.log

theyanqc commented 1 week ago

True, have same issue

Triodes commented 1 week ago

It's very unlikely this has anything to do with pip. Are you guys running the octoapp companion plugin by any chance? That plugin has been inserting some commands into the GCODE files since its latest update that are misinterpreted by the marlin-calc executable that PTG uses.

Some more context: if an M117 command contains the G character in the message it seems marlin-calc might interpret the line incorrectly as a GCODE command, causing it to produce wildly inaccurate estimates.

theyanqc commented 1 week ago

Yes, have I have it. Any ideas how to fix it? Thanks!!

eyal0 commented 1 week ago

I'm able to repair marlin-calc. I haven't updated marlin-calc in a very long time because generally there's no need: Updates to the marlin code rarely affect the print time calculations.

However, if there's a new command in gcodw files that is confusing marlin-calc then I ought to update marlin-calc to be derived from the latest marlin version. That alone might fix the problem because if the latest Marlin supports these new code then updating marlin-calc to be derived from the latest marlin may also cause marlin-calc to have the support.

And if not, then the problem is in marlin-calc and I need to update it. That's not too difficult a task, either.

I can look at it next week.

clarkiej commented 1 week ago

Yes I have OctoApp plugin installed V2.2.1.

I have disabled the OctoApp plugin and the time discrepency issue is fixed: image

The odd thing is that this has only noticed this after I did teh pip update this week, but there was an update to teh OctoApp on the 4th of July oddly enough to V2.1.1, but I only noticed the pip update this week.

I uninstalled and reinstalled OctoApp and the ETA reverts back to silly numbers, so I will leave OctoApp plugin disabled for now.

Thank you for the quick response, and the solution. I dont use the app much apart from remote montoring so it can stay disabled for the time being.

crysxd commented 1 week ago

OctoApp dev here 👋

I think what happens is that PTG really doesn't like the layer commands I insert since the 2.1 update. Initially, I inserted OCTOAPP_LAYER_CHANGE LAYER=1234 and this command got filtered out again before it was send to the printer. This is not standard Gcode, but OctoPrint doesn't really care and it never reaches the printer. I of course did not anticipate it would screw up the PTG calculations.

I'm preparing a new version of the plugin right now that uses M118 E1 OCTOAPP_LAYER_CHANGE LAYER=1234 to disguise the command as standard Gcode. I think this should solve the issue @eyal0?


Update: OctoApp plugin update 2.1.3 should solve the issue, but files that are already analyzed by PTG are of course still affected and need to be re-uploaded with the new OctoApp plugin version.

clarkiej commented 1 week ago

Outstanding guys. Your co-op and responses have been amazing

crysxd commented 1 week ago

@clarkiej If you had a chance to test the new plugin and verify everything is back in order...please let me know :)

clarkiej commented 1 week ago

After uninstalling OctoApp V2.12, I attempted to install the revised OPctoApp V2.1.3 version but got the following error message installing from the URL option and installing from the "get more" option in Plugin Manager:

Installing plugin from https://github.com/crysxd/OctoApp-Plugin/archive/refs/heads/release.zip... /home/Decibel/oprint/bin/python -m pip --disable-pip-version-check install file:///tmp/tmpr71s4ofe/OctoApp-Plugin-release.zip --no-cache-dir Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Processing /tmp/tmpr71s4ofe/OctoApp-Plugin-release.zip Preparing metadata (setup.py): started Preparing metadata (setup.py): finished with status 'error' error: subprocess-exited-with-error

× python setup.py egg_info did not run successfully. │ exit code: 1 ╰─> [6 lines of output] Traceback (most recent call last): File "", line 2, in File "", line 34, in File "/tmp/pip-req-build-lfxcjgls/setup.py", line 105, in package=plugin_package, NameError: name 'plugin_package' is not defined [end of output]

note: This error originates from a subprocess, and is likely not a problem with pip. error: metadata-generation-failed

× Encountered error while generating package metadata. ╰─> See above for output.

note: This is an issue with the package mentioned above, not pip. hint: See above for details. Error! Could not parse output from pip, see plugin_pluginmanager_console.log for generated output

plugin_pluginmanager_console.log

crysxd commented 1 week ago

@clarkiej My bad....new update 2.1.4

clarkiej commented 1 week ago

OK V2.1.4 installed fine: image

Load gcode fileback into Octoprint for PTG to analyse: After Analysing, PTG is still giving incorrect ETA values : image 8.47hrs while Cura ETA is 2hrs 46 min if I disable OctoApp again delete and reload teh gcode file and have PTG alnalyse it, all is right with the world again: image

Issue is still there unfortunately using OctoApp 2.1.4

crysxd commented 1 week ago

@clarkiej Can you download the file with the 8h estimation from OctoPrint and post it here?

Triodes commented 1 week ago

@eyal0 So here's what I've been able to deduce: The following piece of code in marlin-calc is used to check if a G or M code is seen:

bool code_seen(char code)
{
  strchr_pointer = strchr(cmdbuffer, code);
  return (strchr_pointer != NULL);  //Return True if a character was found
}

According to the docs strchr_pointer returns a pointer to the first occurrence of a character. Taking @crysxd his layer change command OCTOAPP_LAYER_CHANGE LAYER=1 as an example this piece of code would return a pointer to the G in the word CHANGE. It would then try to use the following piece of code to decode the GCODE value:

double code_value() {
  return (strtod(&cmdbuffer[strchr_pointer - cmdbuffer + 1], NULL));
}

I'm not fully able to understand this because my C++ knowledge is quite limited, but looking at the docs of strtod it would try to parse until the next whitespace (which would be only the E) as a double. That fails which returns 0.0. The line is now being interpreted as a G0 command.

Next it starts looking for any of the characters XYZE using the code_seen function again. The first character found is the E in LAYER. It would then again try to parse all the characters after this E up until the first whitespace as a double. This fails returning 0.0. The command is now being interpreted as G0 E0. This is resetting the extruder all the way to the beginning (which takes a ton of time) causing the estimates to be much too high.

I think this bug might have been present for longer, but it only appears when a command does not start with G but does contain at least a G and one of XYZ & E. This is pretty unlikely, so it probably seldomly surfaces. It was @crysxd his update that matched the conditions perfectly and also inserts 1 command every layer matching the conditions, causing it to surface.

Edit: side note, I don't really understand what is happening in the code_value() function. But I assumed it would be parsing all the characters after the found letter and up until the first whitespace as a double. Please correct me if I'm wrong.

Triodes commented 1 week ago

afbeelding Look at these outputs: marlin-calc reports having processed 24988 G commands the actual amount of commands (as by my first cat/grep command) is 24937 the amount of OCTOAPP_ commands is 51 24937 + 51 = 24988 exactly. marlin-calc is most definitely interpreting the M118 E1 OCTOAPP_LAYER_CHANGE LAYER=n as a G command. Which it obviously is not.

crysxd commented 1 week ago

I pushed update 2.1.5 and removed all G from the commands :D

eyal0 commented 1 week ago

The best solution would be for marlin-calc to correct notice that leading 'M' and then correctly get the 118 and ignore the rest of the line as a comment, right?

Again, I'm on vacation so I'm unable to dig into it now. Does marlin-calc handle the M codes?

The strchr usage is unfortunate. I understand why strchr is used: because there could be whitespace before the code and we want to ignore that. I think that section of the parsing could be improved to not use strchr and instead correctly skip over whitespace and find the very first letter,

crysxd commented 1 week ago

@eyal0 Enjoy your vacation, we will work around the bug :) I'm pretty sure my 2.1.5 changes without a G will work fine!

clarkiej commented 1 week ago

@clarkiej Can you download the file with the 8h estimation from OctoPrint and post it here?

Original gcode: base.gcode.txt

Gcode downloaded from Octoprint after PTG analysis with OA V2.1.4 enabled giving 8 hr estimation: base.gcode.8hr.txt

I am grabbing V2.1.5 to test right now.

clarkiej commented 1 week ago

OctoApp V2.1.5 installed: image

Ding! Ding! Ding! We have a winner! Analysed with PTG and with OA 2.1.5 enabled is providing the "correct" estimation :

image

The new analysed gcode file form Octoprint:

base.gcode.v2.1.5.txt

Great work @crysdx

Triodes commented 1 week ago

The best solution would be for marlin-calc to correct notice that leading 'M' and then correctly get the 118 and ignore the rest of the line as a comment, right?

This would be the solution yes. I can think of several 'strategies' of implementing this. But I don't speak C++. Otherwise I'd make a PR for you 😅

Again, I'm on vacation so I'm unable to dig into it now. Does marlin-calc handle the M codes?

It does handle several M codes, but it checks for G first. The problem is that it looks for the G character anywhere in the line. Not just at the start. So even though the line is an M118 code. Because it has a G somewhere along the line it starts interpreting it as a G code. I would probably do something like if (line.trim().startswith('G')) { but again. No clue how you would go about that in C++

The strchr usage is unfortunate. I understand why strchr is used: because there could be whitespace before the code and we want to ignore that. I think that section of the parsing could be improved to not use strchr and instead correctly skip over whitespace and find the very first letter,

That's it basically.

@eyal0 Enjoy your holiday! @crysxd has changed his plugin to no longer include a G in the command he inserts, So that suppresses the issue for now. If (and that's a big if) I can find someone at my work who knows C++ I might be able to get you a PR. Do you want that to target a specific repo/branch?

crysxd commented 1 week ago

Great! Seems like this is solved then :) Thank you @Triodes for the amazing analysis of the issue and @clarkiej for the swift testing! And of course @eyal0 for this must-have plugin!

clarkiej commented 1 week ago

I am calling this closed this as successfully addressed due to teh great support and response here. Thanks again guys