refactor: use tracing · tonywu.org/mdbookkit@7886ba4

+130 -80

Cargo.lock

··· 370 370 ] 371 371 372 372 [[package]] 373 + name = "console" 374 + version = "0.16.2" 375 + source = "registry+https://github.com/rust-lang/crates.io-index" 376 + checksum = "03e45a4a8926227e4197636ba97a9fc9b00477e9f4bd711395687c5f0734bec4" 377 + dependencies = [ 378 + "encode_unicode", 379 + "libc", 380 + "once_cell", 381 + "unicode-width 0.2.0", 382 + "windows-sys 0.61.2", 383 + ] 384 + 385 + [[package]] 373 386 name = "convert_case" 374 387 version = "0.4.0" 375 388 source = "registry+https://github.com/rust-lang/crates.io-index" ··· 510 523 "libc", 511 524 "option-ext", 512 525 "redox_users", 513 - "windows-sys 0.60.2", 526 + "windows-sys 0.61.2", 514 527 ] 515 528 516 529 [[package]] ··· 564 577 checksum = "75030f3c4f45dafd7586dd6780965a8c7e8e285a5ecb86713e63a79c5b2766f3" 565 578 dependencies = [ 566 579 "cfg-if", 567 - ] 568 - 569 - [[package]] 570 - name = "env_filter" 571 - version = "0.1.3" 572 - source = "registry+https://github.com/rust-lang/crates.io-index" 573 - checksum = "186e05a59d4c50738528153b83b0b0194d3a29507dfec16eccd4b342903397d0" 574 - dependencies = [ 575 - "log", 576 - "regex", 577 - ] 578 - 579 - [[package]] 580 - name = "env_logger" 581 - version = "0.11.7" 582 - source = "registry+https://github.com/rust-lang/crates.io-index" 583 - checksum = "c3716d7a920fb4fac5d84e9d4bce8ceb321e9414b4409da61b07b75c1e3d0697" 584 - dependencies = [ 585 - "anstream", 586 - "anstyle", 587 - "env_filter", 588 - "jiff", 589 - "log", 590 580 ] 591 581 592 582 [[package]] ··· 1243 1233 source = "registry+https://github.com/rust-lang/crates.io-index" 1244 1234 checksum = "183b3088984b400f4cfac3620d5e076c84da5364016b4f49473de574b2586235" 1245 1235 dependencies = [ 1246 - "console", 1236 + "console 0.15.11", 1247 1237 "number_prefix", 1248 1238 "portable-atomic", 1249 1239 "unicode-width 0.2.0", ··· 1251 1241 ] 1252 1242 1253 1243 [[package]] 1244 + name = "indicatif" 1245 + version = "0.18.3" 1246 + source = "registry+https://github.com/rust-lang/crates.io-index" 1247 + checksum = "9375e112e4b463ec1b1c6c011953545c65a30164fbab5b581df32b3abf0dcb88" 1248 + dependencies = [ 1249 + "console 0.16.2", 1250 + "portable-atomic", 1251 + "unicode-width 0.2.0", 1252 + "unit-prefix", 1253 + "web-time", 1254 + ] 1255 + 1256 + [[package]] 1254 1257 name = "insta" 1255 1258 version = "1.42.2" 1256 1259 source = "registry+https://github.com/rust-lang/crates.io-index" 1257 1260 checksum = "50259abbaa67d11d2bcafc7ba1d094ed7a0c70e3ce893f0d0997f73558cb3084" 1258 1261 dependencies = [ 1259 - "console", 1262 + "console 0.15.11", 1260 1263 "linked-hash-map", 1261 1264 "once_cell", 1262 1265 "pin-project", ··· 1290 1293 checksum = "4a5f13b858c8d314ee3e8f639011f7ccefe71f97f96e50151fb991f267928e2c" 1291 1294 1292 1295 [[package]] 1293 - name = "jiff" 1294 - version = "0.2.4" 1295 - source = "registry+https://github.com/rust-lang/crates.io-index" 1296 - checksum = "d699bc6dfc879fb1bf9bdff0d4c56f0884fc6f0d0eb0fba397a6d00cd9a6b85e" 1297 - dependencies = [ 1298 - "jiff-static", 1299 - "log", 1300 - "portable-atomic", 1301 - "portable-atomic-util", 1302 - "serde", 1303 - ] 1304 - 1305 - [[package]] 1306 - name = "jiff-static" 1307 - version = "0.2.4" 1308 - source = "registry+https://github.com/rust-lang/crates.io-index" 1309 - checksum = "8d16e75759ee0aa64c57a56acbf43916987b20c77373cb7e808979e02b93c9f9" 1310 - dependencies = [ 1311 - "proc-macro2", 1312 - "quote", 1313 - "syn 2.0.100", 1314 - ] 1315 - 1316 - [[package]] 1317 1296 name = "jobserver" 1318 1297 version = "0.1.32" 1319 1298 source = "registry+https://github.com/rust-lang/crates.io-index" ··· 1331 1310 "once_cell", 1332 1311 "wasm-bindgen", 1333 1312 ] 1313 + 1314 + [[package]] 1315 + name = "lazy_static" 1316 + version = "1.5.0" 1317 + source = "registry+https://github.com/rust-lang/crates.io-index" 1318 + checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" 1334 1319 1335 1320 [[package]] 1336 1321 name = "libc" ··· 1439 1424 ] 1440 1425 1441 1426 [[package]] 1427 + name = "matchers" 1428 + version = "0.2.0" 1429 + source = "registry+https://github.com/rust-lang/crates.io-index" 1430 + checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9" 1431 + dependencies = [ 1432 + "regex-automata", 1433 + ] 1434 + 1435 + [[package]] 1442 1436 name = "matches" 1443 1437 version = "0.1.10" 1444 1438 source = "registry+https://github.com/rust-lang/crates.io-index" ··· 1476 1470 "anyhow", 1477 1471 "assert_cmd", 1478 1472 "clap", 1479 - "console", 1480 1473 "git2", 1481 1474 "gix-url", 1482 1475 "insta", 1483 - "log", 1484 1476 "mdbook-markdown", 1485 1477 "mdbook-preprocessor", 1486 1478 "mdbookkit", ··· 1492 1484 "tap", 1493 1485 "tempfile", 1494 1486 "thiserror 2.0.12", 1487 + "tracing", 1495 1488 "url", 1496 1489 ] 1497 1490 ··· 1516 1509 "async-lsp", 1517 1510 "cargo_toml", 1518 1511 "clap", 1519 - "console", 1520 1512 "dirs", 1521 1513 "insta", 1522 - "log", 1523 1514 "lsp-types", 1524 1515 "mdbook-markdown", 1525 1516 "mdbook-preprocessor", ··· 1539 1530 "tokio", 1540 1531 "tokio-util", 1541 1532 "tower", 1533 + "tracing", 1542 1534 ] 1543 1535 1544 1536 [[package]] ··· 1549 1541 "cargo-run-bin", 1550 1542 "chrono", 1551 1543 "clap", 1552 - "console", 1553 - "env_logger", 1554 - "indicatif", 1544 + "console 0.16.2", 1545 + "indicatif 0.18.3", 1555 1546 "insta", 1556 - "log", 1557 1547 "mdbook-markdown", 1558 1548 "mdbook-preprocessor", 1559 1549 "miette", ··· 1564 1554 "serde_json", 1565 1555 "tap", 1566 1556 "toml 0.5.11", 1557 + "tracing", 1558 + "tracing-subscriber", 1567 1559 "url", 1568 1560 ] 1569 1561 ··· 1573 1565 dependencies = [ 1574 1566 "anyhow", 1575 1567 "clap", 1576 - "env_logger", 1577 1568 "gix-url", 1578 - "log", 1579 1569 "mdbook-markdown", 1580 1570 "mdbookkit", 1581 1571 "miette", ··· 1672 1662 version = "0.3.0" 1673 1663 source = "registry+https://github.com/rust-lang/crates.io-index" 1674 1664 checksum = "61807f77802ff30975e01f4f071c8ba10c022052f98b3294119f3e615d13e5be" 1665 + 1666 + [[package]] 1667 + name = "nu-ansi-term" 1668 + version = "0.50.3" 1669 + source = "registry+https://github.com/rust-lang/crates.io-index" 1670 + checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5" 1671 + dependencies = [ 1672 + "windows-sys 0.61.2", 1673 + ] 1675 1674 1676 1675 [[package]] 1677 1676 name = "num-traits" ··· 1903 1902 version = "1.11.0" 1904 1903 source = "registry+https://github.com/rust-lang/crates.io-index" 1905 1904 checksum = "350e9b48cbc6b0e028b0473b114454c6316e57336ee184ceab6e53f72c178b3e" 1906 - 1907 - [[package]] 1908 - name = "portable-atomic-util" 1909 - version = "0.2.4" 1910 - source = "registry+https://github.com/rust-lang/crates.io-index" 1911 - checksum = "d8a2f0d8d040d7848a709caf78912debcc3f33ee4b3cac47d73d1e1069e83507" 1912 - dependencies = [ 1913 - "portable-atomic", 1914 - ] 1915 1905 1916 1906 [[package]] 1917 1907 name = "ppv-lite86" ··· 2493 2483 ] 2494 2484 2495 2485 [[package]] 2486 + name = "sharded-slab" 2487 + version = "0.1.7" 2488 + source = "registry+https://github.com/rust-lang/crates.io-index" 2489 + checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" 2490 + dependencies = [ 2491 + "lazy_static", 2492 + ] 2493 + 2494 + [[package]] 2496 2495 name = "shlex" 2497 2496 version = "1.3.0" 2498 2497 source = "registry+https://github.com/rust-lang/crates.io-index" ··· 2668 2667 "getrandom 0.3.1", 2669 2668 "once_cell", 2670 2669 "rustix 1.0.2", 2671 - "windows-sys 0.60.2", 2670 + "windows-sys 0.61.2", 2672 2671 ] 2673 2672 2674 2673 [[package]] ··· 2738 2737 ] 2739 2738 2740 2739 [[package]] 2740 + name = "thread_local" 2741 + version = "1.1.9" 2742 + source = "registry+https://github.com/rust-lang/crates.io-index" 2743 + checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185" 2744 + dependencies = [ 2745 + "cfg-if", 2746 + ] 2747 + 2748 + [[package]] 2741 2749 name = "tinystr" 2742 2750 version = "0.7.6" 2743 2751 source = "registry+https://github.com/rust-lang/crates.io-index" ··· 2943 2951 2944 2952 [[package]] 2945 2953 name = "tracing" 2946 - version = "0.1.41" 2954 + version = "0.1.44" 2947 2955 source = "registry+https://github.com/rust-lang/crates.io-index" 2948 - checksum = "784e0ac535deb450455cbfa28a6f0df145ea1bb7ae51b821cf5e7927fdcfbdd0" 2956 + checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100" 2949 2957 dependencies = [ 2950 2958 "pin-project-lite", 2951 2959 "tracing-attributes", ··· 2954 2962 2955 2963 [[package]] 2956 2964 name = "tracing-attributes" 2957 - version = "0.1.28" 2965 + version = "0.1.31" 2958 2966 source = "registry+https://github.com/rust-lang/crates.io-index" 2959 - checksum = "395ae124c09f9e6918a2310af6038fba074bcf474ac352496d5910dd59a2226d" 2967 + checksum = "7490cfa5ec963746568740651ac6781f701c9c5ea257c58e057f3ba8cf69e8da" 2960 2968 dependencies = [ 2961 2969 "proc-macro2", 2962 2970 "quote", ··· 2965 2973 2966 2974 [[package]] 2967 2975 name = "tracing-core" 2968 - version = "0.1.33" 2976 + version = "0.1.36" 2977 + source = "registry+https://github.com/rust-lang/crates.io-index" 2978 + checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a" 2979 + dependencies = [ 2980 + "once_cell", 2981 + "valuable", 2982 + ] 2983 + 2984 + [[package]] 2985 + name = "tracing-log" 2986 + version = "0.2.0" 2969 2987 source = "registry+https://github.com/rust-lang/crates.io-index" 2970 - checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c" 2988 + checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" 2971 2989 dependencies = [ 2990 + "log", 2972 2991 "once_cell", 2992 + "tracing-core", 2993 + ] 2994 + 2995 + [[package]] 2996 + name = "tracing-subscriber" 2997 + version = "0.3.22" 2998 + source = "registry+https://github.com/rust-lang/crates.io-index" 2999 + checksum = "2f30143827ddab0d256fd843b7a66d164e9f271cfa0dde49142c5ca0ca291f1e" 3000 + dependencies = [ 3001 + "matchers", 3002 + "nu-ansi-term", 3003 + "once_cell", 3004 + "regex-automata", 3005 + "sharded-slab", 3006 + "smallvec", 3007 + "thread_local", 3008 + "tracing", 3009 + "tracing-core", 3010 + "tracing-log", 2973 3011 ] 2974 3012 2975 3013 [[package]] ··· 3015 3053 checksum = "1fc81956842c57dac11422a97c3b8195a1ff727f06e85c84ed2e8aa277c9a0fd" 3016 3054 3017 3055 [[package]] 3056 + name = "unit-prefix" 3057 + version = "0.5.2" 3058 + source = "registry+https://github.com/rust-lang/crates.io-index" 3059 + checksum = "81e544489bf3d8ef66c953931f56617f423cd4b5494be343d9b9d3dda037b9a3" 3060 + 3061 + [[package]] 3018 3062 name = "untrusted" 3019 3063 version = "0.9.0" 3020 3064 source = "registry+https://github.com/rust-lang/crates.io-index" ··· 3075 3119 "cargo-run-bin", 3076 3120 "clap", 3077 3121 "flate2", 3078 - "indicatif", 3122 + "indicatif 0.17.11", 3079 3123 "reqwest", 3080 3124 "serde_json", 3081 3125 "tap", 3082 3126 "tempfile", 3083 3127 "zip", 3084 3128 ] 3129 + 3130 + [[package]] 3131 + name = "valuable" 3132 + version = "0.1.1" 3133 + source = "registry+https://github.com/rust-lang/crates.io-index" 3134 + checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" 3085 3135 3086 3136 [[package]] 3087 3137 name = "vcpkg" ··· 3317 3367 3318 3368 [[package]] 3319 3369 name = "windows-sys" 3320 - version = "0.60.2" 3370 + version = "0.61.2" 3321 3371 source = "registry+https://github.com/rust-lang/crates.io-index" 3322 - checksum = "f2f500e4d28234f72040990ec9d39e3a6b950f9f22d3dba18416c35882612bcb" 3372 + checksum = "ae137229bcbd6cdf0f7b80a31df61766145077ddf49416a728b02cb3921ff3fc" 3323 3373 dependencies = [ 3324 - "windows-targets 0.53.5", 3374 + "windows-link 0.2.1", 3325 3375 ] 3326 3376 3327 3377 [[package]]

+1 -3

Cargo.toml

··· 22 22 assert_cmd = "2.0.16" 23 23 cargo-run-bin = { version = "1.7.4", default-features = false } 24 24 clap = { version = "4.5.31", features = ["derive"] } 25 - console = { version = "0.15.11" } 26 - env_logger = "0.11.6" 27 25 insta = { version = "1.40.0", features = ["yaml", "filters"] } 28 - log = "0.4.26" 29 26 mdbook-markdown = { version = "0.5.1" } 30 27 mdbook-preprocessor = { version = "0.5.1" } 31 28 mdbookkit = { path = "crates/mdbookkit" } ··· 45 42 thiserror = "2.0.12" 46 43 tokio = { version = "1", default-features = false } 47 44 toml = "0.5" 45 + tracing = "0.1.44" 48 46 url = "2.5.4" 49 47 50 48 [workspace.metadata.bin]

+1 -2

crates/mdbook-permalinks/Cargo.toml

··· 19 19 [dependencies] 20 20 anyhow = { workspace = true } 21 21 clap = { workspace = true } 22 - console = { workspace = true } 23 22 git2 = { version = "0.20.1", default-features = false } 24 23 gix-url = { version = "0.30.0" } 25 - log = { workspace = true } 26 24 mdbook-markdown = { workspace = true } 27 25 mdbook-preprocessor = { workspace = true } 28 26 mdbookkit = { workspace = true } ··· 31 29 serde = { workspace = true } 32 30 tap = { workspace = true } 33 31 thiserror = { workspace = true } 32 + tracing = { workspace = true } 34 33 url = { workspace = true, features = ["serde"] } 35 34 36 35 [dev-dependencies]

+8 -7

crates/mdbook-permalinks/src/diagnostic.rs

··· 2 2 3 3 use miette::LabeledSpan; 4 4 use tap::{Pipe, TapOptional}; 5 + use tracing::Level; 5 6 use url::Url; 6 7 7 8 use mdbookkit::diagnostics::{Diagnostics, Issue, IssueItem, ReportBuilder}; ··· 142 143 } 143 144 144 145 impl Issue for LinkStatus { 145 - fn level(&self) -> log::Level { 146 + fn level(&self) -> Level { 146 147 match self { 147 - Self::Ignored => log::Level::Debug, 148 - Self::Unchanged => log::Level::Debug, 149 - Self::Rewritten => log::Level::Info, 150 - Self::Permalink => log::Level::Info, 151 - Self::Unreachable(..) => log::Level::Warn, 152 - Self::Error(..) => log::Level::Warn, 148 + Self::Ignored => Level::DEBUG, 149 + Self::Unchanged => Level::DEBUG, 150 + Self::Rewritten => Level::INFO, 151 + Self::Permalink => Level::INFO, 152 + Self::Unreachable(..) => Level::WARN, 153 + Self::Error(..) => Level::WARN, 153 154 } 154 155 } 155 156 }

+8 -11

crates/mdbook-permalinks/src/main.rs

··· 5 5 }; 6 6 7 7 use anyhow::{Context, Result, anyhow}; 8 - use console::colors_enabled_stderr; 9 8 use git2::Repository; 10 - use log::LevelFilter; 11 9 use mdbook_markdown::pulldown_cmark; 12 10 use mdbook_preprocessor::{Preprocessor, PreprocessorContext, book::Book}; 13 11 use serde::Deserialize; 14 12 use tap::{Pipe, Tap, TapFallible}; 13 + use tracing::{level_filters::LevelFilter, warn}; 15 14 use url::Url; 16 15 17 16 use mdbookkit::{ 18 17 book::{BookConfigHelper, BookHelper, book_from_stdin}, 19 18 diagnostics::Issue, 19 + emit_debug, emit_warning, 20 20 error::OnWarning, 21 - log_debug, log_warning, 22 - logging::{ConsoleLogger, is_logging}, 21 + logging::Logging, 23 22 }; 24 23 25 24 use self::{ ··· 46 45 match Environment::new(ctx) { 47 46 Ok(Ok(env)) => env.run(ctx, book), 48 47 Ok(Err(err)) => { 49 - log::warn!("{:?}", err.context("preprocessor will be disabled")); 48 + warn!("{:?}", err.context("preprocessor will be disabled")); 50 49 Ok(book) 51 50 } 52 51 Err(err) => Err(err).context(format!( ··· 97 96 let url = self.root_dir.join(&path.to_string_lossy()).ok()?; 98 97 content 99 98 .emit(&url) 100 - .tap_err(log_warning!()) 99 + .tap_err(emit_warning!()) 101 100 .ok() 102 101 .map(|output| (path.clone(), output.to_string())) 103 102 }) ··· 106 105 let status = self 107 106 .report_issues(&content, |_| true) 108 107 .names(|url| self.rel_path(url)) 109 - .level(LevelFilter::Warn) 110 - .logging(is_logging()) 111 - .colored(colors_enabled_stderr()) 108 + .level(LevelFilter::WARN) 112 109 .build() 113 110 .to_stderr() 114 111 .to_status(); ··· 138 135 base.join(&link.link) 139 136 } 140 137 .context("could not derive url") 141 - .tap_err(log_debug!()); 138 + .tap_err(emit_debug!()); 142 139 143 140 let Ok(file_url) = file else { 144 141 link.status = LinkStatus::Ignored; ··· 546 543 } 547 544 548 545 fn main() -> Result<()> { 549 - ConsoleLogger::install(env!("CARGO_PKG_NAME")); 546 + Logging::default().init(); 550 547 let Program { command } = clap::Parser::parse(); 551 548 match command { 552 549 None => {

+2 -2

crates/mdbook-permalinks/src/page.rs

··· 12 12 use url::Url; 13 13 14 14 use mdbookkit::{ 15 - log_warning, 15 + emit_warning, 16 16 markdown::{PatchStream, Spanned}, 17 17 }; 18 18 ··· 153 153 .filter_map(EmitLinkSpan::new) 154 154 .pipe(|stream| PatchStream::new(self.source, stream)) 155 155 .into_string() 156 - .tap_err(log_warning!())? 156 + .tap_err(emit_warning!())? 157 157 .pipe(Ok) 158 158 } 159 159 }

+10 -6

crates/mdbook-permalinks/src/tests.rs

··· 2 2 3 3 use anyhow::Result; 4 4 use git2::Repository; 5 - use log::LevelFilter; 6 5 use rstest::*; 6 + use tracing::level_filters::LevelFilter; 7 7 use url::Url; 8 8 9 9 use mdbookkit::{ 10 + logging::Logging, 10 11 markdown::default_markdown_options, 11 12 portable_snapshots, test_document, 12 - testing::{CARGO_WORKSPACE_DIR, TestDocument, setup_logging}, 13 + testing::{CARGO_WORKSPACE_DIR, TestDocument}, 13 14 }; 14 15 15 16 use crate::{Config, Environment, VersionControl, link::LinkStatus, page::Pages, vcs::Permalink}; ··· 23 24 #[once] 24 25 fn fixture() -> Fixture { 25 26 (|| -> Result<_> { 26 - setup_logging(env!("CARGO_PKG_NAME")); 27 + Logging { 28 + logging: Some(true), 29 + colored: Some(false), 30 + level: LevelFilter::DEBUG, 31 + } 32 + .init(); 27 33 28 34 let env = Environment { 29 35 vcs: VersionControl { ··· 111 117 let env = env.lock().unwrap(); 112 118 let report = env 113 119 .report_issues(pages, test) 114 - .level(LevelFilter::Debug) 120 + .level(LevelFilter::DEBUG) 115 121 .names(|url| env.rel_path(url)) 116 - .colored(false) 117 - .logging(false) 118 122 .build() 119 123 .to_report(); 120 124 drop(env);

+7 -6

crates/mdbook-permalinks/src/vcs.rs

··· 4 4 use git2::{DescribeOptions, Repository}; 5 5 use mdbook_preprocessor::config::Config as MDBookConfig; 6 6 use tap::{Pipe, Tap, TapFallible}; 7 + use tracing::{debug, info}; 7 8 use url::{Url, form_urlencoded::Serializer as SearchParams}; 8 9 9 - use mdbookkit::log_debug; 10 + use mdbookkit::emit_debug; 10 11 11 12 use crate::{ 12 13 Config, VersionControl, ··· 301 302 let head = match repo.head() { 302 303 Ok(head) => head, 303 304 Err(err) => { 304 - log::debug!("{err}"); 305 + debug!("{err}"); 305 306 return Ok(None); 306 307 } 307 308 }; ··· 313 314 .describe_tags() 314 315 .max_candidates_tags(0), // exact match 315 316 ) 316 - .tap_err(log_debug!()) 317 + .tap_err(emit_debug!()) 317 318 .and_then(|tag| tag.format(None)) 318 - .tap_err(log_debug!()) 319 + .tap_err(emit_debug!()) 319 320 { 320 - log::info!("using tag {tag:?}"); 321 + info!("using tag {tag:?}"); 321 322 Ok(Some(tag)) 322 323 } else { 323 324 let sha = head.id().to_string(); 324 - log::info!("using commit {sha}"); 325 + info!("using commit {sha}"); 325 326 Ok(Some(sha)) 326 327 } 327 328 }

+25 -19

crates/mdbook-permalinks/tests/env.rs

··· 6 6 use tap::Pipe; 7 7 use tempfile::TempDir; 8 8 9 - use mdbookkit::testing::{setup_logging, setup_paths}; 9 + use mdbookkit::{logging::Logging, testing::setup_paths}; 10 + use tracing::{debug, info, level_filters::LevelFilter}; 10 11 11 12 #[test] 12 13 fn test_minimum_env() -> Result<()> { 13 - setup_logging(env!("CARGO_PKG_NAME")); 14 + Logging { 15 + logging: Some(true), 16 + colored: Some(false), 17 + level: LevelFilter::DEBUG, 18 + } 19 + .init(); 14 20 15 - log::info!("setup: compile self"); 21 + info!("setup: compile self"); 16 22 Command::new("cargo") 17 23 .args(["build", "--package", env!("CARGO_PKG_NAME")]) 18 24 .arg(if cfg!(debug_assertions) { ··· 27 33 28 34 let root = TempDir::new()?; 29 35 30 - log::debug!("{root:?}"); 36 + debug!("{root:?}"); 31 37 32 - log::info!("given: a book"); 38 + info!("given: a book"); 33 39 Command::new("mdbook") 34 40 .args(["init", "--force"]) 35 41 .env("PATH", &path) ··· 38 44 .assert() 39 45 .success(); 40 46 41 - log::info!("given: preprocessor is enabled"); 47 + info!("given: preprocessor is enabled"); 42 48 std::fs::File::options() 43 49 .append(true) 44 50 .open(root.path().join("book.toml"))? 45 51 .pipe(|mut file| file.write_all("[preprocessor.permalinks]\n".as_bytes()))?; 46 52 47 - log::info!("when: book has path-based links"); 53 + info!("when: book has path-based links"); 48 54 std::fs::File::options() 49 55 .append(true) 50 56 .open(root.path().join("src/chapter_1.md"))? 51 57 .pipe(|mut file| file.write_all("\n[book.toml](../book.toml)\n".as_bytes()))?; 52 58 53 - log::info!("when: book is not in source control"); 59 + info!("when: book is not in source control"); 54 60 55 - log::info!("then: book builds with warnings"); 61 + info!("then: book builds with warnings"); 56 62 Command::new("mdbook") 57 63 .arg("build") 58 64 .env("CI", "false") ··· 62 68 .success() 63 69 .stderr(predicate::str::contains("requires a git repository")); 64 70 65 - log::info!("when: CI=true"); 71 + info!("when: CI=true"); 66 72 67 - log::info!("then: preprocessor fails"); 73 + info!("then: preprocessor fails"); 68 74 Command::new("mdbook") 69 75 .arg("build") 70 76 .env("CI", "true") ··· 74 80 .failure() 75 81 .stderr(predicate::str::contains("requires a git repository")); 76 82 77 - log::info!("when: repo has no commit"); 83 + info!("when: repo has no commit"); 78 84 Command::new("git") 79 85 .arg("init") 80 86 .env("PATH", &path) ··· 82 88 .assert() 83 89 .success(); 84 90 85 - log::info!("then: book builds with warnings"); 91 + info!("then: book builds with warnings"); 86 92 Command::new("mdbook") 87 93 .arg("build") 88 94 .env("CI", "false") ··· 92 98 .success() 93 99 .stderr(predicate::str::contains("no commit found")); 94 100 95 - log::info!("when: repo has no origin"); 101 + info!("when: repo has no origin"); 96 102 Command::new("git") 97 103 .args(["commit", "--allow-empty"]) 98 104 .args(["--message", "init"]) ··· 105 111 .assert() 106 112 .success(); 107 113 108 - log::info!("then: book builds with warnings"); 114 + info!("then: book builds with warnings"); 109 115 Command::new("mdbook") 110 116 .arg("build") 111 117 .env("CI", "false") ··· 115 121 .success() 116 122 .stderr(predicate::str::contains("failed to determine GitHub url")); 117 123 118 - log::info!("when: repo has origin"); 124 + info!("when: repo has origin"); 119 125 Command::new("git") 120 126 .args([ 121 127 "remote", ··· 128 134 .assert() 129 135 .success(); 130 136 131 - log::info!("then: book builds"); 137 + info!("then: book builds"); 132 138 Command::new("mdbook") 133 139 .arg("build") 134 140 .env("PATH", &path) ··· 138 144 .stderr(predicate::str::contains("[WARN]").not()) 139 145 .stderr(predicate::str::contains("using commit")); 140 146 141 - log::info!("when: HEAD is tagged"); 147 + info!("when: HEAD is tagged"); 142 148 Command::new("git") 143 149 .args(["tag", "v0.1.0", "HEAD"]) 144 150 .env("PATH", &path) ··· 146 152 .assert() 147 153 .success(); 148 154 149 - log::info!("then: items are linked using tag instead of commit SHA"); 155 + info!("then: items are linked using tag instead of commit SHA"); 150 156 Command::new("mdbook") 151 157 .arg("build") 152 158 .env("PATH", &path)

+1 -2

crates/mdbook-rustdoc-links/Cargo.toml

··· 21 21 async-lsp = { version = "0.2.2" } 22 22 cargo_toml = { version = "0.21.0" } 23 23 clap = { workspace = true } 24 - console = { workspace = true } 25 24 dirs = { version = "6.0.0" } 26 - log = { workspace = true } 27 25 lsp-types = { version = "0.95.0" } 28 26 mdbook-markdown = { workspace = true } 29 27 mdbook-preprocessor = { workspace = true } ··· 47 45 ] } 48 46 tokio-util = { version = "0.7.13", features = ["compat"] } 49 47 tower = { version = "0.5.2" } 48 + tracing = { workspace = true } 50 49 51 50 [dev-dependencies] 52 51 assert_cmd = { workspace = true }

+7 -6

crates/mdbook-rustdoc-links/src/cache.rs

··· 11 11 use sha2::{Digest, Sha256}; 12 12 use tap::{Pipe, Tap, TapFallible}; 13 13 use tokio::task::JoinSet; 14 + use tracing::debug; 14 15 15 - use mdbookkit::log_debug; 16 + use mdbookkit::emit_debug; 16 17 17 18 use crate::{env::Environment, link::ItemLinks, page::Pages, resolver::Resolver, url::UrlToPath}; 18 19 ··· 28 29 29 30 async fn load(env: &Environment) -> Result<Self::Validated> { 30 31 env.load_temp::<Self, _>("cache.json") 31 - .tap_err(log_debug!())? 32 + .tap_err(emit_debug!())? 32 33 .reuse(env) 33 34 .await 34 - .tap_err(log_debug!()) 35 + .tap_err(emit_debug!()) 35 36 } 36 37 37 38 async fn save<K>(env: &Environment, content: &Pages<'_, K>) -> Result<()> ··· 40 41 { 41 42 let this = Self::build(env, content).await?; 42 43 env.save_temp::<Self, _>("cache.json", &this) 43 - .tap_err(log_debug!()) 44 + .tap_err(emit_debug!()) 44 45 } 45 46 } 46 47 ··· 145 146 // should be tolerable to skip files that we somehow can't read? 146 147 result 147 148 .context("failed to read cache dependency") 148 - .tap_err(log_debug!()) 149 + .tap_err(emit_debug!()) 149 150 .ok() 150 151 }) 151 152 .collect::<Vec<_>>() 152 153 .tap_mut(|deps| deps.sort_by(|(k1, _), (k2, _)| k1.cmp(k2))) // order affects hashing 153 154 .into_iter() 154 155 .fold(Sha256::new(), |mut hash, (name, src)| { 155 - log::debug!("hashing {name}"); 156 + debug!("hashing {name}"); 156 157 hash.update(src); 157 158 hash 158 159 })

+49 -41

crates/mdbook-rustdoc-links/src/client.rs

··· 29 29 }; 30 30 use tokio_util::compat::{TokioAsyncReadCompatExt, TokioAsyncWriteCompatExt}; 31 31 use tower::ServiceBuilder; 32 + use tracing::{Level, debug, trace}; 32 33 33 - use mdbookkit::{log_debug, log_warning, logging::spinner}; 34 + use mdbookkit::{emit_debug, emit_warning, timer, timer_event}; 34 35 35 36 use crate::{ 36 37 env::Environment, ··· 92 93 .dispose() 93 94 .await 94 95 .context("failed to properly stop rust-analyzer") 95 - .tap_err(log_warning!()) 96 + .tap_err(emit_warning!()) 96 97 .ok(); 97 98 } 98 99 self.env ··· 109 110 110 111 impl Server { 111 112 async fn spawn(env: &Environment) -> Result<Self> { 112 - macro_rules! ra_spinner { 113 - () => { 114 - "rust-analyzer" 115 - }; 113 + struct State { 114 + sender: mpsc::Sender<Poll<()>>, 115 + timer: Option<tracing::Span>, 116 + // this span is never entered, ticker/timing is updated on span close 117 + percent_indexed: Option<u32>, 118 + last_update: Option<String>, 119 + } 120 + 121 + impl State { 122 + fn timer(&self) -> Option<tracing::span::Id> { 123 + self.timer.as_ref()?.id() 124 + } 116 125 } 117 126 118 127 /// Listen for [Work Done Progress][workDoneProgress] events from rust-analyzer ··· 157 166 state.percent_indexed = Some(0); 158 167 159 168 let msg = begin.message.as_deref().unwrap_or_default(); 160 - spinner().update(ra_spinner!(), msg); 169 + timer_event!(state.timer(), Level::INFO, "{msg}"); 161 170 162 - let tx = state.tx.clone(); 171 + let tx = state.sender.clone(); 163 172 tokio::spawn(async move { tx.send(Poll::Pending).await.ok() }); 164 173 } 165 174 166 175 Some(WorkDoneProgress::Report(report)) => { 167 - if let Some(msg) = &report.message { 168 - spinner().update(ra_spinner!(), msg); 176 + if let Some(msg) = report.message.as_deref() 177 + && (state.last_update.as_deref()) 178 + .map(|last| last != msg) 179 + .unwrap_or(true) 180 + { 181 + state.last_update = Some(msg.into()); 182 + timer_event!(state.timer(), Level::INFO, "{msg}"); 169 183 } 170 184 171 185 let Some(indexed) = state.percent_indexed.as_mut() else { ··· 185 199 }; 186 200 187 201 if spurious { 188 - log::debug!("ignoring spurious rust-analyzer progress"); 202 + debug!("ignoring spurious rust-analyzer progress"); 189 203 state.percent_indexed = None; 190 204 return; 191 205 } ··· 195 209 } 196 210 } 197 211 198 - Some(WorkDoneProgress::End(end)) => { 212 + Some(WorkDoneProgress::End(_)) => { 199 213 let Some(indexed) = state.percent_indexed else { 200 214 // progress was invalidated 201 215 return; ··· 205 219 return; 206 220 } 207 221 208 - let msg = end.message.as_deref().unwrap_or("indexing done"); 209 - spinner().update(ra_spinner!(), msg); 222 + state.timer.take(); 210 223 211 - let tx = state.tx.clone(); 224 + let tx = state.sender.clone(); 212 225 tokio::spawn(async move { tx.send(Poll::Ready(())).await.ok() }); 213 226 } 214 227 215 228 None => { 216 - log::trace!("{progress:#?}") 229 + trace!("{progress:#?}") 217 230 } 218 231 } 219 232 } 220 233 221 - let (tx, rx) = mpsc::channel(16); 234 + let (sender, receiver) = mpsc::channel(16); 235 + 236 + let timer = timer!(Level::INFO, "rust-analyzer"); 222 237 223 238 let stabilizer = EventSampling { 224 239 buffer: Duration::from_millis(500), 225 240 timeout: env.config.rust_analyzer_timeout(), 226 - } 227 - .using(rx); 228 - 229 - struct State { 230 - tx: mpsc::Sender<Poll<()>>, 231 - percent_indexed: Option<u32>, 241 + receiver, 232 242 } 243 + .build(); 233 244 234 245 let (background, mut server) = MainLoop::new_client(move |_| { 235 246 let state = State { 236 - tx, 247 + sender, 248 + timer: Some(timer), 237 249 percent_indexed: Some(0), 250 + last_update: None, 238 251 }; 239 252 240 253 let mut router = Router::new(state); 241 254 242 255 router 243 256 .notification::<Progress>(|state, progress| { 244 - log::trace!("{progress:#?}"); 257 + trace!("{progress:#?}"); 245 258 probe_progress(state, progress); 246 259 ControlFlow::Continue(()) 247 260 }) 248 261 .notification::<PublishDiagnostics>(|_, diagnostics| { 249 - log::trace!("{diagnostics:#?}"); 262 + trace!("{diagnostics:#?}"); 250 263 ControlFlow::Continue(()) 251 264 }) 252 265 .notification::<ShowMessage>(|_, ShowMessageParams { typ, message }| { ··· 280 293 tokio::spawn(async move { 281 294 let mut stderr = BufReader::new(stderr).lines(); 282 295 while let Some(line) = stderr.next_line().await.ok().flatten() { 283 - log::debug!("{line}"); 296 + debug!("{line}"); 284 297 } 285 298 }); 286 299 ··· 289 302 .run_buffered(stdout.compat(), stdin.compat_write()) 290 303 .await 291 304 .context("LSP client stopped unexpectedly") 292 - .tap_err(log_debug!()) 305 + .tap_err(emit_debug!()) 293 306 .ok(); 294 307 }); 295 308 ··· 357 370 } 358 371 359 372 server.initialized(InitializedParams {})?; 360 - 361 - spinner().create(ra_spinner!(), None); 362 373 363 374 Ok(Self { 364 375 server, ··· 420 431 }, 421 432 })?; 422 433 423 - log::debug!("textDocument/didOpen {}", uri); 434 + debug!("textDocument/didOpen {}", uri); 424 435 425 436 Ok(OpenDocument { 426 437 uri, ··· 452 463 }) 453 464 .await 454 465 .context("failed to request source definition") 455 - .tap_err(log_warning!()) 466 + .tap_err(emit_warning!()) 456 467 .unwrap_or_default() 457 468 .map(|defs| match defs { 458 469 GotoDefinitionResponse::Scalar(loc) => vec![loc.uri], ··· 470 481 .request::<ExternalDocs>(document_position(self.uri.clone(), position)) 471 482 .await 472 483 .context("failed to request external docs") 473 - .tap_err(log_warning!()) 484 + .tap_err(emit_warning!()) 474 485 .unwrap_or_default() 475 486 .context("server returned no result for external docs")?; 476 487 ··· 486 497 uri: self.uri.clone(), 487 498 }, 488 499 }) 489 - .tap_ok(|_| log::debug!("textDocument/didClose {}", self.uri)) 500 + .tap_ok(|_| debug!("textDocument/didClose {}", self.uri)) 490 501 .context("error sending textDocument/didClose") 491 - .tap_err(log_debug!()) 502 + .tap_err(emit_debug!()) 492 503 .ok(); 493 504 } 494 505 } ··· 532 543 533 544 fn log_message(message: String, typ: MessageType) { 534 545 match typ { 535 - MessageType::ERROR | MessageType::WARNING => { 536 - log::warn!("rust-analyzer: {message}") 546 + MessageType::ERROR | MessageType::WARNING | MessageType::INFO | MessageType::LOG => { 547 + debug!("rust-analyzer: {message}") 537 548 } 538 - MessageType::INFO | MessageType::LOG => { 539 - log::debug!("rust-analyzer: {message}") 540 - } 541 - _ => log::trace!("rust-analyzer: {message}"), 549 + _ => trace!("rust-analyzer: {message}"), 542 550 } 543 551 } 544 552

+3 -2

crates/mdbook-rustdoc-links/src/env.rs

··· 12 12 use shlex::Shlex; 13 13 use tap::Pipe; 14 14 use tokio::process::Command; 15 + use tracing::debug; 15 16 16 17 use mdbookkit::{error::OnWarning, markdown::default_markdown_options}; 17 18 ··· 324 325 Ok(cmd) 325 326 } 326 327 Self::VsCode(cmd) => { 327 - log::debug!("using rust-analyzer from {}", cmd.display()); 328 + debug!("using rust-analyzer from {}", cmd.display()); 328 329 Ok(Command::new(cmd)) 329 330 } 330 331 Self::Path => { 331 - log::debug!("using rust-analyzer on PATH"); 332 + debug!("using rust-analyzer on PATH"); 332 333 Ok(Command::new("rust-analyzer")) 333 334 } 334 335 }

+2 -2

crates/mdbook-rustdoc-links/src/link.rs

··· 6 6 use serde::{Deserialize, Serialize}; 7 7 use tap::{Pipe, Tap, TapFallible}; 8 8 9 - use mdbookkit::log_trace; 9 + use mdbookkit::emit_trace; 10 10 11 11 use crate::{env::EmitConfig, item::Item}; 12 12 ··· 36 36 }; 37 37 38 38 let state = Item::parse(path) 39 - .tap_err(log_trace!()) 39 + .tap_err(emit_trace!()) 40 40 .ok() 41 41 .map(LinkState::Parsed) 42 42 .unwrap_or(LinkState::Unparsed);

+4 -4

crates/mdbook-rustdoc-links/src/link/diagnostic.rs

··· 1 1 use std::fmt; 2 2 3 - use log::Level; 4 3 use miette::LabeledSpan; 4 + use tracing::Level; 5 5 6 6 use mdbookkit::diagnostics::{Issue, IssueItem}; 7 7 ··· 35 35 impl Issue for LinkStatus { 36 36 fn level(&self) -> Level { 37 37 match self { 38 - Self::Unresolved => Level::Warn, 39 - Self::Debug => Level::Trace, 40 - Self::Ok => Level::Info, 38 + Self::Unresolved => Level::WARN, 39 + Self::Debug => Level::TRACE, 40 + Self::Ok => Level::INFO, 41 41 } 42 42 } 43 43 }

+11 -15

crates/mdbook-rustdoc-links/src/main.rs

··· 6 6 Result as Result2, 7 7 }; 8 8 use clap::{Parser, Subcommand}; 9 - use console::colors_enabled_stderr; 10 - use log::LevelFilter; 11 9 use mdbook_preprocessor::PreprocessorContext; 12 10 use tap::{Pipe, TapFallible}; 11 + use tracing::{instrument, level_filters::LevelFilter, warn}; 13 12 14 13 use mdbookkit::{ 15 14 book::{BookConfigHelper, BookHelper, book_from_stdin, string_from_stdin}, 16 15 diagnostics::Issue, 17 - log_warning, 18 - logging::{ConsoleLogger, is_logging}, 16 + emit_warning, 17 + logging::Logging, 19 18 }; 20 19 21 20 use self::{ ··· 42 41 43 42 #[tokio::main] 44 43 async fn main() -> Result2<()> { 45 - ConsoleLogger::install(PREPROCESSOR_NAME); 44 + Logging::default().init(); 46 45 match Program::parse().command { 47 46 Some(Command::Supports { .. }) => Ok(()), 48 47 Some(Command::Markdown(options)) => markdown(options).await, ··· 78 77 Describe, 79 78 } 80 79 80 + #[instrument("mdbook-rustdoc-links")] 81 81 async fn mdbook() -> Result2<()> { 82 82 let (ctx, mut book) = book_from_stdin().context("failed to read from mdbook")?; 83 83 ··· 113 113 .filter_map(|(path, _)| { 114 114 let output = content 115 115 .emit(path, &client.env().emit_config()) 116 - .tap_err(log_warning!()) 116 + .tap_err(emit_warning!()) 117 117 .ok()?; 118 118 Some((path.clone(), output.to_string())) 119 119 }) ··· 124 124 let status = content 125 125 .reporter() 126 126 .names(|path| path.display().to_string()) 127 - .level(LevelFilter::Warn) 128 - .logging(is_logging()) 129 - .colored(colors_enabled_stderr()) 127 + .level(LevelFilter::WARN) 130 128 .build() 131 129 .to_stderr() 132 130 .to_status(); ··· 146 144 env.config.fail_on_warnings.check(status.level())?; 147 145 148 146 if env.config.cache_dir.is_some() && status == LinkStatus::Unresolved { 149 - log::warn!( 150 - "The `cache-dir` option is enabled, but some items were \ 151 - not resolved, which will cause rust-analyzer to always run \ 147 + warn!( 148 + "The `cache-dir` option is enabled, but some items could not \ 149 + be resolved, which will cause rust-analyzer to always run \ 152 150 despite the cache." 153 151 ); 154 152 } ··· 181 179 let status = content 182 180 .reporter() 183 181 .names(|_| "<stdin>".into()) 184 - .level(LevelFilter::Warn) 185 - .logging(is_logging()) 186 - .colored(colors_enabled_stderr()) 182 + .level(LevelFilter::WARN) 187 183 .build() 188 184 .to_stderr() 189 185 .to_status();

+23 -35

crates/mdbook-rustdoc-links/src/resolver.rs

··· 4 4 use lsp_types::Position; 5 5 use tap::{Pipe, TapFallible}; 6 6 use tokio::task::JoinSet; 7 + use tracing::{Instrument, Level, debug}; 7 8 8 - use mdbookkit::{log_debug, logging::spinner, styled}; 9 + use mdbookkit::{emit_debug, timer, timer_item}; 9 10 10 - use crate::{ 11 - UNIQUE_ID, 12 - client::{Client, OpenDocument}, 13 - item::Item, 14 - link::ItemLinks, 15 - page::Pages, 16 - url::UrlToPath, 17 - }; 11 + use crate::{UNIQUE_ID, client::Client, item::Item, link::ItemLinks, page::Pages, url::UrlToPath}; 18 12 19 13 /// Type that can provide links. 20 14 /// ··· 75 69 (context, request) 76 70 }; 77 71 78 - log::debug!("request context\n\n{context}\n"); 72 + debug!("request context\n\n{context}\n"); 79 73 80 74 let document = self 81 75 .open(self.env().entrypoint.clone(), context) 82 76 .await? 83 77 .pipe(Arc::new); 84 78 85 - spinner().create("resolve", Some(request.len() as _)); 79 + let timer = timer!(Level::INFO, "resolve-items", count = request.len()); 86 80 87 81 let tasks: JoinSet<Option<(String, ItemLinks)>> = request 88 82 .into_iter() 89 83 .map(|(key, pos)| { 90 84 let key = key.to_string(); 91 85 let doc = document.clone(); 92 - resolve(doc, key, pos) 86 + let timer = timer_item!(&timer, Level::INFO, "resolve", item = ?key); 87 + async move { 88 + for p in pos { 89 + let resolved = doc 90 + .resolve(p) 91 + .await 92 + .with_context(|| format!("{p:?}")) 93 + .context("failed to resolve symbol:") 94 + .tap_err(emit_debug!()) 95 + .ok(); 96 + if let Some(resolved) = resolved { 97 + return Some((key, resolved)); 98 + } 99 + } 100 + None 101 + } 102 + .instrument(timer) 93 103 }) 94 104 .collect(); 95 105 96 - async fn resolve( 97 - doc: Arc<OpenDocument>, 98 - key: String, 99 - pos: Vec<Position>, 100 - ) -> Option<(String, ItemLinks)> { 101 - let _task = spinner().task("resolve", &key); 102 - for p in pos { 103 - let resolved = doc 104 - .resolve(p) 105 - .await 106 - .with_context(|| format!("{p:?}")) 107 - .context("failed to resolve symbol:") 108 - .tap_err(log_debug!()) 109 - .ok(); 110 - if let Some(resolved) = resolved { 111 - return Some((key, resolved)); 112 - } 113 - } 114 - None 115 - } 116 - 117 106 let resolved = tasks 118 107 .join_all() 108 + .instrument(timer) 119 109 .await 120 110 .into_iter() 121 111 .flatten() 122 112 .collect::<HashMap<_, _>>(); 123 - 124 - spinner().finish("resolve", styled!(("done").green())); 125 113 126 114 pages.apply(&resolved); 127 115

+45 -41

crates/mdbook-rustdoc-links/src/sync.rs

··· 4 4 time::Duration, 5 5 }; 6 6 7 - use anyhow::{bail, Result}; 7 + use anyhow::{Result, bail}; 8 8 use tokio::{ 9 - sync::{mpsc, Notify}, 9 + sync::{Notify, mpsc}, 10 10 task::JoinHandle, 11 11 time, 12 12 }; 13 13 14 - pub struct EventSampling { 14 + pub struct EventSampling<T> { 15 15 pub buffer: Duration, 16 16 pub timeout: Duration, 17 + pub receiver: mpsc::Receiver<Poll<T>>, 17 18 } 18 19 19 - impl EventSampling { 20 - pub fn using<T>(self, rx: mpsc::Receiver<Poll<T>>) -> EventSampler<T> 21 - where 22 - T: Clone + Send + Sync + 'static, 23 - { 24 - EventSampler::new(rx, self) 25 - } 26 - } 27 - 28 - /// Some kind of [debouncing]. 29 - /// 30 - /// Listens to events over an [`mpsc::Receiver<Poll<T>>`] and [notifies][Notify] 31 - /// subscribers of [`Poll::Ready`], but only if they are not "immediately" 32 - /// followed by more [`Poll::Pending`], the timing of which is determined by a 33 - /// configured [buffering time][EventSampling::buffer]. 34 - /// 35 - /// [debouncing]: https://developer.mozilla.org/en-US/docs/Glossary/Debounce 36 - #[derive(Debug, Clone)] 37 - pub struct EventSampler<T> { 38 - state: Arc<RwLock<State<T>>>, 39 - event: Arc<Notify>, 40 - } 41 - 42 - #[derive(Debug, Clone)] 43 - enum State<T> { 44 - Pending, 45 - Ready(T), 46 - Timeout, 47 - } 20 + impl<T> EventSampling<T> 21 + where 22 + T: Clone + Send + Sync + 'static, 23 + { 24 + pub fn build(self) -> EventSampler<T> { 25 + let Self { 26 + buffer, 27 + timeout, 28 + mut receiver, 29 + } = self; 48 30 49 - impl<T: Clone + Send + Sync + 'static> EventSampler<T> { 50 - fn new( 51 - mut rx: mpsc::Receiver<Poll<T>>, 52 - EventSampling { buffer, timeout }: EventSampling, 53 - ) -> Self { 54 31 let state = Arc::new(RwLock::new(State::Pending)); 55 32 let event = Arc::new(Notify::new()); 56 33 ··· 59 36 let event = event.clone(); 60 37 async move { 61 38 let mut abort: Option<JoinHandle<()>> = None; 62 - while let Some(value) = time::timeout(timeout, rx.recv()).await.transpose() { 39 + while let Some(value) = time::timeout(timeout, receiver.recv()).await.transpose() { 63 40 if let Some(abort) = abort.take() { 64 41 abort.abort(); 65 42 } ··· 86 63 } 87 64 }); 88 65 89 - Self { event, state } 66 + EventSampler { event, state } 90 67 } 68 + } 91 69 70 + /// Some kind of [debouncing]. 71 + /// 72 + /// Listens to events over an [`mpsc::Receiver<Poll<T>>`] and [notifies][Notify] 73 + /// subscribers of [`Poll::Ready`], but only if they are not "immediately" 74 + /// followed by more [`Poll::Pending`], the timing of which is determined by a 75 + /// configured [buffering time][EventSampling::buffer]. 76 + /// 77 + /// [debouncing]: https://developer.mozilla.org/en-US/docs/Glossary/Debounce 78 + #[derive(Debug, Clone)] 79 + pub struct EventSampler<T> { 80 + state: Arc<RwLock<State<T>>>, 81 + event: Arc<Notify>, 82 + } 83 + 84 + #[derive(Debug, Clone)] 85 + enum State<T> { 86 + Pending, 87 + Ready(T), 88 + Timeout, 89 + } 90 + 91 + impl<T: Clone + Send + Sync + 'static> EventSampler<T> { 92 92 pub async fn wait(&self) -> Result<T> { 93 93 loop { 94 94 { 95 95 match self.state.read().unwrap().clone() { 96 96 State::Pending => {} 97 - State::Ready(value) => return Ok(value), 98 - State::Timeout => bail!("timed out waiting for ready event"), 97 + State::Ready(value) => { 98 + return Ok(value); 99 + } 100 + State::Timeout => { 101 + bail!("timed out waiting for ready event") 102 + } 99 103 } 100 104 } 101 105 self.event.notified().await;

+12 -4

crates/mdbook-rustdoc-links/src/tests.rs

··· 3 3 use rstest::*; 4 4 use similar::{ChangeTag, TextDiff}; 5 5 use tap::Pipe; 6 + use tracing::level_filters::LevelFilter; 6 7 7 - use mdbookkit::{portable_snapshots, test_document, testing::TestDocument}; 8 + use mdbookkit::{logging::Logging, portable_snapshots, test_document, testing::TestDocument}; 8 9 9 10 use crate::{ 10 11 client::Client, ··· 21 22 #[fixture] 22 23 #[once] 23 24 fn fixture() -> Fixture { 25 + Logging { 26 + logging: Some(true), 27 + colored: Some(false), 28 + level: LevelFilter::DEBUG, 29 + } 30 + .init(); 31 + 24 32 let client = Config { 25 33 rust_analyzer: Some("cargo run --package util-rust-analyzer -- analyzer".into()), 26 34 ..Default::default() ··· 65 73 fn assert_report(doc: TestDocument, Fixture { pages, .. }: &Fixture) -> Result<()> { 66 74 let report = pages 67 75 .reporter() 68 - .level(log::LevelFilter::Info) 76 + .level(LevelFilter::INFO) 69 77 .named(|u| u == &doc.url()) 70 78 .names(|_| doc.name()) 71 - .colored(false) 72 - .logging(false) 73 79 .build() 74 80 .to_report(); 81 + 75 82 portable_snapshots!().test(format!("{}.stderr", doc.name()), |name| { 76 83 insta::assert_snapshot!(name, report) 77 84 })?; 85 + 78 86 Ok(()) 79 87 } 80 88

+7 -4

crates/mdbook-rustdoc-links/src/tests/snaps/docs/src/rustdoc-links/supported-syntax.md.snap

··· 19 19 > [!TIP] 20 20 > 21 21 > This page is also used for snapshot testing! To see how all the links would look like 22 - > in Markdown after they have been processed, see 23 - > [supported-syntax.snap](/crates/mdbook-rustdoc-links/src/tests/snaps/supported-syntax.snap) 24 - > and 25 - > [supported-syntax.stderr.snap](/crates/mdbook-rustdoc-links/src/tests/snaps/supported-syntax.stderr.snap). 22 + > in Markdown after they have been processed, see [supported-syntax.snap] and 23 + > [supported-syntax.stderr.snap]. 24 + > 25 + > [supported-syntax.snap]: 26 + > /crates/mdbook-rustdoc-links/src/tests/snaps/docs/src/rustdoc-links/supported-syntax.md.snap 27 + > [supported-syntax.stderr.snap]: 28 + > /crates/mdbook-rustdoc-links/src/tests/snaps/docs/src/rustdoc-links/supported-syntax.md.stderr.snap 26 29 27 30 ## Types, modules, associated items 28 31

+1 -1

crates/mdbook-rustdoc-links/src/tests/snaps/docs/src/rustdoc-links/supported-syntax.md.stderr.snap

··· 3 3 expression: report 4 4 --- 5 5 info: successfully resolved all links 6 - ╭─[docs/src/rustdoc-links/supported-syntax.md:29:10] 6 + ╭─[docs/src/rustdoc-links/supported-syntax.md:32:10] 7 7 │ > 8 8 │ > Module [`alloc`][std::alloc] — Memory allocation APIs. 9 9 · ──────────┬──────────

+28 -19

crates/mdbook-rustdoc-links/tests/env.rs

··· 5 5 use predicates::prelude::*; 6 6 use tap::Pipe; 7 7 use tempfile::TempDir; 8 + use tracing::{debug, info, level_filters::LevelFilter}; 8 9 9 - use mdbookkit::testing::{not_in_ci, setup_logging, setup_paths}; 10 + use mdbookkit::{ 11 + logging::Logging, 12 + testing::{not_in_ci, setup_paths}, 13 + }; 10 14 11 15 #[test] 12 16 #[ignore = "should run in a dedicated environment"] 13 17 fn test_minimum_env() -> Result<()> { 14 - setup_logging(env!("CARGO_PKG_NAME")); 18 + Logging { 19 + logging: Some(true), 20 + colored: Some(false), 21 + level: LevelFilter::DEBUG, 22 + } 23 + .init(); 15 24 16 - log::info!("setup: compile self"); 25 + info!("setup: compile self"); 17 26 Command::new("cargo") 18 27 .args([ 19 28 "build", ··· 35 44 36 45 let root = TempDir::new()?; 37 46 38 - log::debug!("{root:?}"); 47 + debug!("{root:?}"); 39 48 40 - log::info!("given: a book"); 49 + info!("given: a book"); 41 50 Command::new("mdbook") 42 51 .args(["init", "--force"]) 43 52 .env("PATH", &path) ··· 46 55 .assert() 47 56 .success(); 48 57 49 - log::info!("given: preprocessor is enabled"); 58 + info!("given: preprocessor is enabled"); 50 59 std::fs::File::options() 51 60 .append(true) 52 61 .open(root.path().join("book.toml"))? 53 62 .pipe(|mut file| file.write_all("[preprocessor.rustdoc-link]\n".as_bytes()))?; 54 63 55 - log::info!("when: book is not a Cargo project"); 56 - log::info!("then: preprocessor fails"); 64 + info!("when: book is not a Cargo project"); 65 + info!("then: preprocessor fails"); 57 66 Command::new("mdbook") 58 67 .arg("build") 59 68 .env("PATH", &path) ··· 64 73 "failed to determine the current Cargo project", 65 74 )); 66 75 67 - log::info!("given: book is a Cargo project"); 76 + info!("given: book is a Cargo project"); 68 77 Command::new("cargo") 69 78 .arg("init") 70 79 .args(["--name", "temp"]) ··· 82 91 .is_ok() 83 92 && not_in_ci("rust-analyzer code extension is already installed") 84 93 { 85 - log::info!("when: book has item links"); 94 + info!("when: book has item links"); 86 95 std::fs::File::options() 87 96 .append(true) 88 97 .open(root.path().join("src/chapter_1.md"))? 89 98 .pipe(|mut file| file.write_all("\n[std::thread]\n".as_bytes()))?; 90 99 91 - log::info!("then: book builds without errors"); 100 + info!("then: book builds without errors"); 92 101 Command::new("mdbook") 93 102 .arg("build") 94 103 .env("PATH", &path) ··· 102 111 .is_ok() 103 112 && not_in_ci("rust-analyzer is already available") 104 113 { 105 - log::info!("skip testing mdbook build without rust-analyzer") 114 + info!("skip testing mdbook build without rust-analyzer") 106 115 } else { 107 - log::info!("when: rust-analyzer is not configured"); 116 + info!("when: rust-analyzer is not configured"); 108 117 109 - log::info!("when: book has no item links"); 118 + info!("when: book has no item links"); 110 119 111 - log::info!("then: book builds without errors"); 120 + info!("then: book builds without errors"); 112 121 Command::new("mdbook") 113 122 .arg("build") 114 123 .env("PATH", &path) ··· 116 125 .assert() 117 126 .success(); 118 127 119 - log::info!("when: book has item links"); 128 + info!("when: book has item links"); 120 129 std::fs::File::options() 121 130 .append(true) 122 131 .open(root.path().join("src/chapter_1.md"))? 123 132 .pipe(|mut file| file.write_all("\n[std]\n".as_bytes()))?; 124 133 125 - log::info!("then: preprocessor fails"); 134 + info!("then: preprocessor fails"); 126 135 Command::new("mdbook") 127 136 .arg("build") 128 137 .env("PATH", &path) ··· 137 146 // ^ doesn't have a closing `'` because on windows it says 'rust-analyzer.exe' 138 147 ); 139 148 140 - log::info!("when: code extension is installed"); 149 + info!("when: code extension is installed"); 141 150 142 151 let extension_dir = tempfile::Builder::new() 143 152 .prefix(".vscode") ··· 159 168 .assert() 160 169 .success(); 161 170 162 - log::info!("then: book builds without errors"); 171 + info!("then: book builds without errors"); 163 172 Command::new("mdbook") 164 173 .arg("build") 165 174 .env("PATH", &path)

+4 -4

crates/mdbookkit/Cargo.toml

··· 20 20 anyhow = { workspace = true } 21 21 chrono = { version = "0.4.40", features = ["clock"], default-features = false } 22 22 clap = { workspace = true } 23 - console = { version = "0.15.11" } 24 - env_logger = { workspace = true } 25 - indicatif = { version = "0.17.11" } 26 - log = { workspace = true } 23 + console = { version = "0.16.2" } 24 + indicatif = { version = "0.18.3" } 27 25 mdbook-markdown = { workspace = true } 28 26 mdbook-preprocessor = { workspace = true } 29 27 miette = { workspace = true } ··· 33 31 serde_json = { workspace = true } 34 32 tap = { workspace = true } 35 33 toml = { workspace = true } 34 + tracing = { workspace = true } 35 + tracing-subscriber = { version = "0.3.22", features = ["env-filter"] } 36 36 37 37 cargo-run-bin = { workspace = true, optional = true } 38 38 insta = { workspace = true, optional = true }

+4 -2

crates/mdbookkit/src/book.rs

··· 13 13 use serde::Deserialize; 14 14 use serde_json::{Value, json}; 15 15 use tap::Pipe; 16 + use tracing::warn; 16 17 17 18 use crate::markdown::default_markdown_options; 18 19 ··· 63 64 { 64 65 if idx != 0 { 65 66 let recommended = format_name(names[0]); 66 - log::warn!( 67 - "The book.toml section [{name}] is deprecated. Use [{recommended}] instead." 67 + warn!( 68 + "The book.toml section [{name}] is deprecated. \ 69 + Use [{recommended}] instead." 68 70 ); 69 71 } 70 72 return Ok(value);

+44 -61

crates/mdbookkit/src/diagnostics.rs

··· 2 2 3 3 use std::{ 4 4 borrow::Borrow, 5 - fmt::{self, Debug, Display, Write}, 5 + fmt::{self, Write as _}, 6 + io::Write as _, 6 7 }; 7 8 8 - use log::{Level, LevelFilter}; 9 9 use miette::{ 10 10 Diagnostic, GraphicalReportHandler, GraphicalTheme, LabeledSpan, MietteError, 11 11 MietteSpanContents, ReportHandler, Severity, SourceCode, SourceSpan, SpanContents, 12 12 }; 13 13 use owo_colors::Style; 14 14 use tap::{Pipe, Tap}; 15 + use tracing::{Level, debug, error, info, level_filters::LevelFilter, trace, warn}; 16 + 17 + use crate::{ 18 + env::{is_colored, is_logging}, 19 + logging::stderr, 20 + }; 15 21 16 22 /// Trait for Markdown diagnostics. This will eventually be printed to stderr. 17 23 /// ··· 29 35 /// **For implementors:** The [`Display`] implementation, which is the title of each 30 36 /// diagnostic message, should use plurals whenever possible, because error reporters 31 37 /// may elect to group together multiple labels of the same [`Issue`] 32 - pub trait Issue: Default + Debug + Display + Clone + Send + Sync { 38 + pub trait Issue: Default + fmt::Debug + fmt::Display + Clone + Send + Sync { 33 39 fn level(&self) -> Level; 34 40 } 35 41 ··· 46 52 P: IssueItem, 47 53 { 48 54 /// Render a report of the diagnostics using [miette]'s graphical reporting 49 - pub fn to_report(&self, colored: bool) -> String { 50 - let handler = if colored { 55 + pub fn to_report(&self) -> String { 56 + let handler = if is_colored() { 51 57 GraphicalTheme::unicode() 52 58 } else { 53 59 GraphicalTheme::unicode_nocolor() ··· 55 61 .tap_mut(|t| t.characters.error = "error:".into()) 56 62 .tap_mut(|t| t.characters.warning = "warning:".into()) 57 63 .tap_mut(|t| t.characters.advice = "info:".into()) 58 - .tap_mut(|t| t.styles.advice = Style::new().green().toggle(colored)) 59 - .tap_mut(|t| t.styles.warning = Style::new().yellow().toggle(colored)) 60 - .tap_mut(|t| t.styles.error = Style::new().red().toggle(colored)) 64 + .tap_mut(|t| t.styles.advice = Style::new().green().stderr()) 65 + .tap_mut(|t| t.styles.warning = Style::new().yellow().stderr()) 66 + .tap_mut(|t| t.styles.error = Style::new().red().stderr()) 61 67 .tap_mut(|t| { 62 68 // pre-emptively specify colors for all diagnostics, just for this collection 63 69 // doing this because miette doesn't support associating colors with labels yet 64 - t.styles.highlights = if colored { 70 + t.styles.highlights = if is_colored() { 65 71 self.issues 66 72 .iter() 67 73 .map(|item| level_style(item.issue().level())) ··· 128 134 { 129 135 fn severity(&self) -> Option<Severity> { 130 136 match self.status().level() { 131 - Level::Error => Some(Severity::Error), 132 - Level::Warn => Some(Severity::Warning), 137 + Level::ERROR => Some(Severity::Error), 138 + Level::WARN => Some(Severity::Warning), 133 139 _ => Some(Severity::Advice), 134 140 } 135 141 } ··· 142 148 Some(Box::new(self.issues.iter().map(|p| p.label()))) 143 149 } 144 150 145 - fn help<'a>(&'a self) -> Option<Box<dyn Display + 'a>> { 151 + fn help<'a>(&'a self) -> Option<Box<dyn fmt::Display + 'a>> { 146 152 // miette doesn't print the file name if there are no labels to report 147 153 // so we print it here 148 154 if self.issues.is_empty() { ··· 180 186 } 181 187 } 182 188 183 - impl<K, P: IssueItem> Debug for Diagnostics<'_, K, P> { 189 + impl<K, P: IssueItem> fmt::Debug for Diagnostics<'_, K, P> { 184 190 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 185 191 fmt::Debug::fmt(&self.status(), f) 186 192 } 187 193 } 188 194 189 - impl<K, P: IssueItem> Display for Diagnostics<'_, K, P> { 195 + impl<K, P: IssueItem> fmt::Display for Diagnostics<'_, K, P> { 190 196 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 191 197 fmt::Display::fmt(&self.status(), f) 192 198 } ··· 199 205 items: Vec<Diagnostics<'a, K, P>>, 200 206 print_name: F, 201 207 log_filter: LevelFilter, 202 - colored: bool, 203 - logging: bool, 204 208 } 205 209 206 210 impl<'a, K, P, F> ReportBuilder<'a, K, P, F> { ··· 208 212 Self { 209 213 items, 210 214 print_name, 211 - log_filter: LevelFilter::Trace, 212 - colored: true, 213 - logging: true, 215 + log_filter: LevelFilter::TRACE, 214 216 } 215 217 } 216 218 ··· 220 222 G: for<'b> Fn(&'b K) -> String, 221 223 { 222 224 let Self { 223 - items, 224 - log_filter, 225 - colored, 226 - logging, 227 - .. 225 + items, log_filter, .. 228 226 } = self; 229 227 ReportBuilder { 230 228 items, 231 229 print_name, 232 230 log_filter, 233 - colored, 234 - logging, 235 231 } 236 232 } 237 233 238 234 pub fn level(mut self, level: LevelFilter) -> Self { 239 235 self.log_filter = level; 240 - self 241 - } 242 - 243 - pub fn colored(mut self, colored: bool) -> Self { 244 - self.colored = colored; 245 236 self 246 237 } 247 238 ··· 253 244 self.items.retain(|d| f(&d.name)); 254 245 self 255 246 } 256 - 257 - pub fn logging(mut self, logging: bool) -> Self { 258 - self.logging = logging; 259 - self 260 - } 261 247 } 262 248 263 249 impl<'a, K, P, F> ReportBuilder<'a, K, P, F> ··· 272 258 items, 273 259 print_name, 274 260 log_filter, 275 - colored, 276 - logging, 277 261 } = self; 278 262 279 263 let items = items ··· 293 277 }) 294 278 .collect::<Vec<_>>(); 295 279 296 - Reporter { 297 - items, 298 - colored, 299 - logging, 300 - } 280 + Reporter { items } 301 281 } 302 282 } 303 283 304 284 pub struct Reporter<'a, P> { 305 285 items: Vec<Diagnostics<'a, String, P>>, 306 - colored: bool, 307 - logging: bool, 308 286 } 309 287 310 288 impl<P> Reporter<'_, P> ··· 324 302 return self; 325 303 } 326 304 327 - if self.logging { 328 - let status = self.to_status(); 305 + if is_logging() { 329 306 let logs = self.to_logs(); 330 - log::log!(status.level(), "{logs}"); 307 + match self.to_status().level() { 308 + Level::TRACE => trace!("\n\n{logs}"), 309 + Level::DEBUG => debug!("\n\n{logs}"), 310 + Level::INFO => info!("\n\n{logs}"), 311 + Level::WARN => warn!("\n\n{logs}"), 312 + Level::ERROR => error!("\n\n{logs}"), 313 + } 331 314 } else { 332 315 let report = self.to_report(); 333 - log::logger().flush(); 334 - eprint!("\n\n{report}"); 316 + stderr().write_fmt(format_args!("\n\n{report}")).unwrap(); 335 317 }; 336 318 337 319 self ··· 339 321 340 322 pub fn to_report(&self) -> String { 341 323 self.items.iter().fold(String::new(), |mut out, diag| { 342 - writeln!(out, "{}", diag.to_report(self.colored)).unwrap(); 324 + writeln!(out, "{}", diag.to_report()).unwrap(); 343 325 out 344 326 }) 345 327 } 346 328 347 329 pub fn to_logs(&self) -> String { 348 330 self.items.iter().fold(String::new(), |mut out, diag| { 331 + // TODO: flatten, skip heading 349 332 writeln!(out, "{}", diag.to_logs()).unwrap(); 350 333 out 351 334 }) ··· 410 393 411 394 const fn level_style(level: Level) -> Style { 412 395 match level { 413 - Level::Trace => Style::new().dimmed(), 414 - Level::Debug => Style::new().magenta(), 415 - Level::Info => Style::new().green(), 416 - Level::Warn => Style::new().yellow(), 417 - Level::Error => Style::new().red(), 396 + Level::TRACE => Style::new().dimmed(), 397 + Level::DEBUG => Style::new().magenta(), 398 + Level::INFO => Style::new().green(), 399 + Level::WARN => Style::new().yellow(), 400 + Level::ERROR => Style::new().red(), 418 401 } 419 402 } 420 403 421 404 trait StyleCompat { 422 - fn toggle(self, enabled: bool) -> Self; 405 + fn stderr(self) -> Self; 423 406 } 424 407 425 408 impl StyleCompat for Style { 426 - fn toggle(self, enabled: bool) -> Self { 427 - if enabled { self } else { Style::new() } 409 + fn stderr(self) -> Self { 410 + if is_colored() { self } else { Style::new() } 428 411 } 429 412 } 430 413 431 - pub trait Title: Send + Sync + Display {} 414 + pub trait Title: Send + Sync + fmt::Display {} 432 415 433 - impl<K: Send + Sync + Display> Title for K {} 416 + impl<K: Send + Sync + fmt::Display> Title for K {}

+52

crates/mdbookkit/src/env.rs

··· 1 + use std::{ 2 + io::IsTerminal, 3 + sync::{ 4 + LazyLock, 5 + atomic::{AtomicBool, Ordering}, 6 + }, 7 + }; 8 + 9 + use console::{colors_enabled_stderr, set_colors_enabled_stderr}; 10 + 11 + static CI: LazyLock<String> = LazyLock::new(|| std::env::var("CI").unwrap_or("".into())); 12 + 13 + pub(crate) static MDBOOK_LOG: LazyLock<Option<String>> = 14 + LazyLock::new(|| std::env::var("MDBOOK_LOG").ok()); 15 + 16 + #[inline] 17 + pub fn is_ci() -> Option<&'static str> { 18 + let ci = CI.as_str(); 19 + if matches!(ci, "" | "0" | "false") { 20 + None 21 + } else { 22 + Some(ci) 23 + } 24 + } 25 + 26 + static IS_LOGGING: AtomicBool = AtomicBool::new(false); 27 + 28 + #[inline] 29 + pub fn is_logging() -> bool { 30 + if cfg!(feature = "_testing") { 31 + IS_LOGGING.load(Ordering::Relaxed) 32 + } else { 33 + IS_LOGGING.load(Ordering::Relaxed) 34 + || is_ci().is_some() 35 + || MDBOOK_LOG.is_some() 36 + || !std::io::stderr().is_terminal() 37 + } 38 + } 39 + 40 + pub(crate) fn set_logging(enabled: bool) { 41 + IS_LOGGING.store(enabled, Ordering::Relaxed); 42 + } 43 + 44 + #[inline] 45 + pub fn is_colored() -> bool { 46 + colors_enabled_stderr() 47 + } 48 + 49 + #[inline] 50 + pub(crate) fn set_colored(enabled: bool) { 51 + set_colors_enabled_stderr(enabled); 52 + }

+7 -17

crates/mdbookkit/src/error.rs

··· 1 1 use anyhow::{Result, anyhow}; 2 2 use serde::Deserialize; 3 3 use tap::Pipe; 4 + use tracing::Level; 4 5 5 - pub fn is_ci() -> Option<String> { 6 - let ci = std::env::var("CI").unwrap_or("".into()); 7 - if matches!(ci.as_str(), "" | "0" | "false") { 8 - None 9 - } else { 10 - Some(ci) 11 - } 12 - } 6 + use crate::env::is_ci; 13 7 14 8 /// Flag indicating how the program should proceed when there are warnings. 15 9 /// ··· 31 25 } 32 26 33 27 impl OnWarning { 34 - pub fn check(&self, level: log::Level) -> Result<()> { 28 + pub fn check(&self, level: Level) -> Result<()> { 35 29 match level { 36 - log::Level::Error => Err(anyhow!("preprocessor has errors")), 37 - log::Level::Warn => match self { 30 + Level::ERROR => Err(anyhow!("preprocessor has errors")), 31 + Level::WARN => match self { 38 32 Self::AlwaysFail => { 39 33 anyhow!("treating warnings as errors because the `fail-on-warnings` option is set to \"always\"") 40 34 .context("preprocessor has errors") 41 35 .pipe(Err) 42 36 } 43 37 Self::FailInCi => { 44 - let Some(ci) = Self::warning_as_error() else { 38 + let Some(ci) = is_ci() else { 45 39 return Ok(()); 46 40 }; 47 41 anyhow!("treating warnings as errors because the `fail-on-warnings` option is set to \"ci\" and CI={ci}") ··· 55 49 56 50 pub fn adjusted<T, E>(&self, result: Result<Result<T, E>, E>) -> Result<Result<T, E>, E> { 57 51 match result { 58 - Ok(Err(error)) if Self::warning_as_error().is_some() => Err(error), 52 + Ok(Err(error)) if is_ci().is_some() => Err(error), 59 53 result => result, 60 54 } 61 - } 62 - 63 - fn warning_as_error() -> Option<String> { 64 - is_ci() 65 55 } 66 56 }

+1

crates/mdbookkit/src/lib.rs

··· 12 12 pub mod diagnostics; 13 13 #[cfg(feature = "_testing")] 14 14 pub mod docs; 15 + pub mod env; 15 16 pub mod error; 16 17 pub mod logging; 17 18 pub mod markdown;

+396 -354

crates/mdbookkit/src/logging.rs

··· 1 - //! Progress reporting and logging for preprocessors. 2 - 3 1 use std::{ 4 2 collections::BTreeSet, 5 - fmt, io, 6 - sync::{OnceLock, mpsc}, 3 + fmt::Debug, 4 + sync::{Arc, LazyLock, mpsc}, 7 5 thread, 8 6 time::{Duration, Instant}, 9 7 }; 10 8 11 - use anyhow::{Context, Result}; 12 - use console::{StyledObject, Term, colors_enabled_stderr, set_colors_enabled}; 13 - use env_logger::Logger; 9 + use console::{StyledObject, Term}; 14 10 use indicatif::{HumanDuration, ProgressBar, ProgressDrawTarget, ProgressStyle}; 15 - use log::{Level, LevelFilter, Log}; 16 11 use tap::{Pipe, Tap}; 12 + use tracing::{ 13 + Event, Subscriber, 14 + field::{Field, Visit}, 15 + span::{Attributes, Id}, 16 + warn, 17 + }; 18 + use tracing_subscriber::{ 19 + EnvFilter, Layer, 20 + filter::{LevelFilter, filter_fn}, 21 + layer::{Context, SubscriberExt}, 22 + registry::{LookupSpan, SpanRef}, 23 + util::SubscriberInitExt, 24 + }; 17 25 18 - pub fn spinner() -> SpinnerHandle { 19 - SpinnerHandle 26 + use crate::env::{MDBOOK_LOG, is_colored, is_logging, set_colored, set_logging}; 27 + 28 + #[doc(hidden)] 29 + #[macro_export] 30 + macro_rules! branded { 31 + // cannot use env!("CARGO_PKG_NAME") because that would be 32 + // the package name at callsite 33 + ( $suffix:literal ) => {{ concat!("mdbookkit.", $suffix) }}; 20 34 } 21 35 22 - pub struct SpinnerHandle; 36 + macro_rules! is_branded { 37 + ( $metadata:expr, $suffix:literal ) => {{ $metadata.fields().field(branded!($suffix)).is_some() }}; 38 + ( $metadata:expr ) => {{ 39 + $metadata 40 + .fields() 41 + .iter() 42 + .any(|f| f.name().starts_with("mdbookkit.")) 43 + }}; 44 + } 23 45 24 - macro_rules! spinner_log { 25 - ( $level:ident ! ( $($args:tt)* ) ) => { 26 - log::$level!(target: env!("CARGO_CRATE_NAME"), $($args)*); 27 - }; 46 + pub struct Logging { 47 + pub logging: Option<bool>, 48 + pub colored: Option<bool>, 49 + pub level: LevelFilter, 28 50 } 29 51 30 - impl SpinnerHandle { 31 - pub fn create(&self, prefix: &str, total: Option<u64>) -> &Self { 32 - let prefix = prefix.into(); 33 - let msg = Message::Create { prefix, total }; 52 + impl Logging { 53 + pub fn init(self) { 54 + init_logging(self); 55 + } 56 + } 34 57 35 - if let Some(Spinner { tx, .. }) = SPINNER.get() { 36 - tx.send(msg).ok(); 37 - } else { 38 - spinner_log!(info!("{msg}")); 58 + impl Default for Logging { 59 + fn default() -> Self { 60 + Self { 61 + logging: None, 62 + colored: None, 63 + level: LevelFilter::INFO, 39 64 } 65 + } 66 + } 40 67 41 - self 68 + fn init_logging(options: Logging) { 69 + if let Some(logging) = options.logging { 70 + set_logging(logging); 71 + } 72 + if let Some(colored) = options.colored { 73 + set_colored(colored); 42 74 } 43 75 44 - pub fn update<D: fmt::Display>(&self, prefix: &str, update: D) -> &Self { 45 - let key = prefix.into(); 46 - let update = update.to_string(); 47 - let msg = Message::Update { key, update }; 76 + // https://github.com/rust-lang/mdBook/blob/v0.5.2/src/main.rs#L93 48 77 49 - if let Some(Spinner { tx, .. }) = SPINNER.get() { 50 - tx.send(msg).ok(); 51 - } else { 52 - spinner_log!(info!("{msg}")); 53 - } 78 + let filter = EnvFilter::builder() 79 + .with_default_directive(options.level.into()) 80 + .parse_lossy(MDBOOK_LOG.as_deref().unwrap_or_default()); 54 81 55 - self 56 - } 82 + let logger = tracing_subscriber::fmt::layer() 83 + .without_time() 84 + .with_target(filter.max_level_hint().unwrap_or(options.level) < LevelFilter::INFO) 85 + .with_ansi(is_colored()) 86 + .with_writer(|| WRITER.clone()) 87 + .with_filter(if TICKER.is_some() { 88 + Some(filter_fn(|metadata| !is_branded!(metadata))) 89 + } else { 90 + None 91 + }); 57 92 58 - pub fn task<D: fmt::Display>(&self, prefix: &str, task: D) -> TaskHandle { 59 - let key = String::from(prefix); 60 - let task = task.to_string(); 93 + let ticker = ConsoleLayer.with_filter(if TICKER.is_none() { 94 + Some(filter_fn(|metadata| !metadata.is_event())) 95 + } else { 96 + None 97 + }); 61 98 62 - let open = Message::Task { 63 - key: key.clone(), 64 - task: task.clone(), 65 - }; 66 - let done = Some(Message::Done { key, task }); 99 + tracing_subscriber::registry() 100 + .with(filter) 101 + .with(logger) 102 + .with(ticker) 103 + .init(); 104 + } 67 105 68 - if let Some(Spinner { tx, .. }) = SPINNER.get() { 69 - tx.send(open).ok(); 70 - let spin = Some(tx.clone()); 71 - return TaskHandle { spin, done }; 72 - } 106 + macro_rules! derive_event { 107 + ( $id:expr, $metadata:expr, $($field:literal = $value:expr),* ) => {{ 108 + let metadata = $metadata; 109 + let fields = ::tracing::field::FieldSet::new(&[$($field),*], metadata.callsite()); 110 + #[allow(unused)] 111 + let mut iter = fields.iter(); 112 + let values = [$( 113 + (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn tracing::field::Value)), 114 + )*]; 115 + Event::child_of($id, metadata, &fields.value_set(&values)); 116 + }}; 117 + } 73 118 74 - spinner_log!(info!("{open}")); 75 - let spin = None; 76 - TaskHandle { spin, done } 119 + #[macro_export] 120 + macro_rules! timer { 121 + ( $level:expr, $key:literal, $( $span:tt )* ) => { 122 + ::tracing::span!( 123 + $level, 124 + $key, 125 + { $crate::branded!("timer") } = ::tracing::field::Empty, 126 + $($span)* 127 + ) 128 + }; 129 + ( $level:expr, $key:literal ) => { 130 + $crate::timer!($level, $key,) 77 131 } 132 + } 78 133 79 - pub fn finish<D: fmt::Display>(&self, prefix: &str, update: D) { 80 - let key = prefix.into(); 81 - let update = update.to_string(); 82 - let msg = Message::Finish { key, update }; 134 + #[macro_export] 135 + macro_rules! timer_event { 136 + ( $parent:expr, $level:expr, $( $span:tt )* ) => { 137 + ::tracing::event!( 138 + parent: $parent, 139 + $level, 140 + { $crate::branded!("timer.event") } = ::tracing::field::Empty, 141 + $($span)* 142 + ) 143 + }; 144 + ( $parent:expr, $level:expr ) => { 145 + $crate::timer_event!($parent, $level,) 146 + } 147 + } 83 148 84 - if let Some(Spinner { tx, .. }) = SPINNER.get() { 85 - tx.send(msg).ok(); 86 - } else { 87 - spinner_log!(info!("{msg}")); 88 - } 149 + #[macro_export] 150 + macro_rules! timer_item { 151 + ( $parent:expr, $level:expr, $key:literal, $( $span:tt )* ) => { 152 + ::tracing::span!( 153 + parent: $parent, 154 + $level, 155 + $key, 156 + { $crate::branded!("timer.item") } = ::tracing::field::Empty, 157 + $($span)* 158 + ) 159 + }; 160 + ( $parent:expr, $level:expr, $key:literal ) => { 161 + $crate::timer_item!($parent, $level, $key,) 89 162 } 90 163 } 91 164 92 - #[must_use] 93 - pub struct TaskHandle { 94 - spin: Option<mpsc::Sender<Message>>, 95 - done: Option<Message>, 96 - } 165 + struct ConsoleLayer; 97 166 98 - impl Drop for TaskHandle { 99 - fn drop(&mut self) { 100 - let Some(done) = self.done.take() else { return }; 101 - if let Some(ref tx) = self.spin { 102 - tx.send(done).ok(); 103 - } else { 104 - spinner_log!(info!("{done}")); 105 - } 106 - } 107 - } 167 + impl<S> Layer<S> for ConsoleLayer 168 + where 169 + S: Subscriber + for<'a> LookupSpan<'a>, 170 + { 171 + fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) { 172 + let Some(span) = ctx.span(id) else { return }; 108 173 109 - #[derive(Debug)] 110 - enum Message { 111 - Create { prefix: String, total: Option<u64> }, 112 - Update { key: String, update: String }, 113 - Task { key: String, task: String }, 114 - Done { key: String, task: String }, 115 - Finish { key: String, update: String }, 116 - } 174 + if is_branded!(span, "timer") { 175 + let TimerVisitor { count, .. } = TimerVisitor::from_attrs(attrs); 117 176 118 - impl fmt::Display for Message { 119 - fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 120 - match self { 121 - Self::Create { prefix, .. } => fmt::Display::fmt(prefix, f), 122 - Self::Update { key, update } => { 123 - fmt::Display::fmt(key, f)?; 124 - fmt::Display::fmt(" ", f)?; 125 - fmt::Display::fmt(update, f)?; 126 - Ok(()) 127 - } 128 - Self::Task { key, task } => { 129 - fmt::Display::fmt(key, f)?; 130 - fmt::Display::fmt(" ", f)?; 131 - fmt::Display::fmt(task, f)?; 132 - Ok(()) 177 + let timer = Timer { 178 + prefix: SpanPath::to_string(&span), 179 + key: span.name(), 180 + count, 181 + }; 182 + 183 + span.extensions_mut().insert(timer.clone()); 184 + 185 + if let Some(ticker) = &*TICKER { 186 + (ticker.tx).send(ProgressTick::TimerCreate(timer)).ok(); 187 + } else { 188 + derive_event!(id, span.metadata(), "message" = "started"); 133 189 } 134 - Self::Done { key, task } => { 135 - fmt::Display::fmt(key, f)?; 136 - fmt::Display::fmt(" ", f)?; 137 - fmt::Display::fmt(task, f)?; 138 - fmt::Display::fmt(" .. done", f)?; 139 - Ok(()) 140 - } 141 - Self::Finish { key, update } => { 142 - fmt::Display::fmt(key, f)?; 143 - fmt::Display::fmt(" .. ", f)?; 144 - fmt::Display::fmt(update, f)?; 145 - Ok(()) 190 + } else if is_branded!(span, "timer.item") 191 + && let TimerVisitor { 192 + item: Some(item), .. 193 + } = TimerVisitor::from_attrs(attrs) 194 + && let Some(parent) = span.parent() 195 + && let Some(Timer { key, .. }) = parent.extensions().get::<Timer>() 196 + { 197 + span.extensions_mut().insert(TimerItem(item.clone())); 198 + 199 + if let Some(ticker) = &*TICKER { 200 + (ticker.tx).send(ProgressTick::ItemOpen { key, item }).ok(); 201 + } else { 202 + derive_event!(id, span.metadata(), "message" = "started"); 146 203 } 147 204 } 148 205 } 149 - } 150 206 151 - pub fn styled<D>(val: D) -> console::StyledObject<D> { 152 - if let Some(Spinner { term, .. }) = SPINNER.get() { 153 - term.style() 154 - } else { 155 - console::Style::new().for_stderr() 156 - } 157 - .apply_to(val) 158 - } 207 + fn on_close(&self, id: Id, ctx: Context<'_, S>) { 208 + let Some(span) = ctx.span(&id) else { return }; 159 209 160 - #[macro_export] 161 - macro_rules! styled { 162 - ( ( $($display:tt)+ ) . $($style:tt)+ ) => {{ 163 - $crate::logging::styled( $($display)* ) . $($style)* 164 - }}; 165 - } 210 + // n.b. using extensions_mut involves a RwLock write, which will cause 211 + // derive_event to deadlock when it tries to read from the same span 166 212 167 - pub fn is_logging() -> bool { 168 - SPINNER.get().is_none() 169 - } 213 + if let Some(Timer { key, .. }) = span.extensions().get::<Timer>() { 214 + if let Some(ticker) = &*TICKER { 215 + ticker.tx.send(ProgressTick::TimerFinish { key }).ok(); 216 + } else { 217 + derive_event!(id, span.metadata(), "message" = "finished"); 218 + } 219 + } else if let Some(parent) = span.parent() 220 + && let Some(Timer { key, .. }) = parent.extensions().get::<Timer>() 221 + && let Some(TimerItem(item)) = span.extensions().get::<TimerItem>() 222 + { 223 + if let Some(ticker) = &*TICKER { 224 + let item = item.clone(); 225 + (ticker.tx).send(ProgressTick::ItemDone { key, item }).ok(); 226 + } else { 227 + derive_event!(id, span.metadata(), "message" = "finished"); 228 + } 229 + } 230 + } 170 231 171 - #[macro_export] 172 - macro_rules! log_debug { 173 - () => { 174 - |err| log::debug!("{err:?}") 175 - }; 176 - } 232 + fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) { 233 + if !is_branded!(event.metadata(), "timer.event") { 234 + return; 235 + } 177 236 178 - #[macro_export] 179 - macro_rules! log_trace { 180 - () => { 181 - |err| log::trace!("{err:?}") 182 - }; 183 - } 184 - 185 - #[macro_export] 186 - macro_rules! log_warning { 187 - () => { 188 - |err| { 189 - if log::log_enabled!(log::Level::Debug) { 190 - log::warn!("{err:?}") 191 - } else { 192 - log::warn!("{err}") 237 + if let TimerVisitor { 238 + message: Some(msg), .. 239 + } = TimerVisitor::from_event(event) 240 + && let Some(span) = (event.parent().cloned()) 241 + .or_else(|| ctx.current_span().id().cloned()) 242 + .and_then(|id| ctx.span(&id)) 243 + && let Some(Timer { key, .. }) = span.extensions().get::<Timer>() 244 + { 245 + if let Some(ticker) = &*TICKER { 246 + (ticker.tx) 247 + .send(ProgressTick::TimerUpdate { key, msg }) 248 + .ok(); 193 249 } 194 250 } 195 - }; 196 - (detailed) => { 197 - |err| log::warn!("{err:?}") 198 - }; 251 + } 199 252 } 200 253 201 - /// Either a [`console::Term`] or an [`env_logger::Logger`]. 202 - /// 203 - /// This is automatically detected upon installation as the global logger. The logic is: 204 - /// 205 - /// - If the `RUST_LOG` env var is set, this will use [`env_logger`]. 206 - /// - If stderr is not "user-attended", as determined by [`console::user_attended_stderr()`], 207 - /// like if stderr is piped to a file, this will use [`env_logger`]. 208 - /// - Otherwise, this will use [`console`]. 209 - /// 210 - /// When this is a [`console::Term`], logs are handled by the global [`indicatif`] spinner. 211 - /// 212 - /// When this is an [`env_logger::Logger`], there will not be a spinner, and progress 213 - /// reports are printed as logs instead. 214 - pub enum ConsoleLogger { 215 - Console(Term), 216 - Logger(Logger), 254 + #[derive(Debug, Default)] 255 + struct TimerVisitor { 256 + message: Option<String>, 257 + item: Option<Arc<str>>, 258 + count: Option<u64>, 217 259 } 218 260 219 - impl ConsoleLogger { 220 - /// Install a [`ConsoleLogger`] as the global [`log`] logger. 221 - pub fn install(name: &str) { 222 - Self::try_install(name).expect("logger should not have been set"); 261 + impl Visit for TimerVisitor { 262 + fn record_str(&mut self, field: &Field, value: &str) { 263 + match field.name() { 264 + "message" => self.message = Some(value.into()), 265 + "item" => self.item = Some(value.into()), 266 + _ => {} 267 + } 223 268 } 224 269 225 - pub fn try_install(name: &str) -> Result<()> { 226 - log::set_boxed_logger(Box::new(Self::new(name)))?; 227 - log::set_max_level(LevelFilter::max()); 228 - Ok(()) 270 + fn record_u64(&mut self, field: &Field, value: u64) { 271 + if field.name() == "count" { 272 + self.count = Some(value) 273 + } 229 274 } 230 275 231 - fn new(name: &str) -> Self { 232 - match maybe_logging() { 233 - Some(LevelFilter::Off) => SPINNER 234 - .get_or_init(|| spawn_spinner(name)) 235 - .term 236 - .clone() 237 - .pipe(Self::Console), 238 - level => env_logger::Builder::new() 239 - .format(log_format) 240 - .parse_default_env() 241 - .tap_mut(|builder| { 242 - if let Some(level) = level { 243 - builder.filter_level(level); 244 - } 245 - }) 246 - .build() 247 - .pipe(Self::Logger), 248 - } 276 + fn record_debug(&mut self, field: &Field, value: &dyn Debug) { 277 + self.record_str(field, &format!("{value:?}")); 249 278 } 250 279 } 251 280 252 - fn maybe_logging() -> Option<LevelFilter> { 253 - if std::env::var("RUST_LOG") 254 - .map(|v| !v.is_empty()) 255 - .unwrap_or(false) 256 - { 257 - // RUST_LOG to be parsed by env_logger 258 - None 259 - } else if !console::user_attended_stderr() { 260 - // RUST_LOG not set but stderr isn't a terminal 261 - // log info and above 262 - Some(LevelFilter::Info) 263 - } else { 264 - // use spinner instead 265 - Some(LevelFilter::Off) 281 + impl TimerVisitor { 282 + #[inline] 283 + fn from_attrs(attrs: &Attributes<'_>) -> Self { 284 + Self::default().tap_mut(|v| attrs.values().record(v)) 285 + } 286 + 287 + #[inline] 288 + fn from_event(event: &Event<'_>) -> Self { 289 + Self::default().tap_mut(|v| event.record(v)) 266 290 } 267 291 } 268 292 269 - impl Log for ConsoleLogger { 270 - fn enabled(&self, metadata: &log::Metadata) -> bool { 271 - match self { 272 - ConsoleLogger::Logger(logger) => logger.enabled(metadata), 273 - ConsoleLogger::Console(_) => { 274 - if metadata.target().starts_with(env!("CARGO_CRATE_NAME")) { 275 - metadata.level() <= Level::Info 276 - } else { 277 - metadata.level() <= Level::Warn 278 - } 279 - } 280 - } 293 + struct SpanPath<'a, R: LookupSpan<'a>>(Option<SpanRef<'a, R>>); 294 + 295 + impl<'a, R: LookupSpan<'a>> Iterator for SpanPath<'a, R> { 296 + type Item = &'static str; 297 + 298 + fn next(&mut self) -> Option<Self::Item> { 299 + let span = self.0.take()?; 300 + self.0 = span.parent(); 301 + Some(span.name()) 281 302 } 303 + } 282 304 283 - fn log(&self, record: &log::Record) { 284 - match self { 285 - ConsoleLogger::Logger(logger) => logger.log(record), 286 - ConsoleLogger::Console(term) => { 287 - if !self.enabled(record.metadata()) { 288 - return; 289 - } 290 - let Ok(message) = Vec::<u8>::new() 291 - .pipe(|mut buf| log_format(&mut buf, record).and(Ok(buf))) 292 - .context("failed to emit log message") 293 - .and_then(|buf| Ok(String::from_utf8(buf)?)) 294 - else { 295 - return; 296 - }; 297 - let message = styled_log(message.trim_end(), record); 298 - term.write_line(&message.to_string()).ok(); 299 - } 305 + impl<'a, R: LookupSpan<'a>> SpanPath<'a, R> { 306 + fn new(span: &SpanRef<'a, R>) -> Self { 307 + Self(span.parent()) 308 + } 309 + 310 + fn to_string(span: &SpanRef<'a, R>) -> Option<Arc<str>> { 311 + let mut items = Self::new(span).collect::<Vec<_>>(); 312 + if items.is_empty() { 313 + None 314 + } else { 315 + items.reverse(); 316 + Some(items.join(":").into()) 300 317 } 301 318 } 319 + } 302 320 303 - fn flush(&self) { 304 - match self { 305 - ConsoleLogger::Console(term) => { 306 - term.flush().ok(); 307 - } 308 - ConsoleLogger::Logger(logger) => { 309 - logger.flush(); 310 - } 321 + #[derive(Debug, Clone)] 322 + struct Timer { 323 + prefix: Option<Arc<str>>, 324 + key: &'static str, 325 + count: Option<u64>, 326 + } 327 + 328 + impl std::fmt::Display for Timer { 329 + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { 330 + if let Some(ref prefix) = self.prefix { 331 + write!(f, "[{prefix}] {}", self.key) 332 + } else { 333 + write!(f, "{}", self.key) 311 334 } 312 335 } 313 336 } 314 337 315 - pub static SPINNER: OnceLock<Spinner> = OnceLock::new(); 338 + #[derive(Debug, Clone)] 339 + struct TimerItem(Arc<str>); 316 340 317 - pub struct Spinner { 318 - tx: mpsc::Sender<Message>, 319 - term: Term, 341 + #[derive(Debug)] 342 + enum ProgressTick { 343 + TimerCreate(Timer), 344 + TimerUpdate { key: &'static str, msg: String }, 345 + ItemOpen { key: &'static str, item: Arc<str> }, 346 + ItemDone { key: &'static str, item: Arc<str> }, 347 + TimerFinish { key: &'static str }, 320 348 } 321 349 322 - fn spawn_spinner(name: &str) -> Spinner { 323 - // https://github.com/console-rs/indicatif/issues/698 324 - set_colors_enabled(colors_enabled_stderr()); 350 + #[derive(Clone)] 351 + struct ProgressTicker { 352 + tx: mpsc::Sender<ProgressTick>, 353 + } 325 354 326 - let (tx, rx) = mpsc::channel(); 355 + static WRITER: LazyLock<Term> = LazyLock::new(Term::stderr); 327 356 328 - let term = Term::stderr(); 357 + static TICKER: LazyLock<Option<ProgressTicker>> = LazyLock::new(|| { 358 + if is_logging() { 359 + None 360 + } else { 361 + Some(spawn_ticker()) 362 + } 363 + }); 329 364 330 - let target = term.clone(); 331 - let template = format!("{{spinner:.cyan}} [{name}] {{prefix}} ... {{msg}}",); 365 + fn spawn_ticker() -> ProgressTicker { 366 + let (tx, rx) = mpsc::channel(); 332 367 333 - // this thread is detached. this is okay in usage because SPINNER.get_or_init 334 - // guarantees this function is called at most once 368 + let style = ProgressStyle::with_template("{spinner:.cyan} {prefix} ... {msg}") 369 + .unwrap() 370 + .tick_chars("⠇⠋⠙⠸⠴⠦⠿"); 335 371 336 372 thread::spawn(move || { 337 373 struct Bar { 338 - prefix: String, 374 + timer: Timer, 339 375 bar: ProgressBar, 340 376 } 341 377 378 + impl Bar { 379 + fn count(&self) { 380 + let Self { timer, bar } = self; 381 + if let Some(length) = bar.length() { 382 + let counter = styled(format!("({}/{length})", bar.position())).dim(); 383 + bar.set_prefix(format!("{timer} {counter}")) 384 + } 385 + } 386 + } 387 + 342 388 let mut current: Option<Bar> = None; 343 389 344 - let mut tasks = BTreeSet::<String>::new(); 390 + let mut tasks = BTreeSet::new(); 345 391 let mut task_idx = 0; 346 392 let mut interval = Instant::now(); 347 393 348 394 loop { 395 + let current_ref = |key: &str| { 396 + let bar = current.as_ref()?; 397 + if bar.timer.key == key { 398 + Some(bar) 399 + } else { 400 + None 401 + } 402 + }; 403 + 349 404 match rx.recv_timeout(Duration::from_millis(100)) { 350 405 Err(mpsc::RecvTimeoutError::Timeout) => {} 351 406 352 407 Err(mpsc::RecvTimeoutError::Disconnected) => break, 353 408 354 - Ok(Message::Create { prefix, total }) => { 409 + Ok(ProgressTick::TimerCreate(timer)) => { 355 410 if let Some(bar) = current { 356 411 bar.bar.abandon() 357 412 } 358 413 359 - let style = ProgressStyle::with_template(&template) 360 - .unwrap() 361 - .tick_chars("⠇⠋⠙⠸⠴⠦⠿"); 362 - 363 - let bar = ProgressDrawTarget::term(target.clone(), 20) 364 - .pipe(|target| ProgressBar::with_draw_target(total, target)) 365 - .with_prefix(prefix.clone()) 366 - .with_style(style); 414 + let bar = ProgressDrawTarget::term(WRITER.clone(), 20) 415 + .pipe(|target| ProgressBar::with_draw_target(timer.count, target)) 416 + .with_prefix(timer.to_string()) 417 + .with_style(style.clone()); 367 418 368 419 bar.enable_steady_tick(Duration::from_millis(100)); 369 420 370 - current = Some(Bar { prefix, bar }); 421 + current = Some(Bar { timer, bar }); 371 422 } 372 423 373 - Ok(Message::Update { key, update }) => { 374 - let Some(Bar { 375 - ref bar, 376 - ref prefix, 377 - }) = current 378 - else { 424 + Ok(ProgressTick::TimerUpdate { key, msg }) => { 425 + let Some(Bar { bar, .. }) = current_ref(key) else { 379 426 continue; 380 427 }; 381 428 382 - if &key != prefix { 383 - continue; 384 - } 385 - 386 - bar.set_message(update); 429 + bar.set_message(msg); 387 430 bar.tick(); 388 431 } 389 432 390 - Ok(Message::Finish { key, update }) => { 391 - let Some(Bar { 392 - ref bar, 393 - ref prefix, 394 - }) = current 395 - else { 433 + Ok(ProgressTick::TimerFinish { key }) => { 434 + let Some(Bar { bar, .. }) = current_ref(key) else { 396 435 continue; 397 436 }; 398 437 399 - if &key != prefix { 400 - continue; 401 - } 402 - 403 - bar.finish_with_message(update); 438 + bar.finish_with_message(styled("done").green().to_string()); 404 439 current = None; 405 440 } 406 441 407 - Ok(Message::Task { key, task }) => { 408 - let Some(Bar { 409 - ref bar, 410 - ref prefix, 411 - }) = current 412 - else { 442 + Ok(ProgressTick::ItemOpen { key, item }) => { 443 + let Some(current) = current_ref(key) else { 413 444 continue; 414 445 }; 415 446 416 - if &key != prefix { 417 - continue; 418 - } 419 - 420 - if let Some(length) = bar.length() { 421 - let counter = styled(format!("({}/{length})", bar.position())).dim(); 422 - bar.set_prefix(format!("{prefix} {counter}")) 423 - } 447 + current.count(); 448 + current.bar.set_message(styled(&item).magenta().to_string()); 449 + current.bar.tick(); 424 450 425 - bar.set_message(styled(&task).magenta().to_string()); 426 - bar.tick(); 427 - 428 - tasks.insert(task); 451 + tasks.insert(item); 429 452 interval = Instant::now(); 430 453 } 431 454 432 - Ok(Message::Done { key, task }) => { 433 - let Some(Bar { 434 - ref bar, 435 - ref prefix, 436 - }) = current 437 - else { 455 + Ok(ProgressTick::ItemDone { key, item }) => { 456 + let Some(current) = current_ref(key) else { 438 457 continue; 439 458 }; 440 459 441 - if &key != prefix { 442 - continue; 443 - } 460 + current.bar.inc(1); 444 461 445 - bar.inc(1); 446 - 447 - if let Some(length) = bar.length() { 448 - let counter = styled(format!("({}/{length})", bar.position())).dim(); 449 - bar.set_prefix(format!("{prefix} {counter}")) 450 - } 451 - 452 - bar.set_message(styled(&task).green().to_string()); 453 - bar.tick(); 462 + current.count(); 463 + current.bar.set_message(styled(&item).green().to_string()); 464 + current.bar.tick(); 454 465 455 - tasks.insert(task); 466 + tasks.remove(&item); 456 467 interval = Instant::now(); 457 468 } 458 469 } 459 470 460 471 if let Some(Bar { 461 - ref prefix, 472 + timer: Timer { key, .. }, 462 473 ref bar, 474 + .. 463 475 }) = current 464 476 { 465 477 let now = Instant::now(); 466 478 467 479 if now - interval > Duration::from_secs(10) { 468 480 interval = now; 481 + 469 482 if task_idx >= tasks.len() { 470 483 task_idx = 0 471 484 } 485 + 472 486 if let Some(task) = tasks.iter().nth(task_idx) { 473 - spinner_log!(warn!( 474 - "task {prefix} - {task} has been running for more than {}", 475 - HumanDuration(bar.elapsed()) 476 - )); 487 + let elapsed = HumanDuration(bar.elapsed()); 488 + // TODO: how to attach to current span 489 + // TODO: how to clear line for tracing when ticker is running 490 + warn!("task {key} - {task} has been running for more than {elapsed}"); 477 491 bar.set_message(styled(task).magenta().to_string()); 478 492 task_idx += 1; 479 493 } ··· 482 496 } 483 497 }); 484 498 485 - Spinner { tx, term } 499 + ProgressTicker { tx } 500 + } 501 + 502 + #[inline] 503 + pub fn stderr() -> impl std::io::Write { 504 + WRITER.clone() 505 + } 506 + 507 + // FIXME: ensure colors do not appear in tracing output 508 + // https://github.com/tokio-rs/tracing/issues/3378 509 + #[inline] 510 + pub fn styled<D>(val: D) -> StyledObject<D> { 511 + WRITER.style().apply_to(val) 512 + } 513 + 514 + #[macro_export] 515 + macro_rules! emit_trace { 516 + () => { 517 + |err| ::tracing::trace!("{err:?}") 518 + }; 519 + ($fmt:expr) => { 520 + |e| ::tracing::trace!($fmt, e) 521 + }; 486 522 } 487 523 488 - /// <https://github.com/rust-lang/mdBook/blob/07b25cdb643899aeca2307fbab7690fa7eeec36b/src/main.rs#L100-L109> 489 - fn log_format<W: io::Write>(formatter: &mut W, record: &log::Record) -> io::Result<()> { 490 - let message = format!( 491 - "{} [{}] ({}): {}", 492 - chrono::Local::now().format("%Y-%m-%d %H:%M:%S"), 493 - record.level(), 494 - record.target(), 495 - record.args() 496 - ); 497 - let message = styled_log(message, record); 498 - writeln!(formatter, "{message}",) 524 + #[macro_export] 525 + macro_rules! emit_debug { 526 + () => { 527 + |err| ::tracing::debug!("{err:?}") 528 + }; 529 + ($fmt:expr) => { 530 + |e| ::tracing::debug!($fmt, e) 531 + }; 499 532 } 500 533 501 - fn styled_log<D>(message: D, record: &log::Record) -> StyledObject<D> { 502 - match record.level() { 503 - Level::Warn => styled(message).yellow(), 504 - Level::Error => styled(message).red(), 505 - Level::Info => styled(message), 506 - _ => styled(message).dim(), 507 - } 534 + #[macro_export] 535 + macro_rules! emit_warning { 536 + () => { 537 + |e| { 538 + if ::tracing::enabled!(::tracing::Level::DEBUG) { 539 + ::tracing::warn!("{:?}", e) 540 + } else { 541 + ::tracing::warn!("{}", e) 542 + } 543 + } 544 + }; 545 + ($fmt:expr) => { 546 + |e| ::tracing::warn!($fmt, e) 547 + }; 508 548 } 549 + 550 + // TODO: clean up logging messages & make use of spans/instrument

+2 -9

crates/mdbookkit/src/testing.rs

··· 1 1 use std::{ffi::OsString, path::Path, sync::LazyLock}; 2 2 3 3 use anyhow::Result; 4 - use log::LevelFilter; 5 4 use serde::Deserialize; 6 5 use tap::{Pipe, Tap}; 6 + use tracing::info; 7 7 use url::Url; 8 - 9 - use crate::logging::ConsoleLogger; 10 8 11 9 #[derive(Debug, PartialEq, Eq, Hash)] 12 10 pub struct TestDocument { ··· 118 116 } 119 117 } 120 118 121 - pub fn setup_logging(name: &str) { 122 - ConsoleLogger::try_install(name).ok(); 123 - log::set_max_level(LevelFilter::Debug); 124 - } 125 - 126 119 pub fn setup_paths() -> Result<OsString> { 127 120 let mut path = if let Some(path) = std::env::var_os("PATH") { 128 121 std::env::split_paths(&path) ··· 182 175 pub fn not_in_ci<D: std::fmt::Display>(because: D) -> bool { 183 176 let ci = std::env::var("CI").unwrap_or("".into()); 184 177 if matches!(ci.as_str(), "" | "0" | "false") { 185 - log::info!("{because}"); 178 + info!("{because}"); 186 179 true 187 180 } else { 188 181 panic!("{because} but CI={ci}")

-2

docs/Cargo.toml

··· 12 12 [dependencies] 13 13 anyhow = { workspace = true } 14 14 clap = { workspace = true, features = ["unstable-doc"] } 15 - env_logger = { workspace = true } 16 15 gix-url = { version = "0.30.0" } 17 - log = { workspace = true } 18 16 mdbook-markdown = { workspace = true } 19 17 mdbookkit = { workspace = true } 20 18 miette = { workspace = true }

+2 -2

docs/bin/main.rs

··· 3 3 use mdbook_markdown::pulldown_cmark::{CodeBlockKind, CowStr, Event, Parser, Tag, TagEnd}; 4 4 use mdbookkit::{ 5 5 book::{BookHelper, book_from_stdin}, 6 - logging::ConsoleLogger, 6 + logging::Logging, 7 7 markdown::PatchStream, 8 8 }; 9 9 ··· 56 56 } 57 57 58 58 fn main() -> Result<()> { 59 - ConsoleLogger::install(env!("CARGO_PKG_NAME")); 59 + Logging::default().init(); 60 60 let Program { command } = clap::Parser::parse(); 61 61 match command { 62 62 Command::Preprocess { command: None } => preprocess(),

-1

docs/src/index.md

··· 1 - [abc]

+2 -2

docs/src/lib.rs

··· 2 2 3 3 pub use mdbookkit::Diagnostics; 4 4 5 - pub mod error { 6 - pub use mdbookkit::error::is_ci; 5 + pub mod env { 6 + pub use mdbookkit::env::is_ci; 7 7 }

+6 -6

docs/src/rustdoc-links/name-resolution.md

··· 47 47 you may write `crate::*`, although this is not required: 48 48 49 49 > ```md 50 - > The [`is_ci`][crate::error::is_ci] function detects whether the preprocessor is 51 - > running in a [continuous integration](continuous-integration.md) environment, such 52 - > that warnings may be promoted to errors. 50 + > The [`is_ci`][crate::env::is_ci] function detects whether the preprocessor is running 51 + > in a [continuous integration](continuous-integration.md) environment, such that 52 + > warnings may be promoted to errors. 53 53 > ``` 54 54 > 55 - > The [`is_ci`][crate::error::is_ci] function detects whether the preprocessor is 56 - > running in a [continuous integration](continuous-integration.md) environment, such 57 - > that warnings may be promoted to errors. 55 + > The [`is_ci`][crate::env::is_ci] function detects whether the preprocessor is running 56 + > in a [continuous integration](continuous-integration.md) environment, such that 57 + > warnings may be promoted to errors. 58 58 59 59 For everything else, provide its full path, as if you were writing a `use` declaration: 60 60

+1 -1

docs/src/snippets/detecting-ci.md

··· 9 9 10 10 [^ci-true]: 11 11 Specifically, when `CI` is anything other than `""`, `"0"`, or `"false"`. The logic 12 - is encapsulated in the [`is_ci`][crate::error::is_ci] function. 12 + is encapsulated in the [`is_ci`][crate::env::is_ci] function. 13 13 14 14  15 15

-17

docs/src/snippets/logging.md

··· 1 1  2 - 3 - By default, the preprocessor shows a progress spinner when it is running. 4 - 5 - When running in CI, progress is instead printed as logs (using [log] and 6 - [env_logger])[^stderr]. 7 - 8 - You can control logging levels using the [`RUST_LOG`] environment variable. 9 - 10 - [^stderr]: 11 - Specifically, when stderr is redirected to something that isn't a terminal, such as 12 - a file. 13 - 14 -  15 - 16 - [`RUST_LOG`]: https://docs.rs/env_logger/latest/env_logger/#enabling-logging 17 - 18 -

Configure Feed

Configure Feed