search

signag / raspi-cam-srv

Web Server for Raspi Camera Access
MIT License
36 stars 4 forks source link

flask app is running on port 5000, but can't browse to <ip_address:5000> and no logs. #8

Open OldGuyMeltsPlastic opened 3 months ago

OldGuyMeltsPlastic commented 3 months ago

I am trying to run raspi-cam-srv on a Pi 5 with 64 bit Bookworm and two Arducam 16 MP Autofocus cameras over CSI connections. First, a little background information for context: The Pi 5 is running Klipper/Mainsail/Crowsnest to host a 3D printer environment. Crowsnest is another camera application that uses camera-streamer on the back end. While Crowsnest is able to detect both Arducams, it has a warning in its own logs that says: [03/30/24 22:51:30] crowsnest: INFO: Found 2 total available Device(s) [03/30/24 22:51:30] crowsnest: ================================================================ [03/30/24 22:51:30] crowsnest: WARN: 'libcamera' devices are currently not supported on Pi 5! [03/30/24 22:51:30] crowsnest: ================================================================ [03/30/24 22:51:30] crowsnest: Detected 'libcamera' device -> /base/axi/pcie@120000/rp1/i2c@88000/imx519@1a [03/30/24 22:51:30] crowsnest: Detected 'libcamera' device -> /base/axi/pcie@120000/rp1/i2c@80000/imx519@1a

Which led me to go searching for an alternative solution, and I ended up here with raspi-cam-srv.

After going through all of the basic configuration steps, and then also setting up raspi-cam-srv to run as a background service, I am unable to access the web server interface which appears to be running on port 5000, and no logs are generated.


pi@gemeaux:~ $ ps -ef | grep 5000
pi           967       1  0 Mar30 ?        00:00:08 /home/pi/prg/raspi-cam-srv/.venv/bin/python /home/pi/prg/raspi-cam-srv/.venv/bin/flask --app raspiCamSrv run --port 5000 --host=0.0.0.0
pi         29829   29795  0 09:19 pts/1    00:00:00 grep --color=auto 5000
pi@gemeaux:~ $ cd prg
pi@gemeaux:~/prg $ cd raspi-cam-srv/
pi@gemeaux:~/prg/raspi-cam-srv $ ls
config  docs  instance  LICENSE  logs  output  raspiCamSrv  README.md
pi@gemeaux:~/prg/raspi-cam-srv $ cd logs
pi@gemeaux:~/prg/raspi-cam-srv/logs $ ls
raspiCamSrv.log
pi@gemeaux:~/prg/raspi-cam-srv/logs $ source .venv/bin/activate
-bash: .venv/bin/activate: No such file or directory
pi@gemeaux:~/prg/raspi-cam-srv/logs $ cd ..
pi@gemeaux:~/prg/raspi-cam-srv $ source .venv/bin/activate
(.venv) pi@gemeaux:~/prg/raspi-cam-srv $ ls
config  docs  instance  LICENSE  logs  output  raspiCamSrv  README.md
(.venv) pi@gemeaux:~/prg/raspi-cam-srv $ cd logs
(.venv) pi@gemeaux:~/prg/raspi-cam-srv/logs $ ls -al
total 8
drwxr-xr-x  2 pi pi 4096 Mar 28 01:57 .
drwxr-xr-x 11 pi pi 4096 Mar 28 01:57 ..
-rw-r--r--  1 pi pi    0 Mar 31 05:57 raspiCamSrv.log
signag commented 3 months ago

Could you first try to start the Flask server from the command line according to step 13 of RaspiCamSrv Installation.

You should see something like this:
image

Then, you can try to connect.

OldGuyMeltsPlastic commented 3 months ago

When I tried running the app on port 5000, I got: image I expect this because I already configured the service to run in the background, so I don't have to log in and start it manually. So then I tried running it on port 5001, and I got: image And in the browser when I navigate to http://192.168.68.250:5001, I see this: image

OldGuyMeltsPlastic commented 3 months ago

As the feedback seems to indicate that the cameras are in use by whatever process is running on port 5000, I try to point the browser to http://192.168.68:5000, and the icon in the upper left corner of the browser tab just keeps spinning and never shows any web server UI at all: image And while whatever is running on port 5000, and now also on port 5001, I still see no logging in ~prg/raspi-cam-srv/logs, just a zero byte file: image Which as you can understand, makes it difficult to troubleshoot what is happening.

