android icon indicating copy to clipboard operation
android copied to clipboard

Login flow resets on grant permission due to 401 HTTP status code

Open dvzrv opened this issue 3 years ago • 3 comments

⚠️ Before posting ⚠️

  • [X] This is a bug, not a question or an enhancement.
  • [X] I've searched for similar issues and didn't find a duplicate.
  • [X] I've written a clear and descriptive title for this issue, not just "Bug" or "Crash".
  • [X] I agree to follow Nextcloud's Code of Conduct.

Steps to reproduce

  1. Attempt to "Log in" upon first start of app using development version or stable version
  2. Scan QR code or type in server address -> username/password -> click "Grant access"

Expected behaviour

The app finishes the login flow.

Actual behaviour

The message "Access failed: Operation finished with HTTP status code 401 (fail)" is shown.

  • When scanning QR code the app remains on the login screen
  • When typing in username/password and pressing "Grant access" the login flow returns to the form for submitting username and password

Android version

10

Device brand and model

Fairphone 3+

Stock or custom OS?

Custom (explain in "additional information")

Nextcloud android app version

20220820

Nextcloud server version

24.0.4

Using a reverse proxy?

No

Android logs

--------- beginning of system 08-27 19:22:49.564 8783 8783 W ViewRootImpl[AuthenticatorActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_BACK, scanCode=0, metaState=0, flags=0x68, repeatCount=0, eventTime=1018399435, downTime=1018399384, deviceId=-1, source=0x101, displayId=0 } 08-27 19:22:49.565 8783 8783 I chatty : uid=10187(com.nextcloud.android.beta) identical 5 lines 08-27 19:22:49.565 8783 8783 W ViewRootImpl[AuthenticatorActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_BACK, scanCode=0, metaState=0, flags=0x68, repeatCount=0, eventTime=1018399435, downTime=1018399384, deviceId=-1, source=0x101, displayId=0 } 08-27 19:22:49.655 8783 8783 W ViewRootImpl[AuthenticatorActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_BACK, scanCode=0, metaState=0, flags=0x68, repeatCount=0, eventTime=1018399435, downTime=1018399384, deviceId=-1, source=0x101, displayId=0 } 08-27 19:22:49.656 8783 8783 W ViewRootImpl[AuthenticatorActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_BACK, scanCode=0, metaState=0, flags=0x68, repeatCount=0, eventTime=1018399435, downTime=1018399384, deviceId=-1, source=0x101, displayId=0 } 08-27 23:06:50.598 8783 8783 W ViewRootImpl[AuthenticatorActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_BACK, scanCode=0, metaState=0, flags=0x68, repeatCount=0, eventTime=1022089709, downTime=1022089661, deviceId=-1, source=0x101, displayId=0 } 08-27 23:06:50.643 8783 8783 I chatty : uid=10187(com.nextcloud.android.beta) identical 7 lines 08-27 23:06:50.643 8783 8783 W ViewRootImpl[AuthenticatorActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_BACK, scanCode=0, metaState=0, flags=0x68, repeatCount=0, eventTime=1022089709, downTime=1022089661, deviceId=-1, source=0x101, displayId=0 } --------- beginning of main 08-27 23:36:30.897 8783 8783 D AuthenticatorActivity: onStart() starting 08-27 23:36:30.900 8783 8783 D AuthenticatorActivity: onResume() starting 08-27 23:36:30.927 8783 8783 D OperationsService: Starting command with id 11 08-27 23:36:30.929 8783 24893 D OwnCloudClient #0: REQUEST GET /status.php 08-27 23:36:30.932 8783 24893 D AdvancedSslSocketFactory: Creating SSL Socket with remote REDACTED_URL:443, local null:0, params: org.apache.commons.httpclient.params.HttpConnectionParams@b28671e 08-27 23:36:30.932 8783 24893 D AdvancedSslSocketFactory: ... with connection timeout 50000 and socket timeout 60000 08-27 23:36:30.938 8783 24893 I ServerNameIndicator: SSLSocket implementation: org.conscrypt.Java8EngineSocket 08-27 23:36:30.938 8783 24893 I ServerNameIndicator: SNI done, hostname: REDACTED_URL 08-27 23:36:31.185 8783 24893 W HttpMethodBase: Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended. 08-27 23:36:31.186 8783 24893 I GetStatusRemoteOperation: Connection check at https://REDACTED_URL: Operation finished with HTTP status code -1 (success) 08-27 23:36:31.186 8783 24893 D GetServerInfoOperation: Trying empty authorization to detect authentication method 08-27 23:36:31.186 8783 24893 D OwnCloudClient #0: REQUEST HEAD /remote.php/dav 08-27 23:36:31.333 8783 24893 I AuthChallengeProcessor: basic authentication scheme selected 08-27 23:36:31.333 8783 24893 I HttpMethodDirector: No credentials available for BASIC 'Nextcloud'@REDACTED_URL:443 08-27 23:36:31.334 8783 24893 D ExistenceCheckRemoteOperation: Existence check for https://REDACTED_URL/remote.php/dav/files/null// targeting for existence finished with HTTP status 401(FAIL) 08-27 23:36:31.334 8783 24893 D DetectAuthenticationMethodOperation: Authentication method found: BASIC_HTTP_AUTH 08-27 23:36:31.334 8783 24893 D OperationsService: Called 2 listeners 08-27 23:36:31.334 8783 24893 D OperationsService: Stopping after command with id 11 08-27 23:36:31.347 8783 8783 D QrCodeActivity: onStop() ending 08-27 23:36:31.348 8783 8783 D QrCodeActivity: onDestroy() ending 08-27 23:36:31.819 8783 8810 E GetUserInfoRemoteOperation: Failed response while getting user information 08-27 23:36:31.819 8783 8810 E GetUserInfoRemoteOperation: *** status code: 401; response message: {"ocs":{"meta":{"status":"failure","statuscode":997,"message":"Current user is not logged in"},"data":[]}} 08-27 23:36:31.832 8783 8783 D AuthenticatorActivity: Access failed: Operation finished with HTTP status code 401 (fail) 08-27 23:37:29.855 8783 8783 D AuthenticatorActivity: onPause() ending 08-27 23:37:29.892 8783 8783 D AuthenticatorActivity: onStop() ending 08-27 23:37:29.894 8783 8783 D AuthenticatorActivity: onSaveInstanceState(Bundle) starting 08-27 23:38:15.012 8783 8783 D AuthenticatorActivity: onStart() starting 08-27 23:38:15.050 8783 8783 D AuthenticatorActivity: onResume() starting 08-27 23:38:17.160 8783 8783 D OperationsService: Starting command with id 12 08-27 23:38:17.164 8783 24893 D OwnCloudClient #0: REQUEST GET /status.php 08-27 23:38:17.166 8783 24893 D AdvancedSslSocketFactory: Creating SSL Socket with remote REDACTED_URL:443, local null:0, params: org.apache.commons.httpclient.params.HttpConnectionParams@b28671e 08-27 23:38:17.166 8783 24893 D AdvancedSslSocketFactory: ... with connection timeout 50000 and socket timeout 60000 08-27 23:38:17.171 8783 24893 I ServerNameIndicator: SNI done, hostname: REDACTED_URL 08-27 23:38:20.266 8783 24893 W HttpMethodBase: Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended. 08-27 23:38:20.269 8783 24893 I GetStatusRemoteOperation: Connection check at https://REDACTED_URL: Operation finished with HTTP status code -1 (success) 08-27 23:38:20.269 8783 24893 D GetServerInfoOperation: Trying empty authorization to detect authentication method 08-27 23:38:20.270 8783 24893 D OwnCloudClient #0: REQUEST HEAD /remote.php/dav 08-27 23:38:20.400 8783 24893 I AuthChallengeProcessor: basic authentication scheme selected 08-27 23:38:20.403 8783 24893 I HttpMethodDirector: No credentials available for BASIC 'Nextcloud'@REDACTED_URL:443 08-27 23:38:20.404 8783 24893 D ExistenceCheckRemoteOperation: Existence check for https://REDACTED_URL/remote.php/dav/files/null// targeting for existence finished with HTTP status 401(FAIL) 08-27 23:38:20.404 8783 24893 D DetectAuthenticationMethodOperation: Authentication method found: BASIC_HTTP_AUTH 08-27 23:38:20.404 8783 24893 D OperationsService: Called 2 listeners 08-27 23:38:20.404 8783 24893 D OperationsService: Stopping after command with id 12 08-27 23:38:20.407 8783 30865 D OwnCloudClient #3: Creating OwnCloudClient 08-27 23:38:20.408 8783 30865 D OwnCloudClient #3: REQUEST GET /ocs/v2.php/cloud/capabilities 08-27 23:38:20.580 8783 30865 D GetCapabilitiesRemoteOperation: Successful response: {"ocs":{"meta":{"status":"ok","statuscode":200,"message":"OK"},"data":{"version":{"major":24,"minor":0,"micro":4,"string":"24.0.4","edition":"","extendedSupport":false},"capabilities":{"bruteforce":{"delay":0},"metadataAvailable":{"size":["/image\/.*/"]},"spreed":{"features":["audio","video","chat-v2","conversation-v4","guest-signaling","empty-group-room","guest-display-names","multi-room-users","favorites","last-room-activity","no-ping","system-messages","delete-messages","mention-flag","in-call-flags","conversation-call-flags","notification-levels","invite-groups-and-mails","locked-one-to-one-rooms","read-only-rooms","listable-rooms","chat-read-marker","chat-unread","webinary-lobby","start-call-flag","chat-replies","circles-support","force-mute","sip-support","chat-read-status","phonebook-search","raise-hand","room-description","rich-object-sharing","temp-user-avatar-api","geo-location-sharing","voice-message-sharing","signaling-v3","publishing-permissions","clear-history","direct-mention-flag","notification-calls","conversation-permissions","rich-object-list-media","rich-object-delete","unified-search","reactions","chat-reference-id"],"config":{"attachments":{"allowed":false},"chat":{"max-length":32000,"read-privacy":0},"conversations":{"can-create":false},"previews":{"max-gif-size":3145728},"signaling":{"session-ping-limit":200}}},"theming":{"name":"Nextcloud","url":"https://nextcloud.com","slogan":"a safe home for all your data","color":"#0082c9","color-text":"#ffffff","color-element":"#0082c9","color-element-bright":"#0082c9","color-element-dark":"#0082c9","logo":"https://REDACTED_URL/core/img/logo/logo.svg?v=0","background":"https://REDACTED_URL/core/img/background.png?v=0","background-plain":false,"background-default":true,"logoheader":"https://REDACTED_URL/core/img/logo/logo.svg?v=0","favicon":"https://REDACTED_URL/core/img/logo/logo.svg?v=0"}}}}} 08-27 23:38:20.581 8783 30865 D GetCapabilitiesRemoteOperation: *** Added version 08-27 23:38:20.581 8783 30865 D GetCapabilitiesRemoteOperation: *** Added theming 08-27 23:38:20.581 8783 30865 D GetCapabilitiesRemoteOperation: *** Get Capabilities completed 08-27 23:38:33.330 8783 8783 W cr_AwAutofillManager: Autofill is disabled: AutofillManager isn't available in given Context. 08-27 23:38:36.577 8783 8783 W cr_AwAutofillManager: Autofill is disabled: AutofillManager isn't available in given Context. 08-27 23:40:01.031 8783 14497 W IInputConnectionWrapper: getSelectedText on inactive InputConnection 08-27 23:40:01.035 8783 14497 W IInputConnectionWrapper: requestCursorAnchorInfo on inactive InputConnection 08-27 23:40:01.036 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.041 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.129 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.130 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.132 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.134 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.135 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.137 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.138 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.139 8783 14497 W IInputConnectionWrapper: getSelectedText on inactive InputConnection 08-27 23:40:01.140 8783 14497 W IInputConnectionWrapper: getTextBeforeCursor on inactive InputConnection 08-27 23:40:01.564 8783 8783 D AuthenticatorActivity: onPause() ending 08-27 23:40:01.578 8783 8783 D AuthenticatorActivity: onStop() ending 08-27 23:40:01.579 8783 8783 D AuthenticatorActivity: onSaveInstanceState(Bundle) starting 08-27 23:40:42.373 8783 8783 D AuthenticatorActivity: onStart() starting 08-27 23:40:42.411 8783 8783 D AuthenticatorActivity: onResume() starting 08-27 23:41:37.059 8783 8783 D OperationsService: Starting command with id 13 08-27 23:41:37.062 8783 24893 D OwnCloudClient #0: REQUEST GET /status.php 08-27 23:41:37.066 8783 24893 D AdvancedSslSocketFactory: Creating SSL Socket with remote REDACTED_URL:443, local null:0, params: org.apache.commons.httpclient.params.HttpConnectionParams@b28671e 08-27 23:41:37.066 8783 24893 D AdvancedSslSocketFactory: ... with connection timeout 50000 and socket timeout 60000 08-27 23:41:37.073 8783 24893 I ServerNameIndicator: SNI done, hostname: REDACTED_URL 08-27 23:41:37.349 8783 24893 W HttpMethodBase: Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended. 08-27 23:41:37.352 8783 24893 I GetStatusRemoteOperation: Connection check at https://REDACTED_URL: Operation finished with HTTP status code -1 (success) 08-27 23:41:37.352 8783 24893 D GetServerInfoOperation: Trying empty authorization to detect authentication method 08-27 23:41:37.353 8783 24893 D OwnCloudClient #0: REQUEST HEAD /remote.php/dav 08-27 23:41:37.500 8783 24893 I AuthChallengeProcessor: basic authentication scheme selected 08-27 23:41:37.502 8783 24893 I HttpMethodDirector: No credentials available for BASIC 'Nextcloud'@REDACTED_URL:443 08-27 23:41:37.503 8783 24893 D ExistenceCheckRemoteOperation: Existence check for https://REDACTED_URL/remote.php/dav/files/null// targeting for existence finished with HTTP status 401(FAIL) 08-27 23:41:37.504 8783 24893 D DetectAuthenticationMethodOperation: Authentication method found: BASIC_HTTP_AUTH 08-27 23:41:37.504 8783 24893 D OperationsService: Called 2 listeners 08-27 23:41:37.504 8783 24893 D OperationsService: Stopping after command with id 13 08-27 23:41:37.620 8783 8797 W MediaPlayer-JNI: MediaPlayer finalized without being released 08-27 23:41:37.631 8783 8797 W MediaPlayer-JNI: MediaPlayer finalized without being released 08-27 23:41:37.908 8783 8810 E GetUserInfoRemoteOperation: Failed response while getting user information 08-27 23:41:37.908 8783 8810 E GetUserInfoRemoteOperation: *** status code: 401; response message: {"ocs":{"meta":{"status":"failure","statuscode":997,"message":"Current user is not logged in"},"data":[]}} 08-27 23:41:37.927 8783 8783 D AuthenticatorActivity: Access failed: Operation finished with HTTP status code 401 (fail)

