From 17d81db02d28383062ffc2d0511681b908a68f3f Mon Sep 17 00:00:00 2001 From: xxchan Date: Mon, 24 Jun 2024 12:19:41 +0800 Subject: [PATCH] add logs for system commands (#216) --- CHANGELOG.md | 4 ++ Cargo.lock | 131 +++++++++++++++++-------------------- Cargo.toml | 2 +- sqllogictest/src/runner.rs | 64 ++++++++++++------ 4 files changed, 109 insertions(+), 92 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7298d1a..d117f72 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## Unreleased +## [0.20.6] - 2024-06-21 + +* runner: add logs for `system` command (with target `sqllogictest::system_command`) for ease of debugging. + ## [0.20.5] - 2024-06-20 * fix(runner): when running in parallel, the runner will correctly inherit configuration like `sort_mode` and `labels` from the main runner. diff --git a/Cargo.lock b/Cargo.lock index df2b6eb..e9dc9e5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -121,7 +121,7 @@ checksum = "c6fa2087f2753a7da8cc1c0dbfcf89579dd57458e36769de5ac750b4671737ca" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -132,9 +132,9 @@ checksum = "0c4b4d0bd25bd0b74681c0ad21497610ce1b7c91b1022cd21c80c6fbdd9476b0" [[package]] name = "backtrace" -version = "0.3.72" +version = "0.3.73" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "17c6a35df3749d2e8bb1b7b21a976d82b15548788d2735b9d82f329268f71a11" +checksum = "5cc23269a4f8976d0a4d2e7109211a419fe30e8d88d677cd60b6bc79c5732e0a" dependencies = [ "addr2line", "cc", @@ -204,7 +204,7 @@ dependencies = [ "proc-macro-crate", "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", "syn_derive", ] @@ -250,9 +250,9 @@ checksum = "514de17de45fdb8dc022b1a7975556c53c86f9f0aa5f534b98977b171857c2c9" [[package]] name = "cc" -version = "1.0.98" +version = "1.0.99" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "41c270e7540d725e65ac7f1b212ac8ce349719624d7bcff99f8e2e488e8cf03f" +checksum = "96c51067fd44124faa7f870b4b1c969379ad32b2ba805aa959430ceaa384f695" [[package]] name = "cfg-if" @@ -282,9 +282,9 @@ dependencies = [ [[package]] name = "clap" -version = "4.5.4" +version = "4.5.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "90bc066a67923782aa8515dbaea16946c5bcc5addbd668bb80af688e53e548a0" +checksum = "5db83dced34638ad474f39f250d7fea9598bdd239eaced1bdf45d597da0f433f" dependencies = [ "clap_builder", "clap_derive", @@ -292,9 +292,9 @@ dependencies = [ [[package]] name = "clap_builder" -version = "4.5.2" +version = "4.5.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ae129e2e766ae0ec03484e609954119f123cc1fe650337e155d03b022f24f7b4" +checksum = "f7e204572485eb3fbf28f871612191521df159bc3e15a9f5064c66dba3a8c05f" dependencies = [ "anstream", "anstyle", @@ -304,21 +304,21 @@ dependencies = [ [[package]] name = "clap_derive" -version = "4.5.4" +version = "4.5.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "528131438037fd55894f62d6e9f068b8f45ac57ffa77517819645d10aed04f64" +checksum = "c780290ccf4fb26629baa7a1081e68ced113f1d3ec302fa5948f1c381ebf06c6" dependencies = [ "heck 0.5.0", "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] name = "clap_lex" -version = "0.7.0" +version = "0.7.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "98cc8fbded0c607b7ba9dd60cd98df59af97e84d24e49c8557331cfc26d301ce" +checksum = "4b82cf0babdbd58558212896d1a4272303a57bdb245c2bf1147185fb45640e70" [[package]] name = "colorchoice" @@ -390,7 +390,7 @@ dependencies = [ "enum-ordinalize", "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -422,7 +422,7 @@ checksum = "0d28318a75d4aead5c4db25382e8ef717932d0346600cacae6357eb5941bc5ff" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -443,12 +443,9 @@ dependencies = [ [[package]] name = "escape8259" -version = "0.5.2" +version = "0.5.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ba4f4911e3666fcd7826997b4745c8224295a6f3072f1418c3067b97a67557ee" -dependencies = [ - "rustversion", -] +checksum = "5692dd7b5a1978a5aeb0ce83b7655c58ca8efdcb79d21036ea249da95afec2c6" [[package]] name = "fallible-iterator" @@ -539,7 +536,7 @@ checksum = "87750cf4b7a4c0625b1529e4c543c2182106e4dedc60a2a6455e00d212c489ac" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -783,15 +780,15 @@ dependencies = [ [[package]] name = "memchr" -version = "2.7.2" +version = "2.7.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "6c8640c5d730cb13ebd907d8d04b52f55ac9a2eec55b440c8892f40d56c76c1d" +checksum = "78ca9ab1a0babb1e7d5695e3530886289c18cf2f87ec19a575a0abdce112e3a3" [[package]] name = "miniz_oxide" -version = "0.7.3" +version = "0.7.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "87dfd01fe195c66b572b37921ad8803d010623c0aca821bea2302239d155cdae" +checksum = "b8a240ddb74feaf34a79a7add65a741f3167852fba007066dcac1ca548d89c08" dependencies = [ "adler", ] @@ -847,9 +844,9 @@ dependencies = [ [[package]] name = "object" -version = "0.35.0" +version = "0.36.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b8ec7ab813848ba4522158d5517a6093db1ded27575b070f4177b8d12b41db5e" +checksum = "576dfe1fc8f9df304abb159d767a29d0476f7750fbf8aa7ad07816004a207434" dependencies = [ "memchr", ] @@ -890,7 +887,7 @@ checksum = "1e401f977ab385c9e4e3ab30627d6f26d00e2c73eef317493c4ec6d468726cf8" dependencies = [ "cfg-if", "libc", - "redox_syscall 0.5.1", + "redox_syscall 0.5.2", "smallvec", "windows-targets 0.52.5", ] @@ -951,7 +948,7 @@ dependencies = [ "heck 0.4.1", "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -1035,9 +1032,9 @@ dependencies = [ [[package]] name = "proc-macro2" -version = "1.0.85" +version = "1.0.86" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "22244ce15aa966053a896d1accb3a6e68469b97c7f33f284b99f0d576879fc23" +checksum = "5e719e8df665df0d1c8fbfd238015744736151d4445ec0836b8e628aae103b77" dependencies = [ "unicode-ident", ] @@ -1148,23 +1145,23 @@ dependencies = [ [[package]] name = "redox_syscall" -version = "0.5.1" +version = "0.5.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "469052894dcb553421e483e4209ee581a45100d31b4018de03e5a7ad86374a7e" +checksum = "c82cf8cff14456045f55ec4241383baeff27af886adb72ffb2162f99911de0fd" dependencies = [ "bitflags 2.5.0", ] [[package]] name = "regex" -version = "1.10.4" +version = "1.10.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c117dbdfde9c8308975b6a18d71f3f385c89461f7b3fb054288ecf2a2058ba4c" +checksum = "b91213439dad192326a0d7c6ee3955910425f441d7038e0d6933b0aec5c4517f" dependencies = [ "aho-corasick", "memchr", - "regex-automata 0.4.6", - "regex-syntax 0.8.3", + "regex-automata 0.4.7", + "regex-syntax 0.8.4", ] [[package]] @@ -1178,13 +1175,13 @@ dependencies = [ [[package]] name = "regex-automata" -version = "0.4.6" +version = "0.4.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "86b83b8b9847f9bf95ef68afb0b8e6cdb80f498442f5179a29fad448fcc1eaea" +checksum = "38caf58cc5ef2fed281f89292ef23f6365465ed9a41b7a7754eb4e26496c92df" dependencies = [ "aho-corasick", "memchr", - "regex-syntax 0.8.3", + "regex-syntax 0.8.4", ] [[package]] @@ -1195,9 +1192,9 @@ checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" [[package]] name = "regex-syntax" -version = "0.8.3" +version = "0.8.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "adad44e29e4c806119491a7f06f03de4d1af22c3a680dd47f1e6e179439d1f56" +checksum = "7a66a03ae7c801facd77a29370b4faec201768915ac14a721ba36f20bc9c209b" [[package]] name = "rend" @@ -1273,12 +1270,6 @@ dependencies = [ "windows-sys 0.52.0", ] -[[package]] -name = "rustversion" -version = "1.0.17" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "955d28af4278de8121b7ebeb796b6a45735dc01436d898801014aced2773a3d6" - [[package]] name = "rusty-fork" version = "0.3.0" @@ -1326,7 +1317,7 @@ checksum = "500cbc0ebeb6f46627f50f3f5811ccf6bf00643be300b4c3eabc0ef55dc5b5ba" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -1414,7 +1405,7 @@ dependencies = [ [[package]] name = "sqllogictest" -version = "0.20.5" +version = "0.20.6" dependencies = [ "async-trait", "educe", @@ -1437,7 +1428,7 @@ dependencies = [ [[package]] name = "sqllogictest-bin" -version = "0.20.5" +version = "0.20.6" dependencies = [ "anyhow", "async-trait", @@ -1459,7 +1450,7 @@ dependencies = [ [[package]] name = "sqllogictest-engines" -version = "0.20.5" +version = "0.20.6" dependencies = [ "async-trait", "bytes", @@ -1506,9 +1497,9 @@ checksum = "7da8b5736845d9f2fcb837ea5d9e2628564b3b043a70948a3f0b778838c5fb4f" [[package]] name = "subst" -version = "0.3.0" +version = "0.3.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ca1318e5d6716d6541696727c88d9b8dfc8cfe6afd6908e186546fd4af7f5b98" +checksum = "914a3487c294386d731fd33a8116b3ae4a8f95c0976b1550cc6b59b3db6c1e26" dependencies = [ "memchr", "unicode-width", @@ -1516,9 +1507,9 @@ dependencies = [ [[package]] name = "subtle" -version = "2.5.0" +version = "2.6.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "81cdd64d312baedb58e21336b31bc043b77e01cc99033ce76ef539f78e965ebc" +checksum = "0d0208408ba0c3df17ed26eb06992cb1a1268d41b2c0e12e65203fbe3972cee5" [[package]] name = "syn" @@ -1533,9 +1524,9 @@ dependencies = [ [[package]] name = "syn" -version = "2.0.66" +version = "2.0.67" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c42f3f41a2de00b01c0aaad383c5a45241efc8b2d1eda5661812fda5f3cdcff5" +checksum = "ff8655ed1d86f3af4ee3fd3263786bc14245ad17c4c7e85ba7187fb3ae028c90" dependencies = [ "proc-macro2", "quote", @@ -1551,7 +1542,7 @@ dependencies = [ "proc-macro-error", "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -1607,7 +1598,7 @@ checksum = "46c3384250002a6d5af4d114f2845d37b57521033f30d5c3f46c4d70e1197533" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -1670,7 +1661,7 @@ checksum = "5f5ae998a069d4b5aba8ee9dad856af7d520c3699e6159b185c2acd48155d39a" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -1748,7 +1739,7 @@ checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", ] [[package]] @@ -1831,9 +1822,9 @@ checksum = "0336d538f7abc86d282a4189614dfaa90810dfc2c6f6427eaf88e16311dd225d" [[package]] name = "utf8parse" -version = "0.2.1" +version = "0.2.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "711b9620af191e0cdc7468a8d14e709c3dcdb115b36f838e601583af800a370a" +checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821" [[package]] name = "uuid" @@ -1865,9 +1856,9 @@ dependencies = [ [[package]] name = "vte_generate_state_changes" -version = "0.1.1" +version = "0.1.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d257817081c7dffcdbab24b9e62d2def62e2ff7d00b1c20062551e6cccc145ff" +checksum = "2e369bee1b05d510a7b4ed645f5faa90619e05437111783ea5848f28d97d3c2e" dependencies = [ "proc-macro2", "quote", @@ -1915,7 +1906,7 @@ dependencies = [ "once_cell", "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", "wasm-bindgen-shared", ] @@ -1937,7 +1928,7 @@ checksum = "e94f17b526d0a461a191c78ea52bbce64071ed5c04c9ffe424dcb38f74171bb7" dependencies = [ "proc-macro2", "quote", - "syn 2.0.66", + "syn 2.0.67", "wasm-bindgen-backend", "wasm-bindgen-shared", ] diff --git a/Cargo.toml b/Cargo.toml index 5d28fb5..b85f72e 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -3,7 +3,7 @@ resolver = "2" members = ["sqllogictest", "sqllogictest-bin", "sqllogictest-engines", "tests"] [workspace.package] -version = "0.20.5" +version = "0.20.6" edition = "2021" homepage = "https://github.com/risinglightdb/sqllogictest-rs" keywords = ["sql", "database", "parser", "cli"] diff --git a/sqllogictest/src/runner.rs b/sqllogictest/src/runner.rs index 2fa9f49..87a4928 100644 --- a/sqllogictest/src/runner.rs +++ b/sqllogictest/src/runner.rs @@ -3,7 +3,7 @@ use std::collections::HashSet; use std::fmt::{Debug, Display}; use std::path::Path; -use std::process::{Command, ExitStatus}; +use std::process::{Command, ExitStatus, Output}; use std::sync::Arc; use std::time::Duration; use std::vec; @@ -545,6 +545,7 @@ impl> Runner { &mut self, record: Record, ) -> RecordOutput { + tracing::debug!(?record, "testing"); /// Returns whether we should skip this record, according to given `conditions`. fn should_skip( labels: &HashSet, @@ -640,11 +641,11 @@ impl> Runner { let mut cmd = if cfg!(target_os = "windows") { let mut cmd = std::process::Command::new("cmd"); - cmd.arg("/C").arg(command); + cmd.arg("/C").arg(&command); cmd } else { let mut cmd = std::process::Command::new("sh"); - cmd.arg("-c").arg(command); + cmd.arg("-c").arg(&command); cmd }; @@ -655,6 +656,7 @@ impl> Runner { Ok(_) => None, Err(e) => Some(Arc::new(e)), }; + tracing::info!(target:"sqllogictest::system_command", command, "background system command spawned"); return RecordOutput::System { error, stdout: None, @@ -675,26 +677,39 @@ impl> Runner { stderr: String, } - let mut stdout = None; + let mut actual_stdout = None; let error: Option = match result { - Ok(output) => { - if output.status.success() { + Ok(Output { + status, + stdout, + stderr, + }) => { + let stdout = String::from_utf8_lossy(&stdout).to_string(); + let stderr = String::from_utf8_lossy(&stderr).to_string(); + tracing::info!(target:"sqllogictest::system_command", command, ?status, stdout, stderr, "system command executed"); + if status.success() { if expected_stdout.is_some() { - stdout = Some(String::from_utf8_lossy(&output.stdout).to_string()); + actual_stdout = Some(stdout); } None } else { Some(Arc::new(SystemError { - status: output.status, - stdout: String::from_utf8_lossy(&output.stdout).to_string(), - stderr: String::from_utf8_lossy(&output.stderr).to_string(), + status, + stdout, + stderr, })) } } - Err(e) => Some(Arc::new(e)), + Err(error) => { + tracing::error!(target:"sqllogictest::system_command", command, ?error, "failed to run system command"); + Some(Arc::new(error)) + } }; - RecordOutput::System { error, stdout } + RecordOutput::System { + error, + stdout: actual_stdout, + } } Record::Query { conditions, @@ -819,8 +834,6 @@ impl> Runner { /// Run a single record. pub async fn run_async(&mut self, record: Record) -> Result<(), TestError> { - tracing::debug!(?record, "testing"); - let result = self.apply_record(record.clone()).await; match (record, result) { @@ -1509,14 +1522,23 @@ pub fn update_record_with_output( }, RecordOutput::System { stdout: actual_stdout, - error: _, + error, }, - ) => Some(Record::System { - loc, - conditions, - command, - stdout: actual_stdout.clone(), - }), + ) => { + if let Some(error) = error { + tracing::error!( + ?error, + command, + "system command failed while updating the record. It will be unchanged." + ); + } + Some(Record::System { + loc, + conditions, + command, + stdout: actual_stdout.clone(), + }) + } // No update possible, return the original record _ => None,