OctoPrint/OctoPrint-MQTT

Home assistant plugin- Unknown Print time left

chris8837 opened this issue · 11 comments

What were you doing?

  1. ... Home Assistant MQTT Octoprint
  2. ...
  3. ...

What did you expect to happen?

having and issue with print time left saying unknown

What happened instead?

Says unknown. Doesn’t give a value

Version of OctoPrint

Latest

Version of the MQTT plugin

Latest

Used MQTT broker and its version

Home assistant latest

Link to octoprint.log

Link to contents of Javascript console in the browser

Screenshot(s)/video(s) showing the problem

I have the same issue - Approximate Completion Time, Print Time and Print Time left are unknown.
IMG_20230724_084459

I have the same issue.

Here is the corresponding error log in HA

Logger: homeassistant.components.mqtt.models
Source: components/sensor/__init__.py:594
Integration: MQTT (documentation, issues)
First occurred: 14:07:40 (2418 occurrences)
Last logged: 19:49:19

Exception raised when updating state of sensor.anycubic_mega_s_print_time_left, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": true}, "error": ""}, "job": {"file": {"name": "Bild.gcode", "path": "Bild/Bild.gcode", "display": "Bild.gcode", "origin": "local", "size": 22036473, "date": 1690386214}, "estimatedPrintTime": 23780.0, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 10024.919369999687, "volume": 0.0}}, "user": "admin", "estimatedPrintTimeFormatted": "6:36:20"}, "currentZ": 85.61, "progress": {"completion": 92.00171007402137, "filepos": 20273932, "printTime": 21741, "printTimeLeft": 1595, "printTimeLeftOrigin": "slicerestimator", "printTimeLeftFormatted": "0:26:35", "printTimeFormatted": "6:02:21"}, "offsets": {}, "resends": {"count": 0, "transmitted": 658358, "ratio": 0}, "_timestamp": 1690480143}'
Exception raised when updating state of sensor.anycubic_mega_s_print_time, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": true}, "error": ""}, "job": {"file": {"name": "Bild.gcode", "path": "Bild/Bild.gcode", "display": "Bild.gcode", "origin": "local", "size": 22036473, "date": 1690386214}, "estimatedPrintTime": 23780.0, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 10024.919369999687, "volume": 0.0}}, "user": "admin", "estimatedPrintTimeFormatted": "6:36:20"}, "currentZ": 85.61, "progress": {"completion": 92.00171007402137, "filepos": 20273932, "printTime": 21741, "printTimeLeft": 1595, "printTimeLeftOrigin": "slicerestimator", "printTimeLeftFormatted": "0:26:35", "printTimeFormatted": "6:02:21"}, "offsets": {}, "resends": {"count": 0, "transmitted": 658358, "ratio": 0}, "_timestamp": 1690480143}'
Exception raised when updating state of sensor.anycubic_mega_s_approximate_completion_time, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": true}, "error": ""}, "job": {"file": {"name": "Bild.gcode", "path": "Bild/Bild.gcode", "display": "Bild.gcode", "origin": "local", "size": 22036473, "date": 1690386214}, "estimatedPrintTime": 23780.0, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 10024.919369999687, "volume": 0.0}}, "user": "admin", "estimatedPrintTimeFormatted": "6:36:20"}, "currentZ": 85.73, "progress": {"completion": 92.08482682323982, "filepos": 20292248, "printTime": 21757, "printTimeLeft": 1595, "printTimeLeftOrigin": "slicerestimator", "printTimeLeftFormatted": "0:26:35", "printTimeFormatted": "6:02:37"}, "offsets": {}, "resends": {"count": 0, "transmitted": 658957, "ratio": 0}, "_timestamp": 1690480159}'
Exception raised when updating state of sensor.anycubic_mega_s_print_time_left, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": true}, "error": ""}, "job": {"file": {"name": "Bild.gcode", "path": "Bild/Bild.gcode", "display": "Bild.gcode", "origin": "local", "size": 22036473, "date": 1690386214}, "estimatedPrintTime": 23780.0, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 10024.919369999687, "volume": 0.0}}, "user": "admin", "estimatedPrintTimeFormatted": "6:36:20"}, "currentZ": 85.73, "progress": {"completion": 92.08482682323982, "filepos": 20292248, "printTime": 21757, "printTimeLeft": 1595, "printTimeLeftOrigin": "slicerestimator", "printTimeLeftFormatted": "0:26:35", "printTimeFormatted": "6:02:37"}, "offsets": {}, "resends": {"count": 0, "transmitted": 658957, "ratio": 0}, "_timestamp": 1690480159}'
Exception raised when updating state of sensor.anycubic_mega_s_print_time, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": true}, "error": ""}, "job": {"file": {"name": "Bild.gcode", "path": "Bild/Bild.gcode", "display": "Bild.gcode", "origin": "local", "size": 22036473, "date": 1690386214}, "estimatedPrintTime": 23780.0, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 10024.919369999687, "volume": 0.0}}, "user": "admin", "estimatedPrintTimeFormatted": "6:36:20"}, "currentZ": 85.73, "progress": {"completion": 92.08482682323982, "filepos": 20292248, "printTime": 21757, "printTimeLeft": 1595, "printTimeLeftOrigin": "slicerestimator", "printTimeLeftFormatted": "0:26:35", "printTimeFormatted": "6:02:37"}, "offsets": {}, "resends": {"count": 0, "transmitted": 658957, "ratio": 0}, "_timestamp": 1690480159}'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 590, in state
    numerical_value = int(value)
                      ^^^^^^^^^^
