print time estimates wildly wrong since upgrading to 2.0.1

[mightyohm]

OctoPrint Version: 1.3.11

PrintTimeGenius Version (if you know): 2.0.1

Print time estimates are wildly inaccurance since upgrading the plugin. I'm not sure if I upgraded from 2.0.0 or a pre-2.0 version.

Example, a 3 hour job is now showing as 19 hours estimated. I'm using the marlin analyzer. Slicer is PrusaSlicer 2.1.0. I'm printing to a Prusa mk3s.

I tried uninstalling and reinstalling the plugin and deleting all stored compensation values. I think that the print time estimate was actually correct for the first job after deleting compensation, but now it's wildly wrong again.

Once this job finishes I'm going to try downgrading the plugin to see if that fixes it.

[wzhouiup]

I have the same issue on Octoprint 1.3.11 and PrintTimeGenius 2.0.1 for my Ender 3 Pro using Marlin. Estimates can be either drastically too long or too short. I've tried both PrusaSlicer 2.1.0 and Cura 4.3. Previous versions of PTG did not have this issue.

If needed I can upload a debug log.

[mightyohm]

The estimates seem to have improved dramatically on subsequent jobs, so I'm going to keep using 2.0.1 for a while longer and see what happens.

[wzhouiup]

Yea after 4-5 more prints it seems much more accurate. Not sure what happened but I think its ok now.

[eyal0]

I covered it in the release notes but maybe you missed them: https://github.com/eyal0/OctoPrint-PrintTimeGenius/releases/tag/2.0

The latest marlin-calc is incompatible with the old compensation values because the old compensation values were trying to fix a broken marlin-calc but the new marlin-calc will need a different compensation. Hopefully no compensation at all!

Sorry for the inconvenience. Please delete the compensation tables if you keep having trouble. And if you have an example of gcode that requires serious compensation, send it and I'll take a look.

There's more info about how compensation works in the wiki.

Thanks.

[mightyohm]

Here are my new compensation values after deleting the previous compensation values and printing a few parts. Some of the values are quite large, is this normal?

[eyal0]

Wow those are way off! I am surprised. If you're willing, attach one of the simpler ones to this bug report and I'll take a look. For example, the one that took only 988 seconds though it was predicted to take 4083! That's off by a huge factor.

[mightyohm]

I believe that was this file:

print2.zip

[mightyohm]

Here's the most recent (8 hour) print with the predicted 108304 seconds.

pumpkin_full_0.15mm_PLA_MK3S_8h31m.zip

[eyal0]

When I run marlin-calc on print2, I get this:

Processed 28600 Gcodes and 27 Mcodes. 27159 blocks
Total time: 935.909121
Analysis: {"estimatedPrintTime": 935.90912074449772717, "printingArea": {"maxX": 141.72100000000000364, "maxY": 120.32899999999999352, "maxZ": 3.59999990463256836, "minX": 60.00000000000000000, "minY": -3.00000000000000000, "minZ": 0.00000000000000000}, "dimensions": {"width": 81.72100000000000364, "depth": 123.32899999999999352, "height": 3.59999990463256836}, "filament": {"tool0": {"length": 521.53018522546062741, "volume": 3.68647974927731248}}}

935 seconds is pretty close to the actual 988 that it took. In the file, Prusa Slic3r wrote:

; estimated printing time (normal mode) = 17m 39s
; estimated printing time (silent mode) = 17m 39s

That's 1059 seconds, which is also close to the actual print time. But according to that table, the prediction was much much bigger.

For the pumpkin file, marlin-calc predicts 27878 seconds. Inside the file, Prusa Slic3r has predicted 30676 seconds. The actual was 30118.1.

All that was done without knowing the settings of your printer. Would you mind digging into the PTG log and looking for the the part where marlin-calc was run on those files? I'm curious about the command line. It probably has a bunch of M-codes and G-codes in there that can affect the print time. You can find the logs from OctoPrint's settings. Look in there for mentions of marlin-calc.

[mightyohm]

These are the only references to marlin-calc in the logfile:

