nextcloud / server

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

[Bug]: cannot login after upgrade to 29.0.3 due to ACPu cache being full and/or fragmented #46429

Closed jmcclelland closed 4 months ago

jmcclelland commented 4 months ago

⚠️ This issue respects the following points: ⚠️

Bug description

After upgrading to Nextcloud 29.0.3, already logged in users are fine. But if you log out, you cannot log back in. We are using the postgres database. When you try to login you do not get a password error or any error at all - just the login page refreshes. If you enter an incorrect password you get the expected error.

Steps to reproduce

  1. Upgrade from 27 to Nextcloud 29.0.3 with a postgres database
  2. Logout
  3. Try to log back in.

Expected behavior

You should be able to login.

Installation method

Community Manual installation with Archive

Nextcloud Server version

29

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.2

Web server

Nginx

Database engine version

PostgreSQL

Is this bug present after an update or on a fresh install?

Upgraded to a MAJOR version (ex. 28 to 29)

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

Configuration report

{
    "system": {
        "appstoreenabled": false,
        "trusted_domains": [
            "staging.share.mayfirst.org"
        ],
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "overwrite.cli.url": "https:\/\/staging.share.mayfirst.org",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0
        },
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "pgsql",
        "version": "29.0.3.4",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "smtp",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "loglevel": 0,
        "maintenance": false,
        "default_phone_region": "US",
        "theme": "",
        "auth.bruteforce.protection.enabled": false,
        "maintenance_window_start": 1
    }
}

List of activated Apps

Enabled:
  - activity: 2.21.1
  - bookmarks: 14.2.2
  - calendar: 4.7.10
  - circles: 29.0.0-dev
  - cloud_federation_api: 1.12.0
  - comments: 1.19.0
  - contacts: 6.0.0
  - contactsinteraction: 1.10.0
  - dashboard: 7.9.0
  - dav: 1.30.1
  - deck: 1.13.1
  - end_to_end_encryption: 1.15.2
  - federatedfilesharing: 1.19.0
  - federation: 1.19.0
  - files: 2.1.0
  - files_downloadlimit: 2.0.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
  - firstrunwizard: 2.18.0
  - forms: 4.2.4
  - logreader: 2.14.0
  - lookup_server_connector: 1.17.0
  - nextcloud_announcements: 1.18.0
  - notes: 4.10.0
  - notifications: 2.17.0
  - notify_push: 0.6.12
  - oauth2: 1.17.0
  - onlyoffice: 9.3.0
  - password_policy: 1.19.0
  - photos: 2.5.0
  - polls: 7.1.3
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recommendations: 2.1.0
  - related_resources: 1.4.0
  - serverinfo: 1.19.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - support: 1.12.0
  - survey_client: 1.17.0
  - systemtags: 1.19.0
  - tasks: 0.16.0
  - text: 3.10.1
  - theming: 2.4.0
  - twofactor_backupcodes: 1.18.0
  - twofactor_totp: 11.0.0-dev
  - updatenotification: 1.19.1
  - user_external: 3.3.0
  - user_status: 1.9.0
  - user_usage_report: 1.13.1
  - viewer: 2.3.0
  - weather_status: 1.9.0
  - workflowengine: 2.11.0
Disabled:
  - admin_audit: 1.19.0
  - bruteforcesettings: 2.9.0
  - encryption: 2.17.0
  - files_external: 1.21.0
  - mayfirstauth: 2.0.2 (installed 2.0.2)
  - suspicious_login: 7.0.0
  - user_ldap: 1.20.0

Nextcloud Signing status

Can't login.

Nextcloud Logs

{"reqId":"v7dNBfmrX7UmKeP1dgd9","level":0,"time":"2024-07-10T20:42:14+00:00","remoteAddr":"209.51.171.170","user":"admin","app":"no app in context","method":"POST","url":"/login","message":"dirty table reads: SELE
CT * FROM `*PREFIX*authtoken` WHERE `uid` = :dcValue1 ORDER BY `id` ASC LIMIT 1","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","exception":{"Exception":"
Exception","Message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE `uid` = :dcValue1 ORDER BY `id` ASC LIMIT 1","Code":0,"Trace":[{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/3rdparty/doctr
ine/dbal/src/Query/QueryBuilder.php","line":344,"function":"executeQuery","class":"OC\\DB\\Connection","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/3rdparty/doctrine/dbal/src/Query/QueryBuil
der.php","line":384,"function":"executeQuery","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/QueryBuilder/QueryBuilder.php","line":
280,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/QueryBuilder/QueryBuilder.php","line":293,"function":"execu
te","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenMapper.php","line":259,"function":"executeQuery",
"class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenProvider.php","line":123,"function":"getFirstTokenFor
User","class":"OC\\Authentication\\Token\\PublicKeyTokenMapper","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/Manager.php","line":71,"function":"generateToken
","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","lin
e":709,"function":"generateToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authe
ntication/Login/CreateSessionTokenCommand.php","line":67,"function":"createSessionToken","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/
29.0.3-mayfirststage/lib/private/Authentication/Login/ALoginCommand.php","line":39,"function":"process","class":"OC\\Authentication\\Login\\CreateSessionTokenCommand","type":"->"},{"file":"/usr/local/src/nextcloud
/29.0.3-mayfirststage/lib/private/Authentication/Login/CompleteLoginCommand.php","line":47,"function":"processNextOrFinishSuccessfully","class":"OC\\Authentication\\Login\\ALoginCommand","type":"->"},{"file":"/usr
/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/ALoginCommand.php","line":39,"function":"process","class":"OC\\Authentication\\Login\\CompleteLoginCommand","type":"->"},{"file":"/usr/loc
al/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/LoggedInCheckCommand.php","line":60,"function":"processNextOrFinishSuccessfully","class":"OC\\Authentication\\Login\\ALoginCommand","type":"->
"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/ALoginCommand.php","line":39,"function":"process","class":"OC\\Authentication\\Login\\LoggedInCheckCommand","type":"->"},{
"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/EmailLoginCommand.php","line":68,"function":"processNextOrFinishSuccessfully","class":"OC\\Authentication\\Login\\ALoginComman
d","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/ALoginCommand.php","line":39,"function":"process","class":"OC\\Authentication\\Login\\EmailLoginCommand","typ
e":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/UidLoginCommand.php","line":53,"function":"processNextOrFinishSuccessfully","class":"OC\\Authentication\\Login\\ALog
inCommand","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/ALoginCommand.php","line":39,"function":"process","class":"OC\\Authentication\\Login\\UidLoginCommand
","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/UserDisabledCheckCommand.php","line":57,"function":"processNextOrFinishSuccessfully","class":"OC\\Authenticati
on\\Login\\ALoginCommand","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/ALoginCommand.php","line":39,"function":"process","class":"OC\\Authentication\\Login\\
UserDisabledCheckCommand","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/PreLoginHookCommand.php","line":52,"function":"processNextOrFinishSuccessfully","class
":"OC\\Authentication\\Login\\ALoginCommand","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Login/Chain.php","line":107,"function":"process","class":"OC\\Authenticat
ion\\Login\\PreLoginHookCommand","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/core/Controller/LoginController.php","line":351,"function":"process","class":"OC\\Authentication\\Login\\Chain",
"type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/Http/Dispatcher.php","line":232,"function":"tryLogin","class":"OC\\Core\\Controller\\LoginController","type":"->","args"
:["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/Http/Dispatcher.php","line":138,"function":"executeController","class":"OC\\AppFramework\
\Http\\Dispatcher","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/App.php","line":184,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{
"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Route/Router.php","line":338,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/
lib/base.php","line":1050,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/index.php","line":49,"function":"handleRequest","class":"OC","type":"::"
}],"File":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/Connection.php","Line":316,"message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE `uid` = :dcValue1 ORDER BY `id` ASC LIMIT 1"
,"tables":["oc_preferences","oc_authtoken"],"reads":["oc_authtoken"],"exception":{},"CustomMessage":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE `uid` = :dcValue1 ORDER BY `id` ASC LIMIT 1"}}
{"reqId":"RMiG0UGMMAqtO8ExtXEK","level":0,"time":"2024-07-10T20:42:16+00:00","remoteAddr":"209.51.171.170","user":"admin","app":"core","method":"GET","url":"/apps/dashboard/","message":"Session token is invalid because it does not exist","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","exception":{"Exception":"OC\\Authentication\\Exceptions\\InvalidTokenException","Message":"Token does not exist: 6a1b35fd4dbf0dc0e3438ee5fb9939a03d3ffe432210e8bada0d262369a7aeffa1d49be5504a7d7858c54f87b09574b965c4dd1eef0a00a059633bff0b9ed4a6","Code":0,"Trace":[{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenProvider.php","line":167,"function":"getTokenFromCache","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/Manager.php","line":135,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":806,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":269,"function":"validateToken","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":244,"function":"validateSession","class":"OC\\User\\Session","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/legacy/OC_App.php","line":230,"function":"getUser","class":"OC\\User\\Session","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/App/AppManager.php","line":198,"function":"getEnabledApps","class":"OC_App","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/legacy/OC_App.php","line":128,"function":"loadApps","class":"OC\\App\\AppManager","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/legacy/OC_User.php","line":133,"function":"loadApps","class":"OC_App","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":776,"function":"setupBackends","class":"OC_User","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":1181,"function":"init","class":"OC","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/index.php","line":47,"args":["/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php"],"function":"require_once"}],"File":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenProvider.php","Line":196,"message":"Session token is invalid because it does not exist","user":null,"exception":{},"CustomMessage":"Session token is invalid because it does not exist"}}
{"reqId":"RMiG0UGMMAqtO8ExtXEK","level":0,"time":"2024-07-10T20:42:16+00:00","remoteAddr":"209.51.171.170","user":"admin","app":"no app in context","method":"GET","url":"/apps/dashboard/","message":"Session token invalidated before logout","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","data":{"user":"admin"}}
{"reqId":"RMiG0UGMMAqtO8ExtXEK","level":0,"time":"2024-07-10T20:42:16+00:00","remoteAddr":"209.51.171.170","user":"admin","app":"no app in context","method":"GET","url":"/apps/dashboard/","message":"Logging out","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","data":{"user":"admin"}}
{"reqId":"RMiG0UGMMAqtO8ExtXEK","level":0,"time":"2024-07-10T20:42:16+00:00","remoteAddr":"209.51.171.170","user":"--","app":"no app in context","method":"GET","url":"/apps/dashboard/","message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","exception":{"Exception":"Exception","Message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)","Code":0,"Trace":[{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":344,"function":"executeQuery","class":"OC\\DB\\Connection","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":384,"function":"executeQuery","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/QueryBuilder/QueryBuilder.php","line":280,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenMapper.php","line":92,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenProvider.php","line":173,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenMapper","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/Manager.php","line":135,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":656,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":880,"function":"loginWithToken","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":1126,"function":"tryTokenLogin","class":"OC\\User\\Session","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":1039,"function":"handleLogin","class":"OC","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/index.php","line":49,"function":"handleRequest","class":"OC","type":"::"}],"File":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/Connection.php","Line":316,"message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)","tables":["oc_authtoken"],"reads":["oc_authtoken"],"exception":{},"CustomMessage":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)"}}
{"reqId":"RMiG0UGMMAqtO8ExtXEK","level":0,"time":"2024-07-10T20:42:16+00:00","remoteAddr":"209.51.171.170","user":"--","app":"no app in context","method":"GET","url":"/apps/dashboard/","message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","exception":{"Exception":"Exception","Message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)","Code":0,"Trace":[{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":344,"function":"executeQuery","class":"OC\\DB\\Connection","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":384,"function":"executeQuery","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/QueryBuilder/QueryBuilder.php","line":280,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenMapper.php","line":92,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/PublicKeyTokenProvider.php","line":177,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenMapper","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Authentication/Token/Manager.php","line":135,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenProvider","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":656,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/User/Session.php","line":880,"function":"loginWithToken","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":1126,"function":"tryTokenLogin","class":"OC\\User\\Session","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":1039,"function":"handleLogin","class":"OC","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/index.php","line":49,"function":"handleRequest","class":"OC","type":"::"}],"File":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/DB/Connection.php","Line":316,"message":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)","tables":["oc_authtoken"],"reads":["oc_authtoken"],"exception":{},"CustomMessage":"dirty table reads: SELECT * FROM `*PREFIX*authtoken` WHERE (`token` = :dcValue1) AND (`version` = :dcValue2)"}}
{"reqId":"RMiG0UGMMAqtO8ExtXEK","level":0,"time":"2024-07-10T20:42:16+00:00","remoteAddr":"209.51.171.170","user":"--","app":"no app in context","method":"GET","url":"/apps/dashboard/","message":"Current user is not logged in","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:125.0) Gecko/20100101 Firefox/125.0","version":"29.0.3.4","exception":{"Exception":"OC\\AppFramework\\Middleware\\Security\\Exceptions\\NotLoggedInException","Message":"Current user is not logged in","Code":401,"Trace":[{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/Middleware/MiddlewareDispatcher.php","line":96,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\Security\\SecurityMiddleware","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/Http/Dispatcher.php","line":130,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\MiddlewareDispatcher","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/App.php","line":184,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/Route/Router.php","line":338,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/base.php","line":1050,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/usr/local/src/nextcloud/29.0.3-mayfirststage/index.php","line":49,"function":"handleRequest","class":"OC","type":"::"}],"File":"/usr/local/src/nextcloud/29.0.3-mayfirststage/lib/private/AppFramework/Middleware/Security/SecurityMiddleware.php","Line":161,"message":"Current user is not logged in","exception":{},"CustomMessage":"Current user is not logged in"}}

Additional info

No data is written to the authtoken table.

SystemKeeper commented 4 months ago
  1. Upgrade from 27 to Nextcloud 29.0.3 with a postgres database

Did you upgrade directly from 27 to 29 or did you do 27 -> 28 -> 29?

jmcclelland commented 4 months ago

I went from 27 -> 28 -> 29. I didn't test version 28 - but the database upgrade did not report any errors.

jmcclelland commented 4 months ago

Oh. Sorry for the bother. If I comment out the redis configuration in my config.php file, the problem goes away. There still might be a dirty reads problem - but the inability to login seems to be related to redis.

jmcclelland commented 4 months ago

To be more precise: APCu is the culprit (memcache.local), not redis.

jmcclelland commented 4 months ago

I resolved the problem by restarting php-fpm (immediately fixed the problem by clearing the cache). Then I increased the memory (apc.shm_size) from the default 32M to 64M. I see that I can monitor the amount of memory in use via https://domain.org/ocs/v2.php/apps/serverinfo/api/v1/info.

kesselb commented 4 months ago

Sounds related to:

jmcclelland commented 4 months ago

I don't think our problem is related to those tickets reporting errors in distributed systems. We are not running a distributed system.

The bug I reported in this ticket is resolved. The conclusion: it has nothing to do with the dirty reads error or with postgresql. It is not related to using local caching for storing the authtoken. It was caused by the ACPu cache filling up and was resolved by increasing the apc.shm_size and restarting php-fpm.

When the log level is high enough, I still get the dirty reads error, but it is not causing a problem that we have noticed.

Additionally, there could be another bug report - if Nextcloud fails to save a variable to the ACPu cache it should probably trigger some kind of error. That doesn't seem to be happening. But that should probably be a new issue.

jmcclelland commented 4 months ago

Just to close the loop on this one: the underlying cause was not apcu filling up, but instead becoming too fragmented.

The fix that did the trick is changing apc.ttl. Our php setting for apc.ttl was set to 0 (the default in debian). When I set it to apc.ttl = 3600 the problem stopped happening.