Alternative media pump sometimes keeps running continuously when a limited dose is required

I’ve encountered an unfortunate bug where seemingly randomly (maybe 1-3 times every 10 doses) the alternative media pump continues to pump, even though in the UI the Stop button is no longer present, indicating it “thinks” the dosing is finished. I’ve tested changing the pump (swapped PWM cables from one slot to another) and have confirmed that the issue moves to the new pump, so it doesn’t appear to be a hardware issue unless it’s in the HAT/Pi itself. For normal media and waste I’ve tested at least 20x1mL doses and haven’t encountered the issue.

Attached a video of what I mean here. When I don’t pan to show the pump that’s because the dose has executed and stopped correctly.

Are there logs somewhere that I can check to help debug?

hmmm that’s a big problem. It looks like the pump isn’t being “cleaned” up correctly. If you run pio logs on the command line (of the Pioreactor you’re executing against), you should see logs of the pump, including logs around clean-up.

What does your “PWM intensity” say in the UI during this broken state?

Here are the logs. The first two times all was fine, the third time it continued to run. Then I ran continuously to check PWM intensity. When it was erroneously running continuously the UI showed 0% for the intensities, when running properly I got 95% for PWM 3.

2024-12-18T16:04:39+0000 [huey.consumer] INFO Executing nohup /usr/local/bin/pio run add_alt_media --ml 1 --source-of-event UI, env={‘EXPERIMENT’: ’ expression 18th December 2024’, ‘JOB_SOURCE’: ‘user’, ‘ACTIVE’: ‘1’}
2024-12-18T16:04:40+0000 [add_alt_media] DEBUG Initialized GPIO-16 using software-timing, initial frequency = 250.0 hz.
2024-12-18T16:04:40+0000 [add_alt_media] INFO Adding 1.0 mL alt-media.
2024-12-18T16:04:41+0000 [add_alt_media] DEBUG Cleaned up GPIO-16.
2024-12-18T16:04:42+0000 [huey.consumer] INFO Executing nohup /usr/local/bin/pio run add_alt_media --ml 1 --source-of-event UI, env={‘EXPERIMENT’: ’ expression 18th December 2024’, ‘JOB_SOURCE’: ‘user’, ‘ACTIVE’: ‘1’}
2024-12-18T16:04:43+0000 [add_alt_media] DEBUG Initialized GPIO-16 using software-timing, initial frequency = 250.0 hz.
2024-12-18T16:04:43+0000 [add_alt_media] INFO Adding 1.0 mL alt-media.
2024-12-18T16:04:43+0000 [add_alt_media] DEBUG Cleaned up GPIO-16.
2024-12-18T16:04:44+0000 [huey.consumer] INFO Executing nohup /usr/local/bin/pio run add_alt_media --ml 1 --source-of-event UI, env={‘EXPERIMENT’: ’ expression 18th December 2024’, ‘JOB_SOURCE’: ‘user’, ‘ACTIVE’: ‘1’}
2024-12-18T16:04:45+0000 [add_alt_media] DEBUG Initialized GPIO-16 using software-timing, initial frequency = 250.0 hz.
2024-12-18T16:04:45+0000 [add_alt_media] INFO Adding 1.0 mL alt-media.
2024-12-18T16:04:45+0000 [add_alt_media] DEBUG Cleaned up GPIO-16.
2024-12-18T16:05:44+0000 [huey.consumer] INFO Executing nohup /usr/local/bin/pio run add_alt_media --continuously --source-of-event UI, env={‘EXPERIMENT’: ’ expression 18th December 2024’, ‘JOB_SOURCE’: ‘user’, ‘ACTIVE’: ‘1’}
2024-12-18T16:05:44+0000 [add_alt_media] DEBUG Initialized GPIO-16 using software-timing, initial frequency = 250.0 hz.
2024-12-18T16:05:44+0000 [add_alt_media] INFO Running alt_media pump continuously.
2024-12-18T16:05:57+0000 [add_alt_media] INFO Stopped alt_media pump.
2024-12-18T16:05:57+0000 [add_alt_media] DEBUG Cleaned up GPIO-16.

Thanks for bringing this up @noahsprent. We were able to reproduce it. There is a race-condition in the cleanup code. We’ve fixed it on a branch if you want to update your cluster to that (run this on your leader):

pios update app -b pump-fix

Note that this only happens on PWM outputs and 1 and 3. Outputs 2 and 4 are unaffected. Normally alt-media pump is on PWM output 3.

1 Like

Awesome, thanks for such a quick response!