Server error logs

// no message shows up in the nextcloud server log, even after setting the log level to 1
// however, the webserver/ application server report the unauthorized access
{34 vars in 498 bytes} [Sat Aug 27 23:17:07 2022] HEAD /remote.php/dav => generated 0 bytes in 80 msecs (HTTP/1.1 401) 17 headers in 1054 bytes (0 switches on core 0)
{40 vars in 665 bytes} [Sat Aug 27 23:17:08 2022] GET /ocs/v2.php/cloud/user?format=json => generated 106 bytes in 115 msecs (HTTP/2.0 401) 19 headers in 1231 bytes (0 switches on core 0)

Additional information

Tried on LineageOS and EOS.

The nextcloud server setup follows https://docs.nextcloud.com/server/latest/admin_manual/installation/nginx.html#nextcloud-in-the-webroot-of-nginx closely.

dvzrv avatar Aug 27 '22 21:08 dvzrv

FWIW, logging in with https://gitlab.com/bisada/OCBookmarks still works just fine. Anything based on the nextcloud android app stopped working (e.g. news, notes, deck)

dvzrv avatar Aug 27 '22 22:08 dvzrv

The only PR related to login flow that I could find in the 24 branch of nextcloud server is https://github.com/nextcloud/server/pull/32415

Maybe @blizzz and/or @nickvergessen would be able to comment on whether that change could exhibit the issues I am seeing with signing up new devices using the android app.

