feat: Add logging and setup functions for improved debugging in tests

Author: jmjoy

Cargo.lock

@@ -23,6 +23,7 @@ license = { workspace = true }
 cargo_metadata = "0.20.0"
 fastcgi-client = "0.9.0"
 libc = "0.2.169"
+log = { version = "0.4.27", features = ["kv"] }
 phper-macros = { workspace = true }
 tempfile = "3.17.1"
 tokio = { version = "1.43.0", features = ["net"] }

phper-test/Cargo.toml

@@ -11,6 +11,7 @@
 //! Cargo build utilities for building and analyzing Rust libraries.
 
 use cargo_metadata::Message;
+use log::debug;
 use std::{
     io::{self, BufReader},
     path::{Path, PathBuf},
@@ -60,6 +61,7 @@ impl CargoBuilder {
         let reader = BufReader::new(stdout);
         let mut messages = Vec::new();
         for message in cargo_metadata::Message::parse_stream(reader) {
+            debug!(message:?; "cargo build message");
             let message = message?;
             messages.push(message);
         }

phper-test/src/cargo.rs

@@ -11,6 +11,7 @@
 //! Test tools for php cli program.
 
 use crate::context::Context;
+use log::debug;
 use std::{
     panic::{UnwindSafe, catch_unwind, resume_unwind},
     path::Path,
@@ -72,31 +73,32 @@ pub fn test_php_scripts_with_condition(
         let output = cmd.output().unwrap();
         let path = script.as_ref().to_str().unwrap();
 
-        let mut stdout = String::from_utf8(output.stdout.clone()).unwrap();
+        let mut stdout = String::from_utf8_lossy(&output.stdout).to_string();
         if stdout.is_empty() {
             stdout.push_str("<empty>");
         }
 
-        let mut stderr = String::from_utf8(output.stderr.clone()).unwrap();
+        let mut stderr = String::from_utf8_lossy(&output.stderr).to_string();
         if stderr.is_empty() {
             stderr.push_str("<empty>");
-        }
+        };
 
-        eprintln!(
-            "===== command =====\n{} {}\n===== stdout ======\n{}\n===== stderr ======\n{}",
-            &context.php_bin,
-            cmd.get_args().join(" "),
-            stdout,
-            stderr,
-        );
-        #[cfg(target_os = "linux")]
-        if output.status.code().is_none() {
-            use std::os::unix::process::ExitStatusExt;
-            eprintln!(
-                "===== signal ======\nExitStatusExt is None, the signal is: {:?}",
-                output.status.signal()
-            );
-        }
+        debug!(command:% = cmd.get_command().join(" ".as_ref()).to_string_lossy(),
+               status:? = output.status.code(),
+               stdout = &*stdout,
+               stderr:%,
+               signal:? = {
+                   #[cfg(unix)]
+                   {
+                       use std::os::unix::process::ExitStatusExt as _;
+                       output.status.signal()
+                   }
+                   #[cfg(not(unix))]
+                   {
+                       None
+                   }
+               };
+               "execute php test command");
 
         if !condition(output) {
             panic!("test php file `{}` failed", path);

phper-test/src/cli.rs

@@ -11,6 +11,7 @@
 use crate::utils;
 use std::{
     env,
+    ffi::OsStr,
     fs::read_to_string,
     io::Write,
     ops::{Deref, DerefMut},
@@ -125,6 +126,14 @@ pub struct ContextCommand {
 }
 
 impl ContextCommand {
+    pub fn get_command(&self) -> Vec<&OsStr> {
+        let program = self.cmd.get_program();
+        let args = self.cmd.get_args();
+        let mut command = vec![program];
+        command.extend(args);
+        command
+    }
+
     pub fn get_args(&self) -> &[String] {
         &self.args
     }

phper-test/src/context.rs

@@ -12,7 +12,9 @@
 use crate::{context::Context, utils::spawn_command};
 use fastcgi_client::{Client, Params, Request};
 use libc::{SIGTERM, atexit, kill, pid_t};
+use log::debug;
 use std::{
+    borrow::Cow,
     fs,
     path::Path,
     process::Child,
@@ -82,13 +84,11 @@ impl FpmHandle {
             "-y",
             &fpm_conf_file.path().display().to_string(),
         ];
-        eprintln!("===== setup php-fpm =====");
-        eprintln!("{}", argv.join(" "));
+        debug!(argv:% = argv.join(" "); "setup php-fpm");
 
         let child = spawn_command(&argv, Some(Duration::from_secs(3)));
         let log = fs::read_to_string("/tmp/.php-fpm.log").unwrap();
-        eprintln!("===== php-fpm log =====");
-        eprintln!("{}", log);
+        debug!(log:%; "php-fpm log");
         // fs::remove_file("/tmp/.php-fpm.log").unwrap();
 
         let handle = FpmHandle {
@@ -191,24 +191,16 @@ impl FpmHandle {
 
         let no_error = stderr.is_empty();
 
-        let f = |out: Vec<u8>| {
-            String::from_utf8(out)
-                .map(|out| {
-                    if out.is_empty() {
-                        "<empty>".to_owned()
-                    } else {
-                        out
-                    }
-                })
-                .unwrap_or_else(|_| "<not utf8 string>".to_owned())
+        let f = |out| {
+            let out = String::from_utf8_lossy(out);
+            if out.is_empty() {
+                Cow::Borrowed("<empty>")
+            } else {
+                out
+            }
         };
 
-        eprintln!("===== request =====");
-        eprintln!("{}", request_uri);
-        eprintln!("===== stdout ======");
-        eprintln!("{}", f(stdout));
-        eprintln!("===== stderr ======");
-        eprintln!("{}", f(stderr));
+        debug!(uri:% = request_uri, stdout:% = f(&stdout), stderr:% = f(&stderr); "test php request");
 
         assert!(no_error, "request not success: {}", request_uri);
     }

phper-test/src/fpm.rs

@@ -25,6 +25,8 @@ indexmap = "2.7.1"
 phper = { workspace = true }
 
 [dev-dependencies]
+env_logger = { version = "0.11.8", features = ["kv"] }
+log = { version = "0.4.27", features = ["kv"] }
 phper-test = { workspace = true }
 tokio = { version = "1.43.0", features = ["full"] }