Dec 15 02:27:00.617 INFO testing oysterpack_log-0.1.0 against try#aa49d8ef14939ddec0e34b346b60174a5673d48f for pr-56550
Dec 15 02:27:00.617 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-5/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +aa49d8ef14939ddec0e34b346b60174a5673d48f-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 15 02:27:00.956 INFO [stdout] 613a94bf83cdbae47714894bbc703337862b25c58bef0f43d20163ccbc309da0
Dec 15 02:27:00.961 INFO running `"docker" "start" "-a" "613a94bf83cdbae47714894bbc703337862b25c58bef0f43d20163ccbc309da0"`
Dec 15 02:27:01.345 INFO [stderr] usermod: no changes
Dec 15 02:27:01.831 INFO [stderr]    Compiling dot v0.1.4
Dec 15 02:27:01.831 INFO [stderr]    Compiling oysterpack_macros v0.1.0
Dec 15 02:27:01.831 INFO [stderr]    Compiling log v0.4.6
Dec 15 02:27:01.835 INFO [stderr]    Compiling tar v0.4.20
Dec 15 02:27:01.836 INFO [stderr]    Compiling parking_lot_core v0.3.1
Dec 15 02:27:01.836 INFO [stderr]    Compiling curl v0.4.19
Dec 15 02:27:01.836 INFO [stderr]    Compiling crypto-hash v0.3.1
Dec 15 02:27:01.840 INFO [stderr]    Compiling petgraph v0.4.13
Dec 15 02:27:06.483 INFO [stderr]    Compiling globset v0.4.2
Dec 15 02:27:06.486 INFO [stderr]    Compiling git2 v0.7.5
Dec 15 02:27:06.488 INFO [stderr]    Compiling log v0.3.9
Dec 15 02:27:06.535 INFO [stderr]    Compiling jobserver v0.1.12
Dec 15 02:27:06.594 INFO [stderr]    Compiling rustfix v0.4.4
Dec 15 02:27:20.439 INFO [stderr]    Compiling env_logger v0.5.13
Dec 15 02:27:20.584 INFO [stderr]    Compiling fern v0.5.7
Dec 15 02:27:21.921 INFO [stderr]    Compiling syntex_syntax v0.58.1
Dec 15 02:27:22.057 INFO [stderr]    Compiling crates-io v0.18.0
Dec 15 02:27:32.127 INFO [stderr]    Compiling parking_lot v0.6.4
Dec 15 02:27:39.915 INFO [stderr]    Compiling crossbeam-channel v0.2.6
Dec 15 02:27:41.723 INFO [stderr]    Compiling git2-curl v0.8.2
Dec 15 02:27:41.727 INFO [stderr]    Compiling built v0.3.0
Dec 15 02:27:50.454 INFO [stderr]    Compiling ignore v0.4.4
Dec 15 02:28:00.097 INFO [stderr]    Compiling cargo v0.30.0
Dec 15 02:28:32.263 INFO [stderr]    Compiling mml v0.1.41
Dec 15 02:28:40.611 INFO [stderr]    Compiling oysterpack_app_metadata v0.3.1
Dec 15 02:28:51.638 INFO [stderr] su: No module specific data is present
Dec 15 02:28:52.695 INFO running `"docker" "inspect" "613a94bf83cdbae47714894bbc703337862b25c58bef0f43d20163ccbc309da0"`
Dec 15 02:28:53.047 INFO running `"docker" "rm" "-f" "613a94bf83cdbae47714894bbc703337862b25c58bef0f43d20163ccbc309da0"`
Dec 15 02:28:53.379 INFO [stdout] 613a94bf83cdbae47714894bbc703337862b25c58bef0f43d20163ccbc309da0
Dec 15 02:28:53.387 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-5/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +aa49d8ef14939ddec0e34b346b60174a5673d48f-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 15 02:28:53.946 INFO [stdout] 20b067df2c8d0372747dc1946adfdfaa489eccbdd1454057ab5bab48722d0495
Dec 15 02:28:53.949 INFO running `"docker" "start" "-a" "20b067df2c8d0372747dc1946adfdfaa489eccbdd1454057ab5bab48722d0495"`
Dec 15 02:28:55.328 INFO [stderr] usermod: no changes
Dec 15 02:28:55.784 INFO [stderr]    Compiling oysterpack_app_metadata v0.3.1
Dec 15 02:28:55.791 INFO [stderr]    Compiling cargo v0.30.0
Dec 15 02:28:59.925 INFO [stderr]    Compiling oysterpack_app_metadata_macros v0.1.0
Dec 15 02:30:13.720 INFO [stderr]    Compiling oysterpack_built v0.3.2
Dec 15 02:30:22.495 INFO [stderr]    Compiling oysterpack_log v0.1.0 (/source)
Dec 15 02:30:47.683 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1m 52s
Dec 15 02:30:47.701 INFO [stderr] su: No module specific data is present
Dec 15 02:30:48.271 INFO running `"docker" "inspect" "20b067df2c8d0372747dc1946adfdfaa489eccbdd1454057ab5bab48722d0495"`
Dec 15 02:30:48.485 INFO running `"docker" "rm" "-f" "20b067df2c8d0372747dc1946adfdfaa489eccbdd1454057ab5bab48722d0495"`
Dec 15 02:30:48.727 INFO [stdout] 20b067df2c8d0372747dc1946adfdfaa489eccbdd1454057ab5bab48722d0495
Dec 15 02:30:48.733 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-5/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +aa49d8ef14939ddec0e34b346b60174a5673d48f-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 15 02:30:49.134 INFO [stdout] eb784ec320b3b2503b6f595c9c65af4384341d1ad94d891b69757fea91b2e561
Dec 15 02:30:49.136 INFO running `"docker" "start" "-a" "eb784ec320b3b2503b6f595c9c65af4384341d1ad94d891b69757fea91b2e561"`
Dec 15 02:30:50.284 INFO [stderr] usermod: no changes
Dec 15 02:30:50.581 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.27s
Dec 15 02:30:50.601 INFO [stderr]      Running /target/debug/deps/oysterpack_log-2b7b679e5d094c2b
Dec 15 02:30:50.616 INFO [stdout] 
Dec 15 02:30:50.616 INFO [stdout] running 5 tests
Dec 15 02:30:50.617 INFO [stdout] [02:30:50.617][INFO][oysterpack_log::manager][src/manager.rs:62] logging has been initialized using config: {
Dec 15 02:30:50.617 INFO [stdout]   "root_level": "WARN",
Dec 15 02:30:50.617 INFO [stdout]   "crate_level": "DEBUG",
Dec 15 02:30:50.617 INFO [stdout]   "output": {
Dec 15 02:30:50.617 INFO [stdout]     "Stdout": "\n"
Dec 15 02:30:50.617 INFO [stdout]   }
Dec 15 02:30:50.617 INFO [stdout] }
Dec 15 02:30:50.617 INFO [stdout] [02:30:50.617][INFO][oysterpack_log::config::tests][src/config.rs:195] {"root_level":"WARN","output":{"Stdout":"\n"}}
Dec 15 02:30:50.617 INFO [stdout] [02:30:50.617][INFO][oysterpack_log::tests][src/lib.rs:110] default_log_config: test run time: 71.078µs
Dec 15 02:30:50.617 INFO [stdout] test config::tests::default_log_config ... ok
Dec 15 02:30:50.618 INFO [stdout] [02:30:50.617][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:30:50.618 INFO [stdout] [02:30:50.617][INFO][oysterpack_log::foo][src/config.rs:236] foo says hello
Dec 15 02:30:50.618 INFO [stdout] [02:30:50.618][INFO][oysterpack_log::tests][src/lib.rs:110] for_crate: test run time: 337.853µs
Dec 15 02:30:50.619 INFO [stdout] test config::tests::for_crate ... ok
Dec 15 02:30:50.619 INFO [stdout] [02:30:50.618][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:30:50.619 INFO [stdout] [02:30:50.618][INFO][oysterpack_log::config::tests][src/config.rs:186] {"root_level":"INFO","output":{"Stdout":"\n"}}
Dec 15 02:30:50.619 INFO [stdout] [02:30:50.618][INFO][oysterpack_log::tests][src/lib.rs:110] root_log_level_configured: test run time: 47.626µs
Dec 15 02:30:50.619 INFO [stdout] test config::tests::root_log_level_configured ... ok
Dec 15 02:30:50.620 INFO [stdout] [02:30:50.619][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:30:50.620 INFO [stdout] [02:30:50.619][INFO][oysterpack_log::config::tests][src/config.rs:212] {
Dec 15 02:30:50.620 INFO [stdout]   "root_level": "INFO",
Dec 15 02:30:50.620 INFO [stdout]   "crate_level": "INFO",
Dec 15 02:30:50.620 INFO [stdout]   "target_levels": {
Dec 15 02:30:50.620 INFO [stdout]     "a": "WARN",
Dec 15 02:30:50.620 INFO [stdout]     "b": "ERROR",
Dec 15 02:30:50.620 INFO [stdout]     "c": "DEBUG"
Dec 15 02:30:50.620 INFO [stdout]   },
Dec 15 02:30:50.620 INFO [stdout]   "output": {
Dec 15 02:30:50.620 INFO [stdout]     "Stdout": "\n"
Dec 15 02:30:50.620 INFO [stdout]   }
Dec 15 02:30:50.620 INFO [stdout] }
Dec 15 02:30:50.620 INFO [stdout] [02:30:50.619][INFO][oysterpack_log::tests][src/lib.rs:110] default_log_config: test run time: 248.72µs
Dec 15 02:30:50.620 INFO [stdout] test config::tests::log_config_with_all_fields_configured ... ok
Dec 15 02:30:50.620 INFO [stdout] [02:30:50.620][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:30:50.620 INFO [stdout] [02:30:50.620][INFO][oysterpack_log::tests][src/lib.rs:119] it compiles :)
Dec 15 02:30:50.620 INFO [stdout] [02:30:50.620][INFO][oysterpack_log::tests][src/lib.rs:110] compiles: test run time: 27.592µs
Dec 15 02:30:50.621 INFO [stdout] test tests::compiles ... ok
Dec 15 02:30:50.621 INFO [stdout] 
Dec 15 02:30:50.621 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 02:30:50.621 INFO [stdout] 
Dec 15 02:30:50.621 INFO [stderr]      Running /target/debug/deps/version_numbers-46ba7d6f5a239c86
Dec 15 02:30:50.630 INFO [stdout] 
Dec 15 02:30:50.631 INFO [stdout] running 1 test
Dec 15 02:30:50.643 INFO [stdout] test test_html_root_url ... ok
Dec 15 02:30:50.643 INFO [stderr]    Doc-tests oysterpack_log
Dec 15 02:30:50.643 INFO [stdout] 
Dec 15 02:30:50.643 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 02:30:50.643 INFO [stdout] 
Dec 15 02:30:53.619 INFO [stdout] 
Dec 15 02:30:53.619 INFO [stdout] running 2 tests
Dec 15 02:30:59.134 INFO [stdout] test src/lib.rs -  (line 18) ... ok
Dec 15 02:30:59.488 INFO [stdout] test src/config.rs - config::Target::append (line 111) ... ok
Dec 15 02:30:59.488 INFO [stdout] 
Dec 15 02:30:59.488 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 02:30:59.488 INFO [stdout] 
Dec 15 02:30:59.508 INFO [stderr] su: No module specific data is present
Dec 15 02:31:00.231 INFO running `"docker" "inspect" "eb784ec320b3b2503b6f595c9c65af4384341d1ad94d891b69757fea91b2e561"`
Dec 15 02:31:00.616 INFO running `"docker" "rm" "-f" "eb784ec320b3b2503b6f595c9c65af4384341d1ad94d891b69757fea91b2e561"`
Dec 15 02:31:01.047 INFO [stdout] eb784ec320b3b2503b6f595c9c65af4384341d1ad94d891b69757fea91b2e561