Skip to content

Add more logging #645

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
t-aleksander merged 5 commits into from
Jun 18, 2024
Merged

Add more logging #645

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
2564eba
add more logs 1
t-aleksander Jun 14, 2024
7ce48e7
add more logs 2
t-aleksander Jun 17, 2024
b70d172
add missing semicolon
t-aleksander Jun 17, 2024
4c0cc4c
Apply suggestions from code review
t-aleksander Jun 17, 2024
4a17fee
Merge branch 'dev' into add-more-logs
t-aleksander Jun 18, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 17 additions & 6 deletions src/grpc/desktop_client_mfa.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -73,7 +73,7 @@ impl ClientMfaServer {
&mut self,
request: ClientMfaStartRequest,
) -> Result<ClientMfaStartResponse, Status> {
info!("Starting desktop client login: {request:?}");
debug!("Starting desktop client login: {request:?}");
// fetch location
let Ok(Some(location)) =
WireguardNetwork::find_by_id(&self.pool, request.location_id).await
Expand Down Expand Up @@ -117,16 +117,17 @@ impl ClientMfaServer {
.any(|allowed_group| user_info.groups.contains(allowed_group))
{
error!(
"User {} not allowed to connect to location {location}",
user.username
"User {} not allowed to connect to location {location} because he doesn't belong to any of the allowed groups.
User groups: {:?}, allowed groups: {:?}",
user.username, user_info.groups, groups
);
return Err(Status::unauthenticated("unauthorized"));
}
}

// check if selected method is enabled
let method = MfaMethod::try_from(request.method).map_err(|err| {
error!("Invalid MFA method selected: {err}");
error!("Invalid MFA method selected ({}): {err}", request.method);
Status::invalid_argument("invalid MFA method selected")
})?;
match method {
Expand Down Expand Up @@ -159,6 +160,11 @@ impl ClientMfaServer {
// generate auth token
let token = Self::generate_token(&request.pubkey)?;

info!(
"Desktop client MFA login started for {} at location {}",
user.username, location.name
);

// store login session
self.sessions.insert(
request.pubkey,
Expand All @@ -177,7 +183,7 @@ impl ClientMfaServer {
&mut self,
request: ClientMfaFinishRequest,
) -> Result<ClientMfaFinishResponse, Status> {
info!("Finishing desktop client login: {request:?}");
debug!("Finishing desktop client login: {request:?}");
// get pubkey from token
let pubkey = self.parse_token(&request.token)?;

Expand Down Expand Up @@ -261,12 +267,17 @@ impl ClientMfaServer {
Status::internal("unexpected error")
})?;

info!(
"Desktop client login finished for {} at location {}",
user.username, location.name
);

// remove login session from map
self.sessions.remove(&pubkey);

// commit transaction
transaction.commit().await.map_err(|_| {
error!("Failed to commit transaction");
error!("Failed to commit transaction while finishing desktop client login.");
Status::internal("unexpected error")
})?;

Expand Down
26 changes: 19 additions & 7 deletions src/grpc/enrollment.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -99,6 +99,7 @@ impl EnrollmentServer {

let enrollment = Token::find_by_id(&self.pool, token).await?;
if enrollment.is_session_valid(server_config().enrollment_session_timeout.as_secs()) {
info!("Enrollment session validated");
Ok(enrollment)
} else {
error!("Enrollment session expired");
Expand All @@ -117,11 +118,13 @@ impl EnrollmentServer {
&self,
request: EnrollmentStartRequest,
) -> Result<EnrollmentStartResponse, Status> {
debug!("Starting enrollment session, request: {request:?}");
// fetch enrollment token
let mut enrollment = Token::find_by_id(&self.pool, &request.token).await?;

if let Some(token_type) = &enrollment.token_type {
if token_type != ENROLLMENT_TOKEN_TYPE {
error!("Invalid token type used while trying to start enrollment: {token_type}");
return Err(Status::permission_denied("invalid token"));
}

Expand All @@ -140,13 +143,14 @@ impl EnrollmentServer {
})?;

// validate token & start session
info!("Starting enrollment session for user {}", user.username);
debug!("Starting enrollment session for user {}", user.username);
let session_deadline = enrollment
.start_session(
&mut transaction,
server_config().enrollment_session_timeout.as_secs(),
)
.await?;
info!("Enrollment session started for user {}", user.username);

let settings = Settings::get_settings(&mut *transaction)
.await
Expand Down Expand Up @@ -216,7 +220,6 @@ impl EnrollmentServer {

// fetch related users
let mut user = enrollment.fetch_user(&self.pool).await?;
info!("Activating user account for {}", user.username);
if user.has_password() {
error!("User {} already activated", user.username);
return Err(Status::invalid_argument("user already activated"));
Expand Down Expand Up @@ -285,6 +288,8 @@ impl EnrollmentServer {
Status::internal("unexpected error")
})?;

info!("User {} activated", user.username);

Ok(())
}

Expand All @@ -300,8 +305,6 @@ impl EnrollmentServer {
let user = enrollment.fetch_user(&self.pool).await?;

// add device
info!("Adding new device for user {}", user.username);

if !user.is_active {
error!("Can't create device for a disabled user {}", user.username);
return Err(Status::invalid_argument(
Expand Down Expand Up @@ -382,6 +385,12 @@ impl EnrollmentServer {
device_info.as_deref(),
)
.map_err(|_| Status::internal("Failed to render new device added template"))?;

info!(
"Device {} assigned to user {} and added to all networks.",
device.name, user.username
);

let response = DeviceConfigResponse {
device: Some(device.into()),
configs: configs.into_iter().map(Into::into).collect(),
Expand All @@ -397,6 +406,7 @@ impl EnrollmentServer {
&self,
request: ExistingDevice,
) -> Result<DeviceConfigResponse, Status> {
debug!("Getting network info for device: {:?}", request.pubkey);
let enrollment = self.validate_session(request.token.as_deref()).await?;

// get enrollment user
Expand All @@ -410,7 +420,7 @@ impl EnrollmentServer {
let device = Device::find_by_pubkey(&self.pool, &request.pubkey)
.await
.map_err(|_| {
error!("Failed to get device");
error!("Failed to get device by its pubkey: {}", request.pubkey);
Status::internal("unexpected error")
})?;

Expand All @@ -420,7 +430,7 @@ impl EnrollmentServer {
})?;

let networks = WireguardNetwork::all(&self.pool).await.map_err(|err| {
error!("Invalid failed to get networks {err}");
error!("Failed to fetch all networks: {err}");
Status::internal(format!("unexpected error: {err}"))
})?;

Expand All @@ -434,7 +444,7 @@ impl EnrollmentServer {
WireguardNetworkDevice::find(&self.pool, device_id, network_id)
.await
.map_err(|err| {
error!("Invalid failed to get networks {err}");
error!("Failed to fetch wireguard network device for device {} and network {}: {err}", device_id, network_id);
Status::internal(format!("unexpected error: {err}"))
})?;
if let Some(wireguard_network_device) = wireguard_network_device {
Expand All @@ -460,6 +470,8 @@ impl EnrollmentServer {
}
}

info!("Device {} configs fetched", device.name);

let response = DeviceConfigResponse {
device: Some(device.into()),
configs,
Expand Down
80 changes: 59 additions & 21 deletions src/grpc/gateway.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -237,7 +237,9 @@ impl GatewayUpdatesHandler {
{
Some(network_info) => {
if self.network.mfa_enabled && !network_info.is_authorized {
debug!("Created WireGuard device is not authorized to connect to MFA enabled location");
debug!("Created WireGuard device {} is not authorized to connect to MFA enabled location {}",
device.device.name, self.network.name
);
continue;
};
self.send_peer_update(
Expand Down Expand Up @@ -265,7 +267,9 @@ impl GatewayUpdatesHandler {
{
Some(network_info) => {
if self.network.mfa_enabled && !network_info.is_authorized {
debug!("Modified WireGuard device is not authorized to connect to MFA enabled location");
debug!("Modified WireGuard device {} is not authorized to connect to MFA enabled location {}",
device.device.name, self.network.name
);
continue;
};
self.send_peer_update(
Expand Down Expand Up @@ -329,11 +333,17 @@ impl GatewayUpdatesHandler {
.await
{
let msg = format!(
"Failed to send network update, network {network}, update type: {update_type}, error: {err}",
"Failed to send network update, network {network}, update type: {update_type} ({}), error: {err}",
if update_type == 0 {
"CREATE"
} else {
"MODIFY"
},
);
error!(msg);
return Err(Status::new(Code::Internal, msg));
}
debug!("Network update sent for network {network}");
Ok(())
}

Expand All @@ -358,12 +368,13 @@ impl GatewayUpdatesHandler {
.await
{
let msg = format!(
"Failed to send network update, network {}, update type: 2, error: {err}",
"Failed to send network update, network {}, update type: 2 (DELETE), error: {err}",
self.network,
);
error!(msg);
return Err(Status::new(Code::Internal, msg));
}
debug!("Network delete command sent for network {}", self.network);
Ok(())
}

Expand All @@ -379,12 +390,18 @@ impl GatewayUpdatesHandler {
.await
{
let msg = format!(
"Failed to send peer update for network {}, update type: {update_type}, error: {err}",
self.network
"Failed to send peer update for network {}, update type: {update_type} ({}), error: {err}",
self.network,
if update_type == 0 {
"CREATE"
} else {
"MODIFY"
},
);
error!(msg);
return Err(Status::new(Code::Internal, msg));
}
debug!("Peer update sent for network {}", self.network);
Ok(())
}

Expand All @@ -405,12 +422,13 @@ impl GatewayUpdatesHandler {
.await
{
let msg = format!(
"Failed to send peer update for network {}, peer {peer_pubkey}, update type: 2, error: {err}",
"Failed to send peer update for network {}, peer {peer_pubkey}, update type: 2 (DELETE), error: {err}",
self.network,
);
error!(msg);
return Err(Status::new(Code::Internal, msg));
}
debug!("Peer delete command sent for network {}", self.network);
Ok(())
}
}
Expand Down Expand Up @@ -479,18 +497,25 @@ impl gateway_service_server::GatewayService for GatewayServer {
let network_id = Self::get_network_id(request.metadata())?;
let mut stream = request.into_inner();
while let Some(stats_update) = stream.message().await? {
debug!("Received stats message: {stats_update:?}");
let Some(stats_update::Payload::PeerStats(peer_stats)) = stats_update.payload else {
debug!("Received empty stats message");
debug!("Received stats message is empty, skipping.");
continue;
};
let public_key = peer_stats.public_key.clone();
let mut stats = WireguardPeerStats::from_peer_stats(peer_stats, network_id);
// Get device by public key and fill in stats.device_id
// FIXME: keep an in-memory device map to avoid repeated DB requests
stats.device_id = match Device::find_by_pubkey(&self.pool, &public_key).await {
Ok(Some(device)) => device
.id
.ok_or_else(|| Status::new(Code::Internal, "Device has no ID"))?,
Ok(Some(device)) => device.id.ok_or_else(|| {
Status::new(
Code::Internal,
format!(
"Device {} (public key: {public_key}) has no ID",
device.name
),
)
})?,
Ok(None) => {
error!("Device with public key {public_key} not found");
return Err(Status::new(
Expand Down Expand Up @@ -533,9 +558,14 @@ impl gateway_service_server::GatewayService for GatewayServer {
error!("Network {network_id} not found");
Status::new(Code::Internal, format!("Failed to retrieve network: {e}"))
})?
.ok_or_else(|| Status::new(Code::Internal, "Network not found"))?;
.ok_or_else(|| {
Status::new(
Code::Internal,
format!("Network with id {} not found", network_id),
)
})?;

info!("Sending configuration to gateway client, network {network}.");
debug!("Sending configuration to gateway client, network {network}.");

// store connected gateway in memory
{
Expand All @@ -551,17 +581,19 @@ impl gateway_service_server::GatewayService for GatewayServer {

network.connected_at = Some(Utc::now().naive_utc());
if let Err(err) = network.save(&self.pool).await {
error!("Failed to update network {network_id} status: {err}");
error!("Failed to save updated network {network_id} in the database, status: {err}");
}

let peers = network.get_peers(&self.pool).await.map_err(|error| {
error!("Failed to fetch peers for network {network_id}: {error}",);
error!("Failed to fetch peers from the database for network {network_id}: {error}",);
Status::new(
Code::Internal,
format!("Failed to retrieve peers for network: {network_id}"),
format!("Failed to retrieve peers from the database for network: {network_id}"),
)
})?;

info!("Configuration sent to gateway client, network {network}.");

Ok(Response::new(gen_config(&network, peers)))
}

Expand All @@ -572,14 +604,17 @@ impl gateway_service_server::GatewayService for GatewayServer {
let Some(network) = WireguardNetwork::find_by_id(&self.pool, gateway_network_id)
.await
.map_err(|_| {
error!("Failed to fetch network {gateway_network_id}");
error!("Failed to fetch network {gateway_network_id} from the database");
Status::new(
Code::Internal,
format!("Failed to retrieve network {gateway_network_id}"),
format!("Failed to retrieve network {gateway_network_id} from the database"),
)
})?
else {
return Err(Status::new(Code::Internal, "Network not found"));
return Err(Status::new(
Code::Internal,
format!("Network with id {gateway_network_id} not found"),
));
};

info!("New client connected to updates stream: {hostname}, network {network}",);
Expand All @@ -590,8 +625,11 @@ impl gateway_service_server::GatewayService for GatewayServer {
state
.connect_gateway(gateway_network_id, &hostname)
.map_err(|err| {
error!("Failed to connect gateway: {err}");
Status::new(Code::Internal, "Failed to connect gateway")
error!("Failed to connect gateway on network {gateway_network_id}: {err}");
Status::new(
Code::Internal,
"Failed to connect gateway on network {gateway_network_id}",
)
})?;

// clone here before moving into a closure
Expand Down
Loading