Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

default web client not getting any notifications/not connecting to websocket ? #62

Closed
landryb opened this issue Mar 12, 2021 · 7 comments
Closed

default web client not getting any notifications/not connecting to websocket ? #62

landryb opened this issue Mar 12, 2021 · 7 comments

Comments

@landryb
Copy link

landryb commented Mar 12, 2021

Dunno if this issue is similar to #50 or #59 but opening a new one to avoid squatting them..
i've successfully setup notify_push, can connect to it via an app password and test_client,

INFO [test_client] Supported capabilities: ["activity", "bruteforce", "core", "dav", "files", "files_sharing", "notify_push", "ocm", "spreed", "theming", "user_status", "weather_status"]
Found push server at wss://fqdn/push/ws
Authenticated

i see update notifications in the notify_push debug output when uploading a file,

Mar 12 07:48:13 web3 notify_push[27730]: [2021-03-12 07:48:13.919262 +01:00] DEBUG [notify_push] src/lib.rs:370: Received storage update notification for storage 3 and path files
Mar 12 07:48:13 web3 notify_push[27730]: [2021-03-12 07:48:13.983078 +01:00] DEBUG [notify_push] src/lib.rs:370: Received storage update notification for storage 3 and path files/tmp-u6p.xpi

i see pings being sent to test_client

Mar 12 07:48:23 web3 notify_push[27730]: [2021-03-12 07:48:23.921300 +01:00] DEBUG [notify_push::connection] src/connection.rs:106: Sending ping to blandry
Mar 12 07:48:53 web3 notify_push[27730]: [2021-03-12 07:48:53.922449 +01:00] DEBUG [notify_push::connection] src/connection.rs:106: Sending ping to blandry

i see that there's a tcp connection between notify_push and my front nginx reverse proxy (172.20.97.21 is the external IP, 10.0.7.1 is the internal NAT'ed IP of the reverse proxy)

State      Recv-Q      Send-Q                Local Address:Port                  Peer Address:Port
ESTAB      0           0                         10.0.7.11:42600                 172.20.97.21:https       users:(("test_client",pid=27839,fd=3))
ESTAB      0           0                         10.0.7.11:http                      10.0.7.1:59764       users:(("nginx",pid=27047,fd=3))

and a tcp connection between my backend nginx server and notify_push (two nginx stacked)

ESTAB      0           0                         127.0.0.1:35300                    127.0.0.1:7867        users:(("nginx",pid=27047,fd=11))
ESTAB      0           0                         127.0.0.1:7867                     127.0.0.1:35300       users:(("notify_push",pid=27730,fd=11))

i also see some valid metrics:

$curl http://localhost:8867/metrics
active_connection_count 1
total_connection_count 1
mapping_query_count 13
event_count_total 42
message_count_total 0
  • so all in all, seems pretty good.

my instance uses user_ldap and user_cas modules, auth via webdav and web works fine.

but strangely, i dont see usage by the web client interface. no wss connection between my web browser and notify_push (checked in the network tab of dev console), while i would expect to see a permanent connection..

i only see some ajax pings from time to time on https://fqdn/ocs/v2.php/apps/user_status/api/v1/user_status and https://fqdn/apps/user_status/heartbeat.

Not knowing if it was related or not (as the doc doesnt mention a clear dependency on it ?) i went to the activity app parameters for my user and clicked 'push' so that every event should create 'something', but i only see events (file creations, shares between users) in notify_push debug output, nothing on the web client.

So... in what workflow/usecase is notify_push used, and how to enable it for web client ? my understanding was that the desktop clients was using another mechanism, but i'm not sure anymore now...
@icewind1991
Copy link
Member

It should be used automatically for notifications in the web interface if notify_push is setup.

Is there anything in the notify_push log when you reload the page?

@landryb
Copy link
Author

landryb commented Mar 12, 2021

no there's nothing in notify_push debug log when a web client reloads the page. That isnt much a surprise since there's no websocket connection to the page in the network console....

the debug log only contains server side events (file uploads, etc..)
when i redo the self-test:

[12/03 12:48] landry@web3.fluela:/data/web/www/nextcloud/apps/notify_push $occ notify_push:self-test
✓ redis is configured
✓ push server is receiving redis messages
✓ push server can load mount info from database
✓ push server can connect to the Nextcloud server
✓ push server is a trusted proxy
✓ push server is running the same version as the app