2019-10-09 12:39:05,999 Not running built-in analysis.
2019-10-09 12:39:06,023 Disabled: "/mnt/storage/home/jkeyzer/OctoPrint/venv/bin/python2" "/mnt/storage/home/jkeyzer/OctoPrint/venv/lib/python2.7/site-packages/octoprint_PrintTimeGenius/analyzers/analyze_gcode_comments.py" "/mnt/storage/home/jkeyzer/.octoprint/uploads/pumpkin_full_0.15mm_PLA_MK3S_8h31m.gcode"
2019-10-09 12:39:06,023 Running: "/mnt/storage/home/jkeyzer/OctoPrint/venv/bin/python2" "/mnt/storage/home/jkeyzer/OctoPrint/venv/lib/python2.7/site-packages/octoprint_PrintTimeGenius/analyzers/analyze_progress.py" marlin-calc "/mnt/storage/home/jkeyzer/.octoprint/uploads/pumpkin_full_0.15mm_PLA_MK3S_8h31m.gcode" ""
2019-10-09 12:39:06,535 Probably started printing, aborting: '"/mnt/storage/home/jkeyzer/OctoPrint/venv/bin/python2" "/mnt/storage/home/jkeyzer/OctoPrint/venv/lib/python2.7/site-packages/octoprint_PrintTimeGenius/analyzers/analyze_progress.py" marlin-calc "/mnt/storage/home/jkeyzer/.octoprint/uploads/pumpkin_full_0.15mm_PLA_MK3S_8h31m.gcode" ""'
2019-10-09 12:39:33,561 Not running built-in analysis.
2019-10-09 12:39:33,561 Disabled: "/mnt/storage/home/jkeyzer/OctoPrint/venv/bin/python2" "/mnt/storage/home/jkeyzer/OctoPrint/venv/lib/python2.7/site-packages/octoprint_PrintTimeGenius/analyzers/analyze_gcode_comments.py" "/mnt/storage/home/jkeyzer/.octoprint/uploads/pumpkin_full_0.15mm_PLA_MK3S_8h31m.gcode"
2019-10-09 12:39:33,561 Running: "/mnt/storage/home/jkeyzer/OctoPrint/venv/bin/python2" "/mnt/storage/home/jkeyzer/OctoPrint/venv/lib/python2.7/site-packages/octoprint_PrintTimeGenius/analyzers/analyze_progress.py" marlin-calc "/mnt/storage/home/jkeyzer/.octoprint/uploads/pumpkin_full_0.15mm_PLA_MK3S_8h31m.gcode" ""
2019-10-09 12:39:35,571 Sarge output: Running: "/mnt/storage/home/jkeyzer/OctoPrint/venv/lib/python2.7/site-packages/octoprint_PrintTimeGenius/analyzers/marlin-calc.x86_64" "/mnt/storage/home/jkeyzer/.octoprint/uploads/pumpkin_full_0.15mm_PLA_MK3S_8h31m.gcode"
Linear advance enabled
......Read up all remaining commands
Processed 631438 Gcodes and 23632 Mcodes. 624419 blocks
Total time: 108321.598213

[RandyatGretchen]

I have just noticed that my print time estimates are WAY off just recently. They used to be very good. I just added linear advance in the Marlin firmware so maybe that's it?

[eyal0]

@mightyohm It's surprising to me that there are no arguments to marlin-calc. Usually there are bunch of mcodes, like M201, M202, M203, etc.

Are you running on an RPi or something else? If you can run uname -a and show me the output of that...? Maybe you're on an unsupported platform?

[eyal0]

@RandyatGretchen did you catch this one yet: https://github.com/eyal0/OctoPrint-PrintTimeGenius/issues/162#issuecomment-540882128

You might need to delete compensation values.

[mightyohm]

@mightyohm It's surprising to me that there are no arguments to marlin-calc. Usually there are bunch of mcodes, like M201, M202, M203, etc.

Are you running on an RPi or something else? If you can run uname -a and show me the output of that...? Maybe you're on an unsupported platform?

I'm running on Ubuntu 18.04 on an Intel desktop host.

uname -a gives the following output

Linux atom 4.15.0-65-generic #74-Ubuntu SMP Tue Sep 17 17:06:04 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

[RandyatGretchen]

I have just noticed that my print time estimates are WAY off just recently. They used to be very good. I just added linear advance in the Marlin firmware so maybe that's it?

@RandyatGretchen did you catch this one yet: #162 (comment)

You might need to delete compensation values.

I did see that but I am not sure how to do that. Where do I find this compensation table?

[eyal0]

@RandyatGretchen It's in the advanced section of the PrintTimeGenius settings. If you open up the settings, and then look for the PTG settings, and then open up the advanced section, you should see it there. You need to delete all the rows and then hit save.

[eyal0]

@mightyohm I definitely updated the x86_64 version of malin-calc so it should be giving you good answers...

Wow, okay, I'm seeing it now. For some reason, when I compile the code on my desktop, I get a good answer, but on my laptop, a wrong one! That is really strange. I'm getting 108321. So there's something fishy going on! Both are x86.

Just so that I'm clear, octoprint is running on the x86, right? I'll look into this!

[RandyatGretchen]

@RandyatGretchen It's in the advanced section of the PrintTimeGenius settings. If you open up the settings, and then look for the PTG settings, and then open up the advanced section, you should see it there. You need to delete all the rows and then hit save.

OK, Thanks! I will do that.

[eyal0]

