twofactor_u2f icon indicating copy to clipboard operation
twofactor_u2f copied to clipboard

U2F "Adding device" hang

Open robballan opened this issue 4 years ago • 17 comments

Steps to reproduce

  1. add a device
  2. hang with "adding device"

Expected behaviour

Tell us what should happen

Actual behaviour

Tell us what happens instead

Server configuration

Operating system: FreeBSD 12.2

Web server: apache 24

Database: mysql

PHP version: 8.0

Version: (see admin page) 21.0.2

Updated from an older version or fresh install: fresh

List of activated apps:

Enabled:

  • accessibility: 1.7.0
  • activity: 2.14.3
  • bruteforcesettings: 2.1.0
  • cloud_federation_api: 1.4.0
  • comments: 1.11.0
  • contactsinteraction: 1.2.0
  • dashboard: 7.1.0
  • dav: 1.17.1
  • federatedfilesharing: 1.11.0
  • federation: 1.11.0
  • files: 1.16.0
  • files_pdfviewer: 2.1.0
  • files_rightclick: 1.0.0
  • files_sharing: 1.13.1
  • files_trashbin: 1.11.0
  • files_versions: 1.14.0
  • files_videoplayer: 1.10.0
  • firstrunwizard: 2.10.0
  • logreader: 2.6.0
  • lookup_server_connector: 1.9.0
  • nextcloud_announcements: 1.10.0
  • notifications: 2.9.0
  • oauth2: 1.9.0
  • password_policy: 1.11.0
  • photos: 1.3.0
  • privacy: 1.5.0
  • provisioning_api: 1.11.0
  • recommendations: 1.0.0
  • serverinfo: 1.11.0
  • settings: 1.3.0
  • sharebymail: 1.11.0
  • support: 1.4.0
  • survey_client: 1.9.0
  • systemtags: 1.11.0
  • text: 3.2.0
  • theming: 1.12.0
  • twofactor_backupcodes: 1.10.0
  • twofactor_u2f: 6.1.0
  • updatenotification: 1.11.0
  • user_status: 1.1.1
  • viewer: 1.5.0
  • weather_status: 1.1.0
  • workflowengine: 2.3.0 Disabled:
  • admin_audit
  • encryption
  • files_external
  • user_ldap The content of config/config.php:

