Log wächst rasant an - InvalidTokenException

Pablo78 · November 1, 2023, 10:50am

Hallo zusammen,

ich habe bei mir eine VM (Ubuntu 22.04 LTS) mit NC 27.1.3 und ca. 5 Personen die ihre Kalender und Kontakte von iOS Geräte synchronisieren.

Das Nextcloud.log wächst derzeit rasant an und im Log sehe ich folgende Meldungen.

{"reqId":"xxxx","level":2,"time":"2023-11-01T11:51:58+01:00","remoteAddr":"10.10.1.101","user":"--","app":"core","method":"PROPFIND","url":"/remote.php/carddav/addressbooks/familie/z-app-generated--contactsinteraction--recent/","message":"Session token is invalid because it does not exist","userAgent":"iOS/17.1 (21B74) dataaccessd/1.0","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/nextcloud/lib/private/Authentication/Token/Manager.php","line":133,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":782,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":352,"function":"validateToken","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":452,"function":"login","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/apps/dav/lib/Connector/Sabre/Auth.php","line":114,"function":"logClientIn","class":"OC\\User\\Session","type":"->","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/Auth.php","line":232,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->"},{"file":"/var/www/nextcloud/apps/dav/lib/Connector/Sabre/Auth.php","line":139,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":180,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":135,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/apps/dav/appinfo/v1/carddav.php","line":108,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/remote.php","line":172,"args":["/var/www/nextcloud/apps/dav/appinfo/v1/carddav.php"],"function":"require_once"}],"File":"/var/www/nextcloud/lib/private/Authentication/Token/PublicKeyTokenProvider.php","Line":155,"message":"Session token is invalid because it does not exist","user":"familie.kk","exception":{},"CustomMessage":"Session token is invalid because it does not exist"}}
{"reqId":"xxxx","level":2,"time":"2023-11-01T11:51:59+01:00","remoteAddr":"10.10.1.101","user":"--","app":"core","method":"REPORT","url":"/remote.php/carddav/addressbooks/familie/contacts/","message":"Session token is invalid because it does not exist","userAgent":"iOS/17.1 (21B74) dataaccessd/1.0","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/nextcloud/lib/private/Authentication/Token/Manager.php","line":133,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":782,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":352,"function":"validateToken","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":452,"function":"login","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/apps/dav/lib/Connector/Sabre/Auth.php","line":114,"function":"logClientIn","class":"OC\\User\\Session","type":"->","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/Auth.php","line":232,"function":"check","class":"Sabre\\DAV\\Auth\\Backend\\AbstractBasic","type":"->"},{"file":"/var/www/nextcloud/apps/dav/lib/Connector/Sabre/Auth.php","line":139,"function":"auth","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":180,"function":"check","class":"OCA\\DAV\\Connector\\Sabre\\Auth","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","line":135,"function":"check","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/apps/dav/appinfo/v1/carddav.php","line":108,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/remote.php","line":172,"args":["/var/www/nextcloud/apps/dav/appinfo/v1/carddav.php"],"function":"require_once"}],"File":"/var/www/nextcloud/lib/private/Authentication/Token/PublicKeyTokenProvider.php","Line":155,"message":"Session token is invalid because it does not exist","user":"familie.kk","exception":{},"CustomMessage":"Session token is invalid because it does not exist"}}

MfG Paul

Pablo78 · November 1, 2023, 12:08pm

In der sample Config gibt es diese Einträge.
Kann man damit etwas korrigieren?

/**
 * Enforce token authentication for clients, which blocks requests using the user
 * password for enhanced security. Users need to generate tokens in personal settings
 * which can be used as passwords on their clients.
 *
 * Defaults to ``false``
 */
'token_auth_enforced' => false,

/**
 * The interval at which token activity should be updated.
 * Increasing this value means that the last activity on the security page gets
 * more outdated.
 *
 * Tokens are still checked every 5 minutes for validity
 * max value: 300
 *
 * Defaults to ``300``
 */
'token_auth_activity_update' => 60,

Martin_Ho · November 1, 2023, 12:16pm

Denke ich nicht. mich irritiert eher das hier:

Token is too short for a generated token, should be the password during basic auth

Spricht für mich dafür, dass der Reverse proxy falsch gesetzt ist oder in der config.php ein Fehler ist.
was nutzt du als Reverse proxy? und zeig mal die config.php

Oder du hast einfach ein falsches Passwort auf deinem iOS gerät eingegeben. nutzt du für das Adressbuch zusätzliche apps oder wie hast du das eingerichtet?

Crashandy · November 1, 2023, 1:17pm

Hallo @Pablo78,

dazu gibt es bereits ein Issue-Ticket auf Github.

github.com/nextcloud/server

[Bug]: OC\Authentication\Exceptions\InvalidTokenException: Token is too short for a generated token, should be the password during basic auth

opened 04:37PM - 27 Oct 23 UTC

MPTopper

bug 0. Needs triage 27-feedback

### ⚠️ This issue respects the following points: ⚠️ - [X] This is a **bug**, …not a question or a configuration/webserver/proxy issue. - [X] This issue is **not** already reported on [Github](https://github.com/nextcloud/server/issues?q=is%3Aopen+is%3Aissue+label%3Abug) OR [Nextcloud Community Forum](https://help.nextcloud.com/) _(I've searched it)_. - [X] Nextcloud Server **is** up to date. See [Maintenance and Release Schedule](https://github.com/nextcloud/server/wiki/Maintenance-and-Release-Schedule) for supported versions. - [X] I agree to follow Nextcloud's [Code of Conduct](https://nextcloud.com/contribute/code-of-conduct/). ### Bug description Today I updated my Nextcloud server from 27.1.2 to 27.1.3. Immediately afterwards warnings came (every minute) but everything before worked smoothly - Android/Windows Nextcloud clients are connected - connection is succesful, but warnings come nevertheless. Log: ``` [core] Warnung: OC\Authentication\Exceptions\InvalidTokenException: Token is too short for a generated token, should be the password during basic auth at <<closure>> 0. /var/www/html/nextcloud/lib/private/Authentication/Token/Manager.php line 133 OC\Authentication\Token\PublicKeyTokenProvider->getToken("*** sensitive parameters replaced ***") 1. /var/www/html/nextcloud/lib/private/User/Session.php line 782 OC\Authentication\Token\Manager->getToken("*** sensitive parameters replaced ***") 2. /var/www/html/nextcloud/lib/private/User/Session.php line 352 OC\User\Session->validateToken("*** sensitive parameters replaced ***") 3. /var/www/html/nextcloud/lib/private/User/Session.php line 452 OC\User\Session->login("*** sensitive parameters replaced ***") 4. /var/www/html/nextcloud/lib/private/User/Session.php line 580 OC\User\Session->logClientIn("*** sensitive parameters replaced ***") 5. /var/www/html/nextcloud/lib/base.php line 1150 OC\User\Session->tryBasicAuthLogin() 6. /var/www/html/nextcloud/ocs/v1.php line 61 OC::handleLogin() 7. /var/www/html/nextcloud/ocs/v2.php line 23 require_once("/var/www/html/nextcloud/ocs/v1.php") ``` ### Steps to reproduce 1. No idea 2. 3. ### Expected behavior Everything is working but log is blasted with warnings ### Installation method Community Manual installation with Archive ### Nextcloud Server version 27 ### Operating system Debian/Ubuntu ### PHP engine version PHP 8.1 ### Web server Apache (supported) ### Database engine version MariaDB ### Is this bug present after an update or on a fresh install? Updated from a MINOR version (ex. 22.1 to 22.2) ### Are you using the Nextcloud Server Encryption module? Encryption is Disabled ### What user-backends are you using? - [X] Default user-backend _(database)_ - [ ] LDAP/ Active Directory - [ ] SSO - SAML - [ ] Other ### Configuration report _No response_ ### List of activated Apps _No response_ ### Nextcloud Signing status _No response_ ### Nextcloud Logs _No response_ ### Additional info _No response_

Pablo78 · November 1, 2023, 1:22pm

Hallo

Ich habe mein System nach dieser Anleitung aufgesetzt und die Meldungen im Log betreffen alle Benutzer und der Sync der Adressbücher klappt soweit auch.

Nextcloud auf Ubuntu Server 22.04 LTS mit nginx, PostgreSQL/MariaDB, PHP, Let’s Encrypt, Redis und Fail2ban

config.php

<?php
$CONFIG = array (
  'instanceid' => 'xxxxxxxxxxxx',
  'passwordsalt' => 'xxxxxxxxxxxxxxx',
  'secret' => 'xxxxxxxxxxxxxxx',
  'trusted_domains' => 
  array (
    0 => 'cloud.xxxxxx.selfhost.de',
    1 => '10.10.2.3',
  ),
  'datadirectory' => '/var/nextcloud_data',
  'dbtype' => 'mysql',
  'version' => '27.1.3.2',
  'overwrite.cli.url' => 'https://cloud3.xxxxxxx.selfhost.de',
  'dbname' => 'nextcloud_db',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'nextcloud_db_user',
  'dbpassword' => 'xxxxxxxxxxxxxxxx',
  'installed' => true,
  'overwriteprotocol' => 'https',
  'logtimezone' => 'Europe/Berlin',
  'auth.bruteforce.protection.enabled' => false,
  'forcessl' => true,
  'forceSSLforSubdomains' => true,
  'default_language' => 'de',
  'force_locale' => 'de_DE',
  'trashbin_retention_obligation' => 'auto',
  'allow_user_to_change_display_name' => false,
  'appcodechecker' => true,
  'updatechecker' => true,
  'maintenance' => false,
  'activity_expire_days' => 30,
  'updater.release.channel' => 'stable',
  'gs.federation' => 'internal',
  'profile.enabled' => false,
  'theme' => '',
  'blacklisted_files' => 
  array (
    0 => '.htaccess',
    1 => 'Thumbs.db',
    2 => 'thumbs.db',
  ),
  'connectivity_check_domains' => 
  array (
    0 => 'www.nextcloud.com',
    1 => 'www.google.de',
    2 => 'www.heise.de',
  ),
  'app_install_overwrite' => 
  array (
    0 => 'bruteforcesettings',
    1 => 'groupfolders',
    2 => 'quota_warning',
    3 => 'passwords',
    4 => 'impersonate',
    5 => 'calendar_news',
  ),
  'cron_log' => true,
  'enable_previews' => false,
  'preview_max_x' => 1024,
  'preview_max_y' => 768,
  'preview_max_scale_factor' => 1,
  'loglevel' => 2,
  'default_phone_region' => 'DE',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'filelocking.enabled' => true,
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' => 
  array (
    'host' => '/var/run/redis/redis-server.sock',
    'port' => 0,
    'timeout' => 0.0,
  ),
);

Vielen Dank schon mal für deine Hilfe.

MfG Paul

Pablo78 · November 1, 2023, 1:23pm

OK ich lese mir das mal durch