Live view camera not displayed because of web socket error 'ws close 1006'

ldfsilva commented 1 year ago

Describe the bug The camera video is not displayed in the live view option, instead the browser displays a ws close: 1006 error message after the camera of choice is selected.

To Reproduce Steps to reproduce the behavior:

Log-in (top-right corner)
Go to hamburger menu icon 'Moonfire NVR'
Click on 'Live view (experimental)'
Select camera of choice in the camera drop down
See error on bottom left corner of the page

Expected behavior The camera live video to be displayed.

Screenshots

Server (please complete the following information):

If using Docker: docker ps + docker images

$ docker ps -f name=moonfire-nvr
CONTAINER ID   IMAGE                           COMMAND                  CREATED       STATUS             PORTS     NAMES
3635a92f6506   scottlamb/moonfire-nvr:v0.7.5   "/usr/local/bin/moon…"   4 weeks ago   Up About an hour             moonfire-nvr

$ docker images |grep nvr
scottlamb/moonfire-nvr                  v0.7.5    e2149aaf02d2   13 months ago   362MB

Camera (please complete the following information):

Camera manufacturer and model: Amcrest IP2M-841
Software Version 2.520.AC00.18.R, Build Date: 2017-06-29
WEB Version 3.2.1.453504
ONVIF Version 2.42(V2.2.2.428697)

Desktop (please complete the following information):

OS OSX
Browser FireFox
Version 114.0.2 (64-bit)

Additional context The error seem related to a failure in establishing a connection below are the errors displayed in the Firefox developer tools. Note that this isn't browser specific, I've also attempted it on Chrome without luck.

10:20:00.214 tuco: starting stream: sourceopen LiveCamera.tsx:92:12
10:20:00.246 GETws://192.168.0.200:8080/api/cameras/8122bbde-f971-4c9a-9fe6-4eddb3d25e35/sub/live.m4s 
10:20:00.329 Firefox can’t establish a connection to the server at ws://192.168.0.200:8080/api/cameras/8122bbde-f971-4c9a-9fe6-4eddb3d25e35/sub/live.m4s. LiveCamera.tsx:98:14
10:20:00.334 tuco: ws error LiveCamera.tsx:121:12
10:20:00.342 tuco: aborting due to ws close: 1006 LiveCamera.tsx:106:12
10:20:00.343 tuco: stopping stream: ws close: 1006 LiveCamera.tsx:284:12

errors:

GET: stack trace

ldfsilva commented 1 year ago

A dump from user_session, suspecting that user session isn't being used as expected.

sqlite> select user_id, hex(permissions), flags, use_count, last_use_time_sec, last_use_user_agent, domain, description, creation_user_agent, revocation_time_sec, revocation_user_agent, revocation_reason, revocation_reason_detail from user_session; 
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Linux; Android 13) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/114.0.5735.130 Mobile DuckDuckGo/5 Safari/537.36||||
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Linux; Android 13) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/113.0.5672.162 Mobile DuckDuckGo/5 Safari/537.36|1685972696|Mozilla/5.0 (Linux; Android 13) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/113.0.5672.162 Mobile DuckDuckGo/5 Safari/537.36|1|
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/113.0|1688403754|Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0|1|
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Mobile Safari/537.36||||
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36|1688406789|Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36|1|
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Mobile Safari/537.36|1688407234|Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Mobile Safari/537.36|1|
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36|1688406836|Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36|1|
1|080110011801|5|0|||192.168.0.200||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0||||
sqlite>

scottlamb commented 1 year ago

Hmm, you're reminding me that I'm overdue for making a new release. Current HEAD gives a better error message than ws close: 1006.

Do either of these two ideas from the version 0.7.5 troubleshooting guide help? https://github.com/scottlamb/moonfire-nvr/blob/v0.7.5/guide/troubleshooting.md#live-stream-always-fails-with-ws-close-1006

Also, I don't remember if it gives a better error message in this case or not, but the live view only works if the sub stream is enabled for the camera.

suspecting that user session isn't being used as expected

In that last screenshot with the GET, you can switch to the Headers tab and see if there's an s cookie or not.

ldfsilva commented 1 year ago

Do either of these two ideas from the version 0.7.5 troubleshooting guide help?

It did not, I have the sub-stream configured and set to recording. Recording is working fine, I can see those both for the main and sub streams.

