[INFO] crate tokio-trace 0.1.0 is already in cache
[INFO] extracting crate tokio-trace 0.1.0 into work/ex/beta-1.37-6/sources/1.36.0/reg/tokio-trace/0.1.0
[INFO] extracting crate tokio-trace 0.1.0 into work/ex/beta-1.37-6/sources/beta-2019-07-23/reg/tokio-trace/0.1.0
[INFO] validating manifest of tokio-trace-0.1.0 on toolchain 1.36.0
[INFO] running `"/mnt/big/crater/work/local/cargo-home/bin/cargo" "+1.36.0" "read-manifest" "--manifest-path" "Cargo.toml"`
[INFO] validating manifest of tokio-trace-0.1.0 on toolchain beta-2019-07-23
[INFO] running `"/mnt/big/crater/work/local/cargo-home/bin/cargo" "+beta-2019-07-23" "read-manifest" "--manifest-path" "Cargo.toml"`
[INFO] started frobbing tokio-trace-0.1.0
[INFO] finished frobbing tokio-trace-0.1.0
[INFO] frobbed toml for tokio-trace-0.1.0 written to work/ex/beta-1.37-6/sources/1.36.0/reg/tokio-trace/0.1.0/Cargo.toml
[INFO] started frobbing tokio-trace-0.1.0
[INFO] finished frobbing tokio-trace-0.1.0
[INFO] frobbed toml for tokio-trace-0.1.0 written to work/ex/beta-1.37-6/sources/beta-2019-07-23/reg/tokio-trace/0.1.0/Cargo.toml
[INFO] running `"/mnt/big/crater/work/local/cargo-home/bin/cargo" "+1.36.0" "generate-lockfile" "--manifest-path" "Cargo.toml" "-Zno-index-update"`
[INFO] running `"/mnt/big/crater/work/local/cargo-home/bin/cargo" "+beta-2019-07-23" "generate-lockfile" "--manifest-path" "Cargo.toml" "-Zno-index-update"`
[INFO] running `"/mnt/big/crater/work/local/cargo-home/bin/cargo" "+1.36.0" "fetch" "--locked" "--manifest-path" "Cargo.toml"`
[INFO] running `"/mnt/big/crater/work/local/cargo-home/bin/cargo" "+beta-2019-07-23" "fetch" "--locked" "--manifest-path" "Cargo.toml"`
[INFO] testing tokio-trace-0.1.0 against 1.36.0 for beta-1.37-6
[INFO] running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.37-6/worker-1/1.36.0:/opt/crater/target:rw,Z" "-v" "/mnt/big/crater/work/ex/beta-1.37-6/sources/1.36.0/reg/tokio-trace/0.1.0:/opt/crater/workdir:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/opt/crater/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/opt/crater/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/opt/crater/workdir" "-e" "MAP_USER_ID=1000" "-e" "CARGO_TARGET_DIR=/opt/crater/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/crater/cargo-home" "-e" "RUSTUP_HOME=/opt/crater/rustup-home" "-w" "/opt/crater/workdir" "-m" "1536M" "--network" "none" "rustops/crates-build-env" "/opt/crater/cargo-home/bin/cargo" "+1.36.0" "build" "--frozen"`
[INFO] [stdout] 90d9e2f849507f615798db22f46a8f7d31f7a748062702ba93668e25db614033
[INFO] running `"docker" "start" "-a" "90d9e2f849507f615798db22f46a8f7d31f7a748062702ba93668e25db614033"`
[INFO] [stderr]    Compiling tokio-trace v0.1.0 (/opt/crater/workdir)
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.60s
[INFO] running `"docker" "inspect" "90d9e2f849507f615798db22f46a8f7d31f7a748062702ba93668e25db614033"`
[INFO] running `"docker" "rm" "-f" "90d9e2f849507f615798db22f46a8f7d31f7a748062702ba93668e25db614033"`
[INFO] [stdout] 90d9e2f849507f615798db22f46a8f7d31f7a748062702ba93668e25db614033
[INFO] running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.37-6/worker-1/1.36.0:/opt/crater/target:rw,Z" "-v" "/mnt/big/crater/work/ex/beta-1.37-6/sources/1.36.0/reg/tokio-trace/0.1.0:/opt/crater/workdir:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/opt/crater/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/opt/crater/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/opt/crater/workdir" "-e" "MAP_USER_ID=1000" "-e" "CARGO_TARGET_DIR=/opt/crater/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/crater/cargo-home" "-e" "RUSTUP_HOME=/opt/crater/rustup-home" "-w" "/opt/crater/workdir" "-m" "1536M" "--network" "none" "rustops/crates-build-env" "/opt/crater/cargo-home/bin/cargo" "+1.36.0" "test" "--frozen" "--no-run"`
[INFO] [stdout] 1b9f41b30196a2f672aea27dc878d577ab3c46bc0ea502e2a7bddc1840fa5f1f
[INFO] running `"docker" "start" "-a" "1b9f41b30196a2f672aea27dc878d577ab3c46bc0ea502e2a7bddc1840fa5f1f"`
[INFO] [stderr]    Compiling tokio-trace v0.1.0 (/opt/crater/workdir)
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 10.78s
[INFO] running `"docker" "inspect" "1b9f41b30196a2f672aea27dc878d577ab3c46bc0ea502e2a7bddc1840fa5f1f"`
[INFO] running `"docker" "rm" "-f" "1b9f41b30196a2f672aea27dc878d577ab3c46bc0ea502e2a7bddc1840fa5f1f"`
[INFO] [stdout] 1b9f41b30196a2f672aea27dc878d577ab3c46bc0ea502e2a7bddc1840fa5f1f
[INFO] running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.37-6/worker-1/1.36.0:/opt/crater/target:rw,Z" "-v" "/mnt/big/crater/work/ex/beta-1.37-6/sources/1.36.0/reg/tokio-trace/0.1.0:/opt/crater/workdir:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/opt/crater/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/opt/crater/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/opt/crater/workdir" "-e" "MAP_USER_ID=1000" "-e" "CARGO_TARGET_DIR=/opt/crater/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/crater/cargo-home" "-e" "RUSTUP_HOME=/opt/crater/rustup-home" "-w" "/opt/crater/workdir" "-m" "1536M" "--network" "none" "rustops/crates-build-env" "/opt/crater/cargo-home/bin/cargo" "+1.36.0" "test" "--frozen"`
[INFO] [stdout] fba1477a19ffe339e0100a3a0ab5910f8750917265843050d6741a593ce1daae
[INFO] running `"docker" "start" "-a" "fba1477a19ffe339e0100a3a0ab5910f8750917265843050d6741a593ce1daae"`
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.02s
[INFO] [stderr]      Running /opt/crater/target/debug/deps/tokio_trace-da54c8aabeaa0d8e
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stderr]      Running /opt/crater/target/debug/deps/event-9524a9f3d6290582
[INFO] [stdout] 
[INFO] [stdout] running 7 tests
[INFO] [stdout] test move_field_out_of_struct ... ok
[INFO] [stdout] test dotted_field_name ... ok
[INFO] [stdout] test event_without_message ... ok
[INFO] [stdout] test borrowed_field ... ok
[INFO] [stdout] test event_with_message ... ok
[INFO] [stdout] test moved_field ... ok
[INFO] [stdout] test one_with_everything ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stderr]      Running /opt/crater/target/debug/deps/filter_caching_is_lexically_scoped-3c19cac4b3f4abc5
[INFO] [stdout] test filter_caching_is_lexically_scoped ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stderr]      Running /opt/crater/target/debug/deps/filters_are_not_reevaluated_for_the_same_span-603b119eceecd007
[INFO] [stderr]      Running /opt/crater/target/debug/deps/filters_are_reevaluated_for_different_call_sites-470ae7385a5d4b1a
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test filters_are_not_reevaluated_for_the_same_span ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test filters_are_reevaluated_for_different_call_sites ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stderr]      Running /opt/crater/target/debug/deps/macros-80d682fe15fb6c99
[INFO] [stdout] 
[INFO] [stdout] running 25 tests
[INFO] [stdout] test callsite_macro_api ... ok
[INFO] [stdout] test debug ... ok
[INFO] [stdout] test debug_span ... ok
[INFO] [stdout] test event ... ok
[INFO] [stdout] test error_span ... ok
[INFO] [stdout] test error_span_with_parent ... ok
[INFO] [stdout] test info ... ok
[INFO] [stdout] test info_span ... ok
[INFO] [stdout] test debug_span_with_parent ... ok
[INFO] [stdout] test debug_span_root ... ok
[INFO] [stdout] test error_span_root ... ok
[INFO] [stdout] test span ... ok
[INFO] [stdout] test info_span_with_parent ... ok
[INFO] [stdout] test span_root ... ok
[INFO] [stdout] test info_span_root ... ok
[INFO] [stdout] test error ... ok
[INFO] [stdout] test span_with_parent ... ok
[INFO] [stdout] test trace_span_root ... ok
[INFO] [stdout] test trace_span_with_parent ... ok
[INFO] [stdout] test warn ... ok
[INFO] [stdout] test warn_span ... ok
[INFO] [stdout] test warn_span_root ... ok
[INFO] [stdout] test trace ... ok
[INFO] [stdout] test warn_span_with_parent ... ok
[INFO] [stdout] test trace_span ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 25 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 26 tests
[INFO] [stderr]      Running /opt/crater/target/debug/deps/span-977ff3ad81d6e758
[INFO] [stderr]      Running /opt/crater/target/debug/deps/subscriber-2d0dfbb1f6b0f09b
[INFO] [stdout] test contextual_root ... ok
[INFO] [stdout] test contextual_child ... ok
[INFO] [stdout] test add_field_after_new_span ... ok
[INFO] [stdout] test cloning_a_span_calls_clone_span ... ok
[INFO] [stdout] test clone_and_drop_span_always_go_to_the_subscriber_that_tagged_the_span ... ok
[INFO] [stdout] test borrowed_field ... ok
[INFO] [stdout] test drop_span_when_exiting_dispatchers_context ... ok
[INFO] [stdout] test dropping_a_span_calls_drop_span ... ok
[INFO] [stdout] test add_fields_only_after_new_span ... ok
[INFO] [stdout] test explicit_child_regardless_of_ctx ... ok
[INFO] [stdout] test event_outside_of_span ... ok
[INFO] [stdout] test explicit_child ... ok
[INFO] [stdout] test dotted_field_name ... ok
[INFO] [stdout] test handles_to_different_spans_are_not_equal ... ok
[INFO] [stdout] test explicit_root_span_is_root ... ok
[INFO] [stdout] test explicit_root_span_is_root_regardless_of_ctx ... ok
[INFO] [stdout] test handles_to_different_spans_with_the_same_metadata_are_not_equal ... ok
[INFO] [stdout] test handles_to_the_same_span_are_equal ... ok
[INFO] [stdout] test move_field_out_of_struct ... ok
[INFO] [stdout] test moved_field ... ok
[INFO] [stdout] test new_span_after_event ... ok
[INFO] [stdout] test new_span_with_target_and_log_level ... ok
[INFO] [stdout] test span_closes_after_event ... ok
[INFO] [stdout] test span_closes_when_exited ... ok
[INFO] [stdout] test spans_always_go_to_the_subscriber_that_tagged_them ... ok
[INFO] [stdout] enter: foo; id=Id(1);
[INFO] [stdout] exit: foo; id=Id(1);
[INFO] [stdout] drop_span: foo; id=Id(1); refs=1;
[INFO] [stdout] test spans_always_go_to_the_subscriber_that_tagged_them_even_across_threads ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 26 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test event_macros_dont_infinite_loop ... ok
[INFO] [stderr]    Doc-tests tokio-trace
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 33 tests
[INFO] [stdout] test src/lib.rs -  (line 217) ... ok
[INFO] [stdout] test src/lib.rs -  (line 246) ... ok
[INFO] [stdout] test src/lib.rs -  (line 227) ... ok
[INFO] [stdout] test src/lib.rs -  (line 111) ... ok
[INFO] [stdout] test src/lib.rs -  (line 323) ... ok
[INFO] [stdout] test src/lib.rs -  (line 126) ... ok
[INFO] [stdout] test src/lib.rs -  (line 264) ... ok
[INFO] [stdout] test src/lib.rs -  (line 157) ... ok
[INFO] [stdout] test src/lib.rs -  (line 40) ... ok
[INFO] [stdout] test src/macros.rs - debug_span (line 320) ... ok
[INFO] [stdout] test src/lib.rs -  (line 61) ... ok
[INFO] [stdout] test src/macros.rs - event (line 702) ... ok
[INFO] [stdout] test src/lib.rs -  (line 85) ... ok
[INFO] [stdout] test src/macros.rs - debug (line 916) ... ok
[INFO] [stdout] test src/macros.rs - error_span (line 586) ... ok
[INFO] [stdout] test src/macros.rs - error (line 1156) ... ok
[INFO] [stdout] test src/macros.rs - event (line 713) ... ok
[INFO] [stdout] test src/macros.rs - event (line 675) ... ok
[INFO] [stdout] test src/macros.rs - span (line 31) ... ok
[INFO] [stdout] test src/macros.rs - span (line 19) ... ok
[INFO] [stdout] test src/macros.rs - span (line 73) ... ok
[INFO] [stdout] test src/macros.rs - info (line 990) ... ok
[INFO] [stdout] test src/macros.rs - span (line 6) ... ok
[INFO] [stdout] test src/macros.rs - info_span (line 409) ... ok
[INFO] [stdout] test src/macros.rs - span (line 62) ... ok
[INFO] [stdout] test src/macros.rs - span (line 46) ... ok
[INFO] [stdout] test src/macros.rs - warn_span (line 498) ... ok
[INFO] [stdout] test src/macros.rs - trace_span (line 231) ... ok
[INFO] [stdout] test src/macros.rs - warn (line 1075) ... ok
[INFO] [stdout] test src/macros.rs - trace (line 825) ... ok
[INFO] [stdout] test src/span.rs - span (line 37) ... ok
[INFO] [stdout] test src/span.rs - span (line 79) ... ok
[INFO] [stdout] test src/span.rs - span (line 13) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 33 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
[INFO] [stdout] 
[INFO] running `"docker" "inspect" "fba1477a19ffe339e0100a3a0ab5910f8750917265843050d6741a593ce1daae"`
[INFO] running `"docker" "rm" "-f" "fba1477a19ffe339e0100a3a0ab5910f8750917265843050d6741a593ce1daae"`
[INFO] [stdout] fba1477a19ffe339e0100a3a0ab5910f8750917265843050d6741a593ce1daae