Unable to log into nextcloud

defaria · October 16, 2022, 6:06pm

Nextcloud version (eg, 20.0.5): Nextcloud HUB II
Operating system and version (eg, Ubuntu 20.04): Synology DSM 7.1 (Docker)
Apache or nginx version (eg, Apache 2.4.25): 2.4.54
PHP version (eg, 7.4): 8.0.24

The issue you are facing:

Can’t log into Nextcloud as my user. When I go to Nextcloud the login screen appears. I enter my credentials and click login. It takes a really long time but errors out with " Sorry, the page you are looking for is not found". This is the standard message from Synology. Yes, this is a reverse proxy setup. But I can get to the login screen so it shouldn’t be the reverse proxy setup.

Additionally, I can log in as another, unused account I had set up for a friend who apparently never used it or at least never changed the default password I gave him. I get in with this login but not with mine. There is nothing in nextcloud.log (0 length file).

Is this the first time you’ve seen this error? (Y/N):

Steps to replicate it:

The output of your Nextcloud log in Admin > Logging: Can’t give you that 'cause I can’t login as an admin user!

The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

<?php
$CONFIG = array (
  'filesystem_check_change' => 1,
  'instanceid' => 'xxx',
  'passwordsalt' => 'xxx',
  'secret' => 'xxx+',
  'trusted_domains' => 
  array (
    0 => 'cloud.defariahome.com',
    1 => 'defaria.synology.me',
    2 => 'jupiter',
    3 => 'xxx',
  ),
  'default_phone_region' => 'US',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'datadirectory' => '/var/www/html/data',
  'dbtype' => 'mysql',
  'version' => '24.0.6.1',
  'overwrite.cli.url' => 'https://cloud.defariahome.com',
  'overwritehost' => 'cloud.defariahome.com',
  'overwriteprotocol' => 'https',
  'dbname' => 'nextcloud',
  'dbhost' => 'xxx',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'nextcloud',
  'dbpassword' => 'xxx',
  'installed' => true,
  'mail_from_address' => 'Andrew',
  'mail_smtpmode' => 'smtp',
  'mail_sendmailmode' => 'smtp',
  'mail_domain' => 'DeFaria.com',
  'mail_smtpauthtype' => 'LOGIN',
  'mail_smtpauth' => 1,
  'mail_smtphost' => 'defaria.com',
  'mail_smtpport' => '465',
  'mail_smtpname' => 'andrew',
  'mail_smtppassword' => 'xxx',
  'maintenance' => false,
  'enable_previews' => true,
  'enabledPreviewProviders' => 
  array (
    0 => 'OC\\Preview\\Movie',
    1 => 'OC\\Preview\\PNG',
    2 => 'OC\\Preview\\JPEG',
    3 => 'OC\\Preview\\GIF',
    4 => 'OC\\Preview\\BMP',
    5 => 'OC\\Preview\\XBitmap',
    6 => 'OC\\Preview\\MP3',
    7 => 'OC\\Preview\\MP4',
    8 => 'OC\\Preview\\TXT',
    9 => 'OC\\Preview\\MarkDown',
    10 => 'OC\\Preview\\PDF',
  ),
  'theme' => '',
  'loglevel' => 2,
  'mail_smtpsecure' => 'ssl',
);

The output of your Apache/nginx/system log in /var/log/____: This is docker. /var/log/apache2/error.log is a symlink to /dev/stderr. The output from docker logs yields

2603:8000:3602:5720:8177:7863:3dcb:39bb - - [16/Oct/2022:11:03:33 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1691 "-" "-"

Output errors in nextcloud.log in /var/www/ or as admin user in top right menu, filtering for errors. Use a pastebin service if necessary.

Just a 0 length file

wwe · October 16, 2022, 7:26pm

this proofs the system works in general - your network and reverse proxy are doing well, the problem is related to your account. you either really messed up your login or maybe you have been blocked by bruteforce protection - long delays are good hint for this…

as long you have console access to your container you can recover using occ command

defaria · October 16, 2022, 9:28pm

It’s always taken me longer to log in than others. I just assumed that that was because I had more files in there than others.

Read up on brute force protection. I’ve logged in many, many times successfully before but it always takes longer for me to log in. IOW it doesn’t seem to reset itself. They mention checking the bruteforce_attempts table so I went into MariaDB and found a lot of login actions. I deleted them hoping that that would clear the problem. It didn’t.

My reverse proxy config hasn’t changed and still has the entries for trusted domains that it had before except I did change the 192.168.x.x address as that had changed internally), And I had been able to access Nextcloud for a while now, even at my new location.

You mention I can recover using occ command. How does that work?

KarlF12 · October 17, 2022, 2:11am

Seems like I drop this link a few times per day. Please try searching for basic info… It’s well-documented.

https://docs.nextcloud.com/server/stable/admin_manual/configuration_server/occ_command.html

defaria · October 17, 2022, 2:40am

There’s a hella lot of commands there. Care to give me a clue as to which subcommand(s) I need to use to fix the problem?

wwe · October 17, 2022, 6:39am

login performance is not related to number of files… maybe some other data stored in DB like activity, but most likely not even this.

did you at least tried to find suitable command? e.g. occ security:bruteforce:reset [IP address] looks good for me.

defaria · October 17, 2022, 1:53pm

I had no idea that that might be the command. I did search for things like reset and found nothing.

As my NextCloud runs in a Docker container, it took a little while to figure out the correct incantation. Executed it. Tried to log in, took a minute (timed it) then failed the same way.

Jupiter:docker exec -itu www-data nextcloud php occ security:bruteforce:reset 192.168.96.31
Jupiter:echo $?
0
Jupiter:

Perhaps another data point:

Jupiter:docker exec -itu www-data nextcloud php occ security:certificates
+-----------+-------------+--------------+-------------+-----------+
| File Name | Common Name | Organization | Valid Until | Issued By |
+-----------+-------------+--------------+-------------+-----------+
Jupiter:

wwe · October 17, 2022, 3:31pm

then it’s time to double check the logs… docker logs nextcloud will likely give you a hint whats wrong…

defaria · October 17, 2022, 3:54pm

Not seeing much in the way of hints:

2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:22 -0700] "GET /index.php/apps/dashboard/ HTTP/1.1" 303 820 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:22 -0700] "GET /index.php/login?redirect_url=/index.php/apps/dashboard/ HTTP/1.1" 200 6809 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:22 -0700] "GET /dist/core-common.js?v=a5ae8df1-4 HTTP/1.1" 200 2130444 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:23 -0700] "GET /index.php/apps/theming/image/background?v=4 HTTP/1.1" 200 2503113 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:24 -0700] "GET /index.php/apps/theming/manifest?v=4 HTTP/1.1" 200 1699 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:49:30 -0700] "GET /favicon.ico HTTP/1.1" 302 998 "https://cloud.defariahome.com/index.php/login" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:49:31 -0700] "GET /index.php/login HTTP/1.1" 200 6775 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:30 -0700] "POST /index.php/login HTTP/1.1" 303 1236 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"

defaria · October 19, 2022, 3:39pm

So what next?

wwe · October 19, 2022, 3:48pm

you need to further investigate. the logs you provided don’t show any errors.

If you would you I would create another admin account using occ, so you have full access and the option to reset your password and maybe 2FA for your account. It’s always good idea to have a spare admin account in case of trouble (highly secured with long password, 2FA etc…)

defaria · October 19, 2022, 6:11pm

Not sure how to investigate further when there are no errors thrown in the log files.

I attempted to make an admin user by doing this:

www-data@nextcloud:~/html$ php occ user:add --display-name="Administrator" -g admin -g db-admins admin
Enter password: 
Confirm password: 
The user "admin" was created successfully
Display name set to "Administrator"
User "admin" added to group "admin"
Created group "db-admins"
User "admin" added to group "db-admins"
www-data@nextcloud:~/html$

I did find this by looking at my own user:

www-data@nextcloud:~/html$ php occ user:setting andrew login_token
  - login_token:
    - +DJM7afi4vS6Ygx4pldqFw3hP0LBa3kw: 1665671412
    - /bRNf9ri3g7O9pvLh95tQMvykL61Wy3v: 1665671566
    - 0iH5Y9A2ikreRi0a4p807tcOyQYqftXC: 1665941040
    - 0umdpByWkZrVRiivoUnhvmZ2e/mpOQAP: 1665941504
    - 1ARmEGUUDjkWbnUnhA5AHUJ3a8Jhb4jM: 1665676515
    - 1HTZ/WKJ618kBlPkvxeWp7NbzbB2BXiS: 1664730476
...
  - settings:
    - display_name: Andrew DeFaria
www-data@nextcloud:~/html$

There are a bunch of these login_tokens which may explain why it takes so long for my login to fail. Can I just clear these out somehow? I tried using occ to --delete the login_token but that didn’t work. Also tried to set it to blank. Didn’t work either. Still can’t login as andrew but I can as admin now!

wwe · October 19, 2022, 7:32pm

you can delete the tokens one by one using

occ user:setting --delete test3 login_token  1HTZ/WKJ618kBlPkvxeWp7NbzbB2BXiS

but until you have really astronomic amount of such tokens it should be not a problem (I have 3 pages of tokens for my user and didn’t recognize huge login delays).

if you want you can run

date -d @1665676515

on lunux or

(Get-Date 01.01.1970).AddSeconds(1665676515)

on PowerShell to see the timestamp of your tokens…

but now you can analyze Nextcloud logs, reset andrew’s password, using impersonate app you could switch from admin to andrew and double check you see something wrong from your account…

defaria · October 19, 2022, 8:23pm

The problem is there’s nothing in the nextcloud.log.

Don’t know why I’d want to reset my password, I use a password manager, and I know it’s correct. Plus it’s not like Nextcloud said anything like “Invalid password”.

And yes I can log in as admin and impersonate andrew. Done that already. Again I didn’t see any clues. What should I be looking for?

wwe · October 20, 2022, 3:08pm

Nobody can tell you what the issue is, but it must be related to your user as login with other users work. Take a look on all involved components one after another.

Even in case you think the password is right it could have changed somehow - very low-hanging fruit and definitely worth to test… maybe good idea to increase log level of Nextcloud. Otherwise, as you have no luck on the server side, browser dev tools could be a rescue to take a look from the other side - start with F12 and visit you cloud - you will see resources and URL the browser tries to access - maybe this helps.

You mentioned reverse proxy as well - this must have logs as well worth checking (increased log level recommended as well). You can perform login with working and failed user and analyze differences…

defaria · October 20, 2022, 10:40pm

If nobody can truly tell me what the issue is then it logically follows that I can’t tell what the problem is. This is demonstrably false. Properly debugged the issue can be identified. Software engineers like me do this all the time.

It also logically follows that if I try to log in and I purposely give it an incorrect password it does tell me “Invalid username or password” almost at once. So it’s clear that the password I used was correct.

The only thing that dev tools reveal is:

POST https://cloud.defariahome.com/index.php/login 504

Think about it, if I get to NextCloud’s login screen then Nextcloud is up and the reverse proxy is working - otherwise, I wouldn’t see the login screen. It’s only after I enter my credentials and wait a long time does it appear as if the login process has finished. It’s at this time that something times out and I get a 504.

So I upped (actually downed) the log_level in config.php to 0 (all info) and restarted the Nextcloud container with a fresh new nextcloud.log. Here is the output of a failed login

{"reqId":"vYCZJmcKzH0BTnDAXLls","level":0,"time":"2022-10-20T22:31:31+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"music","method":"POST","url":"/index.php/login","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36","version":"24.0.6.1","data":{"app":"music"}}
{"reqId":"ZaqkARZOk1jLIE9PZpgo","level":0,"time":"2022-10-20T22:32:14+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"music","method":"GET","url":"/remote.php/webdav/","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"--","version":"24.0.6.1","data":{"app":"music"}}
{"reqId":"ZaqkARZOk1jLIE9PZpgo","level":0,"time":"2022-10-20T22:32:14+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"webdav","method":"GET","url":"/remote.php/webdav/","message":"No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured, No 'Authorization: Bearer' header found. Either the client didn't send one, or the server is mis-configured","userAgent":"--","version":"24.0.6.1","exception":{"Exception":"Sabre\\DAV\\Exception\\NotAuthenticated","Message":"No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured, No 'Authorization: Bearer' header found. Either the client didn't send one, or the server is mis-configured","Code":0,"Trace":[{"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","Line":152,"CustomMessage":"--"}}
{"reqId":"vhpeLtDpPZmEIXkSHPef","level":0,"time":"2022-10-20T22:32:14+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"music","method":"GET","url":"/remote.php/webdav/","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"--","version":"24.0.6.1","data":{"app":"music"}}
{"reqId":"vhpeLtDpPZmEIXkSHPef","level":0,"time":"2022-10-20T22:32:14+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"no app in context","method":"GET","url":"/remote.php/webdav/","message":"Token is not valid: Token does not exist: token does not exist","userAgent":"--","version":"24.0.6.1","exception":{"Exception":"OC\\Authentication\\Exceptions\\InvalidTokenException","Message":"Token does not exist: token does not exist","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":523,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":436,"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":251,"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":180,"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":135,"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenProvider.php","Line":115,"Previous":{"Exception":"OCP\\AppFramework\\Db\\DoesNotExistException","Message":"token does not exist","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenProvider.php","line":111,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenMapper","type":"->","args":["*** sensitive parameters replaced ***"]},{"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":523,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":436,"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":251,"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":180,"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":135,"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenMapper.php","Line":89},"message":"Token is not valid: Token does not exist: token does not exist","exception":{},"CustomMessage":"Token is not valid: Token does not exist: token does not exist"}}
{"reqId":"dU1fkEfvZ5vQUJb8f4BR","level":0,"time":"2022-10-20T22:32:31+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"music","method":"GET","url":"/favicon.ico","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36","version":"24.0.6.1","data":{"app":"music"}}
{"reqId":"u91L01ewQzAe2Wsrh19h","level":0,"time":"2022-10-20T22:32:31+00:00","remoteAddr":"2603:8000:3602:5720:b2f9:7157:530e:9eb8","user":"--","app":"music","method":"GET","url":"/index.php/login","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36","version":"24.0.6.1","data":{"app":"music"}}

I did experience some times when I was able to log in as my user. I’d logged out and was not able to log back in. Then it seemed to let me in every other time and not I can’t login at all again.

wwe · October 21, 2022, 6:39am

absolutely agree - let me correct my statement: “nobody can tell you what is the problem based on information’s you made available until now”. As a software engineer you understand the the troubleshooting process so you know that you need to identify faulty component and reason of the fault and till now this didn’t happen.

based on the fact other users can successfully login we can assume the system and reverse proxy work, but there until we exactly know the fault chances still exist this components involved in the fault.

additionally for troubleshooting I would disable “music” app (and every other custom app) - once the issue is fixed you can add them one by one.

defaria · October 21, 2022, 3:25pm

The problem is identifying the problem in a huge software base when one is ignorant of the code base and how it operates and then when nothing is written into the logs when something goes wrong.

I forgot to mention that I did disable the music app and that didn’t change anything. It’s not clear to me which apps are custom and which ones aren’t.

Disabled all apps. Tried to log in. Same error.

I must say, error reporting in nextcloud.log is very inconsistent at best. I have the log_level set to the highest amount (0) and times I am not able to log in and I get nothing in nextcloud.log. Other times I’ve seen something like this:

{"reqId":"KfTyQ5P47U560QDLqGVK","level":0,"time":"2022-10-21T14:01:44+00:00","remoteAddr":"2603:8000:3602:5720:d864:33b8:1df2:9515","user":"--","app":"no app in context","method":"GET","url":"/index.php/apps/files/","message":"Current user is not logged in","userAgent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36","version":"24.0.6.1","exception":{"Exception":"OC\\AppFramework\\Middleware\\Security\\Exceptions\\NotLoggedInException","Message":"Current user is not logged in","Code":401,"Trace":[{"file":"/var/www/html/lib/private/AppFramework/Middleware/MiddlewareDispatcher.php","line":97,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\Security\\SecurityMiddleware","type":"->","args":[{"__class__":"OCA\\Files\\Controller\\ViewController"},"index"]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":125,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\MiddlewareDispatcher","type":"->","args":[{"__class__":"OCA\\Files\\Controller\\ViewController"},"index"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Files\\Controller\\ViewController"},"index"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Files\\Controller\\ViewController","index",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["files.view.index"]]},{"file":"/var/www/html/lib/base.php","line":1030,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/files/"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/lib/private/AppFramework/Middleware/Security/SecurityMiddleware.php","Line":153,"message":"Current user is not logged in","exception":{},"CustomMessage":"Current user is not logged in"}}

Interesting, it seems to show me logging in but then says I’m not logged in.

Ok, so I stop the Nextcloud container, empty the log file, start the Nextcloud container and attempt to login. Can’t log in, nothing in nextcloud.log. log_level is at 0, no apps are enabled. Hmm…

Decided to wait a while and then the following appeared in nextcloud.log. Don’t know how long I waited (I went and made breakfast):

{"reqId":"SdeWmGgPewXHGifXIOVA","level":0,"time":"2022-10-21T14:14:13+00:00","remoteAddr":"2603:8000:3602:5720:d864:33b8:1df2:9515","user":"--","app":"webdav","method":"GET","url":"/remote.php/webdav/","message":"No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured, No 'Authorization: Bearer' header found. Either the client didn't send one, or the server is mis-configured","userAgent":"--","version":"24.0.6.1","exception":{"Exception":"Sabre\\DAV\\Exception\\NotAuthenticated","Message":"No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured, No 'Authorization: Bearer' header found. Either the client didn't send one, or the server is mis-configured","Code":0,"Trace":[{"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","Line":152,"CustomMessage":"--"}}
{"reqId":"tTqIhXGuPGFtGL071E21","level":0,"time":"2022-10-21T14:14:13+00:00","remoteAddr":"2603:8000:3602:5720:d864:33b8:1df2:9515","user":"--","app":"no app in context","method":"GET","url":"/remote.php/webdav/","message":"Token is not valid: Token does not exist: token does not exist","userAgent":"--","version":"24.0.6.1","exception":{"Exception":"OC\\Authentication\\Exceptions\\InvalidTokenException","Message":"Token does not exist: token does not exist","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":523,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":436,"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":251,"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":180,"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":135,"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenProvider.php","Line":115,"Previous":{"Exception":"OCP\\AppFramework\\Db\\DoesNotExistException","Message":"token does not exist","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenProvider.php","line":111,"function":"getToken","class":"OC\\Authentication\\Token\\PublicKeyTokenMapper","type":"->","args":["*** sensitive parameters replaced ***"]},{"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":523,"function":"getToken","class":"OC\\Authentication\\Token\\Manager","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/User/Session.php","line":436,"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":251,"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":180,"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":135,"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Authentication/Token/PublicKeyTokenMapper.php","Line":89},"message":"Token is not valid: Token does not exist: token does not exist","exception":{},"CustomMessage":"Token is not valid: Token does not exist: token does not exist"}}
{"reqId":"KJIGxii0LVlQ0W9UdNoE","level":0,"time":"2022-10-21T14:18:38+00:00","remoteAddr":"2603:8000:3602:5720:d864:33b8:1df2:9515","user":"--","app":"webdav","method":"GET","url":"/remote.php/webdav/","message":"No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured, No 'Authorization: Bearer' header found. Either the client didn't send one, or the server is mis-configured","userAgent":"--","version":"24.0.6.1","exception":{"Exception":"Sabre\\DAV\\Exception\\NotAuthenticated","Message":"No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured, No 'Authorization: Bearer' header found. Either the client didn't send one, or the server is mis-configured","Code":0,"Trace":[{"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:GET",[{"__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/appinfo/v1/webdav.php","line":87,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v1/webdav.php"],"function":"require_once"}],"File":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","Line":152,"CustomMessage":"--"}}

Truncated due to posting limit (and lack of the ability to attach a log file).

What now?

wwe · October 21, 2022, 4:31pm

what is about

your nextcloud.log (written to docker STDOUT as well - run docker logs <container>
your reverse proxy log

defaria · October 21, 2022, 6:10pm

LIke the saying “The good thing about standards is that there are soooo many to choose from” - "The good thing about logfiles is there are soooo many places to find them…

And here is the output from a failed attempt to login using docker logs -f nextcloud:

2603:8000:3602:5720:d864:33b8:1df2:9515 - - [21/Oct/2022:09:51:28 -0700] "GET /index.php/apps/dashboard/ HTTP/1.1" 302 899 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36"
2603:8000:3602:5720:d864:33b8:1df2:9515 - - [21/Oct/2022:09:51:28 -0700] "GET /index.php/login HTTP/1.1" 200 4279 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36"
---
2603:8000:3602:5720:d864:33b8:1df2:9515 - andrew [21/Oct/2022:09:51:12 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1577 "-" "-"
2603:8000:3602:5720:d864:33b8:1df2:9515 - - [21/Oct/2022:09:52:34 -0700] "GET /favicon.ico HTTP/1.1" 302 998 "https://cloud.defariahome.com/index.php/login" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36"
2603:8000:3602:5720:d864:33b8:1df2:9515 - - [21/Oct/2022:09:52:34 -0700] "GET /index.php/login HTTP/1.1" 200 4280 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36"

Note I put a line of --- in there to indicate where Nextcloud stopped and asked me for my credentials. The stuff after --- happened after I clicked the Login button.

I have no idea where reverse proxy logs would be kept on a Synology.