@mightyohm Okay I see what is happening now. First, I screwed up when I measured before. I was using an old marlin-calc but I should have been using the new one. If I use my latest marlin-calc, I get a similar answer to you: about 108000 seconds. Way too high!

Then I noticed that in your pumpkin file, you have M900 K30. 30 is a really high value! When Marlin sees a K value that is outside of the range 0-10, it ignores it. So I think that your print is probably printing out a warning when you do that, but you didn't see the warning, and then you printed without linear advance actually.

marlin-calc does not ignore K values outside that range. So the linear advance was in effect and in a big way, slowing down the simulated run to a crawl. That's what happened here. To check, I removed the M900 K30 in your gcode and ran the simulation again. This time, marlin-calc reported an estimated print time of 30347 seconds. This is less than 1% off from the actual and it's even more accurate than the Prusa estimate in the comment in your gcode.

I will add a check for K values outside the 0-10 range and ignore them, same as Marlin does currently. I will also look for other places where marlin-calc should be ignoring inputs because Marlin does, too.

I'll have it ready pretty soon.

[mightyohm]

To your previous question - yes, Octoprint is running on the same x86 host.

I found this reference to M900 in the PrusaSlicer settings (these are the factory defaults): M900 K{if printer_notes=~/.*PRINTER_HAS_BOWDEN.*/}200{elsif nozzle_diameter[0]==0.6}18{else}30{endif} ; Filament gcode

I'm not using a bowden tube and my nozzle diameter is 0.4, so PrusaSlicer is using M900 K30.

That value also shows up on Prusa's wiki here: https://help.prusa3d.com/article/t5w9VsdVai-linear-advanced

It seems that Prusa is recommending K30 for PLA filament. PrusaSlicer's print time estimate is pretty close to the actual time. Why is merlin-calc giving such a different estimate for K30?

[eyal0]

Okay, that's interesting.

Prusa uses their own firmware. It isn't Marlin. I don't know if it is or isn't Marlin-based. But I don't have a prusa simulator, only a marlin simulator. They must be treating the M900 command differently. I would only know by investigating their source code and that would be a lot of work for me.

There is an option in PrusaSlicer to insert M73 command into your file that show the time remaining for the print. There is also an option in PTG to use those, called Use Slic3r PE M73 time remaining. So you could leave the marlin-calc enabled in the option like normal and just add the M73 option so that you would use the PrusaSlicer estimated instead of marlin-calc.

Note that you must not turn off marlin-calc because it is replacing some of the work that the OctoPrint built-in calculator is doing. So if you turn off marlin-calc, you have to turn on the built-in, and the built-in is way slower.

Up to you if you choose to go that route! Either way, you should start getting estimates that are pretty good. (Like I showed, within 1%.)

[eyal0]

Ah, I see this note, too!

http://marlinfw.org/docs/features/lin_advance.html#new-k-value-required

The K values used to be much higher. The new value is based on actual units and it's lower. If I could find the conversion from one to the other, I could do it for you. I'll look for that in the Marlin code.

[eyal0]

thinkyhead submitted the change that did it: https://github.com/MarlinFirmware/Marlin/pull/9712/files

Maybe he knows how to convert from old K values to new K values?

[mightyohm]

@eyal0

I believe that Prusa's firmware is derived from marlin. Some details here: https://github.com/prusa3d/PrusaSlicer/releases/tag/version_1.39.1-alpha

If I understand what you're saying, it sounds like Prusa hasn't incorporated the changes to the K value that are now used by marlin.

I see M73 lines in the output from PrusaSlicer. If I enable two analyzers ("Marlin firmware simulation" and "Use Slic3r PE M73 time remaining"), how do I know which is being used to calculate the print time? Should I remove compensation values when using the M73 time remaning analyzer?

[eyal0]

The options are processed in the order that they appear. So the marlin firmware simulation will run first and it will compute the time to print, filament used, extruding start time, extruding end time, volume of the printed object, etc, using marlin-calc. OctoPrint has all this built-in but OctoPrint does it in python and marlin-calc does it in compiled code so marlin-calc is faster at it. That why the default is to have the built-in disabled and only use marlin-calc. If you disable both the built-in and the "Marlin firmware simulation" then there will be no calculation of the volume of the print. That will screw up OctoPrint because OctoPrint will do checks like figuring out if the thing that you're trying to print is bigger than your printer. So just leave the Marlin simulation on and turn off the built-in.

If you also turn on the "Slic3r PE M73" then it'll fetch Slicer PE print times and print time remaining. That will fetch the "estimated printing time" lines and also the print time progress lines. Those results will partially overwrite the previous results so the volume and filament used and size of the object will still come from marlin-calc but the print time estimates will come from the comments in the file.

So it should just plain work. All of that is by default put into the log files so if you view PTG's log, you ought to see that marlin-calc runs, gets a bunch of details, and then gcode analysis runs and updates those details.