OldGuyMeltsPlastic commented 3 months ago

I am wondering if I am missing some package(s) that this code has as dependencies?

signag commented 3 months ago

Please make sure that no raspiCamSrv server is active:

  1. Stop the service, if it sould be active
    sudo systemctl stop raspiCamSrv.service
  2. If you have started the server on the commandline, stop it with <Ctrl+C>

Now, check whether another program is using port 5000:
sudo netstat -nlp | grep 5000

If you get an empty result, port 5000 is free and you can start the raspiCamSrv server on the commandline, as you did before, but with port 5000.
If the list is not empty, you may probably see which program is using port 5000 and you can use 5001 for raspiCamSrv.

If the camera is in use by another program, you will see something like this (after you connected with the UI):
image

The last error message is the one you see also on the Web UI.

According to logs:
The current setup does not log to the log file but only to the console.
(See raspiCamSrv Troubleshooting)
If necessary, you could change that.

If running as service, you can see the logs with
sudo journalctl -e

OldGuyMeltsPlastic commented 3 months ago

So, stopping the background service and starting the flask app from the command line on port 5000 allowed me to see both camera feeds in the web app in the browser. I then hit CTRL-C to stop the running process, and tried restarting the background service, and in journalctl -e, I see the following: image Any other suggestions? I very much appreciate your help with this!

signag commented 3 months ago

It's probably something wrong in the service file.

Please post the content of the .service file

signag commented 3 months ago

It seems that you are running kTAMV, which is also based on Flask. Don't know which Flask version - perhaps a version < 3.0.0.

Probably, raspiCamSrv, when run as service, is using this Flask version and not the one in the raspi-cam-srv virtual environment.
Therefore, you should check the different path entries in the .service file.

OldGuyMeltsPlastic commented 3 months ago

Here's raspiCamSrv.service: image Here's kTAMV_server.service: image I have uninstalled kTAMV just to confirm there is no conflict, and rebooted. Now when I run sudo journalctl -e, I see that raspiCamSrv is only running on http://127.0.0.1:5000 (twice?), which might explain why I am unable to browse to it on http://192.168.68.250:5000: image

OldGuyMeltsPlastic commented 3 months ago

I also just ran a sudo rpi-update, to get myself onto the latest kernel: Linux gemeaux 6.6.22-v8-16k+ #1747 SMP PREEMPT Wed Mar 27 17:06:56 GMT 2024 aarch64

Still see only the loopback address in the raspiCamSrv service startup. I am wondering if it is being started too early, before the wifi NIC gets its IP address assigned from the wifi router?

OldGuyMeltsPlastic commented 3 months ago

Yes, changing the After line to: After=network-online.target moonraker.service has resolved this for me.

signag commented 3 months ago

This might be a reason, although I have never seen this myself.

Probably, you can try configuration options described in https://systemd.io/NETWORK_ONLINE/

OldGuyMeltsPlastic commented 3 months ago

image

signag commented 3 months ago

Great.
Thanks. I will add a comment to the docs.

OldGuyMeltsPlastic commented 3 months ago

No, thank you for your work and assistance! I know just enough about Linux to be dangerous. ;-)

Now to see if I can resolve the errors I am seeing with kTAMV. Hopefully the author of that server will be equally as responsive as you have been.

OldGuyMeltsPlastic commented 3 months ago

Alright, I fixed kTAMV by updating Flask to 3.0.2 and Werkzeug to 3.0.1 in its own venv, and it is now running as designed. But I am still getting inconsistent results with trying to run raspiCamSrv as a background service. In journalctl, I see:

Apr 02 23:52:58 gemeaux crowsnest[1075]: V4L2 Control: No parameters set for [cam microscope]. Skipped.
Apr 02 23:52:58 gemeaux flask[1083]:  * Serving Flask app 'raspiCamSrv'
Apr 02 23:52:58 gemeaux flask[1083]:  * Debug mode: off
Apr 02 23:52:58 gemeaux flask[1083]: WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
Apr 02 23:52:58 gemeaux flask[1083]:  * Running on all addresses (0.0.0.0)
Apr 02 23:52:58 gemeaux flask[1083]:  * Running on http://127.0.0.1:5000
Apr 02 23:52:58 gemeaux flask[1083]:  * Running on http://192.168.68.250:5000
Apr 02 23:52:58 gemeaux flask[1083]: Press CTRL+C to quit
Apr 02 23:52:58 gemeaux crowsnest[1549]: Starting ustreamer with Device /dev/video0 ...
Apr 02 23:52:59 gemeaux flask[1083]: 192.168.68.67 - - [02/Apr/2024 23:52:59] "GET /photo_feed2?bypassCache=1712116377145 HTTP/1.1" 200 -
Apr 02 23:52:59 gemeaux flask[1083]: 192.168.68.67 - - [02/Apr/2024 23:52:59] "GET /photo_feed?bypassCache=1712116377145 HTTP/1.1" 200 -
Apr 02 23:52:59 gemeaux python3[1081]: 2024-04-02 23:52:59 mobileraker.default.sync INFO Syncing klippy Objects

But browsing to 192.168.68.250:5000 never returns any web server UI at all.

If however, I stop the running raspiCamSrv.service and then activate the venv and run flask --app raspiCamSrv run --port 5000 --host=0.0.0.0 from the command line, the web server starts up and I am able to see my two camera feeds.

I am at a loss as to what to try next. Any suggestions would be greatly appreciated!

signag commented 3 months ago

So, is it correct that, if you are running kTAMV as a service, raspiCamSrv does not work, when it is started as service?
And if the kTAMV service is stopped, the raspiCamSrv service is OK?

OldGuyMeltsPlastic commented 3 months ago

I tried moving the kTAMV_server.service out of /etc/systemd/system and into ~, thereby preventing the kTAMV_server.service from starting on reboot. It uses port 8085 for it's own interface, so I wouldn't have expected this to interfere with the raspiCamSrv.service on port 5000. Powered the Pi 5 off and then back on again, and I still can't log into the web server running in the background service on port 5000. I then run:

sudo systemctl stop raspiCamSrv.service
source ~/prg/raspi-cam-srv/.venv/bin/activate
cd ~/prg/raspi-cam-srv
flask --app raspiCamSrv run --port 5000 --host=0.0.0.0

And am able to log in. One other odd thing, in Mainsail, I have both webcams configured but until I log into the raspiCamSrv server on port 5000, neither shows up with any image. Only after I log into the web server and am looking at the Live tab, does the first camera appear in Mainsail, and the second camera doesn't appear in Mainsail until I click on the Web Cam tab in the raspiCamSrv. Before logging into raspiCamSrv: image Log into raspiCamSrv, and see this: image Without changing anything else, flip the browser back to the other tab, and camera0 is now visible: image Back to Raspi Camera tab, click on the Web Cam tab so both web cams appear on screen: image Again, making no changes, flip back to the other tab, and both camera0 and camera1 are now visible: image Camera0 config in Mainsail: image Camera1 config in Mainsail: image

signag commented 3 months ago

I just fixed an issue with the photo_feed endpoints (see Release Notes).
Probably, this was the reason why you only saw a camera image after you have activated streaming through the raspiCamSrv Web UI.

This bug appeared only for the photo_feed endpoint, not for video_feed. Streaming videos should have been available as soon as the server has been started.

signag commented 3 months ago

Yes, changing the After line to: After=network-online.target moonraker.service has resolved this for me.

3 days ago, you said that you have successfully run raspiCamSrv as a service.
I think that this was after you had uninstalled kTAMV.

And now, after you have reinstalled kTAMV and upgraded it's Flask, it no longer works? - Strange!

OldGuyMeltsPlastic commented 3 months ago

Yes, changing the After line to: After=network-online.target moonraker.service has resolved this for me.

3 days ago, you said that you have successfully run raspiCamSrv as a service. I think that this was after you had uninstalled kTAMV.

And now, after you have reinstalled kTAMV and upgraded it's Flask, it no longer works? - Strange!

kTAMV was still installed at that time. As you asked about the possibility of negative interactions between kTAMV and raspiCamSrv, I moved kTAMV_server.service out of /etc/systemd/system and into ~, in order to test if my issues with raspiCamSrv persisted, and it seems like they are persisting.

OldGuyMeltsPlastic commented 3 months ago

I just fixed an issue with the _photofeed endpoints (see Release Notes). Probably, this was the reason why you only saw a camera image after you have activated streaming through the raspiCamSrv Web UI.

This bug appeared only for the _photofeed endpoint, not for _videofeed. Streaming videos should have been available as soon as the server has been started.

Thank you for this fix, that should hopefully help. I will update my code now.

OldGuyMeltsPlastic commented 3 months ago

After wiping out the old release, and updating to the latest release, the web server starts with one of the two cameras visible and providing a feed to my Mainsail software. The other camera is blank. image Attempting to log into the raspiCamSrv on port 5000 returns badly formatted HTML: image In sudo journalctl -e, I see these errors:

Apr 04 18:13:07 gemeaux flask[1073]: 192.168.68.67 - - [04/Apr/2024 18:13:07] "GET /photo_feed2?bypassCache=1712268787255 HTTP/1.1" 200 -
Apr 04 18:13:07 gemeaux flask[1073]: 192.168.68.67 - - [04/Apr/2024 18:13:07] "GET /photo_feed2?bypassCache=1712268787380 HTTP/1.1" 200 -
Apr 04 18:13:07 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:07 gemeaux flask[1073]: 192.168.68.67 - - [04/Apr/2024 18:13:07] "GET /photo_feed2?bypassCache=1712268787477 HTTP/1.1" 200 -
Apr 04 18:13:08 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:08 gemeaux kernel: rp1-cfe 1f00110000.csi: Using a link rate of 816 Mbps
Apr 04 18:13:09 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:09 gemeaux flask[1073]: Exception in thread Thread-3 (listen):
Apr 04 18:13:09 gemeaux flask[1073]: Traceback (most recent call last):
Apr 04 18:13:09 gemeaux flask[1073]:   File "/usr/lib/python3.11/threading.py", line 1038, in _bootstrap_inner
Apr 04 18:13:09 gemeaux flask[1073]:     self.run()
Apr 04 18:13:09 gemeaux flask[1073]:   File "/usr/lib/python3.11/threading.py", line 975, in run
Apr 04 18:13:09 gemeaux flask[1073]:     self._target(*self._args, **self._kwargs)
Apr 04 18:13:09 gemeaux flask[1073]:   File "/usr/lib/python3/dist-packages/picamera2/picamera2.py", line 90, in listen
Apr 04 18:13:09 gemeaux flask[1073]:     callback()
Apr 04 18:13:09 gemeaux flask[1073]:   File "/usr/lib/python3/dist-packages/picamera2/picamera2.py", line 107, in handle_request
Apr 04 18:13:09 gemeaux flask[1073]:     self.cameras[req.cookie]._requests += [CompletedRequest(req, self.cameras[req.cookie])]
Apr 04 18:13:09 gemeaux flask[1073]:                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 04 18:13:09 gemeaux flask[1073]:   File "/usr/lib/python3/dist-packages/picamera2/request.py", line 108, in __init__
Apr 04 18:13:09 gemeaux flask[1073]:     self.config = self.picam2.camera_config.copy()
Apr 04 18:13:09 gemeaux flask[1073]:                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 04 18:13:09 gemeaux flask[1073]: AttributeError: 'NoneType' object has no attribute 'copy'
Apr 04 18:13:10 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:11 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:12 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:13 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:14 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.
Apr 04 18:13:15 gemeaux kernel: rp1-cfe 1f00128000.csi: csi2_ch0 node link is not enabled.

I am willing to believe that some of these errors may be related to the Arducam IMX519 driver that my cameras use, but I thought I would ask you here for your thoughts. Thanks again for all of your assistance so far. I would be happy to donate some funds to you via PayPal/whatever to offset some of the time you have spent on helping me troubleshoot.

signag commented 3 months ago

After wiping out the old release, and updating to the latest release,

How did you do this?
It seems that your installation is inconsistent.

The normal way to make an update with git is:
cd ~/prg/raspi-cam-srv
sudo systemctl stop raspiCamSrv.service git pull sudo systemctl start raspiCamSrv.service

OldGuyMeltsPlastic commented 3 months ago

sudo systemctl stop raspiCamSrv.service

I took the brute force approach:

sudo systemctl stop raspiCamSrv.service
sudo rm -f /etc/systemd/system/raspiCamSrv.service
sudo rm -fr ~/prg

