Assertion Error in dosing automation for self._latest_od

Software
1

Hey, its me again

I’ve updated to version 25.03.05 and have a new error when playing with dosing automations.

This is my minimal not working example, the od_reading job has been started through the UI before executing this through the worker command line:

from pioreactor.automations.dosing.base import DosingAutomationJobContrib

class MNWE(DosingAutomationJobContrib):
    automation_name = "MNWE"

    def __init__(self, **kwargs):
        super(MNWE,self).__init__(**kwargs)
        self.logger.debug(f"Latest OD: {self.latest_od}")

And that is the console output:

pioreactor@Auto-P01:~ $ pio run dosing_automation --automation-name MNWE
2025-03-06T15:01:53+0100 DEBUG  [dosing_automation] Init.
2025-03-06T15:01:53+0100 INFO   [dosing_automation] Starting MNWE.
2025-03-06T15:01:53+0100 WARNING [dosing_automation] It's recommended to have stirring on to improve mixing during dosing events.
2025-03-06T15:01:53+0100 DEBUG  [dosing_automation] Waiting for OD and growth rate data to arrive
2025-03-06T15:01:53+0100 ERROR  [dosing_automation]
2025-03-06T15:01:53+0100 DEBUG  [dosing_automation]
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 724, in start_dosing_automation
    return klass(
           ^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/base.py", line 105, in __call__
    obj = type.__call__(cls, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/pioreactor/.pioreactor/plugins/MNWE.py", line 10, in __init__
    self.logger.debug(f"Latest OD: {self.latest_od}")
                                    ^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 544, in latest_od
    assert self._latest_od is not None
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError
Traceback (most recent call last):
  File "/usr/local/bin/pio", line 8, in <module>
    sys.exit(pio())
             ^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
         ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/decorators.py", line 33, in new_func
    return f(get_current_context(), *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 765, in click_dosing_automation
    la = start_dosing_automation(
         ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 737, in start_dosing_automation
    raise e
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 724, in start_dosing_automation
    return klass(
           ^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/base.py", line 105, in __call__
    obj = type.__call__(cls, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/pioreactor/.pioreactor/plugins/MNWE.py", line 10, in __init__
    self.logger.debug(f"Latest OD: {self.latest_od}")
                                    ^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 544, in latest_od
    assert self._latest_od is not None
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError
2025-03-06T15:01:53+0100 DEBUG  [dosing_automation] Exiting caused by Python atexit.
2025-03-06T15:01:53+0100 INFO   [dosing_automation] Disconnected.
2025-03-06T15:01:54+0100 DEBUG  [dosing_automation] Disconnected successfully from MQTT.

Thanks and best,

Kai

P.S.: I am unsure if software bugs should be posted here on the forum or if it would be better to move them to github?

2

So this isn’t a bug, but a gotcha. You can access self.latest_od only after it’s populated and has data available. This data comes from MQTT, and might take a few seconds to populate. Can you try adding a time.sleep(5) before the debug statement?

Looking at the code, there is an improvement I can make here to make it more clear what’s going on, so it’s kinda a bug, yes.

I am unsure if software bugs should be posted here on the forum or if it would be better to move them to github?

I think here initially, and we can triage to GH!

3

Ahh I see. Then I will keep this here on the forum :smiley:

Sadly the addition of the sleep did not resolve it. I am running the OD measurement with an interval of 10 seconds and can see on the UI graph that it is running and producing datapoints. The code of the MNWE is now the following:

from pioreactor.automations.dosing.base import DosingAutomationJobContrib
from pioreactor.utils.timing import current_utc_timestamp
import time

class MNWE(DosingAutomationJobContrib):
    automation_name = "MNWE"

    def __init__(self, **kwargs):
        super(MNWE,self).__init__(**kwargs)
        self.logger.debug(f"Current timestamp: {current_utc_timestamp()}")
        time.sleep(20)
        self.logger.debug(f"Current timestamp: {current_utc_timestamp()}")
        self.logger.debug(f"Latest OD: {self.latest_od}")

and the output is this:

pioreactor@Auto-P01:~ $ pio run dosing_automation --automation-name MNWE
2025-03-06T17:06:17+0100 DEBUG  [dosing_automation] Init.
2025-03-06T17:06:17+0100 INFO   [dosing_automation] Starting MNWE.
2025-03-06T17:06:18+0100 WARNING [dosing_automation] It's recommended to have stirring on to improve mixing during dosing events.
2025-03-06T17:06:18+0100 DEBUG  [dosing_automation] Current timestamp: 2025-03-06T16:06:18.005Z
2025-03-06T17:06:38+0100 DEBUG  [dosing_automation] Current timestamp: 2025-03-06T16:06:38.008Z
2025-03-06T17:06:38+0100 DEBUG  [dosing_automation] Waiting for OD and growth rate data to arrive
2025-03-06T17:06:38+0100 ERROR  [dosing_automation]
2025-03-06T17:06:38+0100 DEBUG  [dosing_automation]
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 724, in start_dosing_automation
    return klass(
           ^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/base.py", line 105, in __call__
    obj = type.__call__(cls, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/pioreactor/.pioreactor/plugins/MNWE.py", line 13, in __init__
    self.logger.debug(f"Latest OD: {self.latest_od}")
                                    ^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 544, in latest_od
    assert self._latest_od is not None
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError
Traceback (most recent call last):
  File "/usr/local/bin/pio", line 8, in <module>
    sys.exit(pio())
             ^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
         ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/click/decorators.py", line 33, in new_func
    return f(get_current_context(), *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 765, in click_dosing_automation
    la = start_dosing_automation(
         ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 737, in start_dosing_automation
    raise e
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 724, in start_dosing_automation
    return klass(
           ^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/base.py", line 105, in __call__
    obj = type.__call__(cls, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/pioreactor/.pioreactor/plugins/MNWE.py", line 13, in __init__
    self.logger.debug(f"Latest OD: {self.latest_od}")
                                    ^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/pioreactor/background_jobs/dosing_automation.py", line 544, in latest_od
    assert self._latest_od is not None
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError
2025-03-06T17:06:38+0100 DEBUG  [dosing_automation] Exiting caused by Python atexit.
2025-03-06T17:06:43+0100 DEBUG  [dosing_automation] run_thread still alive!
2025-03-06T17:06:43+0100 INFO   [dosing_automation] Disconnected.
2025-03-06T17:06:44+0100 DEBUG  [dosing_automation] Disconnected successfully from MQTT.

As always thanks for your help :slight_smile:

4

I can reproduce locally - let me see why this is happening and get a solution for you.

1 Like
5

Okay, so the solution is simple, but not obvious. The flow that populates these latest_* attributes starts in self.start_passive_listeners() (see here), but that code only runs after the __init__ is finished (see here).

Anyways, the solution for you is to just start that sooner:

from pioreactor.automations.dosing.base import DosingAutomationJobContrib
from pioreactor.utils.timing import current_utc_timestamp
import time

class MNWE(DosingAutomationJobContrib):
    automation_name = "MNWE"

    def __init__(self, **kwargs):
        super(MNWE,self).__init__(**kwargs)
        self.start_passive_listeners()
        self.logger.debug(f"Current timestamp: {current_utc_timestamp()}")
        self.logger.debug(f"Latest OD: {self.latest_od}")
1 Like
6

Yep that solves it. Thank you so much!

Best, Kai