OctoPrint-PrintTimeGenius icon indicating copy to clipboard operation
OctoPrint-PrintTimeGenius copied to clipboard

Wrong estimated print times

Open tomaae opened this issue 5 years ago • 18 comments

OctoPrint Version: OctoPrint 1.4.2

PrintTimeGenius Version (if you know): PrintTimeGenius Plugin (2.2.6)

What happened: Many estimates by PrintTimeGenius are way wrong, often by hours. See example screenshots bellow with real print times. I'm using PrusaSlicer2.2.0 and Prusa MK2 image image image image

tomaae avatar Oct 22 '20 13:10 tomaae

I will need more information. Can you provide some of the print time genius log output?

eyal0 avatar Oct 22 '20 17:10 eyal0

Sure, I have reanalyzed 3 of them: plugin_PrintTimeGenius_engine.log

tomaae avatar Oct 22 '20 19:10 tomaae

In the log there is no M503 output, yet I expected to see the M503 in there. One possibility is that you haven't run M503.

Can you try going into the terminal on your printer while it isn't printing and type M503 and hit enter? It should output a list of your settings that start with an "M" like M900 or M200, M201, etc. After that, please try re-analyzing the files and look at the log output. Right now your log has this in it:

2020-10-22 21:05:34,116 Running: "/home/pi/oprint/bin/python" "/home/pi/oprint/lib/python3.7/site-packages/octoprint_PrintTimeGenius/analyzers/analyze_progress.py" marlin-calc "/home/pi/.octoprint/uploads/Prusa_enclosure/hyperpixel4lcd-cover_v1_0.2mm_PETG_MK2S_5h10m.gcode" ""

I expected those final quotes to contain an excerpt from your M503 output. Running M503 once should be enough to fix that.

If the new time to print after analysis is not improved then send me the new logs and also one of the gcode files and I'll analyze it here on my computer and see what results I'm getting, to see if they match yours.

Thank you.

eyal0 avatar Oct 22 '20 20:10 eyal0

I ran M503, but it didnt fixed the issue. Plugin found those values now, but time is still off. I'm attaching both log and my latest print's gcode. ledstrip_45angle_0.2mm_PETG_MK2S_5h18m(1).zip plugin_PrintTimeGenius_engine(1).log

tomaae avatar Oct 22 '20 22:10 tomaae

I'll take a look! Let's see. In your log, I see the ledstrip:

Running: "/home/pi/oprint/lib/python3.7/site-packages/octoprint_PrintTimeGenius/analyzers/marlin-calc.armv7l" "/home/pi/.octoprint/uploads/Prusa_enclosure/ledstrip_45angle_0.2mm_PETG_MK2S_5h18m.gcode" "M92 X100.00 Y100.00 Z400.00 E161.30
M203 X500.00 Y500.00 Z12.00 E120.00
M201 X9000 Y9000 Z500 E10000
M204 S1500.00 T1500.00
M205 B20000 E2.50 S0.00 T0.00 X10.00 Y10.00 Z0.20
M207 F2700.00 S3.00 Z0.00
M208 F480.00 S0.00"

And it seems to have grabbed all the input from your M503. If you type M503, I suspect that you'll see details similar to what are above, yes?

In your ledstrip gcode there are some other M codes that will override the ones above and that should be fine.

Inside the gcode, near the end, I see this line:

; estimated printing time (normal mode) = 5h 18m 1s

That's PrusaSlicer's estimate.

marlin-calc also has an estimate and it's in the log:

