Add a minimal tracing-subscriber configuration

While debugging what turned into Azure#103, I added some minimal log
configuration to figure out what was happening. Note that this only logs
to stderr and is only configurable via the `AZURE_INIT_LOG` environment
variable. The most minimal usage is like this:

AZURE_INIT_LOG=info azure-init

Which emits anything at info level or high. Refer to the tracing
documentation[0] for more complex examples.

This doesn't try to integrate with OpenTelemetry or pipe logs to KVP;
those are being wired up in Azure#83.

[0] https://docs.rs/tracing-subscriber/0.3.18/tracing_subscriber/filter/struct.EnvFilter.html#directives

Author: jeremycline

Cargo.toml

@@ -12,6 +12,8 @@ description = "A reference implementation for provisioning Linux VMs on Azure."
 exitcode = "1.1.2"
 anyhow = "1.0.81"
 tokio = { version = "1", features = ["full"] }
+tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+tracing = "0.1.40"
 
 [dependencies.libazureinit]
 path = "libazureinit"

libazureinit/src/media.rs

@@ -13,6 +13,7 @@ use serde::Deserialize;
 use serde_xml_rs::from_str;
 
 use tracing;
+use tracing::instrument;
 
 use crate::error::Error;
 
@@ -76,6 +77,7 @@ pub const PATH_MOUNT_POINT: &str = "/run/azure-init/media/";
 const CDROM_VALID_FS: &[&str] = &["iso9660", "udf"];
 
 // Get a mounted device with any filesystem for CDROM
+#[instrument]
 pub fn get_mount_device() -> Result<Vec<String>, Error> {
     let mut list_devices: Vec<String> = Vec::new();
 
@@ -90,9 +92,12 @@ pub fn get_mount_device() -> Result<Vec<String>, Error> {
 }
 
 // Some zero-sized structs that just provide states for our state machine
+#[derive(Debug)]
 pub struct Mounted;
+#[derive(Debug)]
 pub struct Unmounted;
 
+#[derive(Debug)]
 pub struct Media<State = Unmounted> {
     device_path: PathBuf,
     mount_path: PathBuf,
@@ -108,6 +113,7 @@ impl Media<Unmounted> {
         }
     }
 
+    #[instrument]
     pub fn mount(self) -> Result<Media<Mounted>, Error> {
         create_dir_all(&self.mount_path)?;
 
@@ -140,6 +146,7 @@ impl Media<Unmounted> {
 }
 
 impl Media<Mounted> {
+    #[instrument]
     pub fn unmount(self) -> Result<(), Error> {
         let umount_status =
             Command::new("umount").arg(self.mount_path).status()?;
@@ -162,6 +169,7 @@ impl Media<Mounted> {
         }
     }
 
+    #[instrument]
     pub fn read_ovf_env_to_string(&self) -> Result<String, Error> {
         let mut file_path = self.mount_path.clone();
         file_path.push("ovf-env.xml");
@@ -174,6 +182,7 @@ impl Media<Mounted> {
     }
 }
 
+#[instrument(skip_all)]
 pub fn parse_ovf_env(ovf_body: &str) -> Result<Environment, Error> {
     let environment: Environment = from_str(ovf_body)?;
 
@@ -190,6 +199,7 @@ pub fn parse_ovf_env(ovf_body: &str) -> Result<Environment, Error> {
 }
 
 // Mount the given device, get OVF environment data, return it.
+#[instrument(skip_all)]
 pub fn mount_parse_ovf_env(dev: String) -> Result<Environment, Error> {
     let mount_media =
         Media::new(PathBuf::from(dev), PathBuf::from(PATH_MOUNT_POINT));

src/main.rs

@@ -14,9 +14,14 @@ use libazureinit::{
     reqwest::{header, Client},
     HostnameProvisioner, PasswordProvisioner, Provision, UserProvisioner,
 };
+use tracing::instrument;
+use tracing_subscriber::fmt::format::FmtSpan;
+use tracing_subscriber::layer::SubscriberExt;
+use tracing_subscriber::EnvFilter;
 
 const VERSION: &str = env!("CARGO_PKG_VERSION");
 
+#[instrument]
 fn get_environment() -> Result<Environment, anyhow::Error> {
     let ovf_devices = media::get_mount_device()?;
     let mut environment: Option<Environment> = None;
@@ -33,6 +38,7 @@ fn get_environment() -> Result<Environment, anyhow::Error> {
         .ok_or_else(|| anyhow::anyhow!("Unable to get list of block devices"))
 }
 
+#[instrument(skip_all)]
 fn get_username(
     instance_metadata: Option<&InstanceMetadata>,
     environment: Option<&Environment>,
@@ -60,6 +66,17 @@ fn get_username(
 
 #[tokio::main]
 async fn main() -> ExitCode {
+    let stderr = tracing_subscriber::fmt::layer()
+        .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
+        .with_writer(std::io::stderr);
+    let registry = tracing_subscriber::registry()
+        .with(stderr)
+        .with(EnvFilter::from_env("AZURE_INIT_LOG"));
+    tracing::subscriber::set_global_default(registry).expect(
+        "Only an application should set the global default; \
+        a library is mis-using the tracing API.",
+    );
+
     match provision().await {
         Ok(_) => ExitCode::SUCCESS,
         Err(e) => {
@@ -78,6 +95,7 @@ async fn main() -> ExitCode {
     }
 }
 
+#[instrument]
 async fn provision() -> Result<(), anyhow::Error> {
     let mut default_headers = header::HeaderMap::new();
     let user_agent = header::HeaderValue::from_str(