Closed drpetersen closed 8 months ago
Do you see the matching user in these logs in the original, or are they censored on the disk already:
{
"file": "/var/www/**domain1**/nextcloud/lib/private/Authentication/Token/Manager.php",
"line": 154,
"function": "getTokenById",
"class": "OC\\Authentication\\Token\\PublicKeyTokenProvider",
"type": "->",
"args": [
"*** sensitive parameters replaced ***"
]
},
{
"file": "/var/www/**domain1**/nextcloud/apps/notifications/lib/Push.php",
"line": 580,
"function": "getTokenById",
"class": "OC\\Authentication\\Token\\Manager",
"type": "->",
"args": [
"*** sensitive parameters replaced ***"
]
},
{
"file": "/var/www/**domain1**/nextcloud/apps/notifications/lib/Push.php",
"line": 337,
"function": "validateToken",
"class": "OCA\\Notifications\\Push",
"type": "->",
"args": [
"*** sensitive parameters replaced ***"
]
},
{
"file": "/var/www/**domain1**/nextcloud/apps/notifications/lib/App.php",
"line": 58,
"function": "pushToDevice",
"class": "OCA\\Notifications\\Push",
"type": "->",
"args": [
"*** sensitive parameters replaced ***"
]
},
As far as I understand the password of the access token was marked invalid as it might have changed in the user backend: https://github.com/nextcloud/server/blob/ffdf49a9c2f90f404628232f8b1756db7fdf4603/lib/private/User/Session.php#L773
It should heal automatically after the user logged in via the web interface using the new password: https://github.com/nextcloud/server/blob/ffdf49a9c2f90f404628232f8b1756db7fdf4603/lib/private/Authentication/Listeners/UserLoggedInListener.php#L60
It's a bit strange that no one complained about this for such a long time, so I assume some path changed somewhere recently. However I'm not sure this is really fixable on the notifications side neither on any of the other apps.
The only option I see is: clients need to be able to "get to know" this state and then need to ask the user to perform a login on the web view.
Thanks a lot for your reply. The logs were copied from the /settings/admin/logging
app, and the *** sensitive parameters replaced ***
had already been censored; the **domain1**
was replaced manually by me.
EDIT: Oh, and yes, the *** sensitive parameters replaced ***
is also what is stored verbatim in the log on disk, just looked that up directly in the log file.
Actually, problem A (the calendar problem) started after I switched to the user_oidc
backend on that instance very recently; for problem B, I cannot really tell, because that has gone unnoticed for a long time (like half a year). Might also have been related with the switch to user_oidc
, which I made a lot earlier on that instance.
I do not quite understand what you mean by:
It should heal automatically after the user logged in via the web interface using the new password
I tried what I thought you were saying, i.e. logged in via /login?direct=1
once, but this does not help. (Logged in as the user receiving the notifications, i.e. the one to whom the calendar is shared; but just to be safe also logged in once as the calendar owner.) Should I do something else instead?
Is there some other workaround I might try, like manually clearing expired tokens from some database table or cache?
There is a occ notification:test-push
command:
https://github.com/nextcloud/notifications/blob/master/lib/Command/TestPush.php#L65
You can run that for all of the users involved in the problem.
I tried what I thought you were saying, i.e. logged in via /login?direct=1 once, but this does not help. (Logged in as the user receiving the notifications, i.e. the one to whom the calendar is shared; but just to be safe also logged in once as the calendar owner.) Should I do something else instead?
The problem is it has to be everyone involved in the action. So if multiple people would receive a notification from the same calendar change, all of them need to be okay (that part should be fixable).
Thank you, that is a very helpful hint. Just tried that command with my NC instance A (user1 is me, user2 is the user to whom the calendar is shared):
occ notification:test-push -- **user1**
Trying to push to 5 devices
Language is set to de_DE
Private user key size: 1708
Public user key size: 451
Identified 2 Talk devices and 3 others.
Device token:13943
Device token "last checked" is older than 60 days: 1561017956
Device token:35934
Device token "last checked" is older than 60 days: 1680682300
Device token:48216
Device token is valid
Device public key size: 451
Data to encrypt is: {"nid":14676,"app":"admin_notifications","subject":"Testing push notifications","type":"admin_notifications","id":"65d6f469"}
Signed encrypted push subject
Push notification sent successfully
So, the first one is from 2019 … small wonder it has expired. Actually, I received the test notification in a browser, and after viewing it, I now get:
occ notification:test-push -- **user1**
Trying to push to 5 devices
Language is set to de_DE
Private user key size: 1708
Public user key size: 451
Identified 2 Talk devices and 3 others.
Device token:13943
Device token:35934
Device token:48216
Device public key size: 451
Data to encrypt is: {"nid":14681,"app":"admin_notifications","subject":"Testing push notifications","type":"admin_notifications","id":"65d6fa95"}
Signed encrypted push subject
Push notification sent successfully
So somehow, the expired tokens got renewed. How that happened, I have no idea (but you do, I guess …).
Now for the other user:
occ notification:test-push -- **user2**
Trying to push to 3 devices
Language is set to de_DE
Private user key size: 1704
Public user key size: 451
Identified 1 Talk devices and 2 others.
Device token:15680
Device token "last checked" is older than 60 days: 1561567290
Device token:38119
In PublicKeyTokenProvider.php line 216:
[OC\Authentication\Exceptions\TokenPasswordExpiredException]
notification:test-push [--talk] [--] <user-id>
So, another token dating back to 2019 … If I understand you correctly, that user2 would now have to somehow refresh that token?
I logged in as that user via OIDC – viewed the test notification, tried to dismiss it, got the error message "Notification cannot be dismissed"; then logged out, logged in via /login?direct=1
, viewed notifications, tried to dismiss them, same error. Re-run the above occ
invocation, with almost the same result:
occ notification:test-push -- **user2**
Trying to push to 3 devices
Language is set to de_DE
Private user key size: 1704
Public user key size: 451
Identified 1 Talk devices and 2 others.
Device token:15680
Device token:38119
In PublicKeyTokenProvider.php line 216:
[OC\Authentication\Exceptions\TokenPasswordExpiredException]
notification:test-push [--talk] [--] <user-id>
So now, the "Device token: 15680" seems to have been renewed, but the command still errors out. Anything I could do to fix that? Is there a way to delete the tokens from the /settings/user/security
page of that user? How can I tell which ones, of the dozens listed there? What would be the side-effects? Or is there a better way?
Thanks for your time and help!
Can you run the following query for that user:
SELECT `id`, `password_invalid`, `last_activity`, `last_check`, `type`, `remember`, `name` FROM `oc_authtoken` WHERE `uid` = 'user2';
PS "name" is just to get an indication whether it's from a client or browser. If it contains real names (iPhone of User2) feel free to censor it away.
I found the "problem" why this comes up now
OC\Authentication\Exceptions\TokenPasswordExpiredException
extends OC\Authentication\Exceptions\ExpiredTokenException
extends
OCP\Authentication\Exceptions\ExpiredTokenException
extends
OCP\Authentication\Exceptions\InvalidTokenException
extends 🟥
Exception
but we catch
OC\Authentication\Exceptions\InvalidTokenException
extends 💥
OCP\Authentication\Exceptions\InvalidTokenException
extends 🟥
Exception
So our catch no longer covers TokenPasswordExpiredException
which it did before
OC\Authentication\Exceptions\TokenPasswordExpiredException
extends
OC\Authentication\Exceptions\InvalidTokenException
extends 🟦
Exception
and we catched
OC\Authentication\Exceptions\InvalidTokenException
extends 🟦
Exception
Can you run the following query for that user:
SELECT
id
,password_invalid
,last_activity
,last_check
,type
,remember
,name
FROMoc_authtoken
WHEREuid
= 'user2';
Sure! Here is the output:
Showing rows 0 - 15 (16 total, Query took 0.0004 seconds.)
SELECT `id`, `password_invalid`, `last_activity`, `last_check`, `type`, `remember`, `name` FROM `oc_authtoken` WHERE `uid` = '**user2**';
id password_invalid last_activity last_check type remember name
15680 0 1561567290 1561567290 1 0 Samsung SM-N910F
16204 0 1708588523 1708588523 1 0 Samsung SM-N910F (Nextcloud Talk)
17852 0 1624257933 1624257932 1 0 Samsung SM-N910F
34279 0 1610270375 1610270299 1 0 Thunderbird FileLink
36173 0 1640799711 1640799710 1 0 Samsung SM-N910F
38119 1 1708425985 1708425985 1 0 Samsung SM-A528B
40816 1 1684999518 1684999302 1 0 petersen (Desktop Client - Linux)
45661 1 1686933472 1686933202 1 0 petersen (Desktop Client - Linux)
46060 1 1708380770 1708380501 1 0 petersen (Desktop Client - Linux)
48239 1 1708507491 1708507222 1 0 petersen (Desktop Client - Linux)
48241 0 1708512899 1708512899 0 0 DAVx5/4.1-ose (2021/12/29; dav4jvm; okhttp/4.9.1) Android/13
48244 0 1708552868 1708552743 0 1 Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36
48246 0 1708556003 1708556003 0 0 DAVx5/4.1-ose (2021/12/29; dav4jvm; okhttp/4.9.1) Android/13
48249 0 1708588501 1708588501 0 1 Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36
48250 0 1708588636 1708588636 0 1 Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36
48251 0 1708600137 1708600137 0 0 DAVx5/4.1-ose (2021/12/29; dav4jvm; okhttp/4.9.1) Android/13
So our catch no longer covers TokenPasswordExpiredException which it did before
Looks like an easy fix then … :wink: Thank you!
That being said, that would explain why some people loss their push hashes... if the password was temporarily invalid, we wiped the push token in 27 and before 🤔
Can you apply the following patch and then retry:
diff --git a/lib/Push.php b/lib/Push.php
index cfbd70c0..43bcea39 100644
--- a/lib/Push.php
+++ b/lib/Push.php
@@ -28,13 +28,13 @@ namespace OCA\Notifications;
use GuzzleHttp\Exception\ClientException;
use GuzzleHttp\Exception\ServerException;
-use OC\Authentication\Exceptions\InvalidTokenException;
use OC\Authentication\Token\IProvider;
use OC\Security\IdentityProof\Key;
use OC\Security\IdentityProof\Manager;
use OCA\Notifications\AppInfo\Application;
use OCP\AppFramework\Http;
use OCP\AppFramework\Utility\ITimeFactory;
+use OCP\Authentication\Exceptions\InvalidTokenException;
use OCP\DB\QueryBuilder\IQueryBuilder;
use OCP\Http\Client\IClientService;
use OCP\ICache;
YES! Both problems fixed. :tada:
As per commit message I'm not sure whether the behaviour is correct, but at least it's the same as on 27 again. I think this could really explain vanished push tokens we experienced in the past
From my point of view, everything looks fine. The affected user can also dismiss notifications again, which failed before.
So, I'm going to close this now, hope that's ok. Again, thank you!
Let's keep it open so it closes when the PR is merged
On two different Nextcloud instances, I experience problems with the notifications app which manifest themselves as problems with other apps which are triggering notifications. I am filing this here because in both cases I observed, the problems go away when the
notifications
app is disabled (or, in the case of the calendar app malfunctioning, theevent_update_notification
app).Problem scenario A (calendar):
Steps to reproduce
calendar
, thenotifications
, and theevent_update_notification
apps.Expected behaviour
The data entry sidebar should close and the new appointment should be saved in the calendar.
Actual behaviour
The spinner displaying progress spins infinitely in the now empty data entry sidebar. When I refresh the page, the data entry sidebar is still open with the unsaved appointment.
Problem scenario B (files_pdfviewer):
Steps to reproduce
files_pdfviewer
and thenotifications
appExpected behavior
The PDF file should be displayed in the PDF viewer app.
Actual behaviour
The sharing page opens, but the PDF viewer pane remains empty.
I can reproduce the
calendar
problem reliably on one of the two Nextcloud instances, but not on the other; thefiles_pdfviewer
problem on the other hand happens consistently on the latter instance, but cannot be reproduced on the former. Both instances run on the same server, in the same nginx + php8.2-fpm stack.A problem similar to scenario A has been reported as an issue against the calendar app:
Also, these two issues might be related, as they also involve
TokenPasswordExpiredException
s:Server configuration (identical for both instances, unless otherwise specified)
Operating system: Linux 6.1.0-18-amd64 x86_64 (Debian trixie/sid)
Web server: nginx 1.24.0-2+b1
Database: mysql 10.11.6
PHP version: 8.2.7
Nextcloud version: Nextcloud Hub 7 (28.0.3 RC1)
Where did you install Nextcloud from: via the built-in updater (originally, from Github, ages ago)
Signing status:
List of activated apps:
For the instance from scenario A:
For the instance in scenario B:
Nextcloud configuration:
Instance from scenario A:
Instance from scenario B:
Are you using an external user-backend, if yes which one:
user_oidc
, and also LDAP in the first instance.Client configuration
Browser: Any of Firefox (122.0.1), Brave
[Version 1.64.74 Chromium: 122.0.6261.43 (Offizieller Build) beta (64-Bit)](https://brave.com/latest/)
, Chromium Version121.0.6167.160 (Official Build) built on Debian trixie/sid, running on Debian trixie/sid (64-bit)
Operating system:
Linux 6.6.15-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.6.15-2 (2024-02-04) x86_64 GNU/Linux
Logs
Nextcloud log (data/nextcloud.log)
Scenario A:
Scenario B:
Browser log
Scenario A (browser console log):
Scenario B (browser console log):
Thank you for looking into this. If it would have been better to file two separate issues, please advise me to do so. Also, if there is anything else I can do to help debug this, let me know.