Security key option available for user, but always fail with a 500

[Vaarlion]

Describe the bug
When testing the MFA option, i tried to register my Yubikey, i get a prompt and touch the key, but then get a none-descriptive "Error has occurred".
In the core log, i can see the following.

Webauthn registration error: The user verified bit is not set, and required by policy

A quick google search show that this is a generic error with the library your are using, and doesn't look to me something actionable on our side.

Your documentation currently doesn't talk about Security key in the MFA section : https://docs.defguard.net/admin-and-features/features-and-configuration/wireguard/multi-factor-authentication-mfa-2fa

Note that this happened before and after adding another type of MFA

To Reproduce
Steps to reproduce the behavior:

1. Install the latest version of core and proxy
2. Create a user
3. Go through enrollment
4. Connect with that user to the core
5. Edit the user profile and try to add a Security key

Expected behavior
The Security key is added OR the option is not present

Version information

• Defguard Core version: v1.1.0
• Your browser and version [e.g. chrome 99, safari]: Firefox 132.0.1

Screenshots
If applicable, add screenshots to help explain your problem.

Additional context
Add any other context about the problem here.

[teon]

@Vaarlion could you change your core log level to debug (DEFGUARD_LOG_LEVEL=debug for example in docker env) and do the registration of the key again and paste the logs?
Thank you!

[Vaarlion]

Here is the log in debug when trying to add a security key

nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.852586Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: tower_http::trace::on_request: started processing request
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.853436Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: sqlx::query: summary="SELECT id, user_id, state …" db.statement="\n\nSELECT\n  id,\n  user_id,\n  state \"state: SessionState\",\n  created,\n  expires,\n  webauthn_challenge,\n  web3_challenge,\n  ip_address,\n  device_info\nFROM\n  session\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=269.723µs elapsed_secs=0.000269723
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.854081Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: sqlx::query: summary="SELECT id, \"username\",\"password_hash\",\"last_name\",\"first_name\",\"email\",\"phone\",\"mfa_enabled\",\"is_active\",\"openid_sub\",\"totp_enabled\",\"email_mfa_enabled\",\"totp_secret\",\"email_mfa_secret\",\"mfa_method\" \"mfa_method: …" db.statement="\n\nSELECT\n  id,\n  \"username\",\n  \"password_hash\",\n  \"last_name\",\n  \"first_name\",\n  \"email\",\n  \"phone\",\n  \"mfa_enabled\",\n  \"is_active\",\n  \"openid_sub\",\n  \"totp_enabled\",\n  \"email_mfa_enabled\",\n  \"totp_secret\",\n  \"email_mfa_secret\",\n  \"mfa_method\" \"mfa_method: _\",\n  \"recovery_codes\" \"recovery_codes: _\"\nFROM\n  \"user\"\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=202.225µs elapsed_secs=0.000202225
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.854667Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: sqlx::query: summary="SELECT id, name FROM …" db.statement="\n\nSELECT\n  id,\n  name\nFROM\n  \"group\"\n  JOIN group_user ON \"group\".id = group_user.group_id\nWHERE\n  group_user.user_id = $1\n" rows_affected=0 rows_returned=0 elapsed=363.411µs elapsed_secs=0.000363411
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.854844Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers::auth: Finishing WebAuthn registration for user user01
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.854969Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers::auth: Passkey registration request origin: https://defguard-exp.domain.com/
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.854976Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers::auth: Allowed origins: ["https://defguard-exp.domain.com/"]
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.855302Z ERROR http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers: Webauthn registration error: The user verified bit is not set, and required by policy
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.855352Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: tower_http::trace::on_response: finished processing request latency=2 ms status=500
nov. 26 17:36:15 SERVER-01 defguard[9430]: 2024-11-26T16:36:15.855384Z ERROR http_request{method=POST path=/api/v1/auth/webauthn/finish}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=2 ms

[teon]

@Vaarlion does the domain actually exist and is Defguard reachable under this domain? (Meaning you actually enter in the browser: defguard-exp.domain.com)?

If you are registering a key and the domain which is in the config is not the same you enter in the browser - the registration will not work.

[teon]

The domain must be set in: DEFGUARD_URL and DEFGUARD_WEBAUTHN_RP_ID

[Vaarlion]

does the domain actually exist and is Defguard reachable under this domain

yes, the log have been anonymized but the domain, is reachable using a valid public https cert.

The domain must be set in: DEFGUARD_URL and DEFGUARD_WEBAUTHN_RP_ID

DEFGUARD_URL is set to the correct domain
DEFGUARD_WEBAUTHN_RP_ID is unset, but the config template say : # Optional. Generated based on DEFGUARD_URL if not provided.

I've added it to my domain without https:// and restarted, but sadly i forgot my token (and coffee badge 😱 ) at home today ... can't test it.

[teon]

@Vaarlion ok thank you for your help an logs. we're going to take this to our ,workshop' and straighten this out! Have a good day!

[Vaarlion]

Just FYI, adding DEFGUARD_WEBAUTHN_RP_ID did not fix this issue.
I could test again this morning

nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.430882Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/init}: tower_http::trace::on_request: started processing request
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.431852Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/init}: sqlx::query: summary="SELECT id, user_id, state …" db.statement="\n\nSELECT\n  id,\n  user_id,\n  state \"state: SessionState\",\n  created,\n  expires,\n  webauthn_challenge,\n  web3_challenge,\n  ip_address,\n  device_info\nFROM\n  session\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=262.213µs elapsed_secs=0.000262213
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.432360Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/init}: sqlx::query: summary="SELECT id, \"username\",\"password_hash\",\"last_name\",\"first_name\",\"email\",\"phone\",\"mfa_enabled\",\"is_active\",\"openid_sub\",\"totp_enabled\",\"email_mfa_enabled\",\"totp_secret\",\"email_mfa_secret\",\"mfa_method\" \"mfa_method: …" db.statement="\n\nSELECT\n  id,\n  \"username\",\n  \"password_hash\",\n  \"last_name\",\n  \"first_name\",\n  \"email\",\n  \"phone\",\n  \"mfa_enabled\",\n  \"is_active\",\n  \"openid_sub\",\n  \"totp_enabled\",\n  \"email_mfa_enabled\",\n  \"totp_secret\",\n  \"email_mfa_secret\",\n  \"mfa_method\" \"mfa_method: _\",\n  \"recovery_codes\" \"recovery_codes: _\"\nFROM\n  \"user\"\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=211.215µs elapsed_secs=0.000211215
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.433028Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/init}: sqlx::query: summary="SELECT id, name FROM …" db.statement="\n\nSELECT\n  id,\n  name\nFROM\n  \"group\"\n  JOIN group_user ON \"group\".id = group_user.group_id\nWHERE\n  group_user.user_id = $1\n" rows_affected=0 rows_returned=0 elapsed=240.971µs elapsed_secs=0.000240971
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.433148Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/init}: defguard::handlers::auth: Initializing WebAuthn registration for user user1
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.433697Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/init}: sqlx::query: summary="SELECT passkey FROM webauthn …" db.statement="\n\nSELECT\n  passkey\nFROM\n  webauthn\nWHERE\n  user_id = $1\n" rows_affected=0 rows_returned=0 elapsed=370.592µs elapsed_secs=0.000370592
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.436169Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/init}: sqlx::query: summary="UPDATE session SET webauthn_challenge …" db.statement="\n\nUPDATE\n  session\nSET\n  webauthn_challenge = $1\nWHERE\n  id = $2\n" rows_affected=1 rows_returned=0 elapsed=2.152175ms elapsed_secs=0.002152175
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.436194Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/init}: defguard::handlers::auth: Initialized WebAuthn registration for user user1
nov. 28 11:15:44 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:44.436275Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/init}: tower_http::trace::on_response: finished processing request latency=5 ms status=200
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.187671Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: tower_http::trace::on_request: started processing request
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.188549Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: sqlx::query: summary="SELECT id, user_id, state …" db.statement="\n\nSELECT\n  id,\n  user_id,\n  state \"state: SessionState\",\n  created,\n  expires,\n  webauthn_challenge,\n  web3_challenge,\n  ip_address,\n  device_info\nFROM\n  session\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=285.456µs elapsed_secs=0.000285456
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.188933Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: sqlx::query: summary="SELECT id, \"username\",\"password_hash\",\"last_name\",\"first_name\",\"email\",\"phone\",\"mfa_enabled\",\"is_active\",\"openid_sub\",\"totp_enabled\",\"email_mfa_enabled\",\"totp_secret\",\"email_mfa_secret\",\"mfa_method\" \"mfa_method: …" db.statement="\n\nSELECT\n  id,\n  \"username\",\n  \"password_hash\",\n  \"last_name\",\n  \"first_name\",\n  \"email\",\n  \"phone\",\n  \"mfa_enabled\",\n  \"is_active\",\n  \"openid_sub\",\n  \"totp_enabled\",\n  \"email_mfa_enabled\",\n  \"totp_secret\",\n  \"email_mfa_secret\",\n  \"mfa_method\" \"mfa_method: _\",\n  \"recovery_codes\" \"recovery_codes: _\"\nFROM\n  \"user\"\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=166.252µs elapsed_secs=0.000166252
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.189650Z DEBUG http_request{method=POST path=/api/v1/auth/webauthn/finish}: sqlx::query: summary="SELECT id, name FROM …" db.statement="\n\nSELECT\n  id,\n  name\nFROM\n  \"group\"\n  JOIN group_user ON \"group\".id = group_user.group_id\nWHERE\n  group_user.user_id = $1\n" rows_affected=0 rows_returned=0 elapsed=279.666µs elapsed_secs=0.000279666
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.189866Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers::auth: Finishing WebAuthn registration for user user1
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.189995Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers::auth: Passkey registration request origin: https://defguard-exp.domain.com/
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.190003Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers::auth: Allowed origins: ["https://defguard-exp.domain.com/"]
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.190093Z ERROR http_request{method=POST path=/api/v1/auth/webauthn/finish}: defguard::handlers: Webauthn registration error: The user verified bit is not set, and required by policy
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.190115Z  INFO http_request{method=POST path=/api/v1/auth/webauthn/finish}: tower_http::trace::on_response: finished processing request latency=2 ms status=500
nov. 28 11:15:47 atexo-defguard-exp-infra-01 defguard[25870]: 2024-11-28T10:15:47.190121Z ERROR http_request{method=POST path=/api/v1/auth/webauthn/finish}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=2 ms