Unable to log into nextcloud

[defaria]

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]

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…

@defaria

Still can’t login as andrew but I can as admin now!

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]

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]

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]

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]

@defaria

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.

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.

@defaria

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.

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]

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]

what is about

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

[defaria]

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.

[wwe]

@defaria

The good thing about logfiles is there are soooo many places to find them…

I agree and definitely it would be great the logs live in only one place. but this is a drawback of running complex system build of different components - and this is your job as sysadmin to educate about involved components and locate all the logs this components write.

regarding the above log snippet I have two observations

• I don’t observe any POST request when you submit the password. In my logs there is one…
• it looks like you access the system using IPv6. I was under impression IPv6 doesn’t work well with docker - please review you DNS, routing, firewall etc to verify the system everything works well with IPv6 (for quick test you could “break” the IPv6 with hosts file “:: cloud.defariahome.com” or your local DNS server in case you run one)

[defaria]

@wwe

regarding the above log snippet I have two observations

• I don’t observe any POST request when you submit the password. In my logs there is one…

What can I say? It didn’t put out a POST I guess. Here it is again:

2603:8000:3602:5720:8d53:448f:91dd:6808 - - [23/Oct/2022:13:31:53 -0700] "GET / HTTP/1.1" 302 899 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:105.0) Gecko/20100101 Firefox/105.0"
2603:8000:3602:5720:8d53:448f:91dd:6808 - - [23/Oct/2022:13:31:53 -0700] "GET /index.php/login HTTP/1.1" 200 6774 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:105.0) Gecko/20100101 Firefox/105.0"
2603:8000:3602:5720:8d53:448f:91dd:6808 - - [23/Oct/2022:13:32:07 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1689 "-" "-"
2603:8000:3602:5720:8d53:448f:91dd:6808 - andrew [23/Oct/2022:13:31:06 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1571 "-" "-"
2603:8000:3602:5720:8d53:448f:91dd:6808 - - [23/Oct/2022:13:32:57 -0700] "GET /favicon.ico HTTP/1.1" 404 649 "https://cloud.defariahome.com/index.php/login" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:105.0) Gecko/20100101 Firefox/105.0"

• it looks like you access the system using IPv6. I was under impression IPv6 doesn’t work well with docker - please review you DNS, routing, firewall etc to verify the system everything works well with IPv6 (for quick test you could “break” the IPv6 with hosts file “:: cloud.defariahome.com” or your local DNS server in case you run one)

I don’t do my own DNS. I use 1.1.1.1 and 1.0.0.1.

I have moved and had gotten a new ISP. I have been using Synology’s DDNS (synology.me). This caused my IPv4 address to change so I changed the IPv4 address but I had no idea what to set the new IPv6 address to. Honestly, I didn’t even know if I was using IPv6 at all. It was set to 2603:8000:3602:5720:211:32ff:fed1:7025. However, when I go to places like https://test-ipv6.com/ it tells me “Your IPv6 address on the public Internet appears to be 2603:8000:3602:5720:8d53:448f:91dd:6808”. I tried changing the IPv6 address in the Synology DDNS configuration and now all of my docker applications return with:

Secure Connection Failed

An error occurred during a connection to cloud.defariahome.com. SSL received a record that exceeded the maximum permissible length.

Error code: SSL_ERROR_RX_RECORD_TOO_LONG

    The page you are trying to view cannot be shown because the authenticity of the received data could not be verified.
    Please contact the website owners to inform them of this problem.

Suspicious things remain:

• My DNS has not really changed except as noted above (having to change my IPv4 address due to my move in Synology’s DDNS)
• None of my other docker apps have any problems being accessed (maybe none of them use IPv6 and only NC does?)
• Nextcloud connects and presents the login screen so all of that is working. It may be possible that Nextcloud is connecting and presenting the initial login dialog then switches over to IPv6 to continue. Seems dumb. And other users, like my newly created admin user login so if it’s the case that NC switches to IPv6 then that’s working for admin.
• Perhaps I need to set my IPv6 default gateway? It’s currently stated as fe80::e65e:1bff:fef5:aa97.

Here’s what is returned from nslookup(1) on the Synology:

Jupiter:nslookup cloud.defariahome.com
Server:		1.1.1.1
Address:	1.1.1.1#53

Non-authoritative answer:
cloud.defariahome.com	canonical name = defaria.synology.me.
Name:	defaria.synology.me
Address: 75.80.5.95
Name:	defaria.synology.me
Address: 2603:8000:3602:5720:211:32ff:fed1:7025

Jupiter:

When I change the IPv6 address and re-perform the nslookup I see that it’s updated:

Jupiter:nslookup cloud.defariahome.com
Server:		1.1.1.1
Address:	1.1.1.1#53

Non-authoritative answer:
cloud.defariahome.com	canonical name = defaria.synology.me.
Name:	defaria.synology.me
Address: 75.80.5.95
Name:	defaria.synology.me
Address: 2603:8000:3602:5720:8d53:448f:91dd:6808

Jupiter:

But then everything fails with the error about not being able to provide a secure connection.

Since I saw there was a way to turn off the External Address(IPv6) on Synology I disabled it. My docker apps work but Nextcloud still fails the same way. I don’t think IPv6 is the probelm though I’m still confused why sites report my IPv6 address is different than what seems to be working for me in Synology.

[wwe]

@defaria

2603:8000:3602:5720:8d53:448f:91dd:6808 - - [23/Oct/2022:13:31:53 -0700] "GET / HTTP/1.1" 302 899 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:105.0) Gecko/20100101 Firefox/105.0"