{ "system": { "instanceid": "REMOVED SENSITIVE VALUE", "passwordsalt": "REMOVED SENSITIVE VALUE", "secret": "REMOVED SENSITIVE VALUE", "trusted_domains": [ "localhost", "binary.biltmore", "192.168.150.170", "ashbury.helical.com" ], "datadirectory": "REMOVED SENSITIVE VALUE", "dbtype": "mysql", "version": "21.0.2.1", "overwrite.cli.url": "http://localhost", "dbname": "REMOVED SENSITIVE VALUE", "dbhost": "REMOVED SENSITIVE VALUE", "dbport": "", "dbtableprefix": "oc_", "mysql.utf8mb4": true, "dbuser": "REMOVED SENSITIVE VALUE", "dbpassword": "REMOVED SENSITIVE VALUE", "installed": true, "overwriteprotocol": "https", "simpleSignUpLink.shown": false, "mail_from_address": "REMOVED SENSITIVE VALUE", "mail_smtpmode": "sendmail", "mail_sendmailmode": "smtp", "mail_domain": "REMOVED SENSITIVE VALUE", "mail_smtpauthtype": "LOGIN", "mail_smtphost": "REMOVED SENSITIVE VALUE", "mail_smtpauth": 1, "mail_smtpname": "REMOVED SENSITIVE VALUE", "mail_smtppassword": "REMOVED SENSITIVE VALUE", "mail_smtpsecure": "ssl", "mail_smtpport": "587", "twofactor_enforced": "false", "twofactor_enforced_groups": [], "twofactor_enforced_excluded_groups": [] }, "apps": { "accessibility": { "enabled": "yes", "installed_version": "1.7.0", "types": "" }, "activity": { "enabled": "yes", "installed_version": "2.14.3", "types": "filesystem" }, "backgroundjob": { "lastjob": "154" }, "bruteforcesettings": { "enabled": "yes", "installed_version": "2.1.0", "types": "" }, "cloud_federation_api": { "enabled": "yes", "installed_version": "1.4.0", "types": "filesystem" }, "comments": { "enabled": "yes", "installed_version": "1.11.0", "types": "logging" }, "contactsinteraction": { "enabled": "yes", "installed_version": "1.2.0", "types": "dav" }, "core": { "installed.bundles": "["CoreBundle"]", "installedat": "1623070318.2491", "lastcron": "1623537832", "lastupdateResult": "[]", "lastupdatedat": "1623537681", "public_files": "files_sharing/public.php", "public_webdav": "dav/appinfo/v1/publicwebdav.php", "theming.variables": "32ef7dc01a3ffbcbbaf8fb9483f9bd03", "vendor": "nextcloud" }, "dashboard": { "enabled": "yes", "installed_version": "7.1.0", "types": "" }, "dav": { "enabled": "yes", "installed_version": "1.17.1", "types": "filesystem" }, "federatedfilesharing": { "enabled": "yes", "installed_version": "1.11.0", "types": "" }, "federation": { "enabled": "yes", "installed_version": "1.11.0", "types": "authentication" }, "files": { "enabled": "yes", "installed_version": "1.16.0", "types": "filesystem" }, "files_pdfviewer": { "enabled": "yes", "installed_version": "2.1.0", "types": "" }, "files_rightclick": { "enabled": "yes", "installed_version": "1.0.0", "types": "" }, "files_sharing": { "enabled": "yes", "installed_version": "1.13.1", "types": "filesystem" }, "files_trashbin": { "enabled": "yes", "installed_version": "1.11.0", "types": "filesystem,dav" }, "files_versions": { "enabled": "yes", "installed_version": "1.14.0", "types": "filesystem,dav" }, "files_videoplayer": { "enabled": "yes", "installed_version": "1.10.0", "types": "" }, "firstrunwizard": { "enabled": "yes", "installed_version": "2.10.0", "types": "logging" }, "logreader": { "enabled": "yes", "installed_version": "2.6.0", "types": "" }, "lookup_server_connector": { "enabled": "yes", "installed_version": "1.9.0", "types": "authentication" }, "nextcloud_announcements": { "enabled": "yes", "installed_version": "1.10.0", "pub_date": "Thu, 24 Oct 2019 00:00:00 +0200", "types": "logging" }, "notifications": { "enabled": "yes", "installed_version": "2.9.0", "types": "logging" }, "oauth2": { "enabled": "yes", "installed_version": "1.9.0", "types": "authentication" }, "password_policy": { "enabled": "yes", "installed_version": "1.11.0", "types": "authentication" }, "photos": { "enabled": "yes", "installed_version": "1.3.0", "types": "" }, "privacy": { "enabled": "yes", "installed_version": "1.5.0", "readableLocation": "us", "types": "" }, "provisioning_api": { "enabled": "yes", "installed_version": "1.11.0", "types": "prevent_group_restriction" }, "recommendations": { "enabled": "yes", "installed_version": "1.0.0", "types": "" }, "serverinfo": { "cached_count_filecache": "76211", "cached_count_storages": "3", "enabled": "yes", "installed_version": "1.11.0", "types": "" }, "settings": { "enabled": "yes", "installed_version": "1.3.0", "types": "" }, "sharebymail": { "enabled": "yes", "installed_version": "1.11.0", "types": "filesystem" }, "support": { "enabled": "yes", "installed_version": "1.4.0", "types": "session" }, "survey_client": { "enabled": "yes", "installed_version": "1.9.0", "types": "" }, "systemtags": { "enabled": "yes", "installed_version": "1.11.0", "types": "logging" }, "text": { "enabled": "yes", "installed_version": "3.2.0", "types": "dav" }, "theming": { "enabled": "yes", "installed_version": "1.12.0", "types": "logging" }, "twofactor_backupcodes": { "enabled": "yes", "installed_version": "1.10.0", "types": "" }, "twofactor_u2f": { "enabled": "yes", "installed_version": "6.1.0", "types": "" }, "twofactor_webauthn": { "enabled": "no", "installed_version": "0.2.10", "types": "" }, "updatenotification": { "enabled": "yes", "installed_version": "1.11.0", "types": "", "update_check_errors": "0" }, "user_status": { "enabled": "yes", "installed_version": "1.1.1", "types": "" }, "viewer": { "enabled": "yes", "installed_version": "1.5.0", "types": "" }, "weather_status": { "enabled": "yes", "installed_version": "1.1.0", "types": "" }, "workflowengine": { "enabled": "yes", "installed_version": "2.3.0", "types": "filesystem" } } }