In that last screenshot with the GET, you can switch to the Headers tab and see if there's an s cookie or not.

Confirmed that the cookie s is present. What called my attention here was the values under user_session table, more specifically user_count being 0 and last_use_time_sec empty, but I must say I don't know any better if they're working as intended or not, just assuming from their name. I'm poking more and will report in case I find anything, if you have ideas on how to narrow it down further, I'm all ears and can attempt those.

scottlamb commented 1 year ago

I think the next step might be to try with the updated code that has better error messages. I'll prepare a new release within the next day or two.

What called my attention here was the values under user_session table, more specifically user_count being 0 and last_use_time_sec empty

That seems to be a separate bug; those fields aren't being updated on my installation either. 😞 Filed #282.

scottlamb commented 1 year ago

v0.7.6 is released. Hopefully that either works or produces a more useful error message. Please let me know what you see.

ldfsilva commented 1 year ago

I upgraded from v0.7.5 to v0.7.6[1], interestingly enough the live view worked just fine in Firefox on the first login. After I logged out, it stopped and no longer works even after I logged out and logged back in.

I say it's interesting because the live view now does work as expected on my laptop, both in Chrome and Safari, also works just fine on my phone both on DuckDuckGo and Chrome. I cleared all Firefox cache, logged in/out, but no luck. For some reason it does not want to work there (still investigating).

Tailing the logs (sudo nvr logs -f) while attempting to log-in hasn't helped much, this is what's shown:

2023-07-08T12:45:16.721506  INFO tokio-runtime-worker request{id=01H4VGJZXHSR7N7WTYNHZ58BJY http.client_ip=192.168.0.11 http.method=GET http.target=/ http.status_code=304}: moonfire_nvr::web: sending response headers latency=0.000477s
2023-07-08T12:45:16.903431  INFO tokio-runtime-worker request{id=01H4VGK036RPKT41YS3SQ7B9S9 http.client_ip=192.168.0.11 http.method=GET http.target=/api/?days=true http.status_code=200}: moonfire_nvr::web: sending response headers latency=0.000910s
2023-07-08T12:45:22.948347  INFO tokio-runtime-worker request{id=01H4VGK5VEC37PQETZEGXBB3Q3 http.client_ip=192.168.0.11 http.method=POST http.target=/api/login http.status_code=204}: moonfire_nvr::web: sending response headers latency=0.149754s
2023-07-08T12:45:23.034259  INFO tokio-runtime-worker request{id=01H4VGK62SNZQJW6VBRPQCWBEA http.client_ip=192.168.0.11 http.method=GET http.target=/api/?days=true auth.user=leandro http.status_code=200}: moonfire_nvr::web: sending response headers latency=0.000421s
2023-07-08T12:45:38.327530  INFO tokio-runtime-worker request{id=01H4VGKN0QH22DDD36HP34G9H1 http.client_ip=192.168.0.11 http.method=GET http.target=/static/css/main.7cc71a4c.css.map auth.user=leandro http.status_code=304}: moonfire_nvr::web: sending response headers latency=0.000441s
2023-07-08T12:45:38.329112  INFO tokio-runtime-worker request{id=01H4VGKN0R1F43N1297Z1SQYE4 http.client_ip=192.168.0.11 http.method=GET http.target=/static/js/main.87590f24.js.map auth.user=leandro http.status_code=304}: moonfire_nvr::web: sending response headers latency=0.000229s
2023-07-08T12:46:10.041691  INFO tokio-runtime-worker request{id=01H4VGMKZSEGARTSGTM9K61976 http.client_ip=192.168.0.11 http.method=GET http.target=/static/js/main.87590f24.js.map auth.user=leandro http.status_code=304}: moonfire_nvr::web: sending response headers latency=0.000502s

and in the Firefox developer console I get:

Security Error: Content at http://192.168.0.200:6687/ may not load data from blob:http://192.168.0.200:6687/01fb11e5-d0fb-481b-b645-b33b4a7a0a85.

On additional good notes, use_count is now working and I did like the new log format adopted. While going through this, I've also noticed revocation_reason is not set correctly, notice it's set to 1 whereas according to the Schema logouts should be 0, minor thing, I'll file a separate issue for that one.

