Pioreactor not starting new dosing automation

realPeteDavidson · March 8, 2023, 5:10pm

I just made changes to a dosing automation and wanted to test it out. I had a turbidostat automation running overnight, so I just turned it off, and then I tried to turn the dosing automation on again but it wouldn’t start. I didn’t get any error, and I tried running the default chemostat automation and that won’t respond either. Also, I noticed my media tracker is also showing 0 now:

Not much showing up in the pioreactor log.

tail -n 20 /var/log/pioreactor.log

2023-03-08T08:55:13-0800 [remove_waste] INFO 0.3mL
2023-03-08T08:55:15-0800 [PWM@GPIO-12] DEBUG Cleaned up GPIO-12.
2023-03-08T08:55:16-0800 [PWM@GPIO-12] DEBUG Initialized GPIO-12 using hardware-timing, initial frequency = 200.0 hz.
2023-03-08T08:55:16-0800 [remove_waste] INFO 0.6mL
2023-03-08T08:55:18-0800 [PWM@GPIO-12] DEBUG Cleaned up GPIO-12.
2023-03-08T08:55:18-0800 [dosing_automation] INFO DilutionEvent: Latest Normalized OD = 2.60 >= Target nOD = 2.60; cycled 0.300000 mL Start Time = 317199.96, End Time = 317611.95, Start nOD = 2.59, End nOD = 2.60, growth rate = 0.00
2023-03-08T08:57:43-0800 [temperature_control] DEBUG features={‘previous_heater_dc’: 87.80990789287738, ‘room_temp’: 22.0, ‘time_series_of_temp’: [55.475, 51.75, 48.975, 46.7125, 44.85, 43.2625, 41.9125, 40.75, 39.7875, 38.9375, 38.1875, 37.5625, 37.0, 36.5375, 36.125, 35.75, 35.425, 35.125, 34.85, 34.625, 34.425, 34.225, 34.0625, 33.9, 33.75, 33.625, 33.5, 33.3875, 33.3125]}
2023-03-08T08:57:43-0800 [temperature_automation] DEBUG PID output = 0.20820368711835613
2023-03-08T08:58:34-0800 [dosing_automation] DEBUG Disconnected.
2023-03-08T08:58:34-0800 [dosing_automation] DEBUG Disconnected successfully from MQTT.
2023-03-08T08:58:35-0800 [dosing_control] INFO Disconnected.
2023-03-08T08:58:35-0800 [dosing_control] INFO Updated state from ready to disconnected.
2023-03-08T08:58:35-0800 [dosing_control] DEBUG Exiting caused by Python atexit.
2023-03-08T08:58:36-0800 [dosing_control] DEBUG Disconnected successfully from MQTT.
2023-03-08T08:59:16-0800 [monitor] DEBUG Running nohup pio run dosing_control --automation-name alt_tracking_turbidostat --skip-first-run 0 --media-volume 1.0 --alt-media-volume 0 --alt-media-interval 720 --alt-media-dose-increase 0.05 --duration 0.01 --target-normalized-od 2.6 >/dev/null 2>&1 & from Monitor job.
2023-03-08T08:59:49-0800 [monitor] DEBUG Running nohup pio run dosing_control --automation-name alt_tracking_turbidostat --skip-first-run 0 --media-volume 1.0 --alt-media-volume 0 --alt-media-interval 720 --alt-media-dose-increase 0.05 --duration 0.01 --target-normalized-od 2.6 >/dev/null 2>&1 & from Monitor job.
2023-03-08T09:00:47-0800 [monitor] DEBUG Running nohup pio run dosing_control --automation-name chemostat --skip-first-run 1 --duration 20 --volume 0.5 >/dev/null 2>&1 & from Monitor job.
2023-03-08T09:01:28-0800 [temperature_control] DEBUG features={‘previous_heater_dc’: 88.01811157999573, ‘room_temp’: 22.0, ‘time_series_of_temp’: [55.625, 51.8875, 49.1375, 46.8875, 45.025, 43.4375, 42.1, 40.95, 39.9625, 39.125, 38.3875, 37.75, 37.2, 36.725, 36.3125, 35.9375, 35.6125, 35.3125, 35.0625, 34.8125, 34.625, 34.4375, 34.25, 34.1125, 33.9375, 33.8125, 33.6875, 33.5625, 33.4875]}
2023-03-08T09:01:28-0800 [temperature_automation] DEBUG PID output = -1.342846197563631
2023-03-08T09:01:50-0800 [monitor] DEBUG Running nohup pio run dosing_control --automation-name alt_tracking_turbidostat --skip-first-run 0 --media-volume 0.2 --alt-media-volume 0 --alt-media-interval 720 --alt-media-dose-increase 0.1 --duration 0.01 --target-normalized-od 2.6 >/dev/null 2>&1 & from Monitor job.

