Pioreactor1 going offline when ending experiment

realPeteDavidson · February 16, 2023, 9:14pm

I re-flashed my pioreactor this morning and haven’t yet changed any settings and everything is still on default settings. Now, when I click “End experiment,” or try to start a new experiment, my pioreactor will appear “offline” in the Pioreactors tab. Also, in my Optical density chart, it shows two pioreactors, a “pioreactor1-ch2,” and a “pioreactor1.” When I refresh the page, all the data collected becomes “pioreactor1-ch2,” and new data (collected after refreshing) is label as “pioreactor1.”

I believe these two issues might be related. Do you know what I can do to fix this issue?

Screenshot_20230216_010949

CamDavidsonPilon · February 16, 2023, 9:33pm

Also, in my Optical density chart, it shows two pioreactors, a “pioreactor1-ch2,” and a “pioreactor1.” When I refresh the page, all the data collected becomes “pioreactor1-ch2,” and new data (collected after refreshing) is label as “pioreactor1.”

There was an error in the UI code. I just pushed a fix now. On your Raspberry Pi, run

pio update ui

And try hard refreshing the webpage. This should correct that bug.

The other bug is unrelated, working on it currently.

realPeteDavidson · February 16, 2023, 9:38pm

Thanks! I tried updating it but now I’m getting this error on this page (http://pioreactor1.local/updates)

<?xml version="1.0" encoding="iso-8859-1"?> 500 Internal Server Error

500 Internal Server Error

Also, now it isn’t showing my experiment anyone on the main page. I also can’t see my pioreactor available under http://pioreactor1.local/pioreactors

Edit: I turned the pioreactor off and then on again. Still isn’t showing up.

CamDavidsonPilon · February 16, 2023, 9:50pm

Yea, something odd is going on. I’m seeing the same thing locally, and am debugging now. I’ll post here when a new fix version is up.

CamDavidsonPilon · February 16, 2023, 11:47pm

Here’s a temp fix you can try (and let me know if it works or not):

sudo chmod 777 ~/.pioreactor/storage/ && sudo systemctl restart lighttpd.service

I’m actually very confused why this latest update broke things…still investigating

realPeteDavidson · February 16, 2023, 11:58pm

I tried it and got “sudo: systemct1: command not found”

Edit: Just saw that’s an L, not a 1 haha. I just ran thecommand without issue.

realPeteDavidson · February 17, 2023, 12:02am

Ok, I ran it about a minute ago. I tried refreshing pioreactor1.local, but nothing has changed yet. Should I be waiting longer before it works?

CamDavidsonPilon · February 17, 2023, 12:03am

Okay, probably not the intended fix then. Can you run tail -n 100 /var/log/pioreactorui.log, and post the results here?

realPeteDavidson · February 17, 2023, 12:05am

2023-02-16T16:03:30-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:32-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:34-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:38-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:40-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:42-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:46-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:48-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:50-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:03:54-0800 [huey.consumer] INFO Starting Huey…

It’s that line repeated with different timestamps.

CamDavidsonPilon · February 17, 2023, 12:12am

Oh. That’s new. Can you post the output of

systemctl status huey.service

and

systemctl status lighttpd.service

One of them is failing fast and restarting

realPeteDavidson · February 17, 2023, 12:15am

systemctl status huey.service

● huey.service - Huey service for PioreactorUI
Loaded: loaded (/lib/systemd/system/huey.service; enabled; vendor preset: enabled)
Active: active (running) since Thu 2023-02-16 13:48:49 PST; 2h 24min ago
Process: 809 ExecStartPost=pio log -m huey.service successful -n systemd --local-only (code=exited, status=0/SUCCESS)
Main PID: 808 (huey_consumer)
Tasks: 4 (limit: 1715)
CPU: 1min 44.823s
CGroup: /system.slice/huey.service
└─808 /usr/bin/python3 /usr/local/bin/huey_consumer tasks.huey -s 60 -n -b 1.0 -w 2 -f -C

systemctl status lighttpd.service

● lighttpd.service - Lighttpd Daemon
Loaded: loaded (/lib/systemd/system/lighttpd.service; enabled; vendor preset: enabled)
Active: active (running) since Thu 2023-02-16 16:02:35 PST; 11min ago
Process: 4567 ExecStartPre=/usr/sbin/lighttpd -tt -f /etc/lighttpd/lighttpd.conf (code=exited, status=0/SUCCESS)
Main PID: 4572 (lighttpd)
Tasks: 7 (limit: 1715)
CPU: 10min 22.530s
CGroup: /system.slice/lighttpd.service
├─4572 /usr/sbin/lighttpd -D -f /etc/lighttpd/lighttpd.conf
├─4577 /usr/bin/php-cgi
├─4579 /usr/bin/php-cgi
├─4580 /usr/bin/php-cgi
├─4581 /usr/bin/php-cgi
├─4582 /usr/bin/php-cgi
└─4939 /usr/bin/python3 /var/www/pioreactorui/main.fcgi

I tried the tail command again and it is still giving the same message.

Edit: Just realized part of the message was cutoff and I needed to resize my terminal screen to see it. Both of “Process” lines got cut off, but I just updated them.

CamDavidsonPilon · February 17, 2023, 12:29am

I pushed some changes to a develop branch. Try:

pio update ui -b develop

and then the logs again:

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

realPeteDavidson · February 17, 2023, 12:36am

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

File “/usr/local/lib/python3.9/dist-packages/pioreactor/mureq.py”, line 233, in raise_for_status
raise HTTPErrorStatus(self.status_code)
pioreactor.mureq.HTTPErrorStatus: HTTP response returned error code 500
2023-02-16T13:45:52-0800 [pioreactor] WARNING No experiment found. Check http://pioreactor1.local/api/experiments/latest for an experiment.
2023-02-16T13:45:52-0800 [pioreactor] DEBUG HTTP response returned error code 503
Traceback (most recent call last):
File “/usr/local/lib/python3.9/dist-packages/pioreactor/whoami.py”, line 44, in _get_latest_experiment_name
result.raise_for_status()
File “/usr/local/lib/python3.9/dist-packages/pioreactor/mureq.py”, line 233, in raise_for_status
raise HTTPErrorStatus(self.status_code)
pioreactor.mureq.HTTPErrorStatus: HTTP response returned error code 503
2023-02-16T13:45:55-0800 [pioreactor] WARNING No experiment found. Check http://pioreactor1.local/api/experiments/latest for an experiment.
2023-02-16T13:45:55-0800 [pioreactor] DEBUG HTTP response returned error code 500
Traceback (most recent call last):
File “/usr/local/lib/python3.9/dist-packages/pioreactor/whoami.py”, line 44, in _get_latest_experiment_name
result.raise_for_status()
File “/usr/local/lib/python3.9/dist-packages/pioreactor/mureq.py”, line 233, in raise_for_status
raise HTTPErrorStatus(self.status_code)
pioreactor.mureq.HTTPErrorStatus: HTTP response returned error code 500
2023-02-16T13:46:02-0800 [monitor] INFO Ready.
2023-02-16T13:46:02-0800 [monitor] DEBUG monitor is blocking until disconnected.
2023-02-16T13:48:41-0800 [update-ui] DEBUG wget https://github.com/Pioreactor/pioreactorui/archive/refs/tags/23.2.16.tar.gz -O /tmp/pioreactorui.tar.gz
2023-02-16T13:48:44-0800 [update-ui] DEBUG bash /usr/local/bin/update_ui.sh /tmp/pioreactorui.tar.gz 23.2.16
2023-02-16T13:48:49-0800 [systemd] DEBUG huey.service successful
2023-02-16T13:48:49-0800 [update-ui] NOTICE Updated PioreactorUI to version 23.2.16.
2023-02-16T16:31:15-0800 [update-ui] DEBUG wget https://github.com/Pioreactor/pioreactorui/archive/develop.tar.gz -O /tmp/pioreactorui.tar.gz
2023-02-16T16:31:17-0800 [update-ui] DEBUG bash /usr/local/bin/update_ui.sh /tmp/pioreactorui.tar.gz develop
2023-02-16T16:31:22-0800 [systemd] DEBUG huey.service successful
2023-02-16T16:31:23-0800 [update-ui] NOTICE Updated PioreactorUI to version develop.

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

2023-02-16T16:33:10-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:12-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:15-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:18-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:20-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:23-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:26-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:28-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:31-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:34-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:36-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:39-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:42-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:44-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:47-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:50-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:52-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:54-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:57-0800 [huey.consumer] INFO Starting Huey…
2023-02-16T16:33:59-0800 [huey.consumer] INFO Starting Huey…

CamDavidsonPilon · February 17, 2023, 12:52am

Anything happening in cat /var/log/lighttpd/error.log?

realPeteDavidson · February 17, 2023, 12:53am

2023-02-16 16:52:00: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:03: http-header-glue.c.1499) read() 8 13: Connection reset by peer
2023-02-16 16:52:03: gw_backend.c.2275) response not received, request sent: 891 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:03: http-header-glue.c.1499) read() 9 14: Connection reset by peer
2023-02-16 16:52:03: gw_backend.c.2275) response not received, request sent: 919 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:03: http-header-glue.c.1499) read() 15 17: Connection reset by peer
2023-02-16 16:52:03: gw_backend.c.2275) response not received, request sent: 903 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:03: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:03: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:03: http-header-glue.c.1499) read() 16 19: Connection reset by peer
2023-02-16 16:52:03: gw_backend.c.2275) response not received, request sent: 923 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:03: http-header-glue.c.1499) read() 18 20: Connection reset by peer
2023-02-16 16:52:03: gw_backend.c.2275) response not received, request sent: 919 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:05: http-header-glue.c.1499) read() 16 13: Connection reset by peer
2023-02-16 16:52:05: gw_backend.c.2275) response not received, request sent: 919 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:05: http-header-glue.c.1499) read() 18 14: Connection reset by peer
2023-02-16 16:52:05: gw_backend.c.2275) response not received, request sent: 923 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:05: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:05: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:07: http-header-glue.c.1499) read() 16 10: Connection reset by peer
2023-02-16 16:52:07: gw_backend.c.2275) response not received, request sent: 923 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:07: http-header-glue.c.1499) read() 18 11: Connection reset by peer
2023-02-16 16:52:07: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:07: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:07: gw_backend.c.2275) response not received, request sent: 919 on socket: unix:/tmp/main-fcgi.sock-0 for /main.fcgi?, closing connection
2023-02-16 16:52:10: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:10: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:12: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:12: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:14: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:15: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:18: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:18: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:20: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:20: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:22: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:23: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:26: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:26: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:28: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:28: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:30: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:31: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:34: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:34: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:36: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:36: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused
2023-02-16 16:52:38: gw_backend.c.325) child exited: 1 unix:/tmp/main-fcgi.sock-0
2023-02-16 16:52:39: gw_backend.c.475) unlink /tmp/main-fcgi.sock-0 after connect failed: Connection refused