Then reinstalled raspiCamSrv following your installation instructions.

signag commented 3 months ago

I repeated your steps on a Pi Zero, just in order to make sure that I did not miss anything.
Everything was as it should be.
And I do not expect that this would be different on a (normal) Pi5.

From your screenshot, it seems that Flask did not load the stylesheet.
Did you see any error messages during installation, probably because of network issues?

Two additional remarks:
In order to completely remove a service configuration from the system, you should also disable it in addition to stopping it:
sudo systemctl disable raspiCamSrv.service

I understand that kTAMV is also using the cameras.
From what I know about Picamera2, there would be a conflict if two processes try to use a camera.
Probably, the situation is special for the ArduCams if you are running special drivers.

OldGuyMeltsPlastic commented 3 months ago

I repeated your steps on a Pi Zero, just in order to make sure that I did not miss anything. Everything was as it should be. And I do not expect that this would be different on a (normal) Pi5.

From your screenshot, it seems that Flask did not load the stylesheet. Did you see any error messages during installation, probably because of network issues?

No errors appeared during installation. When the style sheet does not load, it is always after powering up or rebooting the Pi 5, and loading the background raspiCamSrv.service, then navigating to 192.168.68.250:5000 in the browser, which eventually times out before it can display the properly formatted web server page. If I immediately stop the background service, and run the flask command to start the app from the command line, the web server page is displayed properly as expected.

Two additional remarks: In order to completely remove a service configuration from the system, you should also disable it in addition to stopping it: sudo systemctl disable raspiCamSrv.service

Noted.

I understand that kTAMV is also using the cameras. From what I know about Picamera2, there would be a conflict if two processes try to use a camera. Probably, the situation is special for the ArduCams if you are running special drivers.

kTAMV is not running at all (the ktamv_server.service is no longer in /etc/systemd/system).

Crowsnest is running, and detects that the two Arducam IMX519s are connected, but is only configured to use a third camera, which is a USB Microscope on /dev/video0, using libcamera.

I will again run some further testing after disabling both the Crowsnest and kTAMV services, and unplugging the USB Microscope, just to minimize any further confusion.

OldGuyMeltsPlastic commented 3 months ago

Same behaviour, on power up from being turned off, the printer initializes, and in Mainsail, I see only the camera feed from http://192.168.68.250:5000/photo_feed2. The camera feed from http://192.168.68.250:5000/photo_feed is not shown.

In sudo journalctl -e, I see:

Apr 05 08:37:45 gemeaux python3[1055]: 2024-04-05 08:37:45 mobileraker.default INFO Updated companion meta data in moonraker database
Apr 05 08:37:46 gemeaux flask[1057]:  * Serving Flask app 'raspiCamSrv'
Apr 05 08:37:46 gemeaux flask[1057]:  * Debug mode: off
Apr 05 08:37:46 gemeaux flask[1057]: WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
Apr 05 08:37:46 gemeaux flask[1057]:  * Running on all addresses (0.0.0.0)
Apr 05 08:37:46 gemeaux flask[1057]:  * Running on http://127.0.0.1:5000
Apr 05 08:37:46 gemeaux flask[1057]:  * Running on http://192.168.68.250:5000
Apr 05 08:37:46 gemeaux flask[1057]: Press CTRL+C to quit
Apr 05 08:37:47 gemeaux python[1054]: [klippy_connection.py:_request_initial_subscriptions()] - Webhooks Subscribed
Apr 05 08:37:47 gemeaux python[1054]: [klippy_connection.py:_request_initial_subscriptions()] - GCode Output Subscribed
Apr 05 08:37:47 gemeaux python[1054]: [job_state.py:_handle_started()] - Job state initialized: standby
Apr 05 08:37:47 gemeaux python[1054]: [klippy_connection.py:_check_ready()] - Klippy ready
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Klippy has reported a ready state
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Doing a (Re)Sync with moonraker
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Syncing klippy Objects
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Received server info: {'jsonrpc': '2.0', 'result': {'klippy_connected': True, 'klippy_state': 'ready', 'components': ['secrets', 'template', 'klipp>
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Syncing printer Objects
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Subscribing to printer Objects: dict_keys(['gcode_move', 'print_stats', 'virtual_sdcard', 'display_status', 'gcode_macro TIMELAPSE_TAKE_FRAME', 'fi>
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Syncing klippy Objects
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Received server info: {'jsonrpc': '2.0', 'result': {'klippy_connected': True, 'klippy_state': 'ready', 'components': ['secrets', 'template', 'klipp>
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Syncing printer Objects
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Subscribing to printer Objects: dict_keys(['gcode_move', 'print_stats', 'virtual_sdcard', 'display_status', 'gcode_macro TIMELAPSE_TAKE_FRAME', 'fi>
Apr 05 08:37:47 gemeaux python[1054]: [authorization.py:_check_trusted_connection()] - Trusted Connection Detected, IP: 192.168.68.67
Apr 05 08:37:47 gemeaux python[1054]: [application.py:log_request()] - 101 GET /websocket (192.168.68.67) [_TRUSTED_USER_] 1.09ms
Apr 05 08:37:47 gemeaux python[1054]: [websockets.py:open()] - Websocket Opened: ID: 140734629484560, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/53>
Apr 05 08:37:47 gemeaux python[1054]: [websockets.py:_handle_identify()] - Websocket 140734629484560 Client Identified - Name: mainsail, Version: 2.10.0, Type: web
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Subscribing to printer Objects
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO (Re)Sync completed
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO Subscribed to printer Objects
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default.sync INFO (Re)Sync completed
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO No last snapshot available. Evaluating!
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO Snapshot passed threshold. LastSnap: None, NewSnap: PrinterSnapshot(klippy_ready=True, print_state=standby, m117=None, m117_hash=, virtual_sdcard=Virtua>
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO Fetched 1 app Cfgs!
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO Evaluate for machineID ae47ae8a-cfbb-4bef-8d35-5925d2d7f49c, cfg.version: 2.6.14-android , cfg.snap: NotificationSnap(progress=0, progress_live_activity>
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO 0 Notifications for machineID: ae47ae8a-cfbb-4bef-8d35-5925d2d7f49c: state: False, proggress: False, M117 False, GcodeResponse: False, LiveActivity: Fal>
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO No snap update necessary for ae47ae8a-cfbb-4bef-8d35-5925d2d7f49c
Apr 05 08:37:47 gemeaux python3[1055]: 2024-04-05 08:37:47 mobileraker.default INFO ---- Completed Evaluations Task! ----
Apr 05 08:37:48 gemeaux python[1054]: [data_store.py:_init_sensors()] - Configuring available sensors: ['heater_bed', 'temperature_sensor cartographer_coil', 'temperature_fan pi_5', 'temperature_sensor octopus', 'extruder', 'extruder1']
Apr 05 08:37:48 gemeaux flask[1057]: [0:00:19.423535061] [1260] ERROR Camera camera.cpp:675 Camera in Acquired state trying acquire() requiring state Available
Apr 05 08:37:48 gemeaux flask[1057]: picamera2.picamera2 ERROR: Camera __init__ sequence did not complete.
Apr 05 08:37:48 gemeaux flask[1057]: [2024-04-05 08:37:48,528] ERROR in camera_pi: Thread 140734421594496: Camera.initCamera - Error Camera __init__ sequence did not complete.
Apr 05 08:37:48 gemeaux flask[1057]: 192.168.68.67 - - [05/Apr/2024 08:37:48] "GET /photo_feed?bypassCache=1712320703763 HTTP/1.1" 200 -
Apr 05 08:37:48 gemeaux kernel: source of link 'rp1-cfe-fe_config':0->'pisp-fe':1 is not a V4L2 sub-device, driver bug!
Apr 05 08:37:48 gemeaux kernel: rp1-cfe 1f00128000.csi: Using a link rate of 816 Mbps
Apr 05 08:37:49 gemeaux KlipperScreen-start.sh[1014]: 2024-04-05 08:37:49,102 [KlippyWebsocket.py:connect()] - Attempting to connect

The web server page on port 5000 takes a long time to load, but did eventually show a properly formatted page with the style sheet loaded, however, no camera feed is shown on the Live tab, and if I try to click over to the Web Cam tab, the page does not finish loading (note the spinning circle icon in the left of the browser tab): image

Looking back in sudo journalctl -e, I then see this:

Apr 05 08:39:49 gemeaux flask[1057]: 192.168.68.67 - - [05/Apr/2024 08:39:49] "GET /photo_feed2?bypassCache=1712320789636 HTTP/1.1" 200 -
Apr 05 08:39:50 gemeaux kernel: rp1-cfe 1f00110000.csi: Using a link rate of 816 Mbps
Apr 05 08:39:52 gemeaux flask[1057]: Exception in thread Thread-3 (listen):
Apr 05 08:39:52 gemeaux flask[1057]: Traceback (most recent call last):
Apr 05 08:39:52 gemeaux flask[1057]:   File "/usr/lib/python3.11/threading.py", line 1038, in _bootstrap_inner
Apr 05 08:39:52 gemeaux flask[1057]:     self.run()
Apr 05 08:39:52 gemeaux flask[1057]:   File "/usr/lib/python3.11/threading.py", line 975, in run
Apr 05 08:39:52 gemeaux flask[1057]:     self._target(*self._args, **self._kwargs)
Apr 05 08:39:52 gemeaux flask[1057]:   File "/usr/lib/python3/dist-packages/picamera2/picamera2.py", line 90, in listen
Apr 05 08:39:52 gemeaux flask[1057]:     callback()
Apr 05 08:39:52 gemeaux flask[1057]:   File "/usr/lib/python3/dist-packages/picamera2/picamera2.py", line 107, in handle_request
Apr 05 08:39:52 gemeaux flask[1057]:     self.cameras[req.cookie]._requests += [CompletedRequest(req, self.cameras[req.cookie])]
Apr 05 08:39:52 gemeaux flask[1057]:                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 05 08:39:52 gemeaux flask[1057]:   File "/usr/lib/python3/dist-packages/picamera2/request.py", line 108, in __init__
Apr 05 08:39:52 gemeaux flask[1057]:     self.config = self.picam2.camera_config.copy()
Apr 05 08:39:52 gemeaux flask[1057]:                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 05 08:39:52 gemeaux flask[1057]: AttributeError: 'NoneType' object has no attribute 'copy'
Apr 05 08:43:24 gemeaux PackageKit[1243]: daemon quit
Apr 05 08:43:24 gemeaux systemd[1]: packagekit.service: Deactivated successfully.
OldGuyMeltsPlastic commented 3 months ago

I also have 2x Raspberry Pi Camera Rev 1.3 that I can try in place of the 2x Arducam imx519. That should hopefully confirm or rule out an issue with the Arducam imx519 driver.

signag commented 3 months ago

The error at 08:37:48 from picamera2, saying "Camera __init__ sequence did not complete" indicates that Picamera2 or libcamera could not initiate the camera. In most cases, I have seen so far, this occurs when another process uses the camera. Maybe also that there is some kind of incomatibility with your camera drivers.

From what can be read on the ArduCam web page, these cameras should be "fully compatible with Raspberry Pi without installing any additional drivers"
However, from what I read here, ArduCam assures compatibility with Picamera2 only on Bullseye systems whereas you are running Bookworm on the Pi5.

Probably, the kTAMV installation has installed an additional driver making these cameras accessible for kTAMV also under Bookworm. They might be incompatible with Picamera2 and they might be active even if the kTAMV service is not running.
This might possibly explain why raspiCamSrv worked when kTAMV had been uninstalled.

I am very sorry, but I am afraid that I cannot help with your specific system setup.

Probably, in order to clarify the situation, it would be worthwile, running some basic Picamera2 example routines which you may find in the Picamera2 repository.
Or you might possibly learn something if you increase the log levels of Picamera2 and libcamera as described in the raspiCamSrv Troubleshooting Guide

RaspiCamSrv is fully based on Picamera2 and can only work if Picamera2 works.

OldGuyMeltsPlastic commented 3 months ago

Understood. I will confirm with the developer of kTAMV if his code installs any such additional drivers.

Current state is that the Arducam imx519 overlays in /boot/firmware/config.txt have been commented out, and camera_auto_detect=1 is uncommented.

Both Arducams have been replaced with original Raspberry Pi Camera v1.3s.

I will run some higher level tests using picamera2 and troubleshoot at that layer until I get consistently good results.

Then I will come back to raspi-cam-srv and work from a known good baseline with picamera2.

Thank you again for all of your time and guidance. I recognize that my particular configuration is obviously not normal usage.

Have a great weekend!