search

nextcloud / server

☁️ Nextcloud server, a safe home for all your data
https://nextcloud.com
GNU Affero General Public License v3.0
27.32k stars 4.06k forks source link

Token is not valid: Token does not exist #30394

Open fossxplorer opened 2 years ago

fossxplorer commented 2 years ago

NC stable22, MariaDB 1.5 and PHP 7.3 on CentOS 8 Stream.

NC logs shows a lot of the following exceptions:

{"reqId":"gXUwPAhcxv5kTMEsh3Kj","level":0,"time":"2021-12-23T13:30:13+01:00","remoteAddr":"85.226.165.230","user":"--\
","app":"no app in context","method":"PROPFIND","url":"/remote.php/webdav/user001/Tabs/D/Decapitated","message":"Toke\
n is not valid: Token does not exist","userAgent":"--","version":"22.2.3.0","exception":{"Exception":"OC\\Authenticat\
ion\\Exceptions\\InvalidTokenException","Message":"Token does not exist","Code":0,"Trace":[{"file":"/var/www/nextclou\
d/lib/private/Authentication/Token/Manager.php","line":146,"function":"getToken","class":"OC\\Authentication\\Token\\\
DefaultTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/p\
rivate/User/Session.php","line":531,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","a\
rgs":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":447,\
"function":"isTokenPassword","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]\
},{"file":"/var/www/nextcloud/apps/dav/lib/Connector/Sabre/Auth.php","line":129,"function":"logClientIn","class":"OC\\
\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/3rdparty/sa\
bre/dav/lib/DAV/Auth/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\DAV\\Connector\
\\Sabre\\Auth","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/apps/dav/lib\
/Connector/Sabre/Auth.php","line":252,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"-\
>","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextcloud/a\
pps/dav/lib/Connector/Sabre/Auth.php","line":154,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":\
"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextcloud\
/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":182,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth"\
,"type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/n\
extcloud/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":137,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin"\
,"type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/n\
extcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\\
Auth\\Plugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file\
":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server\
","type":"->","args":["beforeMethod:PROPFIND",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Respon\
se"}]]},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","clas\
s":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"\
}]},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\\
DAV\\Server","type":"->","args":[]},{"file":"/var/www/nextcloud/apps/dav/appinfo/v1/webdav.php","line":83,"function":\
"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/nextcloud/remote.php","line":166,"args":\
["/var/www/nextcloud/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/nextcloud/lib/priv\
ate/Authentication/Token/DefaultTokenProvider.php","Line":159,"Previous":{"Exception":"OCP\\AppFramework\\Db\\DoesNot\
ExistException","Message":"token does not exist","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/Authentica\
tion/Token/DefaultTokenProvider.php","line":157,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultToke\
nMapper","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/Authen\
tication/Token/Manager.php","line":146,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenProvider\
","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.\
php","line":531,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive\
 parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":447,"function":"isTokenP\
assword","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/\
nextcloud/apps/dav/lib/Connector/Sabre/Auth.php","line":129,"function":"logClientIn","class":"OC\\User\\Session","typ\
e":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Auth\
/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type\
":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/apps/dav/lib/Connector/Sabre/Aut\
h.php","line":252,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->","args":[{"__class\
__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextcloud/apps/dav/lib/Connecto\
r/Sabre/Auth.php","line":154,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":[{"__cla\
ss__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/\
lib/DAV/Auth/Plugin.php","line":182,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":\
[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextcloud/3rdparty/sa\
bre/dav/lib/DAV/Auth/Plugin.php","line":137,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->","args":\
[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextcloud/3rdparty/sa\
bre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type"\
:"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/nextclou\
d/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args"\
:["beforeMethod:PROPFIND",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/va\
r/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Serv\
er","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/ww\
w/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":\
"->","args":[]},{"file":"/var/www/nextcloud/apps/dav/appinfo/v1/webdav.php","line":83,"function":"exec","class":"Sabr\
e\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/nextcloud/remote.php","line":166,"args":["/var/www/nextcloud\
/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/nextcloud/lib/private/Authentication/T\
[5~oken/DefaultTokenMapper.php","Line":93},"CustomMessage":"Token is not valid: Token does not exist"}}

Is this expected with loglevel set to 0?

brianjmurrell commented 2 years ago

Also seeing this. Would be useful to get a comment on the status of this.

I can't even determine if it's actually causing any problems or not (yet).

coldtobi commented 2 years ago

Same here. Edit: My case is only similar. the backtrace shares a part with the TokenManager. Complete backtrace here: https://jsoneditoronline.org/#left=cloud.97fe1188d4374fd0a9d9e3dc62f52b20

I've been debugging into my case, and could find the reason: My server id using HttpAuth for other non nextcloud parts, so nextcloud tried to use the http-auth user to login the next cloud instance. However, those users are different, so that cannot work. (the server is using user "Foo" while my nextcloud user account is "bar").

NC: Nextcloud Hub II (23.0.0) PHP 7.3 (Debian 10) MariaDB 10.3 (Debian 10)

gdudas commented 2 years ago

We have the same issue after update to 23.0.2.1:

{"reqId":"sUehux83rMs3kZHGCXcO","level":0,"time":"2022-02-23T19:15:13+00:00","remoteAddr":"xxx.131.71.xxx","user":"--","app":"no app in context","method":"PROPFIND","url":"/remote.php/dav/","message":"Token is not valid: Token does not exist","userAgent":"iOS/14.8.1 (18H107) accountsd/1.0","version":"23.0.2.1","exception":{"Exception":"OC\\Authentication\\Exceptions\\InvalidTokenException","Message":"Token does not exist","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Authentication/Token/Manager.php","line":146,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":531,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":447,"function":"isTokenPassword","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":129,"function":"logClientIn","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":252,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":154,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":182,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":137,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args":["beforeMethod:PROPFIND",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/lib/Server.php","line":339,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/DefaultTokenProvider.php","Line":150,"Previous":{"Exception":"OCP\\AppFramework\\Db\\DoesNotExistException","Message":"token does not exist","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Authentication/Token/DefaultTokenProvider.php","line":148,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenMapper","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/Authentication/Token/Manager.php","line":146,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":531,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":447,"function":"isTokenPassword","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":129,"function":"logClientIn","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":252,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":154,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":182,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":137,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args":["beforeMethod:PROPFIND",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/lib/Server.php","line":339,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/DefaultTokenMapper.php","Line":93},"CustomMessage":"Token is not valid: Token does not exist"}}
squash commented 2 years ago

I'm also seeing this on carddav requests and they've gone from being quite fast to taking 4+ seconds to respond with multiple entries similar to the initial report. In my case the client is RoundCube webmail.

{"reqId":"Lctl71QjVA7Li7KWisNR","level":0,"time":"2022-03-18T19:35:28+00:00","remoteAddr":"172.17.0.2","user":"--","app":"no app in
context","method":"REPORT","url":"/remote.php/dav/addressbooks/users/xxx@xxx/default/","message":"Token is not valid: Token does not exist","userAgent":"RCM CardDAV
plugin/2.0.4","version":"22.2.5.1","exception":{"Exception":"OC\\Authentication\\Exceptions\\InvalidTokenException","Message":"Token does not
exist","Code":0,"Trace":[{"file":"/var/customers/domains/xyz.xyz/lib/private/Authentication/Token/Manager.php","line":146,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenProvider","type":"->","args":["***
sensitive parameters replaced ***"]},{"file":"/var/customers/domains/xyz.xyz/lib/private/User/Session.php","line":531,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive
parameters replaced ***"]},{"file":"/var/customers/domains/xyz.xyz/lib/private/User/Session.php","line":447,"function":"isTokenPassword","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Connector/Sabre/Auth.php","line":129,"function":"logClientIn","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Auth/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":["***
sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Connector/Sabre/Auth.php","line":252,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->"},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Connector/Sabre/Auth.php","line":154,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":182,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":137,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Server.php","line":333,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/remote.php","line":166,"args":["/var/customers/domains/xyz.xyz/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/customers/domains/xyz.xyz/lib/private/Authentication/Token/DefaultTokenProvider.php","Line":159,"Previous":{"Exception":"OCP\\AppFramework\\Db\\DoesNotExistException","Message":"token
does not
exist","Code":0,"Trace":[{"file":"/var/customers/domains/xyz.xyz/lib/private/Authentication/Token/DefaultTokenProvider.php","line":157,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenMapper","type":"->","args":["***
sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/lib/private/Authentication/Token/Manager.php","line":146,"function":"getToken","class":"OC\\Authentication\\Token\\DefaultTokenProvider","type":"->","args":["*** sensitive
parameters replaced ***"]},{"file":"/var/customers/domains/xyz.xyz/lib/private/User/Session.php","line":531,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters
replaced ***"]},{"file":"/var/customers/domains/xyz.xyz/lib/private/User/Session.php","line":447,"function":"isTokenPassword","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Connector/Sabre/Auth.php","line":129,"function":"logClientIn","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Auth/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->","args":["***
sensitive parameters replaced
***"]},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Connector/Sabre/Auth.php","line":252,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->"},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Connector/Sabre/Auth.php","line":154,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":182,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":137,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/apps/dav/lib/Server.php","line":333,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->"},{"file":"/var/customers/domains/xyz.xyz/remote.php","line":166,"args":["/var/customers/domains/xyz.xyz/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/customers/domains/xyz.xyz/lib/private/Authentication/Token/DefaultTokenMapper.php","Line":93},"CustomMessage":"Token
is not valid: Token does not exist"}}
glorenzutti commented 2 years ago

Same here. Does anyone found a solution? I didn't try to upgrade to nc24 yet.

legion151 commented 2 years ago

Can relate. I use calendars in thunderbird via caldav. Thunderbird tells me most of the time, that the calendars are not available atm. Found this log now and assume this is the problem.

rahliak commented 2 years ago

Same problem here. My mariadb-usage goes up to 50%-60% CPU. I made a tcpdump and found lots of "UPDATE oc_authtoken SET password = ..."-entries per second (about 22 MB in ~30 seconds). I found lots of "Token does not exist"-messages in nextcloud.log (caldav and webdav). [Nextcloud 24.0.1]

fabwal commented 2 years ago

Same here. Cannot login with some users over LDAP. Nothing specific in the logs. Is it possible to just delete all authtokens from the table? [Nextcloud 24.0.1]

fabwal commented 2 years ago

Same here. Cannot login with some users over LDAP. Nothing specific in the logs. Is it possible to just delete all authtokens from the table? [Nextcloud 24.0.1]

Solved it by deleting all entries from oc_authtoken related to my user (>5900 entries). Can login now :)

Sectorchan commented 2 years ago

I also cleared the bruteforce table and now the caldav login worked on my side.

dshcherb commented 2 years ago

@fabwal

Thanks for the hint. I suddenly couldn't login into only one of my users on 24.0.4snap1.

# the snap-based version has a shortcut to launch the MySQL client:
sudo nextcloud.mysql-client 

mysql> use nextcloud;
mysql> delete from oc_authtoken where uid = "your-affected-user-name";
Query OK, 11927 rows affected (2.75 sec)
szaimen commented 1 year ago

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

My goal is to add a label like e.g. 25-feedback to this ticket of an up-to-date major Nextcloud version where the bug could be reproduced. However this is not going to work without your help. So thanks for all your effort!

If you don't manage to reproduce the issue in time and the issue gets closed but you can reproduce the issue afterwards, feel free to create a new bug report with up-to-date information by following this link: https://github.com/nextcloud/server/issues/new?assignees=&labels=bug%2C0.+Needs+triage&template=BUG_REPORT.yml&title=%5BBug%5D%3A+

nietsmmar commented 1 year ago

@szaimen I am having the same issue with version 25.0.3.

remytms commented 1 year ago

Same for me with NC 25.0.3, Postgresql 14 database and PHP 8.1. Using Davx5 to sync on an Android phone.

tamasgal commented 1 year ago

Huh, OK I guess I hit the same problem in https://github.com/nextcloud/calendar/issues/5048

ChristophWurst commented 1 year ago

This logged error is not necessarily a problem.

During DAV login we check if the provided password is an app password. That is done by checking if a matching token exists. Code is at https://github.com/nextcloud/server/blob/394ad988c7157c0f576b78d591e48e330fe6ca7f/lib/private/User/Session.php#L436. The method happens to log https://github.com/nextcloud/server/blob/394ad988c7157c0f576b78d591e48e330fe6ca7f/lib/private/User/Session.php#L526-L531 with debug level.

If you logged in with an actual app password this is a problem. If you logged in with the login password (like on the login page) then this log message can be safely ignored. It is expected that your password does not match a token in the database.

tamasgal commented 1 year ago

Btw. I have a fresh install with about 160 LDAP users (no migrations whatsoever) and so far nobody managed to sync LDAP on a macOS or iOS calendar. I see "Token is not valid" messages when trying to sign in.

The workaround with clearing the oc_authtoken rows had no effect.

tamasgal commented 1 year ago

@ChristophWurst thanks, I think I understand. But this means that https://github.com/nextcloud/calendar/issues/5048 is a different issue, doesn't it?

remytms commented 1 year ago

I said before I faced this issue. But I was wrong. Indeed these warning about the token appears in the log file, but the real error was in fact the one of this issue: https://github.com/nextcloud/contacts/issues/2638

okkine commented 1 year ago

I'm going to toss my name in here. I've been having the same problem since doing a fresh installation several months ago. Updated to v27.0.2 yestereday, and the problem still persists.

I can syncronise contacts from Next Cloud to my phone using Davx5, however contacts that are edited or newly created on the phone cause a 418 and 500 error in Davx5. Calendars sync as expected in both directions.

havenoclu commented 1 year ago

Observing the same behavior as @okkine here. Running 27.0.2 (via podman using docker.io nextcloud:latest image if it matters) . I can pull down my contacts via Davx5, but any adds/modifications trying to make it back to the server fail with these "Token is not valid" errors in nextcloud.log. I tried clearing the oc_authtoken table entries as noted above with no success. Happy to provide any relevant logs if helpful.

Edit: Bi-directional sync appears to be working for me now. Not sure what happened, but I'm still sitting at 27.0.2 and don't think davx5 was updated so I'm at a loss as to what changed and why things are working as expected now :/

TheGorf commented 11 months ago

I thought I would add my two cents in here that I am also seeing this error in the latest version 27.1.3. I'm deploying via docker. This is a bone stock fresh install with no addons or plugins. Just file management.

nextcloud | [Wed Nov 15 23:45:18.099294 2023] [php:notice] [pid 45] [client 192.168.8.1:0] {"reqId":"ZnqqWmLp0YKMsVBvpThf","level":2,"time":"2023-11-15T23:45:18+00:00","remoteAddr":"192.168.8.1","user":"--","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/geoff/Backups/SMSBackup/sms-20231115030041.xml","message":"Session token is invalid because it does not exist","userAgent":"OkHttp","version":"27.1.3.2","exception":{"Exception":"OC\\\\Authentication\\\\Exceptions\\\\InvalidTokenException","Message":"Token is too short for a generated token, should be the password during basic auth","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Authentication/Token/Manager.php","line":133,"function":"getToken","class":"OC\\\\Authentication\\\\Token\\\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":782,"function":"getToken","class":"OC\\\\Authentication\\\\Token\\\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":352,"function":"validateToken","class":"OC\\\\User\\\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":452,"function":"login","class":"OC\\\\User\\\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":114,"function":"logClientIn","class":"OC\\\\User\\\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Backend/AbstractBasic.php","line":103,"function":"validateUserPass","class":"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Auth","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":232,"function":"check","class":"Sabre\\\\DAV\\\\Auth\\\\Backend\\\\AbstractBasic","type":"->","args":[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Auth.php","line":139,"function":"auth","class":"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Auth","type":"->","args":[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":179,"function":"check","class":"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Auth","type":"->","args":[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":135,"function":"check","class":"Sabre\\\\DAV\\\\Auth\\\\Plugin","type":"->","args":[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]},{"file":"/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\\\DAV\\\\Auth\\\\Plugin","type":"->","args":[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\\\DAV\\\\Server","type":"->","args":["beforeMethod:PROPFIND",[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\\\DAV\\\\Server","type":"->","args":[["Sabre\\\\HTTP\\\\Request"],["Sabre\\\\HTTP\\\\Response"]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\\\DAV\\\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/lib/Server.php","line":365,"function":"exec","class":"Sabre\\\\DAV\\\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\\\DAV\\\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":172,"args":["/var/www/html/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenProvider.php","Line":155,"message":"Session token is invalid because it does not exist","user":"geoff","exception":{},"CustomMessage":"Session token is invalid because it does not exist"}}

It doesn't seem to affect anything as my site runs fine. But it definitely generates a TON of these messages.

kvibber commented 10 months ago

I ran into this while trying to debug failed syncing with RSS Guard and Nextcloud News (running Nextcloud 27.1.4). It makes multiple parallel connections, and they were clogging up and essentially DDOSing my Nextcloud server. I tried switching it to an app-specific password and instead of taking 30+ seconds to fail, it started syncing completely in only 3 seconds.

Fluent Reader had the same problem: unreliable sync when using the primary login, works just fine with an app-specific password.

I haven't had trouble with Dav5x or Floccus Bookmark Sync, but switching them to app-specific passwords sped up sync performance dramatically.

My suspicion is that throwing the exception adds enough overhead per connection that it's noticeable when a client makes multiple serial connections, and can't keep up with multiple parallel connections.