chore: more logs

src/gpg.rs

@@ -65,14 +65,17 @@ save"#,
 
 #[cfg(target_family = "unix")]
 pub fn set_permissions(dir_path: &PathBuf) -> Result<(), WorkerError> {
+    debug!("Setting permissions for gpg temp home");
     use std::os::unix::prelude::PermissionsExt;
 
     let permissions = fs::Permissions::from_mode(0o700);
     fs::set_permissions(dir_path, permissions)?;
+    debug!("Permissions set");
     Ok(())
 }
 
 pub fn init_gpg() -> Result<(String, Child), WorkerError> {
+    debug!("Initiating new gpg session.");
     let mut temp_path = env::temp_dir();
     temp_path.push("yubikey-provision");
 
@@ -87,22 +90,29 @@ pub fn init_gpg() -> Result<(String, Child), WorkerError> {
             .status()?;
 
         if !res.success() {
+            debug!("Failed to Kill current gpg agent via gpgconf --kill gpg-agent");
             return Err(WorkerError::Gpg);
         }
+        debug!("User gpg agent session killed");
     }
 
+    debug!("gpg temporary home: {}", &temp_path_str);
+
     // init temp
     if Path::new(&temp_path).is_dir() {
         fs::remove_dir_all(&temp_path)?;
     }
     fs::create_dir_all(&temp_path)?;
+    debug!("gpg home created");
 
     // init local temp gpg home
 
     let gpg_agent = Command::new("gpg-agent")
         .args(["--homedir", temp_path_str, "--daemon"])
         .spawn()?;
 
+    debug!("gpg agent alive");
+
     Ok((temp_path_str.to_string(), gpg_agent))
 }
 
@@ -112,15 +122,21 @@ pub fn gen_key(
     full_name: &str,
     email: &str,
 ) -> Result<(), WorkerError> {
+    let command_args = [
+        "--homedir",
+        gpg_home,
+        "--batch",
+        "--command-fd",
+        "0",
+        "--full-gen-key",
+    ];
+    debug!(
+        "Generating key via {} with args: {}",
+        gpg_command,
+        command_args.join(" ")
+    );
     let mut child = Command::new(gpg_command)
-        .args([
-            "--homedir",
-            gpg_home,
-            "--batch",
-            "--command-fd",
-            "0",
-            "--full-gen-key",
-        ])
+        .args(command_args)
         .stdin(Stdio::piped())
         .spawn()?;
     let mut stdin = child.stdin.take().ok_or(WorkerError::Gpg)?;
@@ -133,20 +149,26 @@ pub fn gen_key(
 }
 
 pub fn key_to_card(gpg_command: &str, gpg_home: &str, email: &str) -> Result<(), WorkerError> {
+    let command_args = [
+        "--homedir",
+        gpg_home,
+        "--command-fd=0",
+        "--status-fd=1",
+        "--passphrase-fd=0",
+        "--batch",
+        "--yes",
+        "--pinentry-mode=loopback",
+        "--edit-key",
+        "--no-tty",
+        email,
+    ];
+    debug!(
+        "Transferring keys to card via {} with args: {}",
+        gpg_command,
+        command_args.join(" ")
+    );
     let mut child = Command::new(gpg_command)
-        .args([
-            "--homedir",
-            gpg_home,
-            "--command-fd=0",
-            "--status-fd=1",
-            "--passphrase-fd=0",
-            "--batch",
-            "--yes",
-            "--pinentry-mode=loopback",
-            "--edit-key",
-            "--no-tty",
-            email,
-        ])
+        .args(command_args)
         .env("LANG", "en")
         .stdin(Stdio::piped())
         .spawn()?;
@@ -251,7 +273,7 @@ pub async fn provision_key(
     gpg_command: &str,
 ) -> Result<ProvisioningInfo, WorkerError> {
     let full_name = format!("{} {}", job.first_name, job.last_name);
-    info!("Provisioning start for: {}", &job.email);
+    debug!("Provisioning start for: {}", &job.email);
     let check_duration = Duration::from_secs(config.smartcard_retry_interval);
     let mut check_interval = interval(check_duration);
     let mut fail_counter = 0;
@@ -277,23 +299,27 @@ pub async fn provision_key(
     debug!("Key found");
     let (gpg_home, mut gpg_process) = init_gpg()?;
     debug!("Temporary GPG session crated");
+    debug!("Resetting card to factory");
     factory_reset_key()?;
     debug!("OpenPGP Key app restored to factory.");
+    debug!("Generating gpg key...");
     gen_key(gpg_command, &gpg_home, &full_name, &job.email)?;
     debug!("OpenPGP key for {} created", &job.email);
     let fingerprint = get_fingerprint()?;
     let pgp = export_public(gpg_command, &gpg_home, &job.email)?;
     let ssh = export_ssh(gpg_command, &gpg_home, &job.email)?;
     key_to_card(gpg_command, &gpg_home, &job.email)?;
-    debug!("Subkeys saved in yubikey");
+    debug!("Subkeys saved in card");
     // cleanup after provisioning
+    debug!("Clearing gpg process and home");
     if gpg_process.kill().is_err() {
         return Err(WorkerError::GPGSessionEnd);
     }
+    debug!("gpg session killed");
     if fs::remove_dir_all(&gpg_home).is_err() {
         return Err(WorkerError::GPGSessionEnd);
     }
-    debug!("Temporary GPG session cleared and closed");
+    debug!("Temp home cleared");
     info!("Yubikey openpgp provisioning completed.");
     Ok(ProvisioningInfo {
         pgp,

src/main.rs

@@ -38,16 +38,20 @@ async fn main() -> Result<(), WorkerError> {
     let config = get_config().expect("Failed to create config");
     //init logging
     logging::init(&config.log_level, &None).expect("Failed to init logging, check logging config");
+    debug!("config loaded");
     // Check required binaries
     let gpg_command = get_gpg_command();
+    debug!("gpg command: {}", &gpg_command);
     if which("ykman").is_err() {
         panic!("'ykman' not found!");
     }
+    debug!("ykman present");
     // Make grpc client
     let mut url = config.url.clone();
     if config.grpc_ca.is_some() {
         url = url.replace("http://", "https://");
     }
+    debug!("URL: {}", &url);
     let token: MetadataValue<_> = config
         .token
         .clone()
@@ -75,7 +79,9 @@ async fn main() -> Result<(), WorkerError> {
     });
     //register worker
     match client.register_worker(worker_request).await {
-        Ok(_) => {}
+        Ok(_) => {
+            debug!("Worker registered !");
+        }
         Err(e) => {
             if e.code() != Code::AlreadyExists {
                 panic!("Failed to register worker, {}", e);