dvzrv avatar Aug 28 '22 12:08 dvzrv

Should not be able to cause any issues.

nickvergessen avatar Aug 30 '22 06:08 nickvergessen

I am still experiencing this issue and am unable to connect my android devices to my nextcloud instance.

The following can be found in the nextcloud server log:

{"reqId":"BYNQKozmKlDxeFpaJnT3","level":0,"time":"October 04, 2022 00:23:58","remoteAddr":"REDACTED_IP_ADDRESS","user":"--","app":"webdav","method":"HEAD","url":"/remote.php/dav","message":"No public access to this resource., 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, No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured","userAgent":"Mozilla/5.0 (Android) Nextcloud-android/20220927","version":"24.0.5.1","exception":{"Exception":"Sabre\\DAV\\Exception\\NotAuthenticated","Message":"No public access to this resource., 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, No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured","Code":0,"Trace":[{"file":"/usr/share/webapps/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMethod","class":"Sabre\\DAV\\Auth\\Plugin","type":"->"},{"file":"/usr/share/webapps/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":456,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/usr/share/webapps/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/usr/share/webapps/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/usr/share/webapps/nextcloud/apps/dav/lib/Server.php","line":358,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/usr/share/webapps/nextcloud/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->"},{"file":"/usr/share/webapps/nextcloud/remote.php","line":166,"args":["/usr/share/webapps/nextcloud/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/usr/share/webapps/nextcloud/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php","Line":152,"CustomMessage":"--"}}
{"reqId":"QlsXa8a8pIoQayhCETRi","level":0,"time":"October 04, 2022 00:23:59","remoteAddr":"REDACTED_IP_ADDRESS","user":"--","app":"no app in context","method":"GET","url":"/ocs/v2.php/cloud/user?format=json","message":"Current user is not logged in","userAgent":"Mozilla/5.0 (Android) Nextcloud-android/20220927","version":"24.0.5.1","exception":{"Exception":"OC\\AppFramework\\Middleware\\Security\\Exceptions\\NotLoggedInException","Message":"Current user is not logged in","Code":401,"Trace":[{"file":"/usr/share/webapps/nextcloud/lib/private/AppFramework/Middleware/MiddlewareDispatcher.php","line":97,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\Security\\SecurityMiddleware","type":"->"},{"file":"/usr/share/webapps/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":125,"function":"beforeController","class":"OC\\AppFramework\\Middleware\\MiddlewareDispatcher","type":"->"},{"file":"/usr/share/webapps/nextcloud/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/usr/share/webapps/nextcloud/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/usr/share/webapps/nextcloud/ocs/v1.php","line":62,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/usr/share/webapps/nextcloud/ocs/v2.php","line":23,"args":["/usr/share/webapps/nextcloud/ocs/v1.php"],"function":"require_once"}],"File":"/usr/share/webapps/nextcloud/lib/private/AppFramework/Middleware/Security/SecurityMiddleware.php","Line":153,"message":"Current user is not logged in","exception":{},"CustomMessage":"Current user is not logged in"}}

The following nextcloud server issues seem relevant but they have arbitrary and completely unclear conflict resolution: https://github.com/nextcloud/server/issues/31558 https://github.com/nextcloud/server/issues/16947 https://github.com/nextcloud/server/issues/9637 https://github.com/nextcloud/server/issues/8011 https://github.com/nextcloud/server/issues/5482 https://github.com/nextcloud/server/issues/5326

dvzrv avatar Oct 03 '22 22:10 dvzrv

Also, the following android app issues may be related, but I am not sure: https://github.com/nextcloud/android/issues/9827 (the error message is similar).

dvzrv avatar Oct 03 '22 23:10 dvzrv

Had a similar problem (I was unable to use Notes and News on android with 401 errors). I fixed it by removing the NextCloud account from android Settings, force-stopping NextCloud android app, deleting its cache, opening the app again and signing in again. May be worth a try for this problem too.

k3a avatar Jul 10 '23 20:07 k3a

Had similar if not same issue, reported here: https://help.nextcloud.com/t/inexistent-anymore-device-login-fails/169914

To cut long story short, took backup and restored to it (there were couple of troubleshooting/testing steps on the way) and it all worked.

bugsyb avatar Sep 12 '23 11:09 bugsyb

@dvzrv Any of the follow-up comments helpful? Is this still occurring for you?

joshtrichards avatar Oct 08 '23 02:10 joshtrichards

This bug report did not receive an update in the last 4 weeks. Please take a look again and update the issue with new details, otherwise the issue will be automatically closed in 2 weeks. Thank you!

github-actions[bot] avatar Nov 06 '23 00:11 github-actions[bot]