add tracing_subscriber and test_log::test

I don't know when and why we dropped log::* in favor of tracing but when it was done, it made relevant logs not appear any more while debugging so... I added test_log::test which helps by automatically adding info logs from trace package.
2026-02-23 17:05:36 +01:00 · 2025-03-05 12:43:26 +01:00
parent a7f3579a0a
commit 9a01e32c01
7 changed files with 167 additions and 18 deletions
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -249,7 +249,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "531a9155a481e2ee699d4f98f43c0ca4ff8ee1bfd55c31e9e98fb29d2b176fe0"
 dependencies = [
 "memchr",
- "regex-automata",
+ "regex-automata 0.4.9",
 "serde",
 ]

@@ -496,6 +496,7 @@ dependencies = [
 "rexpect",
 "rusqlite",
 "tempfile",
+ "test-log",
 ]

 [[package]]
@@ -1613,6 +1614,8 @@ dependencies = [
 "limbo_core",
 "miette",
 "rustyline",
+ "tracing",
+ "tracing-subscriber",
 ]

 [[package]]
@@ -1665,7 +1668,7 @@ dependencies = [
 "rand 0.8.5",
 "rand_chacha 0.9.0",
 "regex",
- "regex-syntax",
+ "regex-syntax 0.8.5",
 "rstest",
 "rusqlite",
 "rustix",
@@ -1673,6 +1676,7 @@ dependencies = [
 "serde",
 "strum",
 "tempfile",
+ "test-log",
 "thiserror 1.0.69",
 "tracing",
 ]
@@ -1764,7 +1768,7 @@ dependencies = [
 "rand 0.8.5",
 "rand_chacha 0.3.1",
 "regex",
- "regex-syntax",
+ "regex-syntax 0.8.5",
 "rusqlite",
 "serde",
 "serde_json",
@@ -1881,6 +1885,15 @@ version = "0.4.25"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "04cbf5b083de1c7e0222a7a51dbfdba1cbe1c6ab0b15e29fff3f6c077fd9cd9f"

+[[package]]
+name = "matchers"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558"
+dependencies = [
+ "regex-automata 0.1.10",
+]
+
 [[package]]
 name = "md5"
 version = "0.7.0"
@@ -2056,6 +2069,16 @@ version = "2.0.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "5e0826a989adedc2a244799e823aece04662b66609d96af8dff7ac6df9a8925d"

+[[package]]
+name = "nu-ansi-term"
+version = "0.46.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84"
+dependencies = [
+ "overload",
+ "winapi",
+]
+
 [[package]]
 name = "num-format"
 version = "0.4.4"
@@ -2111,6 +2134,12 @@ dependencies = [
 "num-traits",
 ]

+[[package]]
+name = "overload"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39"
+
 [[package]]
 name = "owo-colors"
 version = "4.1.0"
@@ -2599,8 +2628,17 @@ checksum = "b544ef1b4eac5dc2db33ea63606ae9ffcfac26c1416a2806ae0bf5f56b201191"
 dependencies = [
 "aho-corasick",
 "memchr",
- "regex-automata",
- "regex-syntax",
+ "regex-automata 0.4.9",
+ "regex-syntax 0.8.5",
+]
+
+[[package]]
+name = "regex-automata"
+version = "0.1.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132"
+dependencies = [
+ "regex-syntax 0.6.29",
 ]

 [[package]]
@@ -2611,9 +2649,15 @@ checksum = "809e8dc61f6de73b46c85f4c96486310fe304c434cfa43669d7b40f711150908"
 dependencies = [
 "aho-corasick",
 "memchr",
- "regex-syntax",
+ "regex-syntax 0.8.5",
 ]

+[[package]]
+name = "regex-syntax"
+version = "0.6.29"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1"
+
 [[package]]
 name = "regex-syntax"
 version = "0.8.5"
@@ -2855,6 +2899,15 @@ dependencies = [
 "digest",
 ]

+[[package]]
+name = "sharded-slab"
+version = "0.1.7"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "shlex"
 version = "1.3.0"
@@ -3069,6 +3122,28 @@ version = "0.5.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "8f50febec83f5ee1df3015341d8bd429f2d1cc62bcba7ea2076759d315084683"

+[[package]]
+name = "test-log"
+version = "0.2.17"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "e7f46083d221181166e5b6f6b1e5f1d499f3a76888826e6cb1d057554157cd0f"
+dependencies = [
+ "env_logger 0.11.6",
+ "test-log-macros",
+ "tracing-subscriber",
+]
+
+[[package]]
+name = "test-log-macros"
+version = "0.2.17"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "888d0c3c6db53c0fdab160d2ed5e12ba745383d3e85813f2ea0f2b1475ab553f"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn 2.0.96",
+]
+
 [[package]]
 name = "textwrap"
 version = "0.16.1"
@@ -3119,6 +3194,16 @@ dependencies = [
 "syn 2.0.96",
 ]

+[[package]]
+name = "thread_local"
+version = "1.1.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c"
+dependencies = [
+ "cfg-if",
+ "once_cell",
+]
+
 [[package]]
 name = "tinystr"
 version = "0.7.6"
@@ -3175,14 +3260,59 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "784e0ac535deb450455cbfa28a6f0df145ea1bb7ae51b821cf5e7927fdcfbdd0"
 dependencies = [
 "pin-project-lite",
+ "tracing-attributes",
 "tracing-core",
 ]

+[[package]]
+name = "tracing-attributes"
+version = "0.1.28"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "395ae124c09f9e6918a2310af6038fba074bcf474ac352496d5910dd59a2226d"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn 2.0.96",
+]
+
 [[package]]
 name = "tracing-core"
 version = "0.1.33"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c"
+dependencies = [
+ "once_cell",
+ "valuable",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3"
+dependencies = [
+ "log",
+ "once_cell",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.3.19"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008"
+dependencies = [
+ "matchers",
+ "nu-ansi-term",
+ "once_cell",
+ "regex",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing",
+ "tracing-core",
+ "tracing-log",
+]

 [[package]]
 name = "typenum"
@@ -3291,6 +3421,12 @@ dependencies = [
 "getrandom 0.2.15",
 ]

+[[package]]
+name = "valuable"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65"
+
 [[package]]
 name = "vcpkg"
 version = "0.2.15"
--- a/cli/Cargo.toml
+++ b/cli/Cargo.toml
@@ -24,12 +24,18 @@ clap = { version = "4.5", features = ["derive"] }
 comfy-table = "7.1.4"
 dirs = "5.0.1"
 env_logger = "0.10.1"
-limbo_core = { path = "../core", default-features = true, features = ["completion"]}
-rustyline = {version = "15.0.0", default-features = true, features = ["derive"]}
+limbo_core = { path = "../core", default-features = true, features = [
+    "completion",
+] }
+rustyline = { version = "15.0.0", default-features = true, features = [
+    "derive",
+] }
 ctrlc = "3.4.4"
 csv = "1.3.1"
 miette = { version = "7.4.0", features = ["fancy"] }
 cfg-if = "1.0.0"
+tracing-subscriber = { version = "0.3.19", features = ["env-filter"] }
+tracing = "0.1.41"

 [features]
 default = ["io_uring"]
--- a/cli/main.rs
+++ b/cli/main.rs
@@ -7,6 +7,7 @@ mod opcodes_dictionary;

 use rustyline::{error::ReadlineError, Config, Editor};
 use std::sync::atomic::Ordering;
+use tracing_subscriber::{fmt, prelude::*, EnvFilter};

 fn rustyline_config() -> Config {
    Config::builder()
@@ -15,8 +16,11 @@ fn rustyline_config() -> Config {
 }

 fn main() -> anyhow::Result<()> {
-    env_logger::init();
    let mut rl = Editor::with_config(rustyline_config())?;
+    tracing_subscriber::registry()
+        .with(fmt::layer())
+        .with(EnvFilter::from_default_env())
+        .init();
    let mut app = app::Limbo::new(&mut rl)?;
    let home = dirs::home_dir().expect("Could not determine home directory");
    let history_file = home.join(".limbo_history");
--- a/core/Cargo.toml
+++ b/core/Cargo.toml
@@ -48,7 +48,9 @@ limbo_sqlite3_parser = { workspace = true }
 thiserror = "1.0.61"
 getrandom = { version = "0.2.15" }
 regex = "1.11.1"
-regex-syntax = { version = "0.8.5", default-features = false, features = ["unicode"] }
+regex-syntax = { version = "0.8.5", default-features = false, features = [
+    "unicode",
+] }
 chrono = { version = "0.4.38", default-features = false, features = ["clock"] }
 julian_day_converter = "0.4.4"
 jsonb = { version = "0.4.4", optional = true }
@@ -69,8 +71,8 @@ limbo_completion = { workspace = true, optional = true, features = ["static"] }
 miette = "7.4.0"
 strum = "0.26"
 parking_lot = "0.12.3"
-tracing = { version = "0.1.41", default-features = false }
 crossbeam-skiplist = "0.1.3"
+tracing = "0.1.41"
 ryu = "1.0.19"

 [build-dependencies]
@@ -91,9 +93,10 @@ rusqlite = "0.33.0"
 tempfile = "3.8.0"
 quickcheck = { version = "1.0", default-features = false }
 quickcheck_macros = { version = "1.0", default-features = false }
-rand = "0.8.5"  # Required for quickcheck
+rand = "0.8.5" # Required for quickcheck
 rand_chacha = "0.9.0"
 env_logger = "0.11.6"
+test-log = { version = "0.2.17", features = ["trace"] }

 [[bench]]
 name = "benchmark"
--- a/core/storage/btree.rs
+++ b/core/storage/btree.rs
@@ -2744,6 +2744,7 @@ mod tests {
    use rand_chacha::rand_core::RngCore;
    use rand_chacha::rand_core::SeedableRng;
    use rand_chacha::ChaCha8Rng;
+    use test_log::test;

    use super::*;
    use crate::io::{Buffer, Completion, MemoryIO, OpenFlags, IO};
@@ -3242,7 +3243,6 @@ mod tests {
    }

    #[test]
-    #[ignore]
    pub fn btree_insert_fuzz_run_equal_size() {
        for size in 1..8 {
            tracing::info!("======= size:{} =======", size);
@@ -3251,25 +3251,21 @@ mod tests {
    }

    #[test]
-    #[ignore]
    pub fn btree_insert_fuzz_run_random() {
        btree_insert_fuzz_run(128, 16, |rng| (rng.next_u32() % 4096) as usize);
    }

    #[test]
-    #[ignore]
    pub fn btree_insert_fuzz_run_small() {
        btree_insert_fuzz_run(1, 1024, |rng| (rng.next_u32() % 128) as usize);
    }

    #[test]
-    #[ignore]
    pub fn btree_insert_fuzz_run_big() {
        btree_insert_fuzz_run(64, 32, |rng| 3 * 1024 + (rng.next_u32() % 1024) as usize);
    }

    #[test]
-    #[ignore]
    pub fn btree_insert_fuzz_run_overflow() {
        btree_insert_fuzz_run(64, 32, |rng| (rng.next_u32() % 32 * 1024) as usize);
    }
@@ -3570,6 +3566,7 @@ mod tests {
        let usable_space = 4096;
        let mut i = 1000;
        let seed = thread_rng().gen();
+        tracing::info!("seed {}", seed);
        let mut rng = ChaCha8Rng::seed_from_u64(seed);
        while i > 0 {
            i -= 1;
--- a/tests/Cargo.toml
+++ b/tests/Cargo.toml
@@ -25,6 +25,9 @@ assert_cmd = "^2"
 rand_chacha = "0.9.0"
 rand = "0.9.0"

+[dev-dependencies]
+test-log = { version = "0.2.17", features = ["trace"] }
+
 # rexpect does not support windows.
 [target.'cfg(not(windows))'.dependencies]
 rexpect = "0.6.0"
--- a/tests/integration/wal/test_wal.rs
+++ b/tests/integration/wal/test_wal.rs
@@ -6,7 +6,7 @@ use std::rc::Rc;
 use std::sync::{Arc, Mutex};

 #[allow(clippy::arc_with_non_send_sync)]
-#[test]
+#[test_log::test]
 fn test_wal_checkpoint_result() -> Result<()> {
    let tmp_db = TempDatabase::new("test_wal.db");
    let conn = tmp_db.connect_limbo();