The line above shows you are accessing your server via IPv6. If this is a problem or not I can’t say now.

2603:8000:3602:5720:8d53:448f:91dd:6808 > seems to be you client IP, which different from your Synology (server) IP. Often there are two different sets of port forwards in the routers, one for each protocol family maybe need to create additional IPv6 port forward for you Synology system additionally to existing IPv4…

What is definitely a problem is the fact you don’t see any POST request, which exactly the piece where you send credentials to your server. in my case I see exactly the same POST request to /login endpoint within browser console and server logs (docker logs) followed by /selectchallenge (2FA provider) - in your case this might be different if you didn’t enable multi-factor authentication

as you are lucky to have both working and non-working user in your system I would recommend you to follow the logs of your browser, server and reverse proxy and identify the difference…

P.S. earlier you posted a POST request - did the log belong to the working request or did something change?

@defaria

2603:8000:3602:5720:8177:7863:3dcb:39bb - - [17/Oct/2022:08:48:30 -0700] "POST /index.php/login HTTP/1.1" 303

[defaria]

@wwe

@defaria

2603:8000:3602:5720:8d53:448f:91dd:6808 - - [23/Oct/2022:13:31:53 -0700] "GET / HTTP/1.1" 302 899 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:105.0) Gecko/20100101 Firefox/105.0"

The line above shows you are accessing your server via IPv6. If this is a problem or not I can’t say now.

Ok, but what do you say about the oddness of the different IPv6 addresses that I reported?

2603:8000:3602:5720:8d53:448f:91dd:6808 > seems to be you client IP, which different from your Synology (server) IP. Often there are two different sets of port forwards in the routers, one for each protocol family maybe need to create additional IPv6 port forward for you Synology system additionally to existing IPv4…

Doesn’t make sense. First I didn’t have to port forward an IPv6 address before and secondly, if this were the case then no user would be able to log into NextCloud. Also, which IPv6 would I forward and to where?

What is definitely a problem is the fact you don’t see any POST request, which exactly the piece where you send credentials to your server. in my case I see exactly the same POST request to /login endpoint within browser console and server logs (docker logs) followed by /selectchallenge (2FA provider) - in your case this might be different if you didn’t enable multi-factor authentication

Oddly, a POST request pops up about a minute or two after I get the failure message in the browser. That’s why you didn’t see it before. I thought it was done logging stuff. Here it is in this log:

Wizard Jupiter:docker logs nextcloud
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.0.12. Set the 'ServerName' directive globally to suppress this message
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.0.12. Set the 'ServerName' directive globally to suppress this message
[Mon Oct 24 12:52:48.064443 2022] [mpm_prefork:notice] [pid 1] AH00163: Apache/2.4.54 (Debian) PHP/8.0.24 configured -- resuming normal operations
[Mon Oct 24 12:52:48.064524 2022] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND'
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:53:01 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1691 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:54:02 -0700] "GET / HTTP/1.1" 302 998 "-" "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:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:12:53:05 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1583 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:54:03 -0700] "GET /index.php/login HTTP/1.1" 200 6770 "-" "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:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:54:08 -0700] "GET /dist/core-common.js?v=fc579593-4 HTTP/1.1" 200 2130444 "-" "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:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:54:09 -0700] "GET /index.php/apps/theming/image/background?v=4 HTTP/1.1" 200 2503060 "-" "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:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:54:09 -0700] "GET /index.php/apps/theming/manifest?v=4 HTTP/1.1" 200 1701 "-" "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:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:54:15 -0700] "POST /index.php/login HTTP/1.1" 303 1238 "-" "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:c073:9dfd:25eb:8960 - - [24/Oct/2022:12:59:36 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1685 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:12:59:36 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1571 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:03:33 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1689 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:13:03:33 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1573 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:09:09 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1687 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:13:09:09 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1575 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:15:55 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1687 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:13:15:55 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1571 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:17:51 -0700] "GET /index.php/login HTTP/1.1" 200 6871 "-" "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:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:19:10 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1689 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:13:19:10 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1571 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:23:17 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1691 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:13:23:17 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1577 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - - [24/Oct/2022:13:28:04 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1691 "-" "-"
2603:8000:3602:5720:c073:9dfd:25eb:8960 - andrew [24/Oct/2022:13:28:04 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1569 "-" "-"
Wizard Jupiter:

Seems to be throwing a 303 which I find here - 303 See Other - HTTP | MDN.

It really seems like Nextcloud is presenting the login screen, taking way too long to authenticate me then switches perhaps to IPv6 or something and gets lost.

BTW why the periodic “GET /remote.php/webdav/” requests? Some of which succeed (200) and some which fail (401)?

as you are lucky to have both working and non-working user in your system I would recommend you to follow the logs of your browser, server and reverse proxy and identify the difference…

As I said before, I don’t know where these reverse proxy logs might be. I’ve checked the server logs (AFAICT), the docker logs, and the browser inspect things and have posted all my results. I don’t know where else to look or what else to do.

I do see that Synology uses nginx and doesn’t even have Apache installed. Looking into the docker container I see that NextCloud is using Apache and Apache logs are wired to stdout and stderr thus appearing in the docker logs.

[wwe]

@defaria

Doesn’t make sense.

ok, as you are not ready to accept my assistance I’m out of ideas. I wish you good luck resolving your issue…

[defaria]

Well, that’s extremely dismissive. Where did I say I was not ready to accept your assistance? All I said was it doesn’t make sense that I would need to add a port forward for the IPv6 address because I didn’t have to do that before and the fact that others are able to successfully login without any additional IPv6 port forward. You gotta admit that that last point surely seems to support that this suggestion doesn’t make sense.

But I would be willing to try it however as I pointed out before, I seem to have two different IPv6 addresses that different pieces of software think I have.

The Synology seems to think that the proper IPv6 address is 2603:8000:3602:5720:211:32ff:fed1:7025. In fact, if I change that address in the Synology DDNS settings then all of my other docker apps refuse to connect with “Secure Connection Failed” and SSL_ERROR_RX_RECORD_TOO_LONG.

And when I go to places like https://test-ipv6.com it reports my IPv6 address is 2603:8000:3602:5720:8d53:448f:91dd:6808.

So the question would be which of these two IPv6 addresses should I port forward? And, to which port do I forward from and to?

I’ve tried to add port forwards for 2603:8000:3602:5720:211:32ff:fed1:7025 to both port 8080 and port 80. Even tried forwarding port 443. Same failure.

Note I have a Google Nest Wifi and I’m told to set port forwards using the Google Home app. When doing the port forward I can choose a device. The device is my Synology and the Google Home app presents me with 2603:8000:3602:5720:211:32ff:fed1:7025 as an IPv6 address for that device. Further (I haven’t done IPv6 port forwards before) it only has one edit box for the port. So I added three IPv6 port forwards for that address and ports 80, 8080, and 443. Tried to log into Nextcloud as my user - it failed as before.

Google Nest Wifi has a setting to enable IPv6. I tried disabling that and still had the same problem.

I don’t think anything above indicates that I’m not ready to accept your assistance, indeed, I’m trying to do the things you suggest. They are just not working.

[wwe]

@defaria

Well, that’s extremely dismissive. Where did I say I was not ready to accept your assistance?

I spend lot of time trying to understand your issue, but you didn’t seriously follow my advice’s to understand your system, compare working and non-working logs.

I definitely agree from what you posted it makes no sense one use can login and another not (assuming the fact everything is the same)… but discussing about what makes sense and what not doesn’t head us into right direction.

@defaria

So the question would be which of these two IPv6 addresses should I port forward? And, to which port do I forward from and to?

As you stated you are an engineer I take this statement as kidding - you must be aware the IP address of your client is different from your server. The router must point to the server address…

@defaria

8080 and port 80. Even tried forwarding port 443.

I don’t really understand what you are looking for - port 80 (often 8080 as well) is for plain http, port 443 is for TLS/SSL secured https. Depending on your setup the one or another can be right but it depends on your setup

@wwe

this is your job as sysadmin to educate about involved components

Please review your configuration, understand whether your Synology/Nextcloud runs http or https, if there is a reverse proxy or not, collect right log files and come back… I’ll be happy to assist you.

[defaria]

@wwe

@defaria

Well, that’s extremely dismissive. Where did I say I was not ready to accept your assistance?

I spend lot of time trying to understand your issue, but you didn’t seriously follow my advice’s to understand your system, compare working and non-working logs.

Which logs exactly?

I see you can’t find where I said I was not ready to accept your assistance. I wonder why you charged me with that… Anyway

Here’s the docker log of a successful login of admin

2603:8000:3602:5720:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:08 -0700] "GET / HTTP/1.1" 302 998 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:09 -0700] "GET /index.php/login HTTP/1.1" 200 6771 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:09 -0700] "GET /index.php/apps/theming/image/background?v=4 HTTP/1.1" 200 2503060 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:09 -0700] "GET /dist/core-common.js?v=fc579593-4 HTTP/1.1" 200 2130444 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:10 -0700] "GET /index.php/apps/theming/manifest?v=4 HTTP/1.1" 200 1703 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:19 -0700] "POST /index.php/login HTTP/1.1" 303 1235 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:22 -0700] "GET /index.php/apps/dashboard/ HTTP/1.1" 200 10950 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:23 -0700] "GET /index.php/css/icons/icons-vars.css?v=1666725157 HTTP/1.1" 200 32455 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:23 -0700] "GET /apps/activity/js/activity-dashboard.js?v=fc579593-4 HTTP/1.1" 200 286834 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:23 -0700] "GET /apps/notifications/js/notifications-main.js?v=fc579593-4 HTTP/1.1" 200 351634 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:23 -0700] "GET /apps/activity/js/activity-sidebar.js?v=fc579593-4 HTTP/1.1" 200 330726 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:23 -0700] "GET /apps/viewer/js/viewer-main.js?v=fc579593-4 HTTP/1.1" 200 365177 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "GET /ocs/v2.php/search/providers?from=%2Fapps%2Fdashboard%2F HTTP/1.1" 200 1024 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "GET /index.php/apps/recommendations/api/recommendations/always HTTP/1.1" 200 1222 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "PUT /index.php/apps/user_status/heartbeat HTTP/1.1" 200 890 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "PUT /index.php/apps/user_status/heartbeat HTTP/1.1" 200 890 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "GET /index.php/apps/theming/manifest/dashboard?v=4 HTTP/1.1" 200 1701 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "GET /ocs/v2.php/apps/weather_status/api/v1/location HTTP/1.1" 200 880 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:24 -0700] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 200 933 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:25 -0700] "GET /ocs/v2.php/apps/weather_status/api/v1/favorites HTTP/1.1" 200 858 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:25 -0700] "GET /index.php/core/preview?fileId=181422&x=250&y=250 HTTP/1.1" 404 761 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:52:25 -0700] "GET /index.php/core/preview?fileId=181419&x=250&y=250 HTTP/1.1" 404 761 "-" "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:5ac5:64ec:cd69:42a9 - andrew [25/Oct/2022:13:51:57 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1571 "-" "-"