CamDavidsonPilon · February 17, 2023, 1:02am

Oh okay, here it is. So lighttpd is killing itself and restarting for some reason. I’ve seen this happen previously, and it was due to one of:

Permissions error
Bad Python code

I suspect it’s the former. Okay, let’s try:

ls -al /tmp

You said you did a re-flash today: do you mean that you reflashed the Pioreactor image onto the SD card?

realPeteDavidson · February 17, 2023, 1:04am

ls -al /tmp

total 2452
drwxrwxrwt 18 root root 400 Feb 16 17:03 .
drwxr-xr-x 18 root root 4096 Sep 21 17:24 …
drwxrwxrwt 2 root root 40 Feb 16 13:17 .font-unix
drwxr-xr-x 2 pioreactor pioreactor 60 Feb 16 13:45 gpio_in_use
drwxrwxrwt 2 root root 40 Feb 16 13:17 .ICE-unix
drwxr-xr-x 2 pioreactor pioreactor 60 Feb 16 13:45 job_metadata_monitor
drwxr-xr-x 2 pioreactor pioreactor 60 Feb 16 13:45 job_metadata_mqtt_to_db_streaming
drwxr-xr-x 2 pioreactor pioreactor 60 Feb 16 13:45 job_metadata_watchdog
srwxr-xr-x 1 www-data www-data 0 Feb 16 17:03 main-fcgi.sock-0
drwxr-xr-x 2 pioreactor pioreactor 60 Feb 16 13:45 pio_jobs_running
drwxr-xr-x 2 www-data www-data 40 Feb 16 13:45 pioreactor_ui
drwxrwx— 2 pioreactor www-data 100 Feb 16 16:31 pioreactorui_cache
-rw-r–r-- 1 pioreactor pioreactor 2502807 Feb 16 16:31 pioreactorui.tar.gz
drwx------ 3 root root 60 Feb 16 13:36 systemd-private-c3df6d8b66a54130a46dac886e4bf738-ModemManager.service-99qxqf
drwx------ 3 root root 60 Feb 16 13:36 systemd-private-c3df6d8b66a54130a46dac886e4bf738-systemd-logind.service-C6aMWg
drwx------ 3 root root 60 Feb 16 13:36 systemd-private-c3df6d8b66a54130a46dac886e4bf738-systemd-timesyncd.service-qJph3f
drwx------ 3 root root 60 Feb 16 13:36 systemd-private-c3df6d8b66a54130a46dac886e4bf738-vnstat.service-QmhNVg
drwxrwxrwt 2 root root 40 Feb 16 13:17 .Test-unix
drwxrwxrwt 2 root root 40 Feb 16 13:17 .X11-unix
drwxrwxrwt 2 root root 40 Feb 16 13:17 .XIM-unix

