search

nextcloud / notify_push

Update notifications for nextcloud clients
GNU Affero General Public License v3.0
224 stars 40 forks source link

push server is not receiving redis messages #20

Open Luticus opened 3 years ago

Luticus commented 3 years ago

I have the redis server set up on a system on my network and nextcloud is configured to use it properly. It's been working a long time and through many version of nextcloud. Still working in NC21 too.

However when I attempt to go through the manual install (the auto install wouldn't work for me either) I get this message when setting the server location: push server is not receiving redis messages

I'm using the Nextcloud config.php file as recommended in the setup guide. Also I'm using an apache2 reverse proxy.

I do see the "redis is configured" message before the error where it tells me it's not receiving redis messages, so I assume that it's seeing the redis configuration.

To be specific my redis server runs on a different box and the redis settings in nextcloud's config.php point to the server:port of the redis server.

The OS is Debian 10

icewind1991 commented 3 years ago

can you run the binary with LOG=notify_push=trace environment variable and check the parsed config it outputs.

mnestor commented 3 years ago

Do you have a login app installed like sociallogin?

I have sociallogin installed for auth against keycloak and it appears that the test/cookie url path is causing a login redirect and failing the test for me.

nextcloud_app.1.i6bry5m7bjaw@dock01    | 10.0.9.35 - - [23/Feb/2021:13:56:32 -0500] "GET /push/test/cookie HTTP/1.1" 302 1559 "-" "Nextcloud Server Crawler"
nextcloud_app.1.i6bry5m7bjaw@dock01    | 10.0.9.35 - - [23/Feb/2021:13:56:32 -0500] "GET /login HTTP/1.1" 302 1560 "-" "Nextcloud Server Crawler"
nextcloud_app.1.i6bry5m7bjaw@dock01    | 10.0.9.35 - - [23/Feb/2021:13:56:32 -0500] "GET /apps/sociallogin/custom_oidc/keycloak HTTP/1.1" 302 1789 "-" "Nextcloud Server Crawler"

So it appears we need to go file a bug report with sociallogin?

edit: actually all the test paths. perhaps it needs to have an internal auth token it can use to bypass the auth requirement.

Luticus commented 3 years ago

@icewind1991 Well I see this:
The application panicked (crashed). Message: error binding to 0.0.0.0:80: error creating server listener: Permission denied (os error 13) Which makes sense, low ports need root to bind and you guys have the bin running as www-data I think.

-scratch that, this issue is mitigated with the systemd service setting the port to 7867. When I also set the LOG=notify_push=trace in the systemd service or even manually it doesn't really show much with a journalctl -fu notify_push.service. I checked the output on the file like you suggested and the redis output looks ok.

redis: ConnectionInfo { addr: Tcp("redis.example.com", ), db: 0, username: None, passwd: Some("") }

The port and password appear to be correct, I've obviously redacted them here though.

The log outputs DEBUG [notify_push] src/lib.rs:338: Received test cookie ######### when I attempt to do sudo -u www-data php occ notify_push:setup https://www.example.com/push

@mnestor I don't have sociallogin, but I do use the 2fa apps: Two-Factor TOTP Provider 6.0.0 Two-Factor U2F 6.1.0 Two-Factor Admin Support 3.0.0

I also use LDAP authentication, if that matters

I have noticed that there is an update to the Client Push app, so I'll test with that too and let you know. (issue still occurs on version 0.1.3)

Also food for thought, the directions say to install the notify_push app, which is the app name if you install via occ, but if you go to the gui nextcloud interface it's "Client Push". The directions should probably be updated to clarify that, I only found it because I knew to try it with occ app:install.

Chartman123 commented 3 years ago

Sorry for the wrong reference, I had a typo in my first commit message and I can't figure it out how to remove this reference here... 🙈

icewind1991 commented 3 years ago

DEBUG [notify_push] src/lib.rs:338: Received test cookie #########

Looks like it is getting the redis message but maybe there is something wrong with communicating that back to the nextcloud app.

0.1.4 adds a bit more info here during the self test

So it appears we need to go file a bug report with sociallogin?

edit: actually all the test paths. perhaps it needs to have an internal auth token it can use to bypass the auth requirement.

Those endpoints are all marked as public so I would say any app adding auth requirements for them is a problem with that app.

Luticus commented 3 years ago

With the newest version I get this: push server is not receiving redis messages (received 1005149735, got 0)

icewind1991 commented 3 years ago

@Luticus do you still get a DEBUG [notify_push] src/lib.rs:338: Received test cookie in the notify_push output?

andreaslutsch commented 3 years ago

After removing the nginx reverse proxy block and setting a local NEXTCLOUD_URL variable I also have this issue. The service seems to work, I think, but if I do notify_push:self_test or setup, then I also receive 🗴 push server is not receiving redis messages (received 211886646, got 0). I enabled the trace log and also see DEBUG [notify_push] src/lib.rs:360: Received test cookie 211886646 and also other debug lines like: Received storage update notification for storage 7 and path appdata_ocvey4ezdjce/text/documents/331972

DEBUG [notify_push::storage_mapping] src/storage_mapping.rs:96: querying storage mapping for 7 DEBUG [notify_push] src/lib.rs:360: Received storage update notification for storage 7 and path appdata_ocvey4ezdjce/text/documents DEBUG [notify_push] src/lib.rs:360: Received pre_auth user andreasus

I'm not sure if these mean that notify push works or not. I also updated to 0.1.5

Luticus commented 3 years ago

@icewind1991 I do, even with 0.1.5: DEBUG [notify_push] src/lib.rs:360: Received test cookie 1062812323

Luticus commented 3 years ago

0.1.6 doesn't seem to work either, same error about redis messages.

sudo -u www-data php occ notify_push:setup https://www.example.com/push [sudo] password for user: ✓ redis is configured 🗴 push server is not receiving redis messages (received 506331649, got 0)

brknkfr commented 3 years ago

I had the same problem and changing proxy_set_header Host $http_host; (in my case) to proxy_set_header Host $host; in my nginx config fixed it.

Luticus commented 3 years ago

@brknkfr I'm not sure if that will work for me unfortunately, as my Nextcloud is set up on an Apache server so I guess I need to see if there's something equivalent that I could try.

After looking at the nginx instructions, I get what you were saying. That particular directive you changed doesn't seem to match up with anything on the Apache side. I tried using: ProxyPass /push/ws ws://127.0.0.1:7867/ws ProxyPass /push/ http://127.0.0.1:7867/ ProxyPassReverse /push/ http://127.0.0.1:7867/

and even tried a ProxyPassReverse for the websocket, with no luck

even tried it like this: ProxyPass /push/ws ws://www.mydomain.com:7867/ws ProxyPass /push/ http://www.mydomain.com:7867/ ProxyPassReverse /push/ http://www.mydomain.com:7867/

Also tried it with ProxyPass set to use https instead. When using https is when i get the redis error. When using just http, I get this instead: sudo -u www-data php occ notify_push:setup https://www.mydomain.com/push ✓ redis is configured 🗴 can't connect to push server: Client error: GET https://www.mydomain.com/push/test/cookie resulted in a 404 Not Found response

and if i try like this: sudo -u www-data php occ notify_push:setup http://www.mydomain.com/push ✓ redis is configured 🗴 using unencrypted https for push server is strongly discouraged 🗴 can't connect to push server: Client error: GET http://www.mydomain.com/push/test/cookie resulted in a 404 Not Found response: Not found

you can see that doesn't seem to work either.

Nick-Git2 commented 3 years ago

I'm having the same issue using the latest version 1.7:

sudo -u www-data /var/www/nextcloud/occ notify_push:setup https://XXXXX/nextcloud/push ✓ redis is configured 🗴 push server is not receiving redis messages (received 904222169, got 0)

Debugging Log says:

Apr 13 22:58:10 debian systemd[1]: Started Push daemon for Nextcloud clients.

Apr 13 22:58:10 debian notify_push[1552]: [2021-04-13 22:58:10.507747 +02:00] TRACE [notify_push] src/main.rs:42: Running with config: Config { database: AnyConnectOptions(MySql(MySqlConnectOptions { host: "localhost", port: 3306, socket: None, username: "XXXXX", password: Some("XXXXX"), database: Some("XXXXX"), ssl_mode: Preferred, ssl_ca: None, statement_cache_capacity: 100, charset: "utf8mb4", collation: None, log_settings: LogSettings { statements_level: Info, slow_statements_level: Warn, slow_statements_duration: 1s } })), databaseprefix: "oc", redis: [ConnectionInfo { addr: Tcp("localhost", 6379), db: 0, username: None, passwd: None }], nextcloud_url: "https://XXXXX/nextcloud/", metrics_bind: None, log_level: "notify_push=trace", bind: Tcp(0.0.0.0:7867), allow_self_signed: false }

Apr 13 22:58:10 debian notify_push[1552]: [2021-04-13 22:58:10.509237 +02:00] DEBUG [notify_push::storage_mapping] src/storage_mapping.rs:96: querying storage mapping for 1 Apr 13 22:58:10 debian notify_push[1552]: [2021-04-13 22:58:10.579356 +02:00] TRACE [notify_push] src/main.rs:59: Listening on 0.0.0.0:7867 Apr 13 22:58:14 debian notify_push[1552]: [2021-04-13 22:58:14.581417 +02:00] DEBUG [notify_push] src/lib.rs:399: Received test cookie 817484235

I don't know what could be wrong. It seems that everything's up and running and is listening on the right ports

Luticus commented 3 years ago

Just tested 1.7 as well, no luck. issue is exactly the same. I'm thinking there's gotta be some weird config issue I'm missing somewhere, or something. I followed the directions to the letter though, so I'm not sure what it could be.

icewind1991 commented 3 years ago

Can you try running curl https://example.com.com/push/test/cookie after running the setup command

gldhnchn commented 3 years ago

Looks like I have the same issue.

$ sudo -u www-data /usr/bin/php -f /var/www/nextcloud/occ notify_push:setup https://example.com
✓ redis is configured
🗴 push server is not receiving redis messages (received 337895478, got 0)

Output in the log

Apr 14 17:54:57 blackhole notify_push[15879]: [2021-04-14 17:54:57.278104 +02:00] TRACE [tokio_util::codec::framed_impl] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-util-0.6.5/src/codec/framed_impl.rs:135: attempting to decode a frame
Apr 14 17:54:57 blackhole notify_push[15879]: [2021-04-14 17:54:57.278139 +02:00] TRACE [tokio_util::codec::framed_impl] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-util-0.6.5/src/codec/framed_impl.rs:138: frame decoded from buffer
Apr 14 17:54:57 blackhole notify_push[15879]: [2021-04-14 17:54:57.278150 +02:00] DEBUG [notify_push] src/lib.rs:399: Received test cookie 337895478
Apr 14 17:54:57 blackhole notify_push[15879]: [2021-04-14 17:54:57.278159 +02:00] TRACE [tokio_util::codec::framed_impl] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-util-0.6.5/src/codec/framed_impl.rs:135: attempting to decode a frame
$ curl -v https://example.com/push/test/cookie
*   Trying 92.116.***.***:443...
* TCP_NODELAY set
* Connected to example.com (92.116.***.***) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=example.com
*  start date: Apr  1 11:20:43 2021 GMT
*  expire date: Jun 30 11:20:43 2021 GMT
*  subjectAltName: host "example.com" matched cert's "example.com"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x559eb1776cb0)
> GET /push/test/cookie HTTP/2
> Host: example.com
> user-agent: curl/7.68.0
> accept: */*
> 
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* old SSL session ID is stale, removing
* Connection state changed (MAX_CONCURRENT_STREAMS == 128)!
< HTTP/2 200 
< server: nginx
< date: Wed, 14 Apr 2021 15:57:54 GMT
< content-type: text/plain; charset=utf-8
< content-length: 9
< x-frame-options: SAMEORIGIN
< x-robots-tag: none
< referrer-policy: no-referrer
< x-content-type-options: nosniff
< x-download-options: noopen
< x-permitted-cross-domain-policies: none
< x-xss-protection: 1; mode=block
< strict-transport-security: max-age=63072000; includeSubdomains
< cache-control: public, max-age=15778463
< 
* Connection #0 to host example.com left intact
337895478%

output in the log:

Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319472 +02:00] TRACE [mio::poll] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/mio-0.7.11/src/poll.rs:478: registering event source with poller: token=Token(117440513), interests=READABLE | WRITABLE
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319536 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:140: Conn::read_head 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319553 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:81: parse_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319562 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:81: -> parse_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319569 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:129: Request.parse([Header; 100], [u8; 212]) 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319579 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:138: Request.parse Complete(212) 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319588 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:153: headers: [Header { name: "X-Forwarded-Proto", value: [104, 116, 116, 112, 115] }, Header { name: "Connection", value: [85, 112, 103, 114, 97, 100, 101] }, Header { name: "Host", value: [110, 101, 120, 116, 99, 108, 111, 117, 100, 46, 103, 108, 100, 104, 110, 99, 104, 110, 46, 100, 101] }, Header { name: "X-Forwarded-For", value: [49, 56, 56, 46, 55, 52, 46, 51, 50, 46, 50, 53, 51, 44, 32, 49, 50, 55, 46, 48, 46, 48, 46, 49] }, Header { name: "X-Real-IP", value: [49, 56, 56, 46, 55, 52, 46, 51, 50, 46, 50, 53, 51] }, Header { name: "user-agent", value: [99, 117, 114, 108, 47, 55, 46, 54, 56, 46, 48] }, Header { name: "accept", value: [42, 47, 42] }] 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319618 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:81: <- parse_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319626 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:81: -- parse_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319633 +02:00] DEBUG [hyper::proto::h1::io] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:167: parsed 7 headers 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319641 +02:00] DEBUG [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:158: incoming body is empty 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319657 +02:00] TRACE [warp::filters::path] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.1/src/filters/path.rs:212: "ws"?: "test" 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319668 +02:00] TRACE [warp::filters::path] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.1/src/filters/path.rs:212: "test"?: "test" 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319675 +02:00] TRACE [warp::filters::path] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.1/src/filters/path.rs:212: "cookie"?: "cookie" 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319684 +02:00] DEBUG [notify_push] src/lib.rs:249: current test cookie is 337895478
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319699 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:93: encode_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319706 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:93: -> encode_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319713 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:291: Server::encode status=200, body=Some(Known(9)), req_method=Some(GET) 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319724 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:93: <- encode_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319738 +02:00] TRACE [hyper::proto::h1::role] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/role.rs:93: -- encode_headers
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319775 +02:00] DEBUG [hyper::proto::h1::io] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:248: flushed 125 bytes 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319790 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:663: flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Idle } 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319871 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:140: Conn::read_head 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319893 +02:00] TRACE [hyper::proto::h1::io] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/io.rs:179: parse eof 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319902 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:868: State::close_read() 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319910 +02:00] DEBUG [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:208: read eof 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319917 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:874: State::close_write() 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319924 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:868: State::close_read() 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319931 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:874: State::close_write() 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319938 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:663: flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled } 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319981 +02:00] TRACE [hyper::proto::h1::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/proto/h1/conn.rs:670: shut down IO complete 
Apr 14 17:57:54 blackhole notify_push[15879]: [2021-04-14 17:57:54.319992 +02:00] TRACE [mio::poll] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/mio-0.7.11/src/poll.rs:609: deregistering event source from poller
Apr 14 17:57:56 blackhole notify_push[15879]: [2021-04-14 17:57:56.148064 +02:00] TRACE [hyper::client::pool] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.14.4/src/client/pool.rs:749: idle interval checking for expired

systemd unit of notify_push:

[Unit]
Description = Push daemon for Nextcloud clients

[Service]
Environment = PORT=7867
Environment = NEXTCLOUD_URL=https://example.com
Environment = RUST_BACKTRACE=full
Environment = LOG=trace
ExecStart = /var/www/nextcloud/apps/notify_push/bin/x86_64/notify_push /var/www/nextcloud/config/config.php
User=www-data

[Install]
WantedBy = multi-user.target
Nick-Git2 commented 3 years ago

$ sudo -u www-data /var/www/nextcloud/occ notify_push:setup https://XXXXX/nextcloud/push ✓ redis is configured 🗴 push server is not receiving redis messages (received 649162221, got 0)

$ sudo curl https://XXXXX/push/test/cookie 649162221

chrissi55 commented 3 years ago

I made the step sudo -u www-data /var/www/nextcloud/occ notify_push:setup https://my.domain/push

and it seems working with 0.1.7 either but the question is, is there a parameter / Environment variable for /etc/systemd/system/notify_push.service that let me use a password for redis again. in my nextcloud config.php i commented out the redis pass because i disabled the option in redis because of auth errors setting up notify_push.

Thanks

Environment = REDIS_PASSWORD=....
or
Environment = REDIS_PASS_FILE=.....

are not recognized nor working

Luticus commented 3 years ago

@icewind1991 When I run curl https://example.com/push/test/cookie running the setup command I get no output of any kind, it just returns. If I run it with a -v as in curl -v https://example.com/push/test/cookie I get basically identical output to @gldhnchn

sirdrakeistda commented 3 years ago

Same problem here. I managed the problem by restarting the service sudo systemctl restart notify_push After this I was able to run sudo -u www-data php occ notify_push:setup again without problems (if you haven't done the step press esc and do not run the step). Maybe my reboot was the issue.

Nick-Git2 commented 3 years ago

Same problem here. I managed the problem by restarting the service sudo systemctl restart notify_push After this I was able to run sudo -u www-data php occ notify_push:setup again without problems (if you haven't done the step press esc and do not run the step). Maybe my reboot was the issue.

I've just tried your solution but the issue persists.

Luticus commented 3 years ago

I've restarted the service, disabled and reenabled, then started the service, and rebooted the system. None of these things helped.

Tamsy commented 3 years ago

I am struggling with

✓ redis is configured 🗴 push server is not receiving redis messages (received 804108192, got 0)

for three days now on Apache 2.4 on Ubuntu 18.04.5

I have already tried all "solutions" I could find through the internet but unfortunately to no avail. Have given it up for now and hoping there will be a solution (or at least a workaround) to this error anytime soon.

Tamsy commented 3 years ago

I've restarted the service, disabled and reenabled, then started the service, and rebooted the system. None of these things helped.

@Luticus @gldhnchn @Nick-Git2

Do you by any chance run SpiderLabs's ModSecurity with Apache/Nginx on your Nextcloud Hub?

At least with ModSecurity v.2.x on Apache 2.4.48 this seems to be the culprit of the 🗴 push server is not receiving redis messages (received xxxxxxx, got 0) message.

Using the latest Client Push 0.2.0 I switched off (commented out) LoadModule security2_module modules/mod_security2.so restarted Apache, made sure notify_push.service is running and did occ notify_push:setup which showed:

<snip>
Push binary seems to be running already
✓ push server seems to be functioning correctly.
Reverse proxy seems to be configured already
✓ reverse proxy seems to be setup correctly.
  configuration saved

Thereafter I did: occ notify_push:setup https://cloud.ourcloud.com/push which showed:

✓ 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
  configuration saved

Client Push seems to be running/working now as it should.

If you have Modsecurity running just deactivate it and give it a try.

gldhnchn commented 3 years ago

@Tamsy: No, I'm not using ModSecurity.

But I did a recheck with the new version 0.2.0 and everything is running fine now. Thank you!

Xitee1 commented 3 years ago

But I did a recheck with the new version 0.2.0 and everything is running fine now. Thank you!

I have updated to the version 0.2.0 and have restarted notify_push and the system after the update. I still get 🗴 push server is not receiving redis messages (received 412837236, got 0).

Edit: I saw that there is a error message if i type service notify_push status. Failed to setup redis subscription: Failed to connect to redis: Password authentication failed WARN [notify_push] src/lib.rs:379: Redis server disconnected, reconnecting in 1s

Luticus commented 3 years ago

@Tamsy Nope, I am not using that module. Interestingly though I finally managed to get it to work with the automatic setup process when I tried it on the newest version. When I use the manual one I get the same error. There's probably something missing from the manual steps or I did something wrong with the manual ones. I do have it working now though so maybe this can be closed.

rererecursive commented 2 years ago

I was experiencing this issue as well, and the fix for me was to disable/enable the app in Nextcloud: su www-data -s /bin/bash -c "php occ app:disable notify_push" su www-data -s /bin/bash -c "php occ app:enable notify_push"

mortee commented 2 years ago

I have the same problem with v0.4.0 as @Luticus did, I get the 404 error for /push/test/cookie. Also in the log, I see these lines:

TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "ws"?: "" 
TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "test"?: "" 
TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "test"?: "" 
TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "test"?: "" 
TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "test"?: "" 
TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "test"?: "" 
TRACE [warp::filters::path] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filters/path.rs:212: "push"?: "" 
DEBUG [warp::filter::service] /cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.2/src/filter/service.rs:132: rejected: Rejection(NotFound)

which is supposed to look like this:

TRACE [warp::filters::path] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.1/src/filters/path.rs:212: "ws"?: "test" 
TRACE [warp::filters::path] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.1/src/filters/path.rs:212: "test"?: "test" 
TRACE [warp::filters::path] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/warp-0.3.1/src/filters/path.rs:212: "cookie"?: "cookie" 
DEBUG [notify_push] src/lib.rs:249: current test cookie is 337895478

So, apparently, for some reason it refuses to even parse the local part of the request URI. I don't even have the option to set it up using the "wizard", since I intend to run it in a separate docker container.

What might be the problem?

aakerbeere commented 2 years ago

I don't know if this is of any help here.

I occasionally get push server is not receiving redis messages when the server is under heavy load, fex. when an OCR task is running. A subsequent call of occ notify_push:self-test runs successfull.

mortee commented 2 years ago

Actually, while I can't recall the details exactly as this was 3 weeks ago, but some further testing pointed to the direction that if the request's Host header doesn't match what the program expects, then it won't route properly. Which is a problem, since of course I don't want to direct traffic between NC and this program through my router, nor even the frontend proxy; but of course normally I'm accessing NC through those. So, it should accept requests addressed directly to its IP address as well as its external domain name. What's the proper configuration in such a scenario?

mnestor commented 2 years ago

I managed to get this working. Perhaps my compose file can help someone figure out how to get their setup working.

For my external access I have things going through cloudflare zero trust argo tunnel configured somewhere else

version: '3.8'

volumes:
  nextcloud_redis:

services:
  db:
    image: postgres:13.6-alpine
    container_name: nextcloud_db
    restart: always
    volumes:
      - /volume2/nextcloud/db:/var/lib/postgresql/data
      - /volume2/chadburn/scripts/pg_backup.sh:/scripts/pg_backup.sh
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
      - /nfs/scp_backups/nextcloud:/dump
    networks:
      - nextcloud
    environment:
      - POSTGRES_DB
      - POSTGRES_USER
      - POSTGRES_PASSWORD
      - PGHOST=localhost 
      - PGDATABASE=${POSTGRES_DB} 
      - PGUSER=${POSTGRES_USER} 
      - PGPASSWORD=${POSTGRES_PASSWORD} 
    healthcheck:
      test: pg_isready -U ${POSTGRES_USER} -h 127.0.0.1
      interval: 5s

  redis:
    image: redis:7.0.0
    restart: always
    container_name: nextcloud_redis
    networks:
      - nextcloud
    volumes:
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
      - nextcloud_redis:/data

  app:
    image: nextcloud:24.0.0-apache
    restart: always
    container_name: nextcloud_app
    depends_on:
      - db
      - redis
    volumes:
      - /volume2/nextcloud/html:/var/www/html
      - /volume2/nextcloud/cache:/var/www/cache
      - /nfs/nextcloud/data:/storage/data
      - /smb/user:/users
      - /volume2/nextcloud/nextcloud.log:/var/log/nextcloud.log
      # - /volume2/homes:/user_homes
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
    labels:
      - "traefik.enable=true"
      - "traefik.http.services.nextcloud.loadbalancer.server.port=80"
      #internal
      - "traefik.http.routers.nextcloud.entrypoints=internal,cloudflare"
      - "traefik.http.routers.nextcloud.rule=Host(`next.domain.com`)"
      - "traefik.http.routers.nextcloud.service=nextcloud"

      - "traefik.http.routers.nextcloud.middlewares=nextcloud-caldav"
      - "traefik.http.middlewares.nextcloud-caldav.redirectregex.permanent=true"
      - "traefik.http.middlewares.nextcloud-caldav.redirectregex.regex=^https://(.*)/.well-known/(card|cal)dav"
      - "traefik.http.middlewares.nextcloud-caldav.redirectregex.replacement=https://$${1}/remote.php/dav/"
    environment:
      - POSTGRES_HOST=db
      - POSTGRES_DB
      - POSTGRES_USER
      - POSTGRES_PASSWORD
      - NEXTCLOUD_ADMIN_PASSWORD
      - NEXTCLOUD_ADMIN_USER=mnestor
      - NEXTCLOUD_TRUSTED_DOMAINS=${DOMAIN}
      - OVERWRITEHOST=${DOMAIN}
      - OVERWRITEPROTOCOL=https
      - REDIS_HOST=redis
      - UPLOAD_MAX_SIZE=10G
      - PHP_MEMORY_LIMIT=512M
      - APC_SHM_SIZE=128M
      - OPCACHE_MEM_SIZE=128
      - TZ=America/New_York
    networks:
      - proxy
      - nextcloud

  push:
    image: nextcloud:24.0.0-apache
    container_name: nextcloud_push
    restart: always
    volumes:
      - /volume2/nextcloud/html:/var/www/html
      - /volume2/nextcloud/cache:/var/www/cache
      - /nfs/nextcloud/data:/storage/data
      - /smb/user:/users
      - /volume2/nextcloud/nextcloud.log:/var/log/nextcloud.log
      # - /volume2/homes:/user_homes
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
    entrypoint: /var/www/html/custom_apps/notify_push/bin/x86_64/notify_push /var/www/html/config/config.php
    labels:
      - "traefik.enable=true"
      - "traefik.http.services.nextcloud-push.loadbalancer.server.port=7867"
      - "traefik.http.middlewares.nextcloud-push-strip.stripprefix.prefixes=/push"
      #internal
      - "traefik.http.routers.nextcloud-push.entrypoints=internal,cloudflare"
      - "traefik.http.routers.nextcloud-push.rule=Host(`next.domain.com`) && PathPrefix(`/push`)"
      - "traefik.http.routers.nextcloud-push.middlewares=nextcloud-push-strip"
    environment:
      - TZ=America/New_York
      - NEXTCLOUD_URL=http://app/
    depends_on:
      - db
      - redis
      - app
    networks:
      - proxy
      - nextcloud

  cron:
    image: nextcloud:24.0.0-apache
    container_name: nextcloud_cron
    restart: always
    volumes:
      - /volume2/nextcloud/html:/var/www/html
      - /volume2/nextcloud/cache:/var/www/cache
      - /nfs/nextcloud/data:/storage/data
      - /smb/user:/users
      - /volume2/nextcloud/nextcloud.log:/var/log/nextcloud.log
      # - /volume2/homes:/user_homes
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
    entrypoint: /cron.sh
    networks:
      - nextcloud
    depends_on:
      - db
      - redis

networks:
  nextcloud:
    external: true
  proxy:
    external: true

And the stuff I directly configured in config.php since the ENV settings weren't working for me

  'trusted_proxies' =>
  array (
    0 => '10.99.1.0/24',
    1 => '10.99.7.0/24',
  ),
  'trusted_domains' =>
  array (
    0 => 'next.domain.com',
    1 => 'localhost',
  ),
yewkay commented 2 years ago

Came in to post a me too on this issue. Hoping to find a solution I'm on NC 24.0.0, notify_push 0.4.0, redis 7.0.2 I did get 

[2022-07-07 18:12:48.418773 +08:00] DEBUG [h2::codec::framed_read] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/h2-0.3.10/src/codec/framed_read.rs:354: received frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(1), debug_data: b"timeout" }

[2022-07-07 18:12:48.418801 +08:00] DEBUG [rustls::conn] /home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.2/src/conn.rs:1208: Sending warning alert CloseNotify

[2022-07-07 18:12:52.869332 +08:00] DEBUG [notify_push] src/lib.rs:440: Received test cookie 827591900
yewkay commented 2 years ago

is there a notify-push log file for me to get a hint at what could be missing?

yewkay commented 2 years ago

Did more troubleshooting on my end to no avail: before starting notify_push, monitor redis with redis-cli

127.0.0.1:6379> monitor
OK

My system uses sysv, anyway, i started notify_push via commandline for testing

notify_push --allow-self-signed --port 7867 /opt/NextCloud80/nextcloud/config/config.php
1658195098.202955 [0 127.0.0.1:41952] "SET" "notify_push_app_version" "0.4.0"
1658195098.204367 [0 127.0.0.1:41944] "GET" "notify_push_app_version"
1658195098.204541 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_storage_update"
1658195098.204588 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_group_membership_update"
1658195098.204644 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_user_share_created"
1658195098.204680 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_test_cookie"
1658195098.204717 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_activity"
1658195098.204758 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_notification"
1658195098.204792 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_pre_auth"
1658195098.204821 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_custom"
1658195098.204856 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_config"
1658195098.204893 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_query"
1658195098.204923 [0 127.0.0.1:41954] "SUBSCRIBE" "notify_signal"

tried to setup the link 

occ notify_push:setup https://nextcloud.domain.tld/push
✓ redis is configured
🗴 push server is not receiving redis messages (received 1047175563, got 0)

Redis received message 1658195320.229659 [0 127.0.0.1:43146] "PUBLISH" "notify_test_cookie" "1047175563"

check for connection between notify_push to redis connection 

lsof -i :6379

COMMAND     PID  USER   FD   TYPE    DEVICE SIZE/OFF NODE NAME
redis-cli 26731 xxxx    3u  IPv4 189325640      0t0  TCP localhost:41876->localhost:6379 (ESTABLISHED)
notify_pu 26887 xxxx   12u  IPv4 189335172      0t0  TCP localhost:41954->localhost:6379 (ESTABLISHED)
redis-ser 31629 xxxx    6u  IPv4 137672322      0t0  TCP *:6379 (LISTEN)
redis-ser 31629 xxxx    7u  IPv4 189330746      0t0  TCP localhost:6379->localhost:41954 (ESTABLISHED)
redis-ser 31629 xxxx    8u  IPv4 189320895      0t0  TCP localhost:6379->localhost:41876 (ESTABLISHED)

So it seems like redis is receiving the messages but somehow notify_push server isn't able to get the data?

yewkay commented 1 year ago

updated to v0.5.0 still experiencing the same. Everyone else had this issue resolved for them?

yewkay commented 1 year ago

updated to v0.5.0 still experiencing the same. Everyone else had this issue resolved for them?

Finally sorted this out. It was a reverse proxy issue

ProxyPass /push/ws ws://127.0.0.1:7867/ws ProxyPass /push/ http://127.0.0.1:7867/ ProxyPassReverse /push/ http://127.0.0.1:7867/

Needs to be placed above any other proxypass and proxypassreverse. Worked for me using 0.5.0!