i get plenty of debug output so that part seems to work

Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.087872 +01:00] DEBUG [notify_push] src/lib.rs:370: Received test cookie 228954095
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.384047 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 8 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.384141 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is empty
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.384681 +01:00] DEBUG [notify_push] src/lib.rs:229: current test cookie is 228954095
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.384870 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:248: flushed 125 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.385171 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:208: read eof
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.461477 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 8 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.461545 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is empty
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.461626 +01:00] DEBUG [notify_push::storage_mapping] src/storage_mapping.rs:96: querying storage mapping for 1
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.476877 +01:00] INFO [sqlx::query] <unnamed>:0: SELECT user_id, path FROM …; rows: 1, elapsed: 12.535ms
Mar 12 12:48:48 web3 notify_push[27730]: SELECT
Mar 12 12:48:48 web3 notify_push[27730]:   user_id,
Mar 12 12:48:48 web3 notify_push[27730]:   path
Mar 12 12:48:48 web3 notify_push[27730]: FROM
Mar 12 12:48:48 web3 notify_push[27730]:   oc_mounts
Mar 12 12:48:48 web3 notify_push[27730]:   INNER JOIN oc_filecache ON root_id = fileid
Mar 12 12:48:48 web3 notify_push[27730]: WHERE
Mar 12 12:48:48 web3 notify_push[27730]:   storage_id = 1
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.476964 +01:00] DEBUG [notify_push] src/lib.rs:259: storage mapping count for 1 = 1
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.477072 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:248: flushed 117 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.477281 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:208: read eof
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.479932 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 8 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.479984 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is empty
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.486130 +01:00] DEBUG [reqwest::connect] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.11.1/src/connect.rs:529: starting new connection: https://drive.dev.craig.fr/
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.486243 +01:00] DEBUG [hyper::client::connect::dns] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/connect/dns.rs:121: resolving host="drive.dev.craig.fr"
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.487371 +01:00] DEBUG [hyper::client::connect::http] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/connect/http.rs:528: connecting to 172.20.97.21:443
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.487637 +01:00] DEBUG [hyper::client::connect::http] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/connect/http.rs:531: connected to 172.20.97.21:443
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.489729 +01:00] DEBUG [rustls::client::hs] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/hs.rs:204: Resuming session
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.531231 +01:00] DEBUG [rustls::client::hs] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/hs.rs:430: ALPN protocol is Some(b"http/1.1")
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.531297 +01:00] DEBUG [rustls::client::hs] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/hs.rs:598: Using ciphersuite TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.541225 +01:00] DEBUG [rustls::client::hs] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/hs.rs:673: Server supports tickets
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.541348 +01:00] DEBUG [rustls::client::tls12] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/tls12.rs:209: ECDHE curve is ECParameters { curve_type: NamedCurve, named_group: X25519 }
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.541407 +01:00] DEBUG [rustls::client::tls12] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/tls12.rs:508: Server DNS name is DNSName("drive.dev.craig.fr")
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.543168 +01:00] DEBUG [rustls::client::tls12] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/client/tls12.rs:766: Session saved
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.543520 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:270: flushed 95 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.640592 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 22 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.640657 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is content-length (9 bytes)
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.640831 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:225: incoming body completed
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.640951 +01:00] DEBUG [hyper::client::pool] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/pool.rs:374: pooling idle connection for ("https", drive.dev.craig.fr)
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.641085 +01:00] DEBUG [reqwest::async_impl::client] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.11.1/src/async_impl/client.rs:1521: response '200 OK' for https://drive.dev.craig.fr/index.php/apps/notify_push/test/cookie
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.659724 +01:00] DEBUG [notify_push] src/lib.rs:238: got remote test cookie 228954095
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.659850 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:248: flushed 125 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.660125 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:208: read eof
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.662691 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 8 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.662747 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is empty
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.662876 +01:00] DEBUG [hyper::client::pool] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/pool.rs:248: reuse idle connection for ("https", drive.dev.craig.fr)
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.663051 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:270: flushed 121 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725363 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 23 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725430 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is content-length (7 bytes)
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725471 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:225: incoming body completed
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725539 +01:00] DEBUG [hyper::client::pool] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/pool.rs:374: pooling idle connection for ("https", drive.dev.craig.fr)
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725574 +01:00] DEBUG [reqwest::async_impl::client] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/reqwest-0.11.1/src/async_impl/client.rs:1521: response '200 OK' for https://drive.dev.craig.fr/index.php/apps/notify_push/test/remote
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725642 +01:00] DEBUG [notify_push] src/lib.rs:283: got remote 1.2.3.4 when trying to set remote 1.2.3.4
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725748 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:248: flushed 123 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.725950 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:208: read eof
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.728770 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 9 headers
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.728831 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is empty
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.730212 +01:00] DEBUG [hyper::proto::h1::io] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:248: flushed 119 bytes
Mar 12 12:48:48 web3 notify_push[27730]: [2021-03-12 12:48:48.730380 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:208: read eof

the binary used by the service is the one in the notify_push.tar.gz tarball attached to the release page on https://github.com/nextcloud/notify_push/releases/tag/v0.1.6

the only 'complex' setup i have is:

  • the usage of user_cas/user_ldap for auth, but that works fine for eg webdav, and since notify_push IP is in trusted_proxies that shouldnt matter ?
  • the two nginx stacked (one for the reverse proxy, one for the nextcloud instance) but both properly pass websockets since test_client works:
    reverse proxy:
# block is inside a large location / block
                location /push/ {
                        proxy_http_version 1.1;
                        proxy_set_header Upgrade $http_upgrade;
                        proxy_set_header Connection "Upgrade";
                        proxy_set_header Host                   $host;
                        proxy_set_header X-Forwarded-Host       $host;
                        proxy_set_header X-Forwarded-Proto      $scheme;
                        proxy_set_header X-Real-IP              $remote_addr;
                        proxy_set_header X-Forwarded-For        $proxy_add_x_forwarded_for;
                        proxy_pass      http://drive_dev_backend;
                }
# drive_dev_backend points at the webserver IP in an LXC container

webserver:

# block in the nextcloud vhost
        location /push/ {
                proxy_pass http://127.0.0.1:7867/;
                proxy_http_version 1.1;
                proxy_set_header Upgrade $http_upgrade;
                proxy_set_header Connection "Upgrade";
                proxy_set_header Host $host;
                proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        }

@landryb
Copy link
Author

landryb commented Mar 12, 2021

oh and of course i have zero hits on /push/ in both web servers, the only hits i got for that location were from test_client or from self-test:

10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/cookie HTTP/1.1" 200 9 "-" "Nextcloud Server Crawler" 0.063
10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/mapping/1 HTTP/1.1" 200 1 "-" "Nextcloud Server Crawler" 0.016
10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "GET /index.php/apps/notify_push/test/cookie HTTP/1.1" 200 9 "-" "-" 0.097
10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/reverse_cookie HTTP/1.1" 200 9 "-" "Nextcloud Server Crawler" 0.180
10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "GET /index.php/apps/notify_push/test/remote HTTP/1.1" 200 7 "-" "-" 0.061
10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/remote/1.2.3.4 HTTP/1.1" 200 7 "-" "Nextcloud Server Crawler" 0.063
10.0.7.11 10.0.7.11 - [12/Mar/2021:12:48:48 +0100] "POST /push/test/version HTTP/1.1" 200 3 "-" "Nextcloud Server Crawler" 0.002

10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/cookie HTTP/1.1" 200 9 "-" "Nextcloud Server Crawler" 0.064 "-"
10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/mapping/1 HTTP/1.1" 200 1 "-" "Nextcloud Server Crawler" 0.017 "-"
10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "GET /index.php/apps/notify_push/test/cookie HTTP/1.1" 200 9 "-" "-" 0.097 "-"
10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/reverse_cookie HTTP/1.1" 200 9 "-" "Nextcloud Server Crawler" 0.181 "-"
10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "GET /index.php/apps/notify_push/test/remote HTTP/1.1" 200 7 "-" "-" 0.062 "-"
10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "GET /push/test/remote/1.2.3.4 HTTP/1.1" 200 7 "-" "Nextcloud Server Crawler" 0.063 "-"
10.0.7.11 https/TLSv1.2 10.0.7.11:80 - [12/Mar/2021:12:48:48 +0100] "POST /push/test/version HTTP/1.1" 200 3 "-" "Nextcloud Server Crawler" 0.002 "-"

i dont see anything directly related to notify_push in the browser console either, be it information/debug/log types.. oh and that's with firefox 87 beta on openbsd, but i get the same with firefox 86 on windows 7.

The only 'strange' thing i see from time to time, more or less every time i ran the self testing, 65 seconds later i get this in the debug log:

Mar 12 12:49:53 web3 notify_push[27730]: [2021-03-12 12:49:53.728083 +01:00] DEBUG [rustls::session] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.19.0/src/session.rs:806: Sending warning alert CloseNotify
Mar 12 12:49:53 web3 notify_push[27730]: [2021-03-12 12:49:53.728302 +01:00] DEBUG [hyper::proto::h1::conn] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:674: error shutting down IO: Socket not connected (os error 107)
Mar 12 12:49:53 web3 notify_push[27730]: [2021-03-12 12:49:53.728412 +01:00] DEBUG [hyper::client::client] /home/robin/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/client.rs:470: client connection error: error shutting down connection: Socket not connected (os error 107)

but that doesnt seem related to a real user connection, i guess it's linked to self-test connection being not properly torn down ?

@syntron
Copy link

syntron commented Mar 14, 2021

I would also be interested in a test case from the web client. If there is anything I can test, I will do it to provide additional input.

@landryb
Copy link
Author

landryb commented Apr 22, 2021

i've retested with 0.1.7, and it's still the same thing, test_client correctly connects and works (i see notifications creating and removing a file)

$./test_client https://fqdn user pass
Found push server at wss://fqdn/push/ws
Authenticated
Received file update notification
Received file update notification

but nothing seem to come from the web UI. i see zero websocket connection in the browser console either.

besides enabling the application, is there something else to do in nextcloud to get the js client to connect to the websocket ? enabling something around the notifications ? my test user has push notifications for file modifications enabled in its preferences.

what js part client-side should initiate the websocket connection to /push/ ?

@landryb landryb mentioned this issue Apr 22, 2021
Closed
@landryb
Copy link
Author

landryb commented Apr 22, 2021

looking at bit more, it really seems everything server side is properly configured, as notify_push capabilities are advertised in the capabilities json document returned by the API:

curl -H 'OCS-APIREQUEST: true' -H 'Accept: application/json' -u user https://FQDN/ocs/v2.php/cloud/capabilities
...
            "notify_push" : {
               "type" : [
                  "files",
                  "activities",
                  "notifications"
               ],
               "endpoints" : {
                  "websocket" : "wss://FQDN/push/ws",
                  "pre_auth" : "https://FQDN/apps/notify_push/pre_auth"
               }
            },

so it looks to me that everything serverside works, it's just that nothing in the web client consumes/uses the push API it yet ? i dont see any mention of the nodejs lib (https://www.npmjs.com/package/@nextcloud/notify_push) included in the nextcloud/server repository, but reading the announcement at https://nextcloud.com/blog/nextcloud-faster-than-ever-introducing-files-high-performance-back-end/ it says

we also implemented this in the web interface, which also checks every 30 seconds! A user with 3 tabs open is polling the server 3 times every 30 seconds, 10 tabs means a ping every 3 seconds, all day long.

but i'm not seeing those improvements after having setupped everything ? or it's only working in chrome ? in certain apps ?

@landryb
Copy link
Author

landryb commented Apr 23, 2021

ok, i think i got it. the files app itself (ie the one bundled in nextcloud/server repo at https://github.com/nextcloud/server/tree/master/apps/files) has no support (yet?) for refreshing itself when receiving a notification, since it doesnt directly use/import the nodejs notify_push client.

but the notifications app has support for that since nextcloud/notifications#835, and since my nextcloud install is from a git checkout of nextcloud/server repo i dont have the notifications app installed.

once i had notifications app installed and enabled, after reloading the page i indeed have the notifications icon at the top right, and there's a websocket connection made to notify_push backend. if i upload a file via webdav, i see a notify_file event being sent on the websocket connection, so that works but the files app doesnt react to such event/refresh the web UI.

so, in the end, maybe a bug should be filed against files app to react to notify_file events ?

in the meantime, closing this issue, notify_push backend itself works. maybe the doc should mention that it relies on having the notifications app installed and enabled :)

@landryb landryb closed this as completed Apr 23, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@icewind1991 @landryb @syntron