Nothing new in the ui log either (entries from yesterday)

2023-03-07T11:03:18-0800 [huey.consumer] INFO Scheduler runs every 60 second(s).
2023-03-07T11:03:18-0800 [huey.consumer] INFO Periodic tasks are disabled.
2023-03-07T11:03:18-0800 [huey.consumer] INFO The following commands are available:

tasks.add_new_pioreactor

tasks.update_app

tasks.pio

tasks.rm

tasks.pios

tasks.pios_install_plugin

tasks.pios_uninstall_plugin

tasks.write_config_and_sync

2023-03-07T11:03:33-0800 [huey.consumer] INFO Starting Huey…
2023-03-07T11:03:35-0800 [pioreactorui] DEBUG Starting pioreactorui=23.3.1 on pioreactor1…
2023-03-07T11:03:35-0800 [pioreactorui] DEBUG .env={‘DB_LOCATION’: ‘/home/pioreactor/.pioreactor/storage/pioreactor.sqlite’, ‘DOT_PIOREACTOR’: ‘/home/pioreactor/.pioreactor/’, ‘WWW’: ‘/var/www/pioreactorui/’, ‘UI_LOG_LOCATION’: ‘/var/log/pioreactorui.log’}
2023-03-07T11:03:35-0800 [pioreactorui] DEBUG Starting MQTT client
2023-03-07T11:03:35-0800 [pioreactorui] DEBUG Cache location: /tmp/pioreactorui_cache
2023-03-07T11:03:35-0800 [pioreactorui] DEBUG Finished initializing.
2023-03-07T11:11:46-0800 [huey.consumer] INFO Executing pio list-plugins --json
2023-03-07T15:49:12-0800 [pioreactorui] ERROR Yaml error in 07_normalized_od_24_hours.yaml: Expected int | str, got float - at $.lookback
2023-03-07T16:54:59-0800 [pioreactorui] ERROR Yaml error in 09_turbidostat_growth_rate.yaml: Expected str, got null - at $.mqtt_topic

realPeteDavidson · March 8, 2023, 5:14pm

I tried running pio db to see if I might see any error messages there, and then I got this message:

Traceback (most recent call last):
  File "/usr/local/bin/pio", line 5, in <module>
    from pioreactor.cli.pio import pio
  File "/usr/local/lib/python3.9/dist-packages/pioreactor/cli/pio.py", line 542, in <module>
    for plugin in pioreactor.plugin_management.get_plugins().values():
  File "/usr/local/lib/python3.9/dist-packages/pioreactor/plugin_management/__init__.py", line 107, in get_plugins
    module = importlib.import_module(module_name)
  File "/usr/lib/python3.9/importlib/__init__.py", line 127, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "/home/pioreactor/.pioreactor/plugins/alt_tracking_turbidostat.py", line 75
    if self.alt_media_counter >= self.alt_media_interval and self.current_normalized_od >= self.target_normalized_od:

I can try and figure out what’s wrong with my code, but I hadn’t seen that error pop up anywhere until I tried pio db, which seems like strange behavior to me.

CamDavidsonPilon · March 8, 2023, 5:16pm

The python files you put in ~/.pioreactor/plugins are run everytime you invoke pio, so if there is a syntax error in a plugin, it will basically halt new operations.

The traceback you posted doesn’t tell me much - is there a missing bottom half?

It doesn’t have to be this way. In the next release, I’ve added a try/except block to catch syntax errors, so that operation is not totally blocked by a plugin.

realPeteDavidson · March 8, 2023, 7:55pm

Oh, nope, that was the end of the error message I got and I fixed that error (and a couple others) in my code. I just wasn’t able to see the error or start an automation until I typed pio db. That fixed it somehow.