diff --git a/services/identity/src/client_service.rs b/services/identity/src/client_service.rs --- a/services/identity/src/client_service.rs +++ b/services/identity/src/client_service.rs @@ -306,7 +306,11 @@ let platform_metadata = get_platform_metadata(&request)?; let message = request.into_inner(); - debug!("Attempting to log in user: {:?}", &message.username); + info!( + "Attempting to v1 log in password user: {:?}", + redact_sensitive_data(&message.username) + ); + let user_id_and_password_file = self .client .get_user_info_and_password_file_from_username(&message.username) @@ -352,6 +356,10 @@ .await? .is_signed_device_list_flow() { + warn!( + user_id = redact_sensitive_data(&user_id), + "New flow user called LogInPasswordUser RPC" + ); return Err(tonic::Status::failed_precondition( tonic_status_messages::USE_NEW_FLOW, )); @@ -497,6 +505,10 @@ self.verify_and_remove_nonce(&parsed_message.nonce).await?; let wallet_address = eip55(&parsed_message.address); + info!( + "Attempting to v1 log in wallet user: {:?}", + redact_sensitive_data(&wallet_address) + ); let flattened_device_key_upload = construct_flattened_device_key_upload(&message)?; @@ -514,6 +526,10 @@ .await? .is_signed_device_list_flow() { + warn!( + user_id = redact_sensitive_data(&user_id), + "New flow user called LogInWalletUser RPC" + ); return Err(tonic::Status::failed_precondition( tonic_status_messages::USE_NEW_FLOW, )); @@ -712,7 +728,7 @@ tonic_status_messages::USE_V1_FLOW, )); } - debug!( + info!( "Attempting to restore user: {}", redact_sensitive_data(&message.user_id) ); @@ -723,6 +739,10 @@ .await? .is_v1_flow() { + warn!( + user_id = redact_sensitive_data(&message.user_id), + "Legacy flow user called RestoreUser RPC." + ); return Err(tonic::Status::failed_precondition( tonic_status_messages::USE_V1_FLOW, )); @@ -812,6 +832,10 @@ (Some(backup_item), revoke) } else { + error!( + errorType = error_types::GRPC_SERVICES_LOG, + "RestoreUser request without UserKeys present. This shouldn't happen." + ); (None, Defer::empty()) }; @@ -842,6 +866,11 @@ let platform_metadata = get_platform_metadata(&request)?; let message = request.into_inner(); + info!( + user_id = redact_sensitive_data(&message.user_id), + "Attempting to authenticate a new secondary device.", + ); + let challenge_response = SignedNonce::try_from(&message)?; let flattened_device_key_upload = construct_flattened_device_key_upload(&message)?; diff --git a/services/identity/src/comm_service/backup.rs b/services/identity/src/comm_service/backup.rs --- a/services/identity/src/comm_service/backup.rs +++ b/services/identity/src/comm_service/backup.rs @@ -2,16 +2,24 @@ use hex::ToHex; use reqwest::multipart::Part; use sha2::{Digest, Sha256}; +use tracing::info; use crate::{ config::CONFIG, constants::{error_types, tonic_status_messages}, + log::redact_sensitive_data, }; +#[tracing::instrument(skip_all)] pub async fn delete_backup_user_data( user_id: &str, auth_service: &AuthService, ) -> Result<(), crate::error::Error> { + info!( + user_id = redact_sensitive_data(user_id), + "Attempting to remove user backups." + ); + let path = format!("/user_data/{}", user_id); let url = CONFIG .backup_service_url @@ -48,9 +56,15 @@ Ok(()) } +#[tracing::instrument(skip_all)] pub async fn user_has_backup( user_identifier: &str, ) -> Result { + info!( + user_identifier = redact_sensitive_data(user_identifier), + "Attempting to check if user has backup." + ); + let path = format!("/backups/latest/{user_identifier}/backup_info"); let url = CONFIG .backup_service_url @@ -86,6 +100,7 @@ } } +#[tracing::instrument(skip_all)] pub async fn prepare_user_keys( auth_service: &AuthService, user_id: &str, @@ -93,6 +108,11 @@ user_keys: Vec, siwe_backup_msg: Option, ) -> Result { + info!( + user_id = redact_sensitive_data(user_id), + "Attempting to prepare UserKeys backup." + ); + let path = "/utils/prepare_user_keys"; let url = CONFIG .backup_service_url diff --git a/services/identity/src/grpc_services/authenticated.rs b/services/identity/src/grpc_services/authenticated.rs --- a/services/identity/src/grpc_services/authenticated.rs +++ b/services/identity/src/grpc_services/authenticated.rs @@ -20,7 +20,7 @@ use comm_lib::blob::client::BlobServiceClient; use comm_opaque2::grpc::protocol_error_to_grpc_status; use tonic::{Request, Response, Status}; -use tracing::{debug, error, trace}; +use tracing::{debug, error, info, trace, warn}; use super::protos::auth::{ identity_client_service_server::IdentityClientService, @@ -382,6 +382,11 @@ .await? .is_signed_device_list_flow(); + info!( + user_id = redact_sensitive_data(&user_id), + is_new_flow_user, "V1 logout user request." + ); + // don't update device list for new flow users if is_new_flow_user { self @@ -463,14 +468,20 @@ .await? .is_v1_flow() { + warn!( + user_id = redact_sensitive_data(&user_id), + device_id = redact_sensitive_data(&device_id), + "Legacy flow device called LogOutPrimaryDevice RPC" + ); return Err(tonic::Status::failed_precondition( tonic_status_messages::USE_V1_FLOW, )); } - debug!( + info!( "Primary device logout request for user_id={}, device_id={}", - user_id, device_id + redact_sensitive_data(&user_id), + redact_sensitive_data(&device_id) ); self .verify_device_on_device_list( @@ -547,14 +558,20 @@ .await? .is_v1_flow() { + warn!( + user_id = redact_sensitive_data(&user_id), + device_id = redact_sensitive_data(&device_id), + "Legacy flow device called LogOutSecondaryDevice RPC" + ); return Err(tonic::Status::failed_precondition( tonic_status_messages::USE_V1_FLOW, )); } - debug!( + info!( "Secondary device logout request for user_id={}, device_id={}", - user_id, device_id + redact_sensitive_data(&user_id), + redact_sensitive_data(&device_id) ); self .verify_device_on_device_list( @@ -935,6 +952,10 @@ request: tonic::Request, ) -> Result, tonic::Status> { let (user_id, device_id) = get_user_and_device_id(&request)?; + info!( + "Device list update request for user {}.", + redact_sensitive_data(&user_id), + ); let is_new_flow_user = self .db_client @@ -956,6 +977,11 @@ .await?; Some(crate::device_list::validation::update_device_list_rpc_validator) } else { + info!( + user_id = redact_sensitive_data(&user_id), + "Attempting to migrate user to signed device list.", + ); + // new flow migration let Some(current_device_list) = self.db_client.get_current_device_list(&user_id).await? @@ -1230,6 +1256,11 @@ &self, ) -> Result<(), tonic::Status> { let user_id = AUTHORITATIVE_KEYSERVER_OWNER_USER_ID; + info!( + user_id = redact_sensitive_data(user_id), + "Performing authoritative keyserver owner logout." + ); + let devices = self.db_client.get_current_devices(user_id).await?; let keyserver_device_id = devices .iter()