Curious issue with print progress

@OutsourcedGuru

yes your linked Problem it is.
i printed a 1 Hour Print yesterday, so i didnt notice that much lagg behind.
Today im at a 5Hours print and you can clearly see a big lag on the "time" and gecode.
i use a Raspi 3B via Wireless.

Just want to confirm that I am seeing the same issue. Pi 3B+ with wireless connection. Not a huge issue since I don't sit and watch the screen for an entire print, but it is nice for a time estimation, which also lags significantly along with the visualization.

Thanks

I merged a duplicate thread into this one, all of the new comers (and those of you who haven't yet participated in the roll call), please share some data per this post:

Also just to confirm, the print progress in the sidebar under state, is it lading for everyone? Because if so it's a case of the status updates not being pushed in time over the socket, not just the gcode viewer being affected.

1 Like
  • Cura 4.5.0
  • Ender 3 Pro with BL-Touch
  • Marlin 1.1.9
  • 'Lag' increases over time, but estimated to be 3min after 30 min printing
  • Octoprint 1.4.0 on RPi 3B/Wifi

Note: Before Octoprint 1.4.0 upgrade, the printer was slightly behind the Gcode viewer - but understandably due to buffer etc.

This just gets weirder. I have a test print which is just a 3 layer credit card sized plate. Useful for seeing any delays without waiting too long.

If I print the gcode created by Cura it takes 26m10s to complete the print. The live gcode viewer lags by about 3 seconds per layer so it is about 9 seconds delayed by the time it finishes. As the print finishes the "Printed" value in the State section shows 91% then jumps to 100%

If I slice the same model with PrusaSlicer V 2.1.1 (which I only installed today) it produces a slightly smaller gcode file (65kb vs 69kb) but the gcode viewer works perfectly. It shows live progress slightly ahead of actual print - as has been mentioned before probably because of buffering at the printer. The "Printed" value as the print finishes however, is even worse - 87.5%
I have just had a look at the Prusa gcode and there are about 250 lines of comments at the end which is no doubt skewing things. My next test is to remove those comments and try again. No time now but I will do it asap.

I ran four tests - Prusa Cura Prusa Cura - just to be sure and the same results were seen each time. I will report back when I have tested the cleaned up Prusa gcode.

That's interesting. I use PrusaSlicer myself. I'll have to test cura gcode.

The lag in percentage due to a huge dump of comments at file end is to be expected btw - I could strip comments on upload or prior to printing to get more accurate here but that would cause other issues.

I can confirm that if I manually remove the 250 lines (12kb) of comments at the end of the PrusaSlicer gcode file it prints and shows progress perfectly. The gcode viewer stays slightly (a second or so) ahead of actual print head position and the State progress bar gets to 99% just before the print finishes.

For the same print (with just a few comments at layer change etc) Cura produces a 69kb gcode file and Prusa (with the end comments removed) produces 57kb file. I just had a quick side by side view of the two files and I can't detect why Cura produces 12kb more - someone who is more used to interpreting gcode my have more insight.

So it looks like it's something to do with the gcode Cura produces but only in the new Octoprint version.

foosel - sorry I was checking the rc's and started this post when I noticed it in rc5 but because nobody else was seeing it I thought it was something to do with my hardware rather than a bug. I will be more confident next time!

1 Like

It's difficult to say whether or not anyone else's plugins actually read the ending gcode comments. Maybe they do, I don't know.

But if it cleans up things then I'm all for it.

  • CuraLE 3.6.20
  • LulzBot TAZ 6
  • Marlin 1.1.9.34
  • OctoPi 0.17.0, Octoprint 1.4.0 on RPi 3B/Wifi

Printing a 3DBenchy at .18 layer height. Estimated print time with Print Time Genius is 2 hours 10 minutes. After 23 minutes of print time layer height of print = 5.94, GCode Viewer 5.76.

Watching the GCode Viewer while listening to the printer there is a definite lag in the viewer position. It is worse with 1.4.0 than it was with 1.3.12.

pluginslist.zip (838 Bytes)

cura 1.5
CR10-S5
marlin not sure...

I just tested it with deleting the comments at the end, no change. 2 hours into a print, and its about 5minutes behind.

Constantino - no I think the lag in the head position viewer is something to do with V1.4 and the gcode produced by Cura. I think foosel has it on her list of things to do!

I just sliced a test file with Cura 1.4.5 and it's currently printing. So far I cannot see a delay, but I'll keep monitoring.

Hi foosel. Cura V1.4.5? On Windows I think V4.5 has just been released but I don't have that yet. The Cura version causing issues for me is Windows V4.4.1 but from comments above it is also happening with V4.5 and earlier 3.N versions.

I could send you my "credit card" test sliced with Cura and Prusa slicer if there is a way of getting files to you.

John

Er, 4.5 ^^ Sorry. I got confused with my own version numbers there for a bit.

45min into the print btw and still it's behaving normally. Viewer is slightly ahead of the printer.

Getting my hands on those files would be lovely.

Ok version mixup understandable!
And that is what the viewer behaviour is for me when working ok - slightly ahead of print head.

Files are uploaded below. The first is the Cura slice (actually generated with V4.2.1), the second is the Prusa slicer with end of file comments removed. The third is the unedited Prusa slicer.

CE3_MyCardBlank v2.gcode (68.7 KB) MyCardBlank v2_0.2mm_NOCOMMENT_PLA_ENDER3_23m.gcode (56.5 KB) MyCardBlank v2_0.2mm_PLA_ENDER3_23m.gcode (64.2 KB)

John

What is the problem?
octoprint.printer.standard - ERROR - Exception while sending print progress to plugin octoprint_eta
Gcode Viewer is way behind actual Progress

What did you already try to solve it?

Logs (octoprint.log, serial.log or output on terminal tab at a minimum, browser error console if UI issue ... no logs, no support!)
octoprint.printer.standard - ERROR - Exception while sending print progress to plugin octoprint_eta
Traceback (most recent call last):
File "c:\octoprint\venv\lib\site-packages\octoprint\printer\standard.py", line 241, in call_plugins
plugin.on_print_progress(storage, filename, progress)
File "c:\octoprint\venv\lib\site-packages\octoprint_eta_init_.py", line 42, in on_print_progress
self.eta_string = self.calculate_ETA()
File "c:\octoprint\venv\lib\site-packages\octoprint_eta_init_.py", line 30, in calculate_ETA
strtime = format_time(finish_time)
File "c:\octoprint\venv\lib\site-packages\babel\dates.py", line 800, in format_time
format = get_time_format(format, locale=locale)
File "c:\octoprint\venv\lib\site-packages\babel\dates.py", line 411, in get_time_format
return Locale.parse(locale).time_formats[format]
AttributeError: 'NoneType' object has no attribute 'time_formats'

Additional information about your setup (OctoPrint version, OctoPi version, printer, firmware, browser, operating system, ... as much data as possible)
Octoprint Version is 1.4 latest, Printer: Ender 3 Pro, Firmware Marlin 2.0.4.4, Browser Firefox, OS Win 10 Pro, Ryzen 5 Maschine with 16GB Ram. Before upgrading to latest Version all was fine.

[Merged into this main thread where it's being talked about. Please back-read and see what's been said about it so far.]

@OutsourcedGuru actually that sounds like a completely different issue, and one with a plugin to boot which should be addressed by the plugin author and on the plugin's issue tracker, not here.

edit correction, it sounds like two issues, one with a plugin, one being the gcode viewer thing we are looking at here. My bad, sorry.

I can make neither head nor tails of this. I've looked through the GCODE files from @welshjohn (thanks!) but so far nothing sprang to my eye either and I cannot run them (or rather, i don't dare to run them) since I don't have an Ender 3.

I've looked through the difference in the GCODE viewer files between 1.3.12 and 1.4.0 and this is literally the only difference:

So it must not be in the GCODE viewer, but something else. It seems to only affect files sliced with Cura, though also not always (I cannot reproduce it myself with Cura 4.5).

Another round of questions for those of you affected...

  • what browser are you seeing this in?
  • does it only affect the GCODE viewer or is the overall progress bar also affected? If you have a z-height display plugin installed, what about that, does it match reality/is slightly ahead of it or not?

I'm trying to figure out if the data being pushed over the socket from the backend to the frontend is getting delayed here in some way, or if it's a client-only issue

It is weird @foosel. I use Chrome Version 79.0.3945.130 normally but I have just run my test in MS Edge and an old version of Firefox with exactly the same results. Lag with the Cura slice and normal with the Prusa slice.
The overall progress bar is also lagging - so just before the end of a print it will read somewhere in the early 90's percent. When the print finishes it will jump to 100% and then clear.

I have the DisplayLayerProgress Plugin (V1.18.0) installed and that displays the layer number correctly as the print progresses but the estimated time of completion is wrong (pessimistic) as I think it calculates it from the Octoprint "Print time left".

Is there any debug I can switch on to generate potentially useful log files? Happy to do that if there is.