$ sqlite3 db/db "select user_id, hex(permissions), flags, use_count, last_use_time_sec, domain, revocation_reason, revocation_time_sec, revocation_reason_detail, description, creation_user_agent from user_session order by creation_time_sec;"
1|080110011801|5|3|1688842276|192.168.0.200|1|1688842276|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0
1|080110011801|5|5|1688843878|192.168.0.200|1|1688843878|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0
1|080110011801|5|15|1688843589|192.168.0.200|1|1688843589|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36
1|080110011801|5|7|1688843823|192.168.0.200|1|1688843823|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36
1|080110011801|5|5|1688843840|192.168.0.200|1|1688843840|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36
1|080110011801|5|12|1688844227|192.168.0.200|1|1688844227|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0
1|080110011801|5|12|1688845438|192.168.0.200|1|1688845438|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36
1|080110011801|5|10|1688845421|192.168.0.200|1|1688845421|||Mozilla/5.0 (Linux; Android 13) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/114.0.5735.196 Mobile DuckDuckGo/5 Safari/537.36
1|080110011801|5|9|1688845473|192.168.0.200|1|1688845473|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0
1|080110011801|5|7|1688845430|192.168.0.200|1|1688845430|||Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.5.1 Safari/605.1.15
1|080110011801|5|5|1688845411|192.168.0.200|1|1688845411|||Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Mobile Safari/537.36
1|080110011801|5|4|1688845570|192.168.0.200|||||Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/114.0

[1] upgrade process taken:

sudo nvr stop
sudo docker rename moonfire-nvr moonfire-nvr-v0.7.5
Modified /etc/moonfire-nvr.toml config to conform with the new camelCase standard
Modified /usr/local/bin/nvr to reflect the latest version image_name="scottlamb/moonfire-nvr:v0.7.6"
sudo nvr run

ldfsilva commented 1 year ago

Here's some additional details Firefox's dev console report:

Cookie “s” does not have a proper “SameSite” attribute value. Soon, cookies without the “SameSite” attribute or with an invalid value will be treated as “Lax”. This means that the cookie will no longer be sent in third-party contexts. If your application depends on this cookie being available in such contexts, please add the “SameSite=None“ attribute to it. To know more about the “SameSite“ attribute, read https://developer.mozilla.org/docs/Web/HTTP/Headers/Set-Cookie/SameSite

scottlamb commented 1 year ago

Huh. A couple things puzzle me there:

The warning about SameSite. We should be setting SameSite=Lax on new sessions, here and here. It's only a warning though so may not be the cause.
The may not load data from blob:.... I'm not even sure what the blob is. Best guess is it's an "object URL" for the video element, created here. I don't recall the origin rules for that, but it's working for me. Possibly because I'm using Chrome, because I'm using https, and/or because I don't have a port number in my URL.

I'll try doing a little testing in Firefox and see if I can reproduce...

scottlamb commented 1 year ago

Oh, actually, yes, I'm getting the same problem in Firefox 110.0.1 (64-bit) on macOS. So I have something I can play with anyway...

scottlamb commented 1 year ago

Did a little reading. I think we may need a Content-Security-Policy with something like media-source blob:*. Will play with this later.

scottlamb commented 1 year ago

I'd hoped this would help:

diff --git a/ui/public/index.html b/ui/public/index.html
index ca94e9b..73808e0 100644
--- a/ui/public/index.html
+++ b/ui/public/index.html
@@ -7,6 +7,7 @@
 <html lang="en">
   <head>
     <meta charset="utf-8" />
+    <meta http-equiv="Content-Security-Policy" content="media-src 'self' blob:">

     <link
       rel="apple-touch-icon"

but no. I can certainly break the page more with other values of this (pseudo-)header; e.g. changing media-src to default-src goes really badly unless I also add 'unsafe-inline'.

scottlamb commented 1 year ago

Oh, the SameSite warning is on logout. Makes a bit more sense now. I might tweak how that handler works to avoid the warning, although I don't think it's causing any actual problems.

I'm feeling stuck on this security error, though. :-(

scottlamb commented 11 months ago

I still haven't figured out the blob problem, which is super frustrating, but #286 is open for that.

I created #292 specifically for the logout problem.

I think that covers everything here but please pipe up if I missed something.

scottlamb / moonfire-nvr

Live view camera not displayed because of web socket error 'ws close 1006' #277