Too much filament usage is calculated if print is aborted

[Rednax74]

The problem

I just did a couple of retract tests which should use ~ 2g of filament.
I aborted a couple of them and just afterwards I noticed that my spool weight dropped down from ~900 g down to 600 g.
Afterwards I let the prints finish normally and everything looked fine.
The issue could of course als be related to the spoolman database...

Version of octoprint-spoolman

Spoolman (1.1.2)

Version of OctoPrint

Version 1.10.2

Operating system running OctoPrint

OctoPi 0.18.0, running on Raspberry Pi 3 Model B Rev 1.2

Printer model & used firmware incl. version

no-name printer running martlin 2.0.7

Browser and version of browser, operating system running browser

opera under Win10

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-20240910084149.zip

[mdziekon]

Hi @Rednax74, thank you for your report.

Please provide clear steps to reproduce this issue. With the currently provided details I'm unable to work on this issue.

[Rednax74]

Ok, I tried to reproduce it again and so far I couldn't do it, sorry. I will let you know if something like this happens again.

[Rednax74]

ok, now I am sure that somewhere something goes wrong: my 19 h print failed in the last hour of completion (aaargh) due to an serial port issue. Octoprint lost the connection to the printer and went into the "Offline after error" mode.
The model should use 377.77 g of filament it was a new 1 kg spool and now spoolman shows that 1.151 g of filament have been used.
I attached the log files, there is some mentioning of spoolman so maybe that helps
octoprint-logs.zip

[Rednax74]

I just noticed that I set the logging for spoolman to debug, but in my log overview I see nothing related to spoolman name-wise, I would have expected a dedicated log? Where would I find the spoolman log information?

[mdziekon]

@Rednax74 this looks like a completely separate issue - since barely any spool usage has been registered by Spoolman, it seems the Plugin did not commit any usage data at all. I suspect that Spoolman Plugin needs to support a different event type for printer errors (different to currently supported errors). I'll try to investigate that, however I'm not sure if such an edge case is supported by the Octoprint virtual printer which I'm using for development.

[Rednax74]

Hm, I am not sure that I understand what you mean... the print failed after maybe 18 h of print, so up to this moment maybe ~300g should have been used.
Is the extruded filament continously calculated or just at the end of the print?
If I understand you correctly before the failure no usage was reported, so where is this coming from?

[mdziekon]

@Rednax74

The plugin does NOT commit usage in continous intervals (I think that's what Moonraker in the Klipper ecosystem does, which is probably a better approach, although I'm not sure how accurate and performance taxing it is).
Currently, spool usage is committed to Spoolman on print pause, print cancel, print done or print failed events, as seen here:
https://github.com/mdziekon/octoprint-spoolman/blob/master/octoprint_Spoolman/modules/PrinterHandler.py#L31-L37

These are events originating from Octoprint. I have a suspicion that the case you've described here might be yet another event emitted by Octoprint, but I need to investigate that.

[Rednax74]

understood, but it seems like the event is covered since there is spoolusage sended (from my very rough understanding):
2024-09-29 04:21:38,713 - octoprint.plugins.Spoolman - INFO - Extruder '0', spool id: 11, usage: 118947.3303499981
2024-09-29 04:21:43,400 - octoprint.plugins.Spoolman - INFO - [Spoolman][event] Triggered 'plugin_Spoolman_spool_usage_committed' with payload '{'toolIdx': 0, 'spoolId': '11', 'extrusionLength': 118947.3303499981}'
This is send immediately after the serial error occured, so the usage is send to spoolman but the calculation seems to be the problem? Sorry if my comments are not helpful I'll stop, just trying to help somehow :-)

[mdziekon]

@Rednax74 right, initially I didn't catch that "something" has been indeed sent to Spoolman, I assumed that the mentioned 1 or so grams of usage came from some previous usage, sorry for the confusion.

Looking at the log above, it indeed seems the plugin sent the data, and I think it actually calculated it correctly? extrusionLength is in mm, so we see the plugin calculated 118947 mm of filament usage. Assuming this was ABS (~1.04g/cm^3 density I think), this equals to ~300g of filament usage. Event with PLA, this would be ~350g of usage.

So it seems the calculations of the plugin are correct. Unless Spoolman's API has changed, or you have some unusual config in your Spoolman instance for this filament (eg. weird density set), I really don't see where the problem could be in the plugin itself.

[mdziekon]

@Rednax74 Could you please check which version of Spoolman do you currently have, and what's the configuration for the selected spool?

[Rednax74]

yeah you are right, the 118947 mm seems to be about right, it's PLA so ~350 g makes sense too.
So your plugin just sends the used mm to the spoolman databyse and there it is converted to g or is this also done by your plugin? Because I think I saw some conversion to g in your code.
In case you send the calculated weight it might help to save this info also in the log.
The density is defined to 1.24 g/cm^3, so that seems be correct too.
For the diameter and density my spoolman is using a comma: , and not a decimal point: . maybe that has an impact maybe? If I use a decimal point in spoolman it seems to be converted to a , automatically.
I am using Spoolman version 0.19.3 (5c5bd46).

[mdziekon]

@Rednax74

So your plugin just sends the used mm to the spoolman (...)

Yes, that's exactly what happens. Spoolman's API accepts either mm usage or g usage, and for simplicity I chose to use mm. Further conversions are performed by Spoolman. The conversion you might have seen in plugin's code are mostly related to display formatting, but are not used when sending data to Spoolman.

[Rednax74]

But maybe you could still put this info in the log, than would make debugging easier especially if someone put wrong data into the database.
Ok, I'll double check my settings and if I am convinced that my values are correct I'll open up an issue for spoolman directly.
Thank you very much for your help!

[mdziekon]

But maybe you could still put this info in the log, than would make debugging easier especially if someone put wrong data into the database.

Yes indeed, that's a good idea, will most likely add it in some future update.