element-hq / element-hq/element-android

NTFY Endpoint Registration Fails within an Airgapped Environment

Open
#8,228 8 comments 0 reactions 0 assignees View on GitHub
A-Notifications O-Occasional S-Major T-Defect Z-UnifiedPush
Dominant language
Kotlin
Stars
3.7k
Forks
917
Avg merge
8d 20h
Merged PRs (30d)
1

Description

### Steps to reproduce

### Steps to reproduce

Issue History so far:

# Initial Query

Hi 👋 I'm trying to confirm the process for setting up NTFY within an airgapped environment with the app. I think I'm almost there. I believe the issue is with having the NTFY push gateway registering within the app. (Details within thread)

Setup is as follows: (Note all using wildcard certs issued by CA on Server1 - Android app has CA.pem installed)

- Wifi Router (`192.168.0.1`)
- DHCP points to `192.168.0.2` as DNS)
- Server 1 (`192.168.0.2`)
- DNS
- `example.com` / `synapse.example.com` / `element.example.com` -> 192.168.0.2
- `ntfy.example.com` -> 192.168.0.4
- On-Premise installed (Synapse / Element Web App)
- `https://example.com/.well-known/matrix/server` sets `m.server` -> `synapse.example.com:443`
- Synapse homeserver.yml has `192.168.0.1` -> `192.168.0.4` in IP whitelist
- microk8s dns resolvers all set to use 192.168.0.2
- Server 2 (`192.168.0.4`)
- NTFY server running (`https://ntfy.example.com`)
- Phone (`192.168.0.2`)
- Element app installed
- Notification service set to `ntfy`
- NTFY installed
- Custom server set to `https://ntfy.example.com`
- UnifiedPush topic URL added by `im.vector.app`

I believe the issue is that there are still no registered push gateways listed within the Element app. (`Advanced Settings` -> `Notification Targets` says `No registered push gateways`) Going to `Notifications` -> `Troubleshoot Notifications` I get the following:

![image](https://user-images.githubusercontent.com/7443512/223793693-81160535-a2fc-4f11-8f19-a5d9e7578e30.png)

FYI Running the trouble-shooter and immediately going to the home screen (so it's no longer the active app) causes the Test Push to fail. (NTFY doesn't receive any notification / etc.)

NTFY application is happily connected to the created topic (and a test one, which does correctly receive notifications)

![image](https://user-images.githubusercontent.com/7443512/223793727-a6c26f2d-94c0-4e09-a5ad-314d6e6218f4.png)

# Troubleshooting with @MatMaul

> Check `ntfy.example.com` DNS record is visible from `Server 1`?

Server 1 is the DNS server, and pings to ntfy.example.com work successfully (it actually also self-hosts an NTFY web client so can be sure it's working from Server 1)

Initially trying to troubleshoot in the on-prem support, was told "It is the responsibility of Matrix clients to register "pushers" with their homeserver. The pusher contains the URL to the push GW to use" - So I guess I could try registering a pusher using the api manually, see what comes back

> Check if synapse log is returning 500 when registering the pusher.

```
2023-03-06 13:36:10,415 - synapse.access.http.8008 - 460 - INFO - GET-30693 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 30.003sec/0.001sec (0.000sec, 0.001sec) (0.000sec/0.000sec/0) 230B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_2887_2_35_69_1_15_24_0 HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 13:36:11,305 - synapse.access.http.8008 - 460 - INFO - GET-30695 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 30.002sec/0.001sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 230B 200 "GET /_matrix/client/r0/sync?filter=0&set_presence=online&timeout=30000&since=s52_2887_2_35_69_1_15_24_0 HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:36:12,130 - synapse.storage.databases.main.event_push_actions - 1305 - INFO - rotate_notifs-4053 - Rotating notifications
2023-03-06 13:36:12,132 - synapse.storage.databases.main.event_push_actions - 1528 - INFO - rotate_notifs-4053 - Rotating notifications up to: 52
2023-03-06 13:36:12,134 - synapse.storage.databases.main.event_push_actions - 1627 - INFO - rotate_notifs-4053 - Rotating notifications, handling 0 rows
2023-03-06 13:36:12,138 - synapse.storage.databases.main.event_push_actions - 1720 - INFO - rotate_notifs-4053 - Rotating notifications, deleted 0 push actions
2023-03-06 13:36:12,188 - synapse.handlers.presence - 791 - INFO - persist_presence_changes-2026 - Persisting 2 unpersisted presence updates
2023-03-06 13:36:12,212 - synapse.util.caches.lrucache - 212 - INFO - LruCache._expire_old_entries-4053 - Dropped 0 items from caches
```
Those are the logs (I triggered the troubleshooter at 13:36) - I guess the `synapse.storage.databases.main.event_push_actions` are the things related to the registration? I'm not seeing anything immediately obvious as to why it fails 🤔

> Troubleshooter is not triggering pusher registration. Switch back and forth the notification service and check the logs. Expecting to see `processed request` with a path matching [registering a pusher.](https://spec.matrix.org/v1.5/client-server-api/#post_matrixclientv3pushersset)

Sure will also clear the cache / storage of both NTFY and Element apps and try from the beginning for good measure
```
2023-03-06 13:52:08,024 - synapse.handlers.auth - 995 - INFO - POST-30991 - Logging in user @phone:example.com on device BEEIKQOZUK
2023-03-06 13:52:08,025 - synapse.access.http.8008 - 460 - INFO - GET-30985 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 15.699sec/0.003sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 280B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_2919_2_35_69_1_15_24_0 HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 13:52:08,033 - synapse.access.http.8008 - 460 - INFO - POST-30991 - 192.168.0.3 - 8008 - {None} Processed request: 0.332sec/0.001sec (0.312sec, 0.000sec) (0.003sec/0.010sec/5) 216B 200 "POST /_matrix/client/r0/login HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,055 - synapse.access.http.8008 - 460 - INFO - POST-30992 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 0.012sec/0.000sec (0.001sec, 0.001sec) (0.005sec/0.004sec/3) 1807B 200 "POST /_matrix/client/r0/keys/query HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 13:52:08,392 - synapse.access.http.8008 - 460 - INFO - GET-30994 - 192.168.0.3 - 8008 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 78B 200 "GET /_matrix/client/r0/login HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,760 - synapse.handlers.e2e_keys - 614 - INFO - POST-30995 - Updating device_keys for device 'BEEIKQOZUK' for user @phone:example.com at 1678110728760
2023-03-06 13:52:08,762 - synapse.access.http.8008 - 460 - INFO - GET-30996 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.005sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 2B 200 "GET /_matrix/client/r0/thirdparty/protocols HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,777 - synapse.access.http.8008 - 460 - INFO - GET-30993 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 0.723sec/0.004sec (0.000sec, 0.003sec) (0.000sec/0.000sec/0) 280B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_2919_2_35_69_1_15_25_0 HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 13:52:08,783 - synapse.access.http.8008 - 460 - INFO - GET-30997 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.005sec/0.003sec (0.004sec, 0.000sec) (0.001sec/0.001sec/1) 14B 200 "GET /_matrix/client/r0/pushers HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,786 - synapse.access.http.8008 - 460 - INFO - POST-30995 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.025sec/0.006sec (0.004sec, 0.002sec) (0.003sec/0.012sec/5) 47B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,788 - synapse.access.http.8008 - 460 - INFO - GET-30998 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.001sec/0.005sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 656B 200 "GET /_matrix/client/r0/capabilities HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,814 - synapse.access.http.8008 - 460 - INFO - GET-31000 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 27B 200 "GET /_matrix/media/r0/config HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,820 - synapse.handlers.e2e_keys - 686 - INFO - POST-31001 - Adding one_time_keys dict_keys(['signed_curve25519:AAAABQ', 'signed_curve25519:AAAABA', 'signed_curve25519:AAAAAw', 'signed_curve25519:AAAAAg', 'signed_curve25519:AAAAAQ']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110728820
2023-03-06 13:52:08,831 - synapse.access.http.8008 - 460 - INFO - POST-31001 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.011sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.006sec/3) 47B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,837 - synapse.access.http.8008 - 460 - INFO - GET-31002 - 192.168.0.3 - 8008 - {None} Processed request: 0.000sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 808B 200 "GET /_matrix/client/versions HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,929 - synapse.handlers.e2e_keys - 686 - INFO - POST-31003 - Adding one_time_keys dict_keys(['signed_curve25519:AAAACQ', 'signed_curve25519:AAAACA', 'signed_curve25519:AAAABw', 'signed_curve25519:AAAABg', 'signed_curve25519:AAAACg']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110728929
2023-03-06 13:52:08,939 - synapse.access.http.8008 - 460 - INFO - POST-31003 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.010sec/0.001sec (0.004sec, 0.000sec) (0.001sec/0.005sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:08,945 - synapse.access.http.8008 - 460 - INFO - GET-31004 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.004sec/0.001sec (0.001sec, 0.000sec) (0.001sec/0.001sec/2) 472B 200 "GET /_matrix/client/r0/devices HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,044 - synapse.access.http.8008 - 460 - INFO - POST-31005 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 0.005sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.002sec/3) 2298B 200 "POST /_matrix/client/r0/keys/query HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 13:52:09,065 - synapse.handlers.e2e_keys - 686 - INFO - POST-31006 - Adding one_time_keys dict_keys(['signed_curve25519:AAAADQ', 'signed_curve25519:AAAADA', 'signed_curve25519:AAAACw', 'signed_curve25519:AAAADw', 'signed_curve25519:AAAADg']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729065
2023-03-06 13:52:09,073 - synapse.access.http.8008 - 460 - INFO - POST-31006 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.008sec/0.000sec (0.001sec, 0.001sec) (0.001sec/0.005sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,113 - synapse.handlers.e2e_keys - 686 - INFO - POST-31008 - Adding one_time_keys dict_keys(['signed_curve25519:AAAAEQ', 'signed_curve25519:AAAAEA', 'signed_curve25519:AAAAFA', 'signed_curve25519:AAAAEw', 'signed_curve25519:AAAAEg']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729113
2023-03-06 13:52:09,113 - synapse.access.http.8008 - 460 - INFO - GET-31007 - 192.168.0.3 - 8008 - {None} Processed request: 0.000sec/0.002sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 808B 200 "GET /_matrix/client/versions HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,122 - synapse.access.http.8008 - 460 - INFO - POST-31008 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.009sec/0.001sec (0.002sec, 0.000sec) (0.002sec/0.004sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,149 - synapse.handlers.e2e_keys - 686 - INFO - POST-31009 - Adding one_time_keys dict_keys(['signed_curve25519:AAAAFQ', 'signed_curve25519:AAAAGQ', 'signed_curve25519:AAAAGA', 'signed_curve25519:AAAAFw', 'signed_curve25519:AAAAFg']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729149
2023-03-06 13:52:09,162 - synapse.access.http.8008 - 460 - INFO - POST-31009 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.013sec/0.001sec (0.002sec, 0.000sec) (0.001sec/0.009sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,165 - synapse.access.http.8008 - 460 - INFO - POST-31010 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.008sec/0.000sec (0.004sec, 0.001sec) (0.002sec/0.001sec/1) 17B 200 "POST /_matrix/client/r0/user/@phone:example.com/filter HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,251 - synapse.access.http.8008 - 460 - INFO - GET-31011 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.003sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.001sec/2) 23B 200 "GET /_matrix/client/r0/profile/@phone:example.com HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,261 - synapse.handlers.e2e_keys - 686 - INFO - POST-31012 - Adding one_time_keys dict_keys(['signed_curve25519:AAAAHg', 'signed_curve25519:AAAAHQ', 'signed_curve25519:AAAAHA', 'signed_curve25519:AAAAGw', 'signed_curve25519:AAAAGg']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729261
2023-03-06 13:52:09,269 - synapse.access.http.8008 - 460 - INFO - POST-31012 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.008sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.005sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,358 - synapse.handlers.e2e_keys - 686 - INFO - POST-31013 - Adding one_time_keys dict_keys(['signed_curve25519:AAAAHw', 'signed_curve25519:AAAAIw', 'signed_curve25519:AAAAIg', 'signed_curve25519:AAAAIQ', 'signed_curve25519:AAAAIA']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729358
2023-03-06 13:52:09,366 - synapse.access.http.8008 - 460 - INFO - POST-31013 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.008sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.004sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,436 - synapse.handlers.e2e_keys - 686 - INFO - POST-31014 - Adding one_time_keys dict_keys(['signed_curve25519:AAAAJw', 'signed_curve25519:AAAAJg', 'signed_curve25519:AAAAJQ', 'signed_curve25519:AAAAJA', 'signed_curve25519:AAAAKA']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729436
2023-03-06 13:52:09,445 - synapse.access.http.8008 - 460 - INFO - POST-31014 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.009sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.005sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,504 - synapse.handlers.e2e_keys - 686 - INFO - POST-31016 - Adding one_time_keys dict_keys(['signed_curve25519:AAAAKw', 'signed_curve25519:AAAAKg', 'signed_curve25519:AAAALQ', 'signed_curve25519:AAAALA', 'signed_curve25519:AAAAKQ']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729504
2023-03-06 13:52:09,515 - synapse.access.http.8008 - 460 - INFO - POST-31016 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.011sec/0.001sec (0.002sec, 0.000sec) (0.001sec/0.006sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,560 - synapse.handlers.e2e_keys - 686 - INFO - POST-31017 - Adding one_time_keys dict_keys(['signed_curve25519:AAAALw', 'signed_curve25519:AAAALg', 'signed_curve25519:AAAAMg', 'signed_curve25519:AAAAMQ', 'signed_curve25519:AAAAMA']) for device 'BEEIKQOZUK' for user '@phone:example.com' at 1678110729560
2023-03-06 13:52:09,572 - synapse.access.http.8008 - 460 - INFO - POST-31017 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.012sec/0.001sec (0.002sec, 0.000sec) (0.001sec/0.006sec/3) 48B 200 "POST /_matrix/client/r0/keys/upload HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,582 - synapse.access.http.8008 - 460 - INFO - GET-31015 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.112sec/0.001sec (0.029sec, 0.000sec) (0.016sec/0.055sec/40) 19580B 200 "GET /_matrix/client/r0/sync?filter=0&set_presence=offline&timeout=0 HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [20 dbevts]
2023-03-06 13:52:09,657 - synapse.access.http.8008 - 460 - INFO - GET-31018 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.003sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.001sec/2) 310B 200 "GET /_matrix/client/unstable/room_keys/version HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,860 - synapse.access.http.8008 - 460 - INFO - GET-31020 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.003sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.001sec/2) 472B 200 "GET /_matrix/client/r0/devices HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:09,879 - synapse.access.http.8008 - 460 - INFO - POST-31021 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.005sec/0.001sec (0.001sec, 0.000sec) (0.001sec/0.003sec/3) 2798B 200 "POST /_matrix/client/r0/keys/query HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:10,029 - synapse.access.http.8008 - 460 - INFO - PUT-31022 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.008sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.005sec/3) 2B 200 "PUT /_matrix/client/r0/sendToDevice/m.room_key_request/31f4235c-ddd0-43f1-a62e-787e18026101 HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:10,075 - synapse.access.http.8008 - 460 - INFO - PUT-31023 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.008sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.004sec/3) 2B 200 "PUT /_matrix/client/r0/sendToDevice/m.room_key_request/c9038f8a-e608-406c-885e-ca5a9e2d680b HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:10,132 - synapse.access.http.8008 - 460 - INFO - GET-31024 - 192.168.0.3 - 8008 - {None} Processed request: 0.000sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 808B 200 "GET /_matrix/client/versions HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:10,149 - synapse.access.http.8008 - 460 - INFO - GET-30999 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 1.349sec/0.002sec (0.003sec, 0.000sec) (0.000sec/0.000sec/0) 382B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_2919_2_35_69_1_15_26_0 HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 13:52:10,156 - synapse.access.http.8008 - 460 - INFO - GET-31025 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.017sec/0.001sec (0.004sec, 0.000sec) (0.002sec/0.006sec/5) 1256B 200 "GET /_matrix/client/r0/sync?filter=0&set_presence=online&timeout=0&since=s52_2919_2_35_69_1_15_26_0 HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:10,177 - synapse.access.http.8008 - 460 - INFO - POST-31027 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.005sec/0.001sec (0.002sec, 0.000sec) (0.001sec/0.003sec/3) 2798B 200 "POST /_matrix/client/r0/keys/query HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:10,217 - synapse.access.http.8008 - 460 - INFO - GET-31028 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.005sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.002sec/1) 192B 200 "GET /_matrix/client/r0/sync?filter=0&set_presence=online&timeout=0&since=s52_2920_2_35_69_1_17_26_0 HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 13:52:12,131 - synapse.storage.databases.main.event_push_actions - 1305 - INFO - rotate_notifs-4085 - Rotating notifications
2023-03-06 13:52:12,132 - synapse.storage.databases.main.event_push_actions - 1528 - INFO - rotate_notifs-4085 - Rotating notifications up to: 52
2023-03-06 13:52:12,133 - synapse.storage.databases.main.event_push_actions - 1627 - INFO - rotate_notifs-4085 - Rotating notifications, handling 0 rows
2023-03-06 13:52:12,137 - synapse.storage.databases.main.event_push_actions - 1720 - INFO - rotate_notifs-4085 - Rotating notifications, deleted 0 push actions
2023-03-06 13:52:12,188 - synapse.handlers.presence - 791 - INFO - persist_presence_changes-2042 - Persisting 2 unpersisted presence updates
2023-03-06 13:52:12,212 - synapse.util.caches.lrucache - 212 - INFO - LruCache._expire_old_entries-4085 - Dropped 0 items from caches
2023-03-06 13:52:12,312 - synapse.storage.databases.main.metrics - 475 - INFO - generate_user_daily_visits-409 - Calling _generate_user_daily_visits
2023-03-06 13:52:13,838 - synapse.access.http.8008 - 460 - INFO - GET-31030 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.003sec/0.000sec (0.000sec, 0.000sec) (0.001sec/0.001sec/2) 472B 200 "GET /_matrix/client/r0/devices HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
```
Thats the logs from the point of first login -- most is just registering the new device etc. -- nothing matching `/_matrix/client/v3/pushers/set` though
So I guess that means the server isn't seeing such a request come in? Checking manually going to `https://synapse.example.com/_matrix/client/v3/pushers/set` works at least from Server 1 / 2 and the phone.

Can access that from all - actually tried again to double check and get the following:
```
2023-03-06 14:04:02,970 - synapse.access.http.8008 - 460 - INFO - GET-31229 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 0.002sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.001sec/1) 14B 200 "GET /_matrix/client/r0/pushers HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 14:04:06,938 - synapse.access.http.8008 - 460 - INFO - GET-31220 - 192.168.0.3 - 8008 - {@phone:example.com} Processed request: 30.002sec/0.000sec (0.000sec, 0.001sec) (0.000sec/0.000sec/0) 230B 200 "GET /_matrix/client/r0/sync?filter=0&set_presence=online&timeout=30000&since=s52_2938_2_35_69_1_20_26_0 HTTP/1.1" "Element dbg/1.5.28-dev (Google Pixel 6; Android 13; TQ1A.230205.002; Flavour GooglePlay; MatrixAndroidSdk2 1.5.28)" [0 dbevts]
2023-03-06 14:04:07,539 - synapse.access.http.8008 - 460 - INFO - GET-31222 - 192.168.0.2 - 8008 - {@computer:example.com} Processed request: 30.002sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 230B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_2938_2_35_69_1_20_26_0 HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/110.0" [0 dbevts]
2023-03-06 14:04:12,130 - synapse.storage.databases.main.event_push_actions - 1305 - INFO - rotate_notifs-4109 - Rotating notifications
2023-03-06 14:04:12,131 - synapse.storage.databases.main.event_push_actions - 1528 - INFO - rotate_notifs-4109 - Rotating notifications up to: 52
2023-03-06 14:04:12,133 - synapse.storage.databases.main.event_push_actions - 1627 - INFO - rotate_notifs-4109 - Rotating notifications, handling 0 rows
2023-03-06 14:04:12,137 - synapse.storage.databases.main.event_push_actions - 1720 - INFO - rotate_notifs-4109 - Rotating notifications, deleted 0 push actions
2023-03-06 14:04:12,188 - synapse.handlers.presence - 791 - INFO - persist_presence_changes-2054 - Persisting 2 unpersisted presence updates
2023-03-06 14:04:12,212 - synapse.util.caches.lrucache - 212 - INFO - LruCache._expire_old_entries-4109 - Dropped 0 items from caches
```
It's doing `/_matrix/client/r0/pushers` not `/_matrix/client/v3/pushers`, but it's an actual request in that direct so probably closer to what you were expecting to see

**Went on a tangent here about NTFY server version / apk package name which were ultimately ruled out as potential issues in the process**

# Rageshake Issue / Logcat tests

Thanks for all the help on this so far!! I've gone through and done a test and filtered the logs from Synapse, NTFY and the logcat to between 19:22pm -> 19.23pm (where I ran through all the steps). I'm collating everything within https://github.com/matrix-org/element-android-rageshakes/issues/50380 🤞 There's something in there that explains what's going on. Also going to dig around with the Admin API to list the pushers etc. to see if there's anything at all listed for the user.

I'm hoping the above has enough information within to help figure out what's going wrong with the registration. I manually merged all the logs into a combined log ordered chronologically -> https://github.com/matrix-org/element-android-rageshakes/files/10902597/combined\_and\_ordered.log

# Troubleshooting with @bmarty

> Disable / enable notification to force a set pusher request? (via `Enable notification for this session`)

I filtered the logcat based on the package name - hopefully thats okay. [logcat.log](https://github.com/vector-im/element-android/files/10923652/logcat.log)

so for referenceI adb shell'd on. Then did logcat | grep [im.vector.app](http://im.vector.app/)

> No pusher registration request.

Perhaps I was too hasty ending the logcat? [logcat2.log](https://github.com/vector-im/element-android/files/10923640/logcat2.log)

That one I doublechecked it appeared in NTFY afterwards too - which it did, and left a little longer after. Process followed is:

- start logcat
- Turn off notifications for the session
- Turn on notifications for the session
- Select ntfy from the prompt
- Switch to NTFY app to confirm

To cover all bases, (and attempt to have a complete logcat that's not lightyears long) - I setup aosp on a old pixel 2xl (so hopefully as little other things going on in the bg as possible unlike personal phone) and did a run through from scratch. Below is that logcat. I didn't filter on application name or anything and I followed these steps:

- start logcat
- Open Element, select example.com as server, logged in as notify user, accepted usage prompt, select google for notifications, then verified the session
- Opened Notification settings, disabled notifications for session, then re-enabled and select ntfy
- Switched to ntfy, confirmed entry listed
- Switched to Element, ran troubleshoot

[logcat.log](https://github.com/vector-im/element-android/files/10923652/logcat.log)

> `ToggleNotificationsForCurrentSessionUseCase: push notif is enabled, deleting any account data and updating pusher` but [the current code](https://github.com/vector-im/element-android/blob/develop/vector/src/main/java/im/vector/app/features/settings/notifications/usecase/ToggleNotificationsForCurrentSessionUseCase.kt#L50) does not seem to register a pusher if it does not exist yet.

> Change Notification method and select again ntfy to force a refresh of the pusher.

That's how I was previously changing when troubleshooting with MatMaul - but can give it try like that and send over the logcat - see if it throws up anything different / useful. Just to confirm: the problem is that the HS does not notify the Push gateway, right?

Erm I'm not sure on the specifics, possibly, the only concrete error message I have is the troubleshoot flow stating that "Failed to register endpoint token to homeserver: Unknown Error"

I can at least confirm from this https://unifiedpush.org/users/troubleshooting/ that the issue isn't with the distributor (i.e. NTFY) as I successfully receive a Unified Push notification using the UP-example app

> This error is displayed when there is no pushers registered on the HS. I guess the troubleshoot Quick fix has no effect?

Clicking the 'Reset Notification Method' button that appears - just presents the change notification method prompt. Clicking NTFY again and re-running tests has the same error unfortunately

# Confirmation of Synapse -> NTFY -> Phone flow works via Client-Server API

So fairly sure now that the Home Server and NTFY are working OK and it's something the app isn't doing right.

Using the ClientServer API I have registered a new pusher with this cURL command:

```bash
curl -H "Content-Type: application/json" -H "Authorization: Bearer syt_bm90aWZ5_iAMjqfxqmvKzBeaAdJME_054oG2" -d '{"app_display_name":"Mat Rix","app_id":"com.example.app.ios","append":false,"data":{"format":"event_id_only","url":"https://ntfy.example.com/_matrix/push/v1/notify"},"device_display_name":"iPhone 9","kind":"http","lang":"en","pushkey":"https://ntfy.example.com/example"}' --insecure -X POST https://synapse.example.com/_matrix/client/v3/pushers/set
```

I then have sent a message from `computer` user to `notify` user. NTFY receives the notification, and publishes to `https://ntfy.example.com/example` (the push key). I have manually subscribed to the `ntfy.example.com/example` topic and receive on the phone the json notification string

This method above obviously doesn't use UnifiedPush ?format?, so what I get on the phone is the raw notification json, but as far as the overall flow... registering a pusher to the homeserver, the homeserver pushing successfully to the gateway, and the gateway sending to a device it works.

# Patch file sent for more detailed logs on custom built apk

> We miss some log when this error occurs. Apply patch for more logs

Logs attached! I will also make a proper issue on the android github and collate all these threads / msgs

[logcat4.log](https://github.com/vector-im/element-android/files/10923781/logcat4.log)

### Outcome

#### What did you expect?

Phone to successfully register endpoint token with homeserver so that notifications are served successfully to the phone when the application isn't in focus via NTFY.

#### What happened instead?

No notification is ever received by the phone due to the failure to successfully register the pusher with synapse.

### Your phone model

Pixel 6 & Pixel 2 XL

### Operating system version

Android 13

### Application version and app store

1.5.28-dev [40105280] (G-448374fc) feature/bma/certList 448374fc (both with and without Patch applied

### Homeserver

On-Premise Installer 02.01 (Believe thats Synapse version 1.72.0)

### Will you send logs?

Yes

### Are you willing to provide a PR?

Yes

### Outcome

### Outcome

#### What did you expect?

Phone to successfully register endpoint token with homeserver so that notifications are served successfully to the phone when the application isn't in focus via NTFY.

#### What happened instead?

No notification is ever received by the phone due to the failure to successfully register the pusher with synapse.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.