Yes. I reflashed the Pioreactor image onto the SD card. I downloaded a new image from the website yesterday.

CamDavidsonPilon · February 17, 2023, 1:11am

Oh I think I know. I think it’s a Python env problem.

Try this:

cd /var/www/pioreactorui/ && python app.py

Do you get an import error?

If so, do

cd /var/www/pioreactorui/ && sudo pip install -r requirements.txt

Then you can restart the webserver: sudo systemctl restart lighttpd.service

realPeteDavidson · February 17, 2023, 1:14am

No error.

pioreactor@pioreactor1:~ $ cd /var/www/pioreactorui/ && python app.py
pioreactor@pioreactor1:/var/www/pioreactorui $ ls
app.py huey.db logo192.png manifest.json requirements.txt tasks.py
asset-manifest.json huey.db-shm logo512.png pioreactor_icon.svg robots.txt version.py
CHANGELOG.md huey.db-wal logo.png precache-manifest.3ca4177aba3b0e56d7f6b07d24749b6d.js service-worker.js views.py
contrib index.html main.fcgi __ pycache__ static white_colour.png
favicon.ico LICENSE main.py README.md structs.py

I did not encounter an error, and there is already a file called app.py as well as a file called requirements.txt.

CamDavidsonPilon · February 17, 2023, 1:16am

Ah try using main.py

cd /var/www/pioreactorui/ && python main.py