ValueError: invalid literal for int() with base 10: 'Jul 27, 20:35:25'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/mqtt/models.py", line 270, in process_write_state_requests
    entity.async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 742, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 810, in _async_write_ha_state
    state = self._stringify_state(available)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 748, in _stringify_state
    if (state := self.state) is None:
                 ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 594, in state
    raise ValueError(
ValueError: Sensor sensor.anycubic_mega_s_approximate_completion_time has device class 'None', state class 'measurement' unit 'None' and suggested precision 'None' thus indicating it has a numeric value; however, it has the non-numeric value: 'Jul 27, 20:35:25' (<class 'str'>)

Are all the effected people of this error using slicer estimator plugin? It seems from the error listed above @phbasler is for sure.

Just to confirm: Yes, I have the slicer estimator plugin enabled. I used Cura to create the gcode file.

I have the same issue too with my Octoprint-server. I use this plugin for the estimation: https://github.com/eyal0/OctoPrint-PrintTimeGenius

The mentioned issue has appeared since roundabout 2 months, before I could see the print-time left and print-time via MQTT in Home Assistant.

Logger: homeassistant.components.mqtt.models
Source: components/sensor/init.py:594
Integration: MQTT (documentation, issues)
First occurred: 22:38:24 (6 occurrences)
Last logged: 22:38:24

Exception raised when updating state of sensor.octoprint_print_time, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Starting", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": false}, "error": ""}, "job": {"file": {"name": "CE5_cable_holder_cover.gcode", "path": "CE5_cable_holder_cover.gcode", "display": "CE5_cable_holder_cover.gcode", "origin": "local", "size": 5804194, "date": 1690490286}, "estimatedPrintTime": 12225.168123146685, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 8598.851623536088, "volume": 20.682661959385502}}, "user": "octopi", "estimatedPrintTimeFormatted": "3:23:45"}, "currentZ": null, "progress": {"completion": 0.0, "filepos": 0, "printTime": 0, "printTimeLeft": null, "printTimeLeftOrigin": null, "printTimeLeftFormatted": null, "printTimeFormatted": "0:00:00"}, "offsets": {"tool0": 0}, "resends": {"count": 0, "transmitted": 7, "ratio": 0}, "_timestamp": 1690490304}'
Exception raised when updating state of sensor.octoprint_approximate_completion_time, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": false}, "error": ""}, "job": {"file": {"name": "CE5_cable_holder_cover.gcode", "path": "CE5_cable_holder_cover.gcode", "display": "CE5_cable_holder_cover.gcode", "origin": "local", "size": 5804194, "date": 1690490286}, "estimatedPrintTime": 12225.168123146685, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 8598.851623536088, "volume": 20.682661959385502}}, "user": "octopi", "estimatedPrintTimeFormatted": "3:23:45"}, "currentZ": null, "progress": {"completion": 0.0035319288087200394, "filepos": 205, "printTime": 0, "printTimeLeft": 12186, "printTimeLeftOrigin": "genius", "printTimeLeftFormatted": "3:23:06", "printTimeFormatted": "0:00:00"}, "offsets": {"tool0": 0}, "resends": {"count": 0, "transmitted": 11, "ratio": 0}, "_timestamp": 1690490304}'
Exception raised when updating state of sensor.octoprint_print_time_left, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": false}, "error": ""}, "job": {"file": {"name": "CE5_cable_holder_cover.gcode", "path": "CE5_cable_holder_cover.gcode", "display": "CE5_cable_holder_cover.gcode", "origin": "local", "size": 5804194, "date": 1690490286}, "estimatedPrintTime": 12225.168123146685, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 8598.851623536088, "volume": 20.682661959385502}}, "user": "octopi", "estimatedPrintTimeFormatted": "3:23:45"}, "currentZ": null, "progress": {"completion": 0.0035319288087200394, "filepos": 205, "printTime": 0, "printTimeLeft": 12186, "printTimeLeftOrigin": "genius", "printTimeLeftFormatted": "3:23:06", "printTimeFormatted": "0:00:00"}, "offsets": {"tool0": 0}, "resends": {"count": 0, "transmitted": 11, "ratio": 0}, "_timestamp": 1690490304}'
Exception raised when updating state of sensor.octoprint_print_time, topic: 'octoPrint/hass/printing' with payload: b'{"state": {"text": "Printing", "flags": {"operational": true, "printing": true, "cancelling": false, "pausing": false, "resuming": false, "finishing": false, "closedOrError": false, "error": false, "paused": false, "ready": false, "sdReady": false}, "error": ""}, "job": {"file": {"name": "CE5_cable_holder_cover.gcode", "path": "CE5_cable_holder_cover.gcode", "display": "CE5_cable_holder_cover.gcode", "origin": "local", "size": 5804194, "date": 1690490286}, "estimatedPrintTime": 12225.168123146685, "averagePrintTime": null, "lastPrintTime": null, "filament": {"tool0": {"length": 8598.851623536088, "volume": 20.682661959385502}}, "user": "octopi", "estimatedPrintTimeFormatted": "3:23:45"}, "currentZ": null, "progress": {"completion": 0.0035319288087200394, "filepos": 205, "printTime": 0, "printTimeLeft": 12186, "printTimeLeftOrigin": "genius", "printTimeLeftFormatted": "3:23:06", "printTimeFormatted": "0:00:00"}, "offsets": {"tool0": 0}, "resends": {"count": 0, "transmitted": 11, "ratio": 0}, "_timestamp": 1690490304}'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 590, in state
    numerical_value = int(value)
                      ^^^^^^^^^^
