Skip to content

Commit

Permalink
Merge #701: Add logs to Health Check API
Browse files Browse the repository at this point in the history
e0836bd feat: [#700] add logs to Health Check API (Jose Celano)

Pull request description:

  Add logs to Health Check API. Example:

  ```console
  2024-02-19T11:30:21.061293933+00:00 [HEALTH CHECK API][INFO] request; method=GET uri=/health_check request_id=78933bbf-c4cf-4897-b972-4c0fd252159a
  2024-02-19T11:30:21.070329733+00:00 [HEALTH CHECK API][INFO] response; latency=9 status=200 OK request_id=78933bbf-c4cf-4897-b972-4c0fd252159a
  ```

ACKs for top commit:
  josecelano:
    ACK e0836bd

Tree-SHA512: 62dc341c86b263aeb2a2613a371ee32167b85b57411438033ab121b47f68c12c668740c007163ddcecf8bb48e5e09ee7d00c598f2e24fccf97192f644f1ba4a4
  • Loading branch information
josecelano committed Feb 19, 2024
2 parents db71f2a + e0836bd commit d3344da
Show file tree
Hide file tree
Showing 4 changed files with 67 additions and 13 deletions.
6 changes: 3 additions & 3 deletions src/bootstrap/jobs/health_check_api.rs
Original file line number Diff line number Diff line change
Expand Up @@ -47,18 +47,18 @@ pub async fn start_job(config: &HealthCheckApi, register: ServiceRegistry) -> Jo

// Run the API server
let join_handle = tokio::spawn(async move {
info!(target: "Health Check API", "Starting on: {protocol}://{}", bind_addr);
info!(target: "HEALTH CHECK API", "Starting on: {protocol}://{}", bind_addr);

let handle = server::start(bind_addr, tx_start, rx_halt, register);

if let Ok(()) = handle.await {
info!(target: "Health Check API", "Stopped server running on: {protocol}://{}", bind_addr);
info!(target: "HEALTH CHECK API", "Stopped server running on: {protocol}://{}", bind_addr);
}
});

// Wait until the server sends the started message
match rx_start.await {
Ok(msg) => info!(target: "Health Check API", "Started on: {protocol}://{}", msg.address),
Ok(msg) => info!(target: "HEALTH CHECK API", "Started on: {protocol}://{}", msg.address),
Err(e) => panic!("the Health Check API server was dropped: {e}"),
}

Expand Down
8 changes: 4 additions & 4 deletions src/console/ci/e2e/logs_parser.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ use serde::{Deserialize, Serialize};

const UDP_TRACKER_PATTERN: &str = "[UDP Tracker][INFO] Starting on: udp://";
const HTTP_TRACKER_PATTERN: &str = "[HTTP Tracker][INFO] Starting on: ";
const HEALTH_CHECK_PATTERN: &str = "[Health Check API][INFO] Starting on: ";
const HEALTH_CHECK_PATTERN: &str = "[HEALTH CHECK API][INFO] Starting on: ";

#[derive(Serialize, Deserialize, Debug, Default)]
pub struct RunningServices {
Expand All @@ -27,8 +27,8 @@ impl RunningServices {
/// 2024-01-24T16:36:14.615716574+00:00 [torrust_tracker::bootstrap::jobs][INFO] TLS not enabled
/// 2024-01-24T16:36:14.615764904+00:00 [API][INFO] Starting on http://127.0.0.1:1212
/// 2024-01-24T16:36:14.615767264+00:00 [API][INFO] Started on http://127.0.0.1:1212
/// 2024-01-24T16:36:14.615777574+00:00 [Health Check API][INFO] Starting on: http://127.0.0.1:1313
/// 2024-01-24T16:36:14.615791124+00:00 [Health Check API][INFO] Started on: http://127.0.0.1:1313
/// 2024-01-24T16:36:14.615777574+00:00 [HEALTH CHECK API][INFO] Starting on: http://127.0.0.1:1313
/// 2024-01-24T16:36:14.615791124+00:00 [HEALTH CHECK API][INFO] Started on: http://127.0.0.1:1313
/// ```
///
/// It would extract these services:
Expand Down Expand Up @@ -88,7 +88,7 @@ mod tests {
let logs = "\
[UDP Tracker][INFO] Starting on: udp://0.0.0.0:8080\n\
[HTTP Tracker][INFO] Starting on: 0.0.0.0:9090\n\
[Health Check API][INFO] Starting on: 0.0.0.0:10010";
[HEALTH CHECK API][INFO] Starting on: 0.0.0.0:10010";
let running_services = RunningServices::parse_from_logs(logs);

assert_eq!(running_services.udp_trackers, vec!["127.0.0.1:8080"]);
Expand Down
58 changes: 56 additions & 2 deletions src/servers/health_check_api/server.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,14 +3,24 @@
//! This API is intended to be used by the container infrastructure to check if
//! the whole application is healthy.
use std::net::SocketAddr;
use std::time::Duration;

use axum::http::{HeaderName, HeaderValue};
use axum::response::Response;
use axum::routing::get;
use axum::{Json, Router};
use axum_server::Handle;
use futures::Future;
use hyper::Request;
use log::debug;
use serde_json::json;
use tokio::sync::oneshot::{Receiver, Sender};
use tower_http::compression::CompressionLayer;
use tower_http::propagate_header::PropagateHeaderLayer;
use tower_http::request_id::{MakeRequestId, RequestId, SetRequestIdLayer};
use tower_http::trace::{DefaultMakeSpan, TraceLayer};
use tracing::{Level, Span};
use uuid::Uuid;

use crate::bootstrap::jobs::Started;
use crate::servers::health_check_api::handlers::health_check_handler;
Expand All @@ -31,14 +41,48 @@ pub fn start(
let router = Router::new()
.route("/", get(|| async { Json(json!({})) }))
.route("/health_check", get(health_check_handler))
.with_state(register);
.with_state(register)
.layer(CompressionLayer::new())
.layer(SetRequestIdLayer::x_request_id(RequestIdGenerator))
.layer(PropagateHeaderLayer::new(HeaderName::from_static("x-request-id")))
.layer(
TraceLayer::new_for_http()
.make_span_with(DefaultMakeSpan::new().level(Level::INFO))
.on_request(|request: &Request<axum::body::Body>, _span: &Span| {
let method = request.method().to_string();
let uri = request.uri().to_string();
let request_id = request
.headers()
.get("x-request-id")
.map(|v| v.to_str().unwrap_or_default())
.unwrap_or_default();

tracing::span!(
target: "HEALTH CHECK API",
tracing::Level::INFO, "request", method = %method, uri = %uri, request_id = %request_id);
})
.on_response(|response: &Response, latency: Duration, _span: &Span| {
let status_code = response.status();
let request_id = response
.headers()
.get("x-request-id")
.map(|v| v.to_str().unwrap_or_default())
.unwrap_or_default();
let latency_ms = latency.as_millis();

tracing::span!(
target: "HEALTH CHECK API",
tracing::Level::INFO, "response", latency = %latency_ms, status = %status_code, request_id = %request_id);
}),
)
.layer(SetRequestIdLayer::x_request_id(RequestIdGenerator));

let socket = std::net::TcpListener::bind(bind_to).expect("Could not bind tcp_listener to address.");
let address = socket.local_addr().expect("Could not get local_addr from tcp_listener.");

let handle = Handle::new();

debug!(target: "Health Check API", "Starting service with graceful shutdown in a spawned task ...");
debug!(target: "HEALTH CHECK API", "Starting service with graceful shutdown in a spawned task ...");

tokio::task::spawn(graceful_shutdown(
handle.clone(),
Expand All @@ -55,3 +99,13 @@ pub fn start(

running
}

#[derive(Clone, Default)]
struct RequestIdGenerator;

impl MakeRequestId for RequestIdGenerator {
fn make_request_id<B>(&mut self, _request: &Request<B>) -> Option<RequestId> {
let id = HeaderValue::from_str(&Uuid::new_v4().to_string()).expect("UUID is a valid HTTP header value");
Some(RequestId::new(id))
}
}
8 changes: 4 additions & 4 deletions tests/servers/health_check_api/environment.rs
Original file line number Diff line number Diff line change
Expand Up @@ -51,21 +51,21 @@ impl Environment<Stopped> {

let register = self.registar.entries();

debug!(target: "Health Check API", "Spawning task to launch the service ...");
debug!(target: "HEALTH CHECK API", "Spawning task to launch the service ...");

let server = tokio::spawn(async move {
debug!(target: "Health Check API", "Starting the server in a spawned task ...");
debug!(target: "HEALTH CHECK API", "Starting the server in a spawned task ...");

server::start(self.state.bind_to, tx_start, rx_halt, register)
.await
.expect("it should start the health check service");

debug!(target: "Health Check API", "Server started. Sending the binding {} ...", self.state.bind_to);
debug!(target: "HEALTH CHECK API", "Server started. Sending the binding {} ...", self.state.bind_to);

self.state.bind_to
});

debug!(target: "Health Check API", "Waiting for spawning task to send the binding ...");
debug!(target: "HEALTH CHECK API", "Waiting for spawning task to send the binding ...");

let binding = rx_start.await.expect("it should send service binding").address;

Expand Down

0 comments on commit d3344da

Please sign in to comment.