2020-10-23 00:34:46,306 Result: {"estimatedPrintTime": 18928.351941785175, "printingArea":

That's in seconds. In hours, minutes, and seconds, it's 5 hours, 15 minutes, 28 seconds. So it looks like PrusaSlicer and marlin-calc are in pretty good agreement!

Ah, but here's the problem. The compensation. It seems that in one or many of your recent prints, they took way less time than expected. Like, off by 75%:

2020-10-23 00:34:46,682 Recent heat-up times in seconds: 120.85924274900754
2020-10-23 00:34:46,683 Average heat-up: 120.85924274900754 seconds
2020-10-23 00:34:46,684 Recent cool-down times in seconds: 0.5315373519988498
2020-10-23 00:34:46,684 Average cool-down: 0.5315373519988498 seconds
2020-10-23 00:34:46,684 Time spent printing, actual vs predicted: 3480.5264717300015/13839.968563850041
2020-10-23 00:34:46,684 Average scaling factor: 0.25148369778968477

So the estimate is getting decreased by a lot! That could happen if some previous print or prints reported much less time than marlin-calc reported, so it's trying to compensate.

This will fix itself over time but the easiest way for you is to just delete those old stats. In the PrintTimeGenius options, under "advanced", you should see a table of previous prints and compensation values. Just go ahead and wipe them out. That'll reset back to no compensation and it should fix your problem. You will need to re-analyze the files after you do that.

Let me know if that helps you. Thanks!

eyal0 avatar Oct 22 '20 23:10 eyal0

Yes, I use cancel object plugin sometimes when I need just certain piece from a set that I have already sliced. I have deleted compensation values and now the estimate looks fine. What can be done here, so cancel object wont mess up estimates?

tomaae avatar Oct 23 '20 00:10 tomaae

Yes, I think that there is already a cancel object issue being tracked. It's really hard to do. The problem is that I'm calculating all the time to print ahead of time and I don't know how I could adjust it for which objects print and which don't.

Do you often use cancel object? Maybe I could at least not use prints with cancelled objects in the compensation database?

eyal0 avatar Oct 23 '20 01:10 eyal0

I dont use it too often. Yes, just not using prints where some objects were cancelled for compensation database would be a solution. If it can be done.

tomaae avatar Oct 23 '20 06:10 tomaae

We're talking about it here: https://github.com/paukstelis/Octoprint-Cancelobject/issues/60

PTG doesn't have any way right now to know if cancelobjects got used so there's work to be done.

eyal0 avatar Oct 23 '20 14:10 eyal0

I'm noticing the same thing. This explains what's going on, but I very frequently realize I forgot something right after starting a print, cancel it, fix it, and start over, so I will pretty much always have bad data points in the "compensation" database. Seems like pausing a print to change filament might also throw a wrench in it and skew the compensation data the other direction.

What about excluding things that fall outside some kind of calculated statistical curve? Like, for instance, discard compensation data for any print where actual time is more than one standard deviation above or below the predicted time. Python lib NumPy might handle most of the heavy lifting:

  • https://datagy.io/python-standard-deviation/
  • https://numpy.org/

That might get the estimation back on track faster than just waiting for enough "completed normally" prints to render the canceled (or paused) ones insignificant. Even a fixed percentage difference between estimated and actual might work as a basis for exclusion, i.e. only include compensation data from prints that completed within +/- 15% of the estimated time. That would basically just mean you're starting with an assumption that the estimates are normally somewhat accurate, and if they're far enough off at the start, then none of the compensation data ever gets considered.

rthomas6charter avatar May 06 '21 21:05 rthomas6charter

But prints that are cancelled shouldn't even show up in the compensation table.

Are you sure that cancelled prints are showing up in there? I've never been able to confirm it.

eyal0 avatar May 07 '21 15:05 eyal0

I've been wondering for a while now why PTG is telling me that my 6 hour print is going to take 26 hours to complete until I found this issue. Now I know to delete the compensation data. For those of us where this compensation data gets scewed over time, maybe we could just have an option to disable compensation altogether?

mgfarmer avatar Feb 20 '22 17:02 mgfarmer

This is a good idea...

Currently, there are 3 values for compensation: Time to heat, time to print, and time to cool.

The time to heat is measured as the time from the start of the print until filament starts extruding.

The time to cool is measured as the time from the end of the extruding until the print is done.

All the rest of it is the time to print and that value is compared against the results of marlin-calc, the time estimator, to see how similar the print time is to the estimate. The average factor difference is incorporated into each print.

The print time compensation is causing trouble often for users and I think that it's causing more trouble than it is worth. Maybe what we can do is make each of those values either be automatically derived (as today) or let the user specify each one. Any value that is specified will override the automatic derivation. So, for example, if you're happy with the heating and cooling time measurements (in seconds), then you could just leave those blanks. But if you are unhappy with the factor applied to the printing then you could set that to 1, which means to multiple the result of marlin-calc by one. (Multiplying by 1 does nothing, of course!). Or set it to 1.05 if you want 5% added to the value each time. All this would be instead of the current method, which is taking an average of the last 5 prints.

This seems like a solution that will solve your problem and also provide flexibility for users.

Because the calculation is usually pretty good from marlin-calc and too many users have this problem with compensation, I think that the new default will be to have 1.0 for the scaling factor of the print time but have the heat up and cooldown times continue to be computed by the averages.

How does this plan sound?

If I create a version of PTG that does this, would one you like to test it out?

eyal0 avatar Feb 22 '22 17:02 eyal0

Hi Eyal, Your plan sounds good to me. I'm always a fan a flexibility when it comes to software configuration. I'd be happy to try this out for you.

Question: Are the heat up/down compensation times stored per-target-temp, or does one setting apply to all target temperatures? For instance, would the heat up times for my PETG prints (with a much higher bed temp) affect the compensation values for my PLA prints (with a lower bed temp).

mgfarmer avatar Feb 22 '22 21:02 mgfarmer

@mgfarmer It's ready. If you want to try it, go into the plugin installation screen in OctoPrint, like normal, but put in this URL for the installation:

https://github.com/eyal0/OctoPrint-PrintTimeGenius/archive/refs/heads/compensation_values.zip

You do not need to uninstall PTG before you do this. All your old settings will be retained. You do not need to download that file; OctoPrint will download it for you when you provide the URL. When a future version of PTG is installed, it will install over this testing version and all settings will be retained.

After you do this, go into settings, PTG settings, then click on advanced and observe that you have the calculated compensation values there. If you delete them then they will be calculated as normal, using the average of previous prints. If you fill them in with a number then that will be used instead of the average. By default, the compensation for extruding is 1.0 and the rest are derived from averages. You can modify them or blank them out. Press "Save" to save your changes.

After that, future print time estimates will be affected, but only future ones. You can go back into settings and request for a file to be re-analyzed. After being analyzed, you can print the file and see the estimated print time. You will also see the effect of forcing compensation in the PTG plugin logs, which you can download and inspect. It will say "Forced".

Please try it out, let me know how it goes. Let me know if you have suggestions. Thanks.

eyal0 avatar Feb 26 '22 00:02 eyal0

Sounds great. Thanks for the detailed instructions. I'll let you how testing goes.

On Fri, Feb 25, 2022, 4:36 PM Eyal @.***> wrote:

@mgfarmer https://github.com/mgfarmer It's ready. If you want to try it, go into the plugin installation screen in OctoPrint, like normal, but put in this URL for the installation:

https://github.com/eyal0/OctoPrint-PrintTimeGenius/archive/refs/heads/compensation_values.zip

You do not need to uninstall PTG before you do this. All your old settings will be retained.

After you do this, go into settings, PTG settings, then click on advanced and observe that you have the calculated compensation values there. If you delete them then they will be calculated as normal, using the average of previous prints. If you fill them in with a number then that will be used instead of the average. By default, the compensation for extruding is 1.0 and the rest are derived from averages. You can modify them or blank them out. Press "Save" to save your changes.

After that, future print time estimates will be affected, but only future ones. You can go back into settings and request for a file to be re-analyzed. After being analyzed, you can print the file and see the estimated print time. You will also see the effect of forcing compensation in the PTG plugin logs, which you can download and inspect. It will say "Forced".

Please try it out, let me know how it goes. Let me know if you have suggestions. Thanks.

— Reply to this email directly, view it on GitHub https://github.com/eyal0/OctoPrint-PrintTimeGenius/issues/214#issuecomment-1051398573, or unsubscribe https://github.com/notifications/unsubscribe-auth/AUUGZBHDZ3WJADHEC22WSADU5AOCNANCNFSM4S3HRJGA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you were mentioned.Message ID: @.***>

mgfarmer avatar Feb 26 '22 02:02 mgfarmer

After reading through all these various comments and suggestions, nothing really matches what I am seeing. I don't often cancel print jobs, but everyone once in a while, it does happen. My issues is, looking at the OctoPrint screen, it states - Print time (ongoing) 28:37, Print time Left 1.5 Hours, Approx Total Print Time: 1.5 hours. I've seen some prints showing Approx Total Print time = 14.5 hours, Print Time (ongoing) 03:32:34, Print Time Left: 24.2 hours. How is it OctoPrint is showing over 10 hours more for the Print time Left than the Total Print time? This makes no sense. Even after printing a part for 28+min, the Print time Left can equal the Total Print Time Estimate? Something is wrong with the algorithm here. I realize this can be relative, but this is worse than Microsoft time for copying files, and that is really bad....

lorenmcguire avatar Sep 24 '23 20:09 lorenmcguire

You shouldn't be seeing approximate print time at all with Print Time Genius, only the exact print time.

eyal0 avatar Sep 26 '23 14:09 eyal0