And here’s an unsuccessful login for my user:

2603:8000:3602:5720:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:55:01 -0700] "GET / 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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:55:01 -0700] "GET /index.php/login HTTP/1.1" 200 6771 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:55:07 -0700] "POST /index.php/login HTTP/1.1" 303 1238 "-" "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:5ac5:64ec:cd69:42a9 - - [25/Oct/2022:13:59:20 -0700] "GET /remote.php/webdav/ HTTP/1.1" 401 1691 "-" "-"
2603:8000:3602:5720:5ac5:64ec:cd69:42a9 - andrew [25/Oct/2022:13:59:20 -0700] "GET /remote.php/webdav/ HTTP/1.1" 200 1579 "-" "-"
2603:8000:3602:5720:85f1:b235:c5cd:22b7 - andrew [25/Oct/2022:14:00:05 -0700] "PROPFIND /remote.php/dav/files/andrew// HTTP/1.1" 207 1391 "-" "Mozilla/5.0 (Android) Nextcloud-android/3.22.2"

The first two lines in the unsuccessful login appeared before it prompted me to log in. There was a long wait and then the 3rd line with POST in it, appeared about a minute after it displayed the error message indicating it failed to log me in. Subsequent lines all seem to be some sort of polling of webdav.

As I see it the log for the successful login has a bunch of GETs after a POST for the login which makes sense, the admin user was able to log in and Nextcloud preceded to do a bunch of GETs getting information and status. Whereas the unsuccessful login does a POST and then seems to time out.

