Starting enrollment on already activated user

[teon]

Instance has newest core (0.11.0) and proxy. I want to Add a new device for a user that already has 5 devices and did multiple instance Add previously.

• I login as the user
• In the profile click "Add device" and copy token

In to 0.5.0 client I enter enroll url + token and Enrollment process starts! and not adding the device. Expected just to name the device and add instance.

I even try to complete the process and get logs:

• Client:

2024-08-06][14:09:12][INFO][defguard_client::commands] Instances retrieved(4)
[2024-08-06][14:10:28][ERROR][k0@tauri://localhost/assets/index-4cc3f797.js:68:7119] Failed to activate user during the enrollment. Error details: {"error":"user already activated"} Error status code: 400

• Core:

defguard | 2024-08-06T14:10:28.743785Z  INFO defguard::grpc: Received message from proxy
defguard | 2024-08-06T14:10:28.744279Z  INFO defguard::grpc::enrollment: Enrollment session validated
defguard | 2024-08-06T14:10:28.745211Z  INFO defguard::db::models::device: Adding device iMac to all existing networks
defguard | 2024-08-06T14:10:28.745593Z  INFO defguard::db::models::wireguard: Assigning IP in network [ID 1] TEST for [ID 19] iMac
defguard | 2024-08-06T14:10:28.746776Z  INFO defguard::db::models::device: Created IP: 10.12.12.5 for device: iMac
defguard | 2024-08-06T14:10:28.747294Z  INFO defguard::db::models::wireguard: Assigning IP in network [ID 2] office for [ID 19] iMac
defguard | 2024-08-06T14:10:28.747921Z  INFO defguard::db::models::device: Created IP: 10.11.1.4 for device: iMac
defguard | 2024-08-06T14:10:28.753718Z  INFO defguard::handlers::mail: Sent new device notification to [email protected]
defguard | 2024-08-06T14:10:28.753727Z  INFO defguard::grpc::enrollment: Device iMac assigned to user teon and added to all networks.
defguard | 2024-08-06T14:10:28.782709Z  INFO defguard::grpc: Received message from proxy
defguard | 2024-08-06T14:10:28.783174Z  INFO defguard::grpc::enrollment: Enrollment session validated
defguard | 2024-08-06T14:10:28.783489Z ERROR defguard::grpc::enrollment: User teon already activated
defguard | 2024-08-06T14:10:28.783501Z ERROR defguard::grpc: activate user error status: InvalidArgument, message: "user already activated", details: [], metadata: MetadataMap { headers: {} }

• Proxy:

proxy_1  | 2024-08-06T14:10:28.770956Z INFO defguard_proxy::handlers::enrollment: 10.11.0.10 POST /api/v1/enrollment/activate_user Activating user - phone number Some("123123") || Tracing data:  http_request: 
proxy_1  | 2024-08-06T14:10:28.782981Z ERROR defguard_proxy::error: 10.1.0.110 POST /api/v1/enrollment/activate_user Bad request: user already activated || Tracing data:  http_request: 

Seems to be Core error, it's wired - in logs it states **user teon starts enrolment for teon :D ** and then sends email for desktop configuration (not enrollment):

defguard | 2024-08-06T14:29:17.710843Z DEBUG http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::handlers::user: User teon starting enrollment for user teon
defguard | 2024-08-06T14:29:17.711161Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: User teon starting desktop configuration for user teon, notification enabled: true
defguard | 2024-08-06T14:29:17.711171Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Removing unused enrollment tokens for user teon
defguard | 2024-08-06T14:29:17.711174Z DEBUG http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Deleting unused enrollment tokens for user 1
defguard | 2024-08-06T14:29:17.711783Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Deleted 0 unused enrollment tokens for user 1
defguard | 2024-08-06T14:29:17.712217Z DEBUG http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Sending desktop configuration start mail for user teon to [email protected]
defguard | 2024-08-06T14:29:17.712222Z DEBUG http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Preparing welcome message context for enrollment token 0nukVc0fsdf3F34N3P1eyH8aqwEuUpW
defguard | 2024-08-06T14:29:17.712224Z DEBUG http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Fetching user for enrollment
defguard | 2024-08-06T14:29:17.712348Z DEBUG http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Fetching admin for enrollment
defguard | 2024-08-06T14:29:17.712469Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Fetched admin id 1 for enrollment
defguard | 2024-08-06T14:29:17.714071Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::db::models::enrollment: Sent desktop configuration start mail for user teon to xxx@xxx..
defguard | 2024-08-06T14:29:17.716952Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: defguard::handlers::user: User teon started enrollment for user teon
defguard | 2024-08-06T14:29:17.716980Z  INFO http_request{method=POST path=/api/v1/user/teon/start_desktop}: tower_http::trace::on_response: finished processing request latency=7 ms status=201

Aditionally we need to:

• [x] Fix all the logs to show username and not ID;s
• [x] Make like: Fetched admin id 1 for enrollment - DEBUG
• [x] Add logs that inform that a user XXXX added DESTKOP activation or Started enrollment

[t-aleksander]

This doesn't happen every time (at least in my experience): I've added multiple devices on already activated users with the latest released version and never encountered this issue, so there may be some additional circumstances that cause this bug

[teon]

@cpprian merge to dev and change version to 1.0.0

[t-aleksander]

@teon please verify this issue when you update your proxy version as discussed

[teon]

It was proxy 0.4...