Login loop after manually upgrading to NC 14.0.0.19

[BernieO]

On a testing instance after upgrading from 13.0.6 to 14.0.0.19 I can not login anymore due to a redirect loop. This happens on two testing instances (SQLite3 and PostgreSQL)
A fresh install of 14.0.0.19 with exactly the same setup works though (tested only with SQLite3). I also have another testing instance with MariaDB with the same webserver configuration. Upgrading this MariaDB instance from 13.0.6 to 14.0.0.19 works with no issues (the login loop does not happen at this instance).
In the forum there is a user running apache with the same problem using MySQL (14.0.0RC1 though):
https://help.nextcloud.com/t/login-authentication-on-fresh-14-rc1-fails/36399

Steps to reproduce

1. update Nextcloud manually like this: https://github.com/nextcloud/documentation/blob/master/admin_manual/maintenance/manual_upgrade.rst
2. visit https://nextcloud.server.com/login
3. enter username and password and click on login
4. get a 303 redirerect first to https://nextcloud.server.com/apps/files which redirects with a 3030 back to https://nextcloud.server.com/login?redirect_url=/apps/files/

Only posting data from my SQLite3 installation below.

Expected behaviour

User should be logged in.

Actual behaviour

User gets redirected to login page

Server configuration

Operating system:
Debian Stretch 9.5

Web server:
nginx 1.10.3
Note: this is a testing instance with the nginx-configuration taken from here:
https://github.com/nextcloud/documentation/blob/master/admin_manual/installation/nginx.rst

Database:
SQLite

PHP version:
PHP Version 7.0.30-0+deb9u1

Nextcloud version: (see Nextcloud admin page)
14.0.0.19

Updated from an older Nextcloud/ownCloud or fresh install:
Updated manually from 13.0.6 (version was upgraded before many times also with manual upgrade. Can't remember what was the original version. Probably something starting with 9.0)

Where did you install Nextcloud from:
https://download.nextcloud.com/server/releases/nextcloud-14.0.0.tar.bz2

Signing status:
can't log in to nextcloud

List of activated apps:
sudo -u www-data php occ app:list returns...

Enabled:
  - accessibility: 1.0.1
  - activity: 2.7.0
  - admin_audit: 1.4.0
  - cloud_federation_api: 0.0.1
  - comments: 1.4.0
  - dav: 1.6.0
  - federatedfilesharing: 1.4.0
  - federation: 1.4.0
  - files: 1.9.0
  - files_pdfviewer: 1.3.2
  - files_sharing: 1.6.2
  - files_texteditor: 2.6.0
  - files_trashbin: 1.4.1
  - files_versions: 1.7.1
  - files_videoplayer: 1.3.0
  - firstrunwizard: 2.3.0
  - gallery: 18.1.0
  - logreader: 2.0.0
  - lookup_server_connector: 1.2.0
  - nextcloud_announcements: 1.3.0
  - notifications: 2.2.1
  - oauth2: 1.2.1
  - password_policy: 1.4.0
  - provisioning_api: 1.4.0
  - serverinfo: 1.4.0
  - sharebymail: 1.4.0
  - support: 1.0.0
  - survey_client: 1.2.0
  - systemtags: 1.4.0
  - theming: 1.5.0
  - twofactor_backupcodes: 1.3.1
  - updatenotification: 1.4.1
  - workflowengine: 1.4.0
Disabled:
  - encryption
  - files_external
  - user_external
  - user_ldap

Nextcloud configuration:
sudo -u www-data php occ config:list system returns:

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "sqlite.webroot.de"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "overwrite.cli.url": "sqlite.webroot.de",
        "dbtype": "sqlite3",
        "version": "14.0.0.19",
        "logtimezone": "UTC",
        "installed": true,
        "maintenance": false,
        "appstore.experimental.enabled": true,
        "loglevel": 2,
        "data-fingerprint": "15b4a9b1a74e0c02ae45682f227e98ad"
    }
}

Are you using external storage, if yes which one:
No

Are you using encryption:
No

Are you using an external user-backend, if yes which one:
No

Client configuration

Browser:
Firefox

Operating system:

Logs

Web server error log