ValueError: invalid literal for int() with base 10: '0:00:00'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/mqtt/models.py", line 270, in process_write_state_requests
    entity.async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 742, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 810, in _async_write_ha_state
    state = self._stringify_state(available)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 748, in _stringify_state
    if (state := self.state) is None:
                 ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 594, in state
    raise ValueError(
ValueError: Sensor sensor.octoprint_print_time has device class 'None', state class 'measurement' unit 'None' and suggested precision 'None' thus indicating it has a numeric value; however, it has the non-numeric value: '0:00:00' (<class 'str'>)

"printTimeFormatted": "0:00:00"

seems to be what the sensor may be getting this from and that definitely is not formatted as a number. do you have the ability to change the sensor to use (payload).progress.printTime instead?

thanks for your quick reply. sorry to say that , I dont know how I could change the sensor that it uses(payload).progress.printTime instead. I am no expert by all means, maybe something has changed in the code as it worked fine until 2 months ago. Do you think it has to do with the print-time plugin?

This was due to a change that was made to use seconds within the Home Assistant interface instead of a formatted time, so Home Assistant can display the time left in a graph instead of a spam of event changes!

I have released a patch to fix this error, and it is waiting to be merged into the next release. For now you can test it here https://github.com/mreditor97/octoprint-homeassistant/archive/patch/print-time.zip

great, thanks a lot! will install it as soon as my 12h-print is done ;) happy weekend

In case you do not want to reinstall something until the update is available on octoprint:

In the config mqtt messages of the sensors is the line

"state_cl": "measurement",

I removed this line from the json payload and published it again and now the sensor shows the value as used to.
Just be aware that this will be overwritten once the mqtt octoprint plugin republishes the payload (probably at a restart).

So, since this appears to be a OctoPrint-HomeAssistant and HA change and nothing to do with the MQTT plugin side of things, closing this ticket.