I definitely agree from what you posted it makes no sense one use can login and another not (assuming the fact everything is the same)… but discussing about what makes sense and what not doesn’t head us into right direction.

Huh? If something doesn’t make logical sense then it surely is heading us in the right direction to not follow that path right? You can change “doesn’t make sense” to “I don’t think this is the right path to go down” if it makes you feel better.

@defaria

So the question would be which of these two IPv6 addresses should I port forward? And, to which port do I forward from and to?

As you stated you are an engineer I take this statement as kidding - you must be aware the IP address of your client is different from your server. The router must point to the server address…

You should not take my statement as I’m kidding because I’m not. I realize there are different IP addresses for the client and server. But I wasn’t talking about that. I was talking about that if I go to https://test-ipv5.com it tells me that my IPv6 address is 2603:8000:3602:5720:5ac5:64ec:cd69:42a9.

However, nslookup says the IPv6 associated with cloud.defariahome.com is 2603:8000:3602:5720:211:32ff:fed1:7025:

Jupiter:nslookup cloud.defariahome.com
Server:		1.1.1.1
Address:	1.1.1.1#53

Non-authoritative answer:
cloud.defariahome.com	canonical name = defaria.synology.me.
Name:	defaria.synology.me
Address: 75.80.5.95
Name:	defaria.synology.me
Address: 2603:8000:3602:5720:211:32ff:fed1:7025

Jupiter:

Plus the DDNS setting on the Synology also says that same IPv6 address:

Unfortunately, Synology’s DSM does not show the full IPv6 address but on the previous screen it does:

So my confusion is which IPv6 address represents the server’s address for cloud.defariahome.com? 2603:8000:3602:5720:5ac5:64ec:cd69:42a9 as reported by https://test-ipv6.com or 2603:8000:3602:5720:211:32ff:fed1:7025 as known by DNS with nslookup and who is also configured into the Synology DDNS? My IPv4 address of 75.80.5.95 sure appears to be the IPv4 address of my house as I had to set change that when I moved from the previous IPv4 address before my other docker apps would work.

@defaria

8080 and port 80. Even tried forwarding port 443.

I don’t really understand what you are looking for - port 80 (often 8080 as well) is for plain http, port 443 is for TLS/SSL secured https. Depending on your setup the one or another can be right but it depends on your setup

You said, “Often there are two different sets of port forwards in the routers, one for each protocol family maybe need to create additional IPv6 port forward for you Synology system additionally to existing IPv4…”. I took this to mean maybe I needed to forward an IPv6 port. But which port? The only IPv4 port I have forwarded is 443 to point to my Synology. As I understand it, the reverse proxy will take requests from that secure port, look at the domain name then route the connection to the appropriate port that the docker container is expecting. As I said, I tried all of 80, 8080, and 443. Why 80 and 8080? Well doesn’t Nextcloud use 8080? Not sure why I tried to forward 80, but for 443 I thought perhaps the 443 port on IPv4 and IPv6 are separate and distinct and maybe NC started using IPv4, put up the login page, then decided to switch to IPv6 for some reason and then back to :443. It was a simple and quick test to do.

Please review your configuration, understand whether your Synology/Nextcloud runs http or https, if there is a reverse proxy or not, collect right log files and come back… I’ll be happy to assist you.

To my knowledge I don’t use http, I use only https. Yes, there’s a reverse proxy - that was mentioned in the OP. I collected and reported on all logs that I know about. I mentioned that I don’t know where the reverse proxy logs may be. If you can define what the “right log files” are and where they are located I’ll go collect them.

[defaria]

Still can’t log in. Anybody else have any ideas?

[yaokai]

My server have the same issue. One of my user unable to login when using reverse proxy. But if directly access the server, this user can finally logined in after about 1 minute waiting. This example why nginx (reverse proxy) reports “time out”.
Not sure if the login delay is related to the file size of user or not. There are many users under the server.
User A has files size about 900 GB under it’s account, it uses about 60 seconds to login in.
User B has file size about 120 GB under it’s account, it uses about 10 seconds to login in.
Other users with less files have no login delay.
Still no fix…