feat: add startup time to logging output

This change adds a startup time counter to the output when starting up
a server. The main purpose of this is to verify whether the impact of
changes actually speeds up the loading of the server.

Author: mgattozzi

Cargo.toml

@@ -182,6 +182,7 @@ inherits = "release"
 codegen-units = 16
 lto = false
 incremental = true
+debug = 1
 
 # This profile extends the `quick-release` profile with debuginfo turned on in order to
 # produce more human friendly symbols for profiling tools

influxdb3/src/commands/serve.rs

@@ -40,6 +40,7 @@ use std::{collections::HashMap, path::Path, str::FromStr};
 use std::{num::NonZeroUsize, sync::Arc};
 use thiserror::Error;
 use tokio::net::TcpListener;
+use tokio::time::Instant;
 use tokio_util::sync::CancellationToken;
 use trace_exporters::TracingConfig;
 use trace_http::ctx::TraceHeaderParser;
@@ -359,6 +360,7 @@ fn ensure_directory_exists(p: &Path) {
 }
 
 pub async fn command(config: Config) -> Result<()> {
+    let startup_timer = Instant::now();
     let num_cpus = num_cpus::get();
     let build_malloc_conf = build_malloc_conf();
     info!(
@@ -542,7 +544,7 @@ pub async fn command(config: Config) -> Result<()> {
     } else {
         builder.build()
     };
-    serve(server, frontend_shutdown).await?;
+    serve(server, frontend_shutdown, startup_timer).await?;
 
     Ok(())
 }

influxdb3_server/src/lib.rs

@@ -35,12 +35,14 @@ use iox_query::QueryDatabase;
 use iox_query_params::StatementParams;
 use iox_time::TimeProvider;
 use observability_deps::tracing::error;
+use observability_deps::tracing::info;
 use service::hybrid;
 use std::convert::Infallible;
 use std::fmt::Debug;
 use std::sync::Arc;
 use thiserror::Error;
 use tokio::net::TcpListener;
+use tokio::time::Instant;
 use tokio_util::sync::CancellationToken;
 use tower::Layer;
 use trace::ctx::SpanContext;
@@ -174,7 +176,11 @@ impl<T> Server<T> {
     }
 }
 
-pub async fn serve<T>(server: Server<T>, shutdown: CancellationToken) -> Result<()>
+pub async fn serve<T>(
+    server: Server<T>,
+    shutdown: CancellationToken,
+    startup_timer: Instant,
+) -> Result<()>
 where
     T: TimeProvider,
 {
@@ -206,6 +212,9 @@ where
     let hybrid_make_service = hybrid(rest_service, grpc_service);
 
     let addr = AddrIncoming::from_listener(server.listener)?;
+    let timer_end = Instant::now();
+    let startup_time = timer_end.duration_since(startup_timer);
+    info!("Server Startup Time: {}ms", startup_time.as_millis());
     hyper::server::Builder::new(addr, Http::new())
         .tcp_nodelay(true)
         .serve(hybrid_make_service)