Client configuration

Browser: Safari

Operating system: Mac OS X 11.4

Logs

Web server error log
Insert your webserver log here
Server log (data/nextcloud.log)

{"reqId":"PEjCnGCv7lS7XvRlu1Sf","level":3,"time":"2021-06-12T22:51:00+00:00","remoteAddr":"192.168.150.10","user":"robb","app":"index","method":"POST","url":"/nextcloud/index.php/apps/twofactor_u2f/settings/finishregister","message":{"Exception":"Exception","Message":"OCA\TwoFactorU2F\Controller\SettingsController::finishRegister(): Argument #1 ($registrationData) must be of type string, null given, called in /usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/Http/Dispatcher.php on line 218","Code":0,"Trace":[{"file":"/usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/App.php","line":157,"function":"dispatch","class":"OC\AppFramework\Http\Dispatcher","type":"->"},{"file":"/usr/local/www/apache24/data/nextcloud/lib/private/Route/Router.php","line":302,"function":"main","class":"OC\AppFramework\App","type":"::"},{"file":"/usr/local/www/apache24/data/nextcloud/lib/base.php","line":993,"function":"match","class":"OC\Route\Router","type":"->"},{"file":"/usr/local/www/apache24/data/nextcloud/index.php","line":37,"function":"handleRequest","class":"OC","type":"::"}],"File":"/usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","Line":159,"Previous":{"Exception":"TypeError","Message":"OCA\TwoFactorU2F\Controller\SettingsController::finishRegister(): Argument #1 ($registrationData) must be of type string, null given, called in /usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/Http/Dispatcher.php on line 218","Code":0,"Trace":[{"file":"/usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":218,"function":"finishRegister","class":"OCA\TwoFactorU2F\Controller\SettingsController","type":"->"},{"file":"/usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":127,"function":"executeController","class":"OC\AppFramework\Http\Dispatcher","type":"->"},{"file":"/usr/local/www/apache24/data/nextcloud/lib/private/AppFramework/App.php","line":157,"function":"dispatch","class":"OC\AppFramework\Http\Dispatcher","type":"->"},{"file":"/usr/local/www/apache24/data/nextcloud/lib/private/Route/Router.php","line":302,"function":"main","class":"OC\AppFramework\App","type":"::"},{"file":"/usr/local/www/apache24/data/nextcloud/lib/base.php","line":993,"function":"match","class":"OC\Route\Router","type":"->"},{"file":"/usr/local/www/apache24/data/nextcloud/index.php","line":37,"function":"handleRequest","class":"OC","type":"::"}],"File":"/usr/local/www/apache24/data/nextcloud/apps/twofactor_u2f/lib/Controller/SettingsController.php","Line":65},"CustomMessage":"--"},"userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.1.1 Safari/605.1.15","version":"21.0.2.1"}

Browser log
Insert your browser log here, this could for example include:

a) The javascript console log
b) The network log

Here's the Nextcloud log entry:

"Exception: OCA\TwoFactorU2F\Controller\SettingsController::finishRegister(): Argument #1 ($registrationData) must be of type string, null given"

robballan avatar Jun 12 '21 22:06 robballan

See https://github.com/nextcloud/twofactor_u2f/issues/690

ChristophWurst avatar Jun 14 '21 06:06 ChristophWurst

In my case (unsure whether exactly related), this happened when I tried to add the same U2F device several times. In infinitely hanged without an error message.

TheOneWithTheBraid avatar Aug 27 '21 20:08 TheOneWithTheBraid

I'm seeing the same issue, endless spinning and the error:

OCA\TwoFactorU2F\Controller\SettingsController::finishRegister():
Argument #1 ($registrationData) must be of type string, null given,
called in /var/www/html/lib/private/AppFramework/Http/Dispatcher.php
on line 217 in file /var/www/html/custom_apps/twofactor_u2f/lib/Controller/SettingsController.php line 65

And I already have overwriteprotocol: https set, so that's not it.

 > php occ config:list | jq .system.overwriteprotocol
"https"

jakubgs avatar Feb 22 '22 17:02 jakubgs

I can see the request to /index.php/apps/twofactor_u2f/settings/finishregister being made:

image

And the payload is there:

image

jakubgs avatar Feb 22 '22 17:02 jakubgs

We can see saveRegistrationData is called from the AddDeviceDialog: https://github.com/nextcloud/twofactor_u2f/blob/5fe47c09b070aa9d67e12c9fcc95c0e5cf601483/src/components/AddDeviceDialog.vue#L178-L191 Which created a data object with the name attribute set to what the user provides, which then is sent via: https://github.com/nextcloud/twofactor_u2f/blob/7edb7f7a6fbb5f9d67cbf9388deb34105b20f6fe/src/services/RegistrationService.js#L32-L37 To the /apps/twofactor_u2f/settings/finishregister endpoint. Which we can see happened above, as expected.

So the issue probably isn't on the frontend, meaning Vue/JS side.

jakubgs avatar Feb 22 '22 18:02 jakubgs

This is the full error btw: https://gist.github.com/jakubgs/951909e3253baf46cc54e5a9521b255d

jakubgs avatar Feb 22 '22 18:02 jakubgs

These three issues seem related:

  • https://github.com/nextcloud/server/issues/23063
  • https://github.com/nextcloud/server/issues/29371
  • https://github.com/nextcloud/server/issues/30549

They all include the must be of type string, null given error caused somewhere in the stack trace by lib/private/AppFramework/Http/Dispatcher.php, which seems to indicate the payload is lost somewhere along the way..

jakubgs avatar Feb 22 '22 18:02 jakubgs

I can't add a new WebAuthn device. Is this related or should i open a new issue?

Browser Log (Firefox):

starting webauthn registration AddDevice.vue:158
[DEBUG] settings: confirmed password 
Object { app: "settings", uid: "user" }
ConsoleLogger.js:29:16
XHRPOSThttps://cloud.example.com/settings/api/personal/webauthn/registration
[HTTP/2 500 Internal Server Error 141ms]

[ERROR] settings: Error persisting webauthn registration 
Object { app: "settings", uid: "user", error: Error }
ConsoleLogger.js:41:16
Error: Server-Fehler beim Versuch die WebAuthn-Geräte-Registrierung abzuschließen
    e AddDevice.vue:195
    u runtime.js:63
    _invoke runtime.js:294
    v runtime.js:119
    x vue-settings-personal-webauthn.js:223
    s vue-settings-personal-webauthn.js:223
    promise callback*x vue-settings-personal-webauthn.js:223
    a vue-settings-personal-webauthn.js:223
    saveRegistrationData vue-settings-personal-webauthn.js:223
    saveRegistrationData vue-settings-personal-webauthn.js:223
    saveRegistrationData vue-settings-personal-webauthn.js:223
    promise callback*submit AddDevice.vue:179
    VueJS 28
    start AddDevice.vue:116
    promise callback*start AddDevice.vue:116
    VueJS 2
AddDevice.vue:183

aikitori avatar Mar 11 '22 13:03 aikitori

I've added dome debugging prints to the code to check the values, and when the payload for POST request is:

image

The $arguments variable looks like this right before call to call_user_func_array():

[NULL, NULL, "yubikey"]

Where yubikey is the $name passed to finishRegister():

	public function finishRegister(string $registrationData, string $clientData, string $name = null): JSONResponse {
		return new JSONResponse($this->manager->finishRegistration($this->userSession->getUser(), $registrationData, $clientData, $name));
	}

So we're clearly missing $registrationData and $clientData.

jakubgs avatar Mar 24 '22 16:03 jakubgs

When I put a debug line here:

			$this->logger->info("WTF param: $param -> '$value' ($type)");

I can see that the arguments are all of type string but the first two are empty strings:

WTF param: registrationData -> '' (string)
WTF param: clientData -> '' (string)
WTF param: name -> 'yubikey' (string)

But then the first two empty strings somehow get turned into NULLs.

jakubgs avatar Mar 24 '22 16:03 jakubgs

Specifically, I printed contents of $arguments before and after this line: https://github.com/nextcloud/server/blob/v23.0.3/lib/private/AppFramework/Http/Dispatcher.php#L214

And it appears that the empty string in $value turns into NULL the moment this assignment in the loop takes place:

			$arguments[] = $value;

Which as far as I can tell should not be happening: https://user-images.githubusercontent.com/2212681/159962326-04aa86cd-79ba-4c5d-9864-c1f621f4dedd.png

But I lack the context to know if these should even be empty strings in the first place.

jakubgs avatar Mar 24 '22 16:03 jakubgs

@ChristophWurst sorry for pinging you directly but I'd appreciate some insight here.

What are the expected values for $registrationData and $clientData? I assume it's not NULL, but is empty string valid? My guess would be that no, but I lack the context to know what should be in those variables.

Are those variables supposed to be present in the JSON that is POSTed to the finishregister endpint? If so then the issue must be on the client side since those are not visible when looking up the request in browser dev console.

jakubgs avatar Mar 24 '22 16:03 jakubgs

Based on these lines it appears that the registrationData should contains something more: https://github.com/nextcloud/twofactor_u2f/blob/5fe47c09b070aa9d67e12c9fcc95c0e5cf601483/src/components/AddDeviceDialog.vue#L178-L180 Correct?

So that would mean the issue is somewhere in the frontend JS? Or maybe the issue is the browser not providing this data?

jakubgs avatar Mar 24 '22 16:03 jakubgs

It appears to me that if something went wrong on client side we should see this error here: https://github.com/nextcloud/twofactor_u2f/blob/5fe47c09b070aa9d67e12c9fcc95c0e5cf601483/src/components/AddDeviceDialog.vue#L110-L116

But instead what I get is:

Uncaught (in promise) Error: U2F device registration failed (error code unknown)
    at a.rejectRegistration (AddDeviceDialog.vue:157:1)
    at AddDeviceDialog.vue:135:1

Though I can see that there is a payload sent to the startregister endpoint:

image

jakubgs avatar Mar 24 '22 16:03 jakubgs

And the error appears to be handled by this case: https://github.com/nextcloud/twofactor_u2f/blob/5fe47c09b070aa9d67e12c9fcc95c0e5cf601483/src/components/AddDeviceDialog.vue#L153-L159 The errorCode being the unknown fallback doesn't help debug this.

jakubgs avatar Mar 24 '22 16:03 jakubgs

I think the key to this issue is this error:

Failed to execute 'postMessage' on 'DOMWindow': The target origin provided ('chrome-extension://kmendfapggjehodndflmmgagdbamhnfd') does not match the recipient window's origin ('null').
(anonymous) @ generated-google-u2f-api.js:534
load (async)
r.getIframePort_ @ generated-google-u2f-api.js:532
(anonymous) @ generated-google-u2f-api.js:206

Which is described here:

  • https://github.com/grantila/u2f-api/issues/13

But the thing is I already have overwriteprotocol: https set, as well as some other related settings:

  'overwrite.cli.url' => 'https://localhost',
  'overwritehost' => 'cloud.example.org',
  'overwriteprotocol' => 'https',
  'trusted_domains' => 
  array (
    0 => 'localhost',
    1 => 'cloud.example.org',
    2 => 'onlyoffice.example.org',
  ),
  'trusted_proxies' => 
  array (
    0 => '127.0.0.1',
    1 => '10.0.0.0/8',
    2 => '172.17.0.0/16',
  ),

But something is still missing. Maybe my trusted_proxies are incorrect.

jakubgs avatar Mar 25 '22 09:03 jakubgs

I'm starting to think the most sensible thing is to just disable U2F extension in favor of WebAuthN since U2F is deprecated.

Because I really can't get this to work no matter how I change my reverse proxy setup.

jakubgs avatar Mar 25 '22 11:03 jakubgs