Dec 15 02:27:00.820 INFO testing oysterpack_log-0.1.0 against master#bd47d6825bf4090517549d33cfef10d3300b4a75 for pr-56550
Dec 15 02:27:00.820 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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:01.077 INFO [stdout] 4134cc23f8e49ee478c15871b7793743ade22b4e78055c794c4d0234ae212a2d
Dec 15 02:27:01.085 INFO running `"docker" "start" "-a" "4134cc23f8e49ee478c15871b7793743ade22b4e78055c794c4d0234ae212a2d"`
Dec 15 02:27:01.583 INFO [stderr] usermod: no changes
Dec 15 02:27:01.943 INFO [stderr]    Compiling dot v0.1.4
Dec 15 02:27:01.943 INFO [stderr]    Compiling oysterpack_macros v0.1.0
Dec 15 02:27:01.946 INFO [stderr]    Compiling syntex_pos v0.58.1
Dec 15 02:27:01.950 INFO [stderr]    Compiling lock_api v0.1.5
Dec 15 02:27:01.950 INFO [stderr]    Compiling log v0.4.6
Dec 15 02:27:01.950 INFO [stderr]    Compiling serde_ignored v0.0.4
Dec 15 02:27:01.952 INFO [stderr]    Compiling curl-sys v0.4.15
Dec 15 02:27:01.954 INFO [stderr]    Compiling tar v0.4.20
Dec 15 02:27:02.187 INFO [stderr]    Compiling parking_lot_core v0.3.1
Dec 15 02:27:03.604 INFO [stderr]    Compiling rand_chacha v0.1.0
Dec 15 02:27:07.167 INFO [stderr]    Compiling rand_pcg v0.1.1
Dec 15 02:27:07.175 INFO [stderr]    Compiling rand v0.6.1
Dec 15 02:27:07.183 INFO [stderr]    Compiling libgit2-sys v0.7.11
Dec 15 02:27:07.183 INFO [stderr]    Compiling crypto-hash v0.3.1
Dec 15 02:27:07.377 INFO [stderr]    Compiling log v0.3.9
Dec 15 02:27:08.097 INFO [stderr]    Compiling jobserver v0.1.12
Dec 15 02:27:11.275 INFO [stderr]    Compiling fern v0.5.7
Dec 15 02:27:11.501 INFO [stderr]    Compiling petgraph v0.4.13
Dec 15 02:27:11.501 INFO [stderr]    Compiling syntex_errors v0.58.1
Dec 15 02:27:11.567 INFO [stderr]    Compiling globset v0.4.2
Dec 15 02:27:11.723 INFO [stderr]    Compiling env_logger v0.5.13
Dec 15 02:27:12.075 INFO [stderr]    Compiling curl v0.4.19
Dec 15 02:27:34.319 INFO [stderr]    Compiling syntex_syntax v0.58.1
Dec 15 02:27:34.319 INFO [stderr]    Compiling crates-io v0.18.0
Dec 15 02:27:34.711 INFO [stderr]    Compiling rustfix v0.4.4
Dec 15 02:27:44.260 INFO [stderr]    Compiling parking_lot v0.6.4
Dec 15 02:27:53.912 INFO [stderr]    Compiling crossbeam-channel v0.2.6
Dec 15 02:27:56.671 INFO [stderr]    Compiling tempfile v3.0.5
Dec 15 02:28:01.828 INFO [stderr]    Compiling ignore v0.4.4
Dec 15 02:28:44.395 INFO [stderr]    Compiling git2 v0.7.5
Dec 15 02:28:50.601 INFO [stderr]    Compiling mml v0.1.41
Dec 15 02:28:59.079 INFO [stderr]    Compiling oysterpack_app_metadata v0.3.1
Dec 15 02:29:02.643 INFO [stderr]    Compiling git2-curl v0.8.2
Dec 15 02:29:02.655 INFO [stderr]    Compiling built v0.3.0
Dec 15 02:29:08.802 INFO [stderr]    Compiling cargo v0.30.0
Dec 15 02:29:13.492 INFO [stderr] su: No module specific data is present
Dec 15 02:29:15.283 INFO running `"docker" "inspect" "4134cc23f8e49ee478c15871b7793743ade22b4e78055c794c4d0234ae212a2d"`
Dec 15 02:29:15.670 INFO running `"docker" "rm" "-f" "4134cc23f8e49ee478c15871b7793743ade22b4e78055c794c4d0234ae212a2d"`
Dec 15 02:29:16.067 INFO [stdout] 4134cc23f8e49ee478c15871b7793743ade22b4e78055c794c4d0234ae212a2d
Dec 15 02:29:16.074 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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:29:16.572 INFO [stdout] 71bb7c3c9f03e6c14d21427a690cbd0f0d82f08f529cd1740b7a616d2b3dc3f2
Dec 15 02:29:16.580 INFO running `"docker" "start" "-a" "71bb7c3c9f03e6c14d21427a690cbd0f0d82f08f529cd1740b7a616d2b3dc3f2"`
Dec 15 02:29:18.319 INFO [stderr] usermod: no changes
Dec 15 02:29:18.896 INFO [stderr]    Compiling oysterpack_app_metadata v0.3.1
Dec 15 02:29:18.903 INFO [stderr]    Compiling cargo v0.30.0
Dec 15 02:29:22.332 INFO [stderr] su: No module specific data is present
Dec 15 02:29:23.977 INFO running `"docker" "inspect" "71bb7c3c9f03e6c14d21427a690cbd0f0d82f08f529cd1740b7a616d2b3dc3f2"`
Dec 15 02:29:24.249 INFO running `"docker" "rm" "-f" "71bb7c3c9f03e6c14d21427a690cbd0f0d82f08f529cd1740b7a616d2b3dc3f2"`
Dec 15 02:29:24.618 INFO [stdout] 71bb7c3c9f03e6c14d21427a690cbd0f0d82f08f529cd1740b7a616d2b3dc3f2
Dec 15 02:29:24.625 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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:29:25.197 INFO [stdout] f7f0c9f6af9760d3e8b795906d743d3bc209e69266d1a37a89d0553bebd7298c
Dec 15 02:29:25.200 INFO running `"docker" "start" "-a" "f7f0c9f6af9760d3e8b795906d743d3bc209e69266d1a37a89d0553bebd7298c"`
Dec 15 02:29:25.868 INFO [stderr] usermod: no changes
Dec 15 02:29:26.175 INFO [stderr]    Compiling oysterpack_app_metadata v0.3.1
Dec 15 02:29:26.175 INFO [stderr]    Compiling cargo v0.30.0
Dec 15 02:29:29.683 INFO [stderr]    Compiling oysterpack_app_metadata_macros v0.1.0
Dec 15 02:30:31.752 INFO [stderr]    Compiling oysterpack_built v0.3.2
Dec 15 02:30:39.773 INFO [stderr]    Compiling oysterpack_log v0.1.0 (/source)
Dec 15 02:31:07.487 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1m 41s
Dec 15 02:31:07.503 INFO [stderr]      Running /target/debug/deps/oysterpack_log-d7eb0ca859c95c80
Dec 15 02:31:07.515 INFO [stdout] 
Dec 15 02:31:07.515 INFO [stdout] running 5 tests
Dec 15 02:31:07.515 INFO [stdout] [02:31:07.508][INFO][oysterpack_log::manager][src/manager.rs:62] logging has been initialized using config: {
Dec 15 02:31:07.515 INFO [stdout]   "root_level": "WARN",
Dec 15 02:31:07.515 INFO [stdout]   "crate_level": "DEBUG",
Dec 15 02:31:07.515 INFO [stdout]   "output": {
Dec 15 02:31:07.515 INFO [stdout]     "Stdout": "\n"
Dec 15 02:31:07.515 INFO [stdout]   }
Dec 15 02:31:07.515 INFO [stdout] }
Dec 15 02:31:07.515 INFO [stdout] [02:31:07.508][INFO][oysterpack_log::config::tests][src/config.rs:195] {"root_level":"WARN","output":{"Stdout":"\n"}}
Dec 15 02:31:07.515 INFO [stdout] [02:31:07.508][INFO][oysterpack_log::tests][src/lib.rs:110] default_log_config: test run time: 44.04µs
Dec 15 02:31:07.515 INFO [stdout] [02:31:07.511][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:31:07.515 INFO [stdout] [02:31:07.511][INFO][oysterpack_log::foo][src/config.rs:236] foo says hello
Dec 15 02:31:07.515 INFO [stdout] [02:31:07.511][INFO][oysterpack_log::tests][src/lib.rs:110] for_crate: test run time: 34.563µs
Dec 15 02:31:07.523 INFO [stderr]      Running /target/debug/deps/version_numbers-0ac0febd4d1050ca
Dec 15 02:31:07.523 INFO [stdout] test config::tests::default_log_config ... ok
Dec 15 02:31:07.523 INFO [stdout] test config::tests::for_crate ... ok
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.515][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.515][INFO][oysterpack_log::config::tests][src/config.rs:212] {
Dec 15 02:31:07.523 INFO [stdout]   "root_level": "INFO",
Dec 15 02:31:07.523 INFO [stdout]   "crate_level": "INFO",
Dec 15 02:31:07.523 INFO [stdout]   "target_levels": {
Dec 15 02:31:07.523 INFO [stdout]     "a": "WARN",
Dec 15 02:31:07.523 INFO [stdout]     "b": "ERROR",
Dec 15 02:31:07.523 INFO [stdout]     "c": "DEBUG"
Dec 15 02:31:07.523 INFO [stdout]   },
Dec 15 02:31:07.523 INFO [stdout]   "output": {
Dec 15 02:31:07.523 INFO [stdout]     "Stdout": "\n"
Dec 15 02:31:07.523 INFO [stdout]   }
Dec 15 02:31:07.523 INFO [stdout] }
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.515][INFO][oysterpack_log::tests][src/lib.rs:110] default_log_config: test run time: 100.114µs
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.515][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.516][INFO][oysterpack_log::config::tests][src/config.rs:186] {"root_level":"INFO","output":{"Stdout":"\n"}}
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.516][INFO][oysterpack_log::tests][src/lib.rs:110] root_log_level_configured: test run time: 40.684µs
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.516][WARN][oysterpack_log::manager][src/manager.rs:70] logging has already been initialized
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.516][INFO][oysterpack_log::tests][src/lib.rs:119] it compiles :)
Dec 15 02:31:07.523 INFO [stdout] [02:31:07.516][INFO][oysterpack_log::tests][src/lib.rs:110] compiles: test run time: 24.714µs
Dec 15 02:31:07.523 INFO [stdout] test config::tests::log_config_with_all_fields_configured ... ok
Dec 15 02:31:07.523 INFO [stdout] test config::tests::root_log_level_configured ... ok
Dec 15 02:31:07.523 INFO [stdout] test tests::compiles ... ok
Dec 15 02:31:07.523 INFO [stdout] 
Dec 15 02:31:07.523 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 02:31:07.523 INFO [stdout] 
Dec 15 02:31:07.531 INFO [stdout] 
Dec 15 02:31:07.531 INFO [stdout] running 1 test
Dec 15 02:31:07.547 INFO [stdout] test test_html_root_url ... ok
Dec 15 02:31:07.547 INFO [stdout] 
Dec 15 02:31:07.547 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 02:31:07.547 INFO [stdout] 
Dec 15 02:31:07.547 INFO [stderr]    Doc-tests oysterpack_log
Dec 15 02:31:10.889 INFO [stdout] 
Dec 15 02:31:10.889 INFO [stdout] running 2 tests
Dec 15 02:31:17.519 INFO [stdout] test src/lib.rs -  (line 18) ... ok
Dec 15 02:31:17.775 INFO [stdout] test src/config.rs - config::Target::append (line 111) ... ok
Dec 15 02:31:17.775 INFO [stdout] 
Dec 15 02:31:17.775 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 02:31:17.775 INFO [stdout] 
Dec 15 02:31:17.799 INFO [stderr] su: No module specific data is present
Dec 15 02:31:18.933 INFO running `"docker" "inspect" "f7f0c9f6af9760d3e8b795906d743d3bc209e69266d1a37a89d0553bebd7298c"`
Dec 15 02:31:19.275 INFO running `"docker" "rm" "-f" "f7f0c9f6af9760d3e8b795906d743d3bc209e69266d1a37a89d0553bebd7298c"`
Dec 15 02:31:19.581 INFO [stdout] f7f0c9f6af9760d3e8b795906d743d3bc209e69266d1a37a89d0553bebd7298c