10.228.104.42 - - [08/Sep/2018:06:54:44 +0200] "POST /login?redirect_url=/apps/files/ HTTP/2.0" 303 927 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:62.0) Gecko/20100101 Firefox/62.0"
10.228.104.42 - - [08/Sep/2018:06:54:44 +0200] "GET /apps/files/ HTTP/2.0" 303 1111 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:62.0) Gecko/20100101 Firefox/62.0"
10.228.104.42 - - [08/Sep/2018:06:54:45 +0200] "GET /login?redirect_url=/apps/files/ HTTP/2.0" 200 4634 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:62.0) Gecko/20100101 Firefox/62.0"
10.228.104.42 - - [08/Sep/2018:06:54:46 +0200] "GET /cron.php HTTP/2.0" 200 638 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:62.0) Gecko/20100101 Firefox/62.0"

Nextcloud log (data/nextcloud.log)

This is all from my nextcloud.log. New login-attempts are not logged in loglevel=2

{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:46:35+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Repair::step: Repair step: Queue a one-time job to cleanup old backups of the updater","userAgent":"--","version":"13.0.6.1"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:46:35+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Repair::step: Repair step: Repair pending cron jobs","userAgent":"--","version":"13.0.6.1"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:46:35+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Repair::info: Repair info: Repaired 1 pending cron job(s).","userAgent":"--","version":"13.0.6.1"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:46:35+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Updater::startCheckCodeIntegrity: Starting code integrity check...","userAgent":"--","version":"13.0.6.1"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:47:36+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Updater::finishedCheckCodeIntegrity: Finished code integrity check","userAgent":"--","version":"13.0.6.1"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:47:36+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Updater::updateEnd: Update successful","userAgent":"--","version":"14.0.0.19"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:47:36+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Updater::maintenanceActive: Maintenance mode is kept active","userAgent":"--","version":"14.0.0.19"}
{"reqId":"y9Mg8SQymZcmsa8gelYo","level":1,"time":"2018-09-07T08:47:36+00:00","remoteAddr":"","user":"--","app":"updater","method":"","url":"--","message":"\\OC\\Updater::resetLogLevel: Reset log level to Warning(2)","userAgent":"--","version":"14.0.0.19"}
{"reqId":"3vIUzP4LhhMEsjTzL3Gj","level":3,"time":"2018-09-07T09:12:03+00:00","remoteAddr":"10.228.104.42","user":"--","app":"index","method":"GET","url":"\/login?redirect_url=\/index.php\/settings\/integrity\/failed","message":{"Exception":"Exception","Message":"The requested uri(\/login) cannot be processed by the script '\/settings\/integrity\/failed')","Code":0,"Trace":[{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/base.php","line":932,"function":"getRawPathInfo","class":"OC\\AppFramework\\Http\\Request","type":"->","args":[]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/index.php","line":42,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/AppFramework\/Http\/Request.php","Line":742,"CustomMessage":"--"},"userAgent":"Mozilla\/5.0 (Macintosh; Intel Mac OS X 10.11; rv:61.0) Gecko\/20100101 Firefox\/61.0","version":"14.0.0.19"}

Browser log

The Browser log reflects the log from nginx:
entering username and password an clicking on login opens
https://sqlite.webroot.de/login?redirect_url=/apps/files/
which redirects me with a 303 to
https://sqlite.webroot.de/apps/files
and that redirects me instantly also with a 303 back to
https://sqlite.webroot.de/login?redirect_url=/apps/files/

[nextcloud-bot]

GitMate.io thinks possibly related issues are #8829 (login loop), #10885 (NC 14.0.0 beta 4, web login failed after upgrade from 13.0.5.2), #10603 (Ideas for NC 14), #8199 (Redirect Loop after upgrading to 13.0 (InvalidSignatureException)), and #3134 (After upgrade from NC 10.0 to 11.0.1 --> slow performance).

[BernieO]

Looks indeed like a duplicate of #10885

[asseti6]

I am the user in the forum. It should be noted that the issue only occurs with migration/upgrades, meaning it issue is likely to reside in the database changes during the upgrade itself or a missing file. Again, there is not useful log output to give a starting point.

In your output, there is a bit more useful information. The system is failing the integrity check on the redirect. I will dig into it over the evening with your information if no one else has solved yet. Marking for myself as a reminder.

[BernieO]

Actually I am not sure whether that line with the integrity check has anything to do with the login loop as I noticed that nothing is written to the log when I try to login now. I have not idea where that line comes from as the integrity check done during the upgrade didn‘t report any errors (see last lines above the very last line in the log I posted in the initial post). Maybe I've been locked in during the upgrade and afterwards tried to refresh the page.

For further investigation I changed the nextcloud loglevel to 0 and these are the entries when I try to login (with correct credentials!) and the login loop occurs:

{"reqId":"zSwsdKMb5ddZvfupI4MB","level":0,"time":"2018-09-09T05:41:10+00:00","remoteAddr":"10.228.104.41","user":"--","app":"core","method":"GET","url":"\/apps\/files\/","message":{"Exception":"OC\\AppFramework\\Middleware\\Security\\Exceptions\\NotLoggedInException","Message":"Current user is not logged in","Code":401,"Trace":[{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/AppFramework\/Middleware\/MiddlewareDispatcher.php","line":95,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\Security\\SecurityMiddleware","type":"->","args":[{"__class__":"OCA\\Files\\Controller\\ViewController"},"index"]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/AppFramework\/Http\/Dispatcher.php","line":98,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\MiddlewareDispatcher","type":"->","args":[{"__class__":"OCA\\Files\\Controller\\ViewController"},"index"]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/AppFramework\/App.php","line":118,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Files\\Controller\\ViewController"},"index"]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/AppFramework\/Routing\/RouteActionHandler.php","line":47,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["ViewController","index",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},{"_route":"files.view.index"}]},{"function":"__invoke","class":"OC\\AppFramework\\Routing\\RouteActionHandler","type":"->","args":[{"_route":"files.view.index"}]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/Route\/Router.php","line":297,"function":"call_user_func","args":[{"__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"},{"_route":"files.view.index"}]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/base.php","line":989,"function":"match","class":"OC\\Route\\Router","type":"->","args":["\/apps\/files\/"]},{"file":"\/usr\/share\/nginx\/sqlite.webroot.de\/index.php","line":42,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"\/usr\/share\/nginx\/sqlite.webroot.de\/lib\/private\/AppFramework\/Middleware\/Security\/SecurityMiddleware.php","Line":143,"CustomMessage":"--"},"userAgent":"Mozilla\/5.0 (iPad; CPU OS 11_4_1 like Mac OS X) AppleWebKit\/605.1.15 (KHTML, like Gecko) Version\/11.0 Mobile\/15E148 Safari\/604.1","version":"14.0.0.19"}
{"reqId":"QGFflr0jcNFCFkozAXsQ","level":0,"time":"2018-09-09T05:41:11+00:00","remoteAddr":"10.228.104.41","user":"--","app":"core","method":"GET","url":"\/login?redirect_url=\/apps\/files\/","message":"Scss is disabled for \/usr\/share\/nginx\/sqlite.webroot.de\/core\/css\/jquery-ui-fixes.scss, ignoring","userAgent":"Mozilla\/5.0 (iPad; CPU OS 11_4_1 like Mac OS X) AppleWebKit\/605.1.15 (KHTML, like Gecko) Version\/11.0 Mobile\/15E148 Safari\/604.1","version":"14.0.0.19"}

As you can see the in the very first line there is an exception thrown that I am not logged in - resulting in a 401 and a new request (redirect) to login?redirect_url=/apps/files/.

[ChristophWurst]

Looks indeed like a duplicate of #10885

@BernieO these two issues look very similar. Could you join us over there and help with narrowing down the cause? I've posted a few suspicions and I need someone to actually test it because I cannot reproduce (even with the specific setup you listed above).

[BernieO]

Sure - I am willing to help and joined there.

[ChristophWurst]

Thanks a lot, @BernieO! ✌️

[jerome-diver]

nextcloud-14.0.4.2 on freebsd and nginx server is runing
same problem
at login, there is a redirection to url app/files
but many call (6 by second) and fall down with "the page isn't redirecting correctly"