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.

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

No normal notifications but occ test-pushes work fine #2213

Open
SteveCaruso opened this issue Feb 21, 2025 · 9 comments
Open

No normal notifications but occ test-pushes work fine #2213

SteveCaruso opened this issue Feb 21, 2025 · 9 comments

Comments

@SteveCaruso
Copy link

At a bit of a loss for this one.

Notifications were working fine up until about two weeks ago.

I have all notifications turned on and push notifications installed, but no matter what I do, no notifications are being sent for normal actions (Talk, file changes, etc. etc. etc.). Not to any browser tabs, not to the Talk app, not to the Nextcloud app, regardless if it's Android or iOS.

However, When I test notifications with occ notification:test-push --talk xxx the test push works without issue for all connected endpoints.

I re-authenticated/re-logged to refresh all tokens, in so it doesn't (immediately) seem to be related to #2157 .

Server configuration

Web server: Apache

Database: MySQL

PHP version: 8.2.25

Nextcloud version: 29.0.12

List of activated apps
Enabled:
  - activity: 2.21.1
  - app_api: 3.2.3
  - assistant: 1.1.0
  - bookmarks: 14.2.7
  - bruteforcesettings: 2.9.0
  - calendar: 4.7.16
  - checksum: 1.2.5
  - circles: 29.0.0-dev
  - cloud_federation_api: 1.12.0
  - collectives: 2.16.1
  - comments: 1.19.0
  - contacts: 6.0.3
  - contactsinteraction: 1.10.0
  - cookbook: 0.11.2
  - dashboard: 7.9.0
  - dav: 1.30.1
  - deck: 1.13.3
  - external: 5.4.1
  - federatedfilesharing: 1.19.0
  - federation: 1.19.0
  - files: 2.1.1
  - files_downloadlimit: 2.0.0
  - files_external: 1.21.0
  - files_pdfviewer: 2.10.0
  - files_reminders: 1.2.0
  - files_sharing: 1.21.0
  - files_trashbin: 1.19.0
  - files_versions: 1.22.0
  - fileslibreofficeedit: 2.0.1
  - firstrunwizard: 2.18.0
  - flow_notifications: 1.9.0
  - forms: 4.3.7
  - groupfolders: 17.0.10
  - impersonate: 1.16.0
  - integration_mastodon: 3.1.1
  - integration_openai: 2.0.3
  - logreader: 2.14.0
  - lookup_server_connector: 1.17.0
  - maps: 1.4.0
  - news: 25.2.1
  - nextcloud_announcements: 1.18.0
  - notes: 4.11.0
  - notifications: 2.17.0
  - notify_push: 1.0.0
  - oauth2: 1.17.1
  - otpmanager: 0.5.4
  - password_policy: 1.19.0
  - passwords: 2024.12.21
  - phonetrack: 0.8.2
  - photos: 2.5.0
  - polls: 7.3.1
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recommendations: 2.1.0
  - related_resources: 1.4.0
  - richdocuments: 8.4.9
  - richdocumentscode: 24.4.1103
  - serverinfo: 1.19.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - spreed: 19.0.13
  - support: 1.12.0
  - survey_client: 1.17.0
  - systemtags: 1.19.0
  - tables: 0.8.4
  - text: 3.10.1
  - theming: 2.4.0
  - twofactor_backupcodes: 1.18.0
  - twofactor_nextcloud_notification: 3.9.0
  - twofactor_totp: 11.0.0-dev
  - updatenotification: 1.19.1
  - user_status: 1.9.0
  - viewer: 2.3.0
  - weather_status: 1.9.0
  - workflowengine: 2.11.0
Disabled:
  - admin_audit: 1.19.0
  - context_chat: 2.2.1 (installed 2.2.1)
  - encryption: 2.17.0
  - files_rightclick: 0.15.1 (installed 1.6.0)
  - mail: 3.7.15 (installed 3.7.15)
  - memories: 7.2.0 (installed 7.2.0)
  - suspicious_login: 7.0.0
  - talk_matterbridge: 1.31.1026000 (installed 1.31.1026000)
  - tasks: 0.16.1 (installed 0.16.1)
  - user_ldap: 1.20.0
Nextcloud configuration
{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            ***redacted***
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "29.0.12.2",
        "overwrite.cli.url": "https:\/\/***redacted***",
        "overwriteprotocol": "https",
        "htaccess.RewriteBase": "\/",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "maintenance": false,
        "theme": "",
        "loglevel": 2,
        "mail_smtpmode": "smtp",
        "mail_sendmailmode": "smtp",
        "memories.exiftool_no_local": true,
        "memories.vod.path": "\/var\/www\/***redacted***\/public_html\/apps\/memories\/bin-ext\/go-vod-amd64",
        "updater.release.channel": "stable",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memories.db.triggers.fcu": true,
        "app_install_overwrite": [
            "news",
            "talk_matterbridge"
        ],
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***"
    }
}

Browser

Browser name: All browsers

Browser version: Various

Operating system: Fedora 41

Browser log

This is the log, opening Talk and sending and receiving a message when the tab is inactive.

[DEBUG] spreed: 3gji9v8q | long polling | 6 090.00 ms status undefined [talk-main.js:34510:451](https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10)
Error happened while getting chat messages. Trying again in  6 
Object { stack: "o@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33523:2101\n17013/x</</Je.onabort@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33522:4342\nEventHandlerNonNull*17013/x</<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33522:4313\n17013/x<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33522:3430\nA@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33524:1635\npromise callback*_request@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33523:1117\nrequest@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33522:8038\n55978/</E.prototype[w]@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33523:1600\n12125/l/<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33524:7785\nwS@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:34060:332\nrequest@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:34510:102\nlookForNewMessages@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:34530:13647\n_r/<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33545:9257\nZa.prototype.dispatch@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33545:5485\nZa/this.dispatch@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33545:4504\ngetNewMessages@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:36233:19574\ngetNewMessages/<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:36233:20002\nsetTimeout handler*getNewMessages@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:36233:19981\n", message: "Request aborted", name: "AxiosError", code: "ECONNABORTED", config: {…}, request: XMLHttpRequest }
[talk-main.js:36233:20162](https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10)
Navigating away, leaving conversation [talk-main.js:36494:4094](https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10)
Content-Security-Policy: Ignoring “blob:” within script-src-elem: ‘strict-dynamic’ specified [3gji9v8q](https://***redacted***/call/3gji9v8q)
[WARN] viewer: Some mimes were ignored because they are not enabled in the server previews config 
Object { app: "viewer", uid: "steve", level: 2, ignoredMimes: (3) […] }
[previewUtils-Br-PuwWw.chunk.mjs:973:459](https://***redacted***/apps/viewer/js/previewUtils-Br-PuwWw.chunk.mjs)
Unified search initialized! [UnifiedSearch.vue:54](webpack:///nextcloud/core/src/views/UnifiedSearch.vue)
Setting current user [App.vue:444:11](webpack:///talk/src/App.vue)
Conversations have been restored from BrowserStorage [conversationsStore.js:429:10](webpack:///talk/src/store/conversationsStore.js)
Detected browser Firefox 134 (134.0) [browserCheck.js:76:9](webpack:///talk/src/utils/browserCheck.js)
Initializing unified search plugin-filters from talk [search.js:41:10](webpack:///talk/src/search.js)
session heartbeat polling started [session-heartbeat.js:103:9](webpack:///nextcloud/core/src/session-heartbeat.js)
Registering notifications container as a menu [NotificationsApp.vue:237](webpack:///notifications/src/NotificationsApp.vue)
Notifications permissions granted [NotificationsApp.vue:480](webpack:///notifications/src/NotificationsApp.vue)
Has notify_push enabled, slowing polling to 15 minutes [NotificationsApp.vue:249](webpack:///notifications/src/NotificationsApp.vue)
Polling interval updated to 900000 [NotificationsApp.vue:443](webpack:///notifications/src/NotificationsApp.vue)
Started background fetcher as session_keepalive is enabled [NotificationsApp.vue:293](webpack:///notifications/src/NotificationsApp.vue)
Content-Security-Policy: The page’s settings blocked a JavaScript eval (script-src) from being executed because it violates the following directive: “script-src 'nonce-ZVIrSzFqbEN3SWQvYVdaMEZNRHNIamxtQllhaklyRkhkc3hSU2MyZlprVT06Tml1K2hYZ0Q5K0lHQ3hJY1pJZWhhVUZmTWYvWmFQZ0dQcHhuQWJ6TUZHbz0=' blob:” (Missing 'unsafe-eval') [3gji9v8q:112:31](https://***redacted***/call/3gji9v8q)
[WASM] Loading model of size: 249792 [talk-JitsiStreamBackgroundEffect.worker.worker.js:1:7917](https://***redacted***/apps/spreed/js/talk-JitsiStreamBackgroundEffect.worker.worker.js?v=2152220e2d9b93980901)
INFO: Created TensorFlow Lite XNNPACK delegate for CPU. [talk-JitsiStreamBackgroundEffect.worker.worker.js:1:7917](https://***redacted***/apps/spreed/js/talk-JitsiStreamBackgroundEffect.worker.worker.js?v=2152220e2d9b93980901)
Search providers 
Array(28) [ {…}, {…}, {…}, {…}, {…}, {…}, {…}, {…}, {…}, {…}, … ]
[UnifiedSearchModal.vue:276](webpack:///nextcloud/core/src/views/UnifiedSearchModal.vue)
Contacts 
Array(26) [ {…}, {…}, {…}, {…}, {…}, {…}, {…}, {…}, {…}, {…}, … ]
[UnifiedSearchModal.vue:280](webpack:///nextcloud/core/src/views/UnifiedSearchModal.vue)
[DEBUG] spreed: 3gji9v8q | get context | 1 676.00 ms status 200 [debugTimer.ts:27:10](webpack:///talk/src/utils/debugTimer.ts)
Scrolling to a focused message programmatically [MessagesList.vue:1055:11](webpack:///talk/src/components/MessagesList/MessagesList.vue)
X-Nextcloud-Talk-Hash initialised:  b6ecf2a017ed1725e5cb313de3c5a49b1f5c0080 [talkHash.js:58:12](webpack:///talk/src/stores/talkHash.js)
Conversations were saved to BrowserStorage. Estimated object size: 13.85 kB [conversationsStore.js:445:10](webpack:///talk/src/store/conversationsStore.js)
Got notification data, restoring default polling interval. [NotificationsApp.vue:399](webpack:///notifications/src/NotificationsApp.vue)
Content-Security-Policy: The page’s settings blocked the loading of a resource (default-src) at https://***redacted***/apps/bookmarks/js/bookmarks-src_components_CustomPickerElement_vue.js?v=701bcc160f3393c4928b because it violates the following directive: “default-src 'none'” [3gji9v8q](https://***redacted***/call/3gji9v8q)
Joined [signaling.js:242:10](webpack:///talk/src/utils/signaling.js)
Conversations were saved to BrowserStorage. Estimated object size: 13.85 kB [conversationsStore.js:445:10](webpack:///talk/src/store/conversationsStore.js)
[DEBUG] spreed: 3gji9v8q | long polling | 30 208.00 ms status 304 [debugTimer.ts:27:10](webpack:///talk/src/utils/debugTimer.ts)
setVisualLastReadMessageId token=3gji9v8q id=12714 [MessagesList.vue:897:11](webpack:///talk/src/components/MessagesList/MessagesList.vue)
[DEBUG] spreed: 3gji9v8q | long polling | 11 145.00 ms status 200 [debugTimer.ts:27:10](webpack:///talk/src/utils/debugTimer.ts)
[DEBUG] spreed: 3gji9v8q | long polling | 5 131.00 ms status 200 [debugTimer.ts:27:10](webpack:///talk/src/utils/debugTimer.ts)
Session has been marked as inactive [useActiveSession.js:107:11](webpack:///talk/src/composables/useActiveSession.js)
Conversations were saved to BrowserStorage. Estimated object size: 13.81 kB [conversationsStore.js:445:10](webpack:///talk/src/store/conversationsStore.js)
[DEBUG] spreed: 3gji9v8q | long polling | 30 071.00 ms status 304 [debugTimer.ts:27:10](webpack:///talk/src/utils/debugTimer.ts)
Conversations were saved to BrowserStorage. Estimated object size: 13.81 kB [conversationsStore.js:445:10](webpack:///talk/src/store/conversationsStore.js)
[DEBUG] spreed: 3gji9v8q | long polling | 21 154.00 ms status 200 [debugTimer.ts:27:10](webpack:///talk/src/utils/debugTimer.ts)
setVisualLastReadMessageId token=3gji9v8q id=12716 2 [MessagesList.vue:897:11](webpack:///talk/src/components/MessagesList/MessagesList.vue)
Session has been marked as active [useActiveSession.js:87:11](webpack:///talk/src/composables/useActiveSession.js)
Conversations were saved to BrowserStorage. Estimated object size: 13.81 kB

And this is the output from the notifications test:

Trying to push to 2 devices

Language is set to en
Private user key size: 1704
Public user key size: 451
Identified 1 Talk devices and 1 others.

Device token:106550
Device token is valid
Device public key size: 450
Data to encrypt is: {"nid":7386,"app":"admin_notification_talk","subject":"Testing push notifications","type":"admin_notifications","id":"67b7cb43"}
Signed encrypted push subject
Push notification sent successfully

After which my browser and my Android Talk install both received the notification without issue.

Similarly with any other notifications for any other type.

Thanks.

@SteveCaruso
Copy link
Author

And I'm at a further loss, as the moment I submitted this -- without changing anything -- I received a notification. But it was from a group chat that I had not been testing notifications from. Here's the javascript log:

[DEBUG] spreed: oe3kxb6t | get context | 909.00 ms status 200 debugTimer.ts:27:10
Message to focus not found in DOM 12398 MessagesList.vue:1045:12
Scrolling to a focused message programmatically MessagesList.vue:1055:11
Deferring notification refresh from browser storage are notify_push event to give the last tab the chance to do it NotificationsApp.vue:369
Invalid avatar url /avatar/Family/64/dark NcAvatar-lRUjWiR6.mjs:524:16
clearLastReadMessage because of isSticky token=oe3kxb6t MessagesList.vue:964:12
Got notification data, restoring default polling interval. NotificationsApp.vue:399
File info for /Talk/IMG_2648.jpg fetched 
Object { filename: "/Talk/IMG_2648.jpg", basename: "IMG_2648.jpg", lastmod: "Fri, 21 Feb 2025 21:48:39 GMT", size: 358928, type: "file", etag: "b9c9c1bc1bfbddcadcf892c6228965a0", mime: "image/jpeg", tags: "", getcontentlength: 358928, getcontenttype: "image/jpeg", … }
viewer-main.mjs:9:14127
setVisualLastReadMessageId token=oe3kxb6t id=12721 MessagesList.vue:897:11
OC.requestToken changed BQFDX5uZmGyUwczOG00qM2RcE3CzSlXCzJWePj1j+I0=:SjV3DNrYrwnto7imawpnRBxlJwnJAByDhMWodkwwiqI= index.js:314:9
Conversations were saved to BrowserStorage. Estimated object size: 13.77 kB conversationsStore.js:445:10
[DEBUG] spreed: oe3kxb6t | long polling | 30 160.00 ms status 304 debugTimer.ts:27:10
Conversations were saved to BrowserStorage. Estimated object size: 13.77 kB conversationsStore.js:445:10
Scrolling to a focused message programmatically MessagesList.vue:1055:11
[DEBUG] spreed: oe3kxb6t | long polling | 25 032.00 ms cancelled debugTimer.ts:27:10
The request has been canceled 
Object { stack: "o@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33523:2101\nc@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33522:7538\n64874/o/<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33522:6916\ncancelLookForNewMessages@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:34530:15146\n_r/<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33545:9257\nZa.prototype.dispatch@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33545:5485\nZa/this.dispatch@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:33545:4504\nhandler@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:36233:11856\nln@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:27602:26504\n85471/k.prototype.run@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:27602:31154\nF@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:27602:36528\n85471/ne/<@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:27602:27585\ngn@https://***redacted***/apps/spreed/js/talk-main.js?v=0045b390-10:27602:26997\n", message: "canceled", name: "CanceledError", code: "ERR_CANCELED" }
MessagesList.vue:714:13
Joined signaling.js:242:10
[DEBUG] spreed: 3gji9v8q | long polling | 26 623.00 ms status 200 debugTimer.ts:27:10
Conversations were saved to BrowserStorage. Estimated object size: 13.79 kB conversationsStore.js:445:10
Session has been marked as inactive useActiveSession.js:107:11
[DEBUG] spreed: 3gji9v8q | long polling | 18 114.00 ms status 200 debugTimer.ts:27:10
Conversations were saved to BrowserStorage. Estimated object size: 13.78 kB conversationsStore.js:445:10
setVisualLastReadMessageId token=3gji9v8q id=12722 2 MessagesList.vue:897:11
Session has been marked as active useActiveSession.js:87:11
[DEBUG] spreed: 3gji9v8q | long polling | 30 565.00 ms status 304 debugTimer.ts:27:10
Conversations were saved to BrowserStorage. Estimated object size: 13.78 kB conversationsStore.js:445:10
[DEBUG] spreed: 3gji9v8q | long polling | 30 102.00 ms status 304 debugTimer.ts:27:10
Refreshing notifications are notify_push event NotificationsApp.vue:374
Got notification data, restoring default polling interval. NotificationsApp.vue:399
Conversations were saved to BrowserStorage. Estimated object size: 13.81 kB conversationsStore.js:445:10
clearLastReadMessage because of isSticky token=3gji9v8q MessagesList.vue:964:12
setVisualLastReadMessageId token=3gji9v8q id=12723 MessagesList.vue:897:11
[DEBUG] spreed: 3gji9v8q | long polling | 30 168.00 ms status 200

@SteveCaruso
Copy link
Author

SteveCaruso commented Feb 21, 2025

New twist!

I had the individual I was testing notifications with log out and log back in.

It seems that this is related to #2157 -- but on the receiving end, too.

@nickvergessen
Copy link
Member

It seems that this is related to #2157 -- but on the receiving end, too.

That is always on only on the receiving end.
We are working on a fix to a problem that was introduced with a recent change in server. It seems the getLastCheck is no longer updated regularly unless the password was explicitly provided, which is never the case by mobile apps. So we now switch to getLastCheck and getLastActivity and simply take the maximum of it. But since that is not public API it's not as easy.

That being said, the notification:test-push should have told you then that a device was ignored because of the 60 days? But you didn't share the log.

@SteveCaruso
Copy link
Author

I did share the log, but I stuck it at the bottom of the Browser Log section. My apologies.

Here it is again:

Trying to push to 2 devices

Language is set to en
Private user key size: 1704
Public user key size: 451
Identified 1 Talk devices and 1 others.

Device token:106550
Device token is valid
Device public key size: 450
Data to encrypt is: {"nid":7386,"app":"admin_notification_talk","subject":"Testing push notifications","type":"admin_notifications","id":"67b7cb43"}
Signed encrypted push subject
Push notification sent successfully

No expiry notices.

@SteveCaruso
Copy link
Author

So to recap:

My devices were not receiving notifications from another user's actions (e.g. when they changed files, or when they messaged me on Talk).

Once that other user refreshed their credentials, I started receiving notifications from their actions again.

My device's credentials were current the entire time.

@nickvergessen
Copy link
Member

Identified 1 Talk devices and 1 others.

The test command might be a bit misleading. in that case, maybe we need to make it more obvious, but notification:test-push --talk should have pinged the talk app and check if that one received a message.

Maybe we can adjust the command output to help with that, or do all devices by default and add a --files as counter part for --talk

@SteveCaruso
Copy link
Author

I'm not sure I'm being properly understood, so please forgive me:

When I used notification:test-push --talk it pinged me fine every time. I had one browser window open, and Talk on my Android phone, and both got the test notifications.

I wasn't getting any notifications from the other user until they logged out and logged back in.

Before they logged out and logged back in, I could be looking at the Talk conversation's tab in the browser and seeing the asterix show up for new messages from their conversation from polling, but no notification. Or I could be watching when they would change a file or folder and refresh or not, and no notification would land on my end.

So it appears that even if someone's credentials are off, they are not sending notifications to other users in my case.

@nickvergessen
Copy link
Member

So it appears that even if someone's credentials are off, they are not sending notifications to other users in my case.

No that's definitely not the case. It's more likely then, that you did not leave the conversation, and when you have an active session we do not send push notifications

@SteveCaruso
Copy link
Author

Highly unlikely. The person who I was messaging logging out and logging back in was the sole variable that changed when messages from their actions started being sent to my account again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants