[INFO] fetching crate expectrl 0.6.0...
[INFO] testing expectrl-0.6.0 against try#015dbcea68b7642e2acc268b5c8f3e9086fc02ff for pr-102570
[INFO] extracting crate expectrl 0.6.0 into /workspace/builds/worker-2/source
[INFO] validating manifest of crates.io crate expectrl 0.6.0 on toolchain 015dbcea68b7642e2acc268b5c8f3e9086fc02ff
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+015dbcea68b7642e2acc268b5c8f3e9086fc02ff" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] started tweaking crates.io crate expectrl 0.6.0
[INFO] finished tweaking crates.io crate expectrl 0.6.0
[INFO] tweaked toml for crates.io crate expectrl 0.6.0 written to /workspace/builds/worker-2/source/Cargo.toml
[INFO] crate crates.io crate expectrl 0.6.0 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+015dbcea68b7642e2acc268b5c8f3e9086fc02ff" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:bb5b0feb4f87116a4ea905b7ff5bf5b85913db05e9f0fbc1abdd3168928d9075" "/opt/rustwide/cargo-home/bin/cargo" "+015dbcea68b7642e2acc268b5c8f3e9086fc02ff" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 6b91bec2b2ce4d349c821a247fab221f49fa54d77f46587ef4ec4618709400c3
[INFO] running `Command { std: "docker" "start" "-a" "6b91bec2b2ce4d349c821a247fab221f49fa54d77f46587ef4ec4618709400c3", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "6b91bec2b2ce4d349c821a247fab221f49fa54d77f46587ef4ec4618709400c3", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "6b91bec2b2ce4d349c821a247fab221f49fa54d77f46587ef4ec4618709400c3", kill_on_drop: false }`
[INFO] [stdout] 6b91bec2b2ce4d349c821a247fab221f49fa54d77f46587ef4ec4618709400c3
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:bb5b0feb4f87116a4ea905b7ff5bf5b85913db05e9f0fbc1abdd3168928d9075" "/opt/rustwide/cargo-home/bin/cargo" "+015dbcea68b7642e2acc268b5c8f3e9086fc02ff" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 2ca0d9e92b008d3df91c79459d2082de230f336adbcba64a43cf0a2a08146334
[INFO] running `Command { std: "docker" "start" "-a" "2ca0d9e92b008d3df91c79459d2082de230f336adbcba64a43cf0a2a08146334", kill_on_drop: false }`
[INFO] [stderr]    Compiling autocfg v1.1.0
[INFO] [stderr]    Compiling libc v0.2.133
[INFO] [stderr]    Compiling bitflags v1.2.1
[INFO] [stderr]    Compiling memchr v2.5.0
[INFO] [stderr]    Compiling cfg-if v1.0.0
[INFO] [stderr]    Compiling pin-utils v0.1.0
[INFO] [stderr]    Compiling regex-syntax v0.6.27
[INFO] [stderr]    Compiling memoffset v0.6.5
[INFO] [stderr]    Compiling aho-corasick v0.7.18
[INFO] [stderr]    Compiling nix v0.21.2
[INFO] [stderr]    Compiling nix v0.25.0
[INFO] [stderr]    Compiling regex v1.6.0
[INFO] [stderr]    Compiling ptyprocess v0.3.0
[INFO] [stderr]    Compiling expectrl v0.6.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 20.74s
[INFO] running `Command { std: "docker" "inspect" "2ca0d9e92b008d3df91c79459d2082de230f336adbcba64a43cf0a2a08146334", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "2ca0d9e92b008d3df91c79459d2082de230f336adbcba64a43cf0a2a08146334", kill_on_drop: false }`
[INFO] [stdout] 2ca0d9e92b008d3df91c79459d2082de230f336adbcba64a43cf0a2a08146334
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:bb5b0feb4f87116a4ea905b7ff5bf5b85913db05e9f0fbc1abdd3168928d9075" "/opt/rustwide/cargo-home/bin/cargo" "+015dbcea68b7642e2acc268b5c8f3e9086fc02ff" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] caa0c7228d35fba371e1776f428d35bd7d80d4209027dd2dab19d77b349b858e
[INFO] running `Command { std: "docker" "start" "-a" "caa0c7228d35fba371e1776f428d35bd7d80d4209027dd2dab19d77b349b858e", kill_on_drop: false }`
[INFO] [stderr]    Compiling expectrl v0.6.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 16.20s
[INFO] running `Command { std: "docker" "inspect" "caa0c7228d35fba371e1776f428d35bd7d80d4209027dd2dab19d77b349b858e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "caa0c7228d35fba371e1776f428d35bd7d80d4209027dd2dab19d77b349b858e", kill_on_drop: false }`
[INFO] [stdout] caa0c7228d35fba371e1776f428d35bd7d80d4209027dd2dab19d77b349b858e
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:bb5b0feb4f87116a4ea905b7ff5bf5b85913db05e9f0fbc1abdd3168928d9075" "/opt/rustwide/cargo-home/bin/cargo" "+015dbcea68b7642e2acc268b5c8f3e9086fc02ff" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] f7d4bb119660fb56832e95a67cd6d68f57849f83fee9c2849ed1376c05e91759
[INFO] running `Command { std: "docker" "start" "-a" "f7d4bb119660fb56832e95a67cd6d68f57849f83fee9c2849ed1376c05e91759", kill_on_drop: false }`
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 0.05s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/expectrl-02105e7665a87d70)
[INFO] [stdout] 
[INFO] [stdout] running 23 tests
[INFO] [stdout] test captures::tests::test_captures_get ... ok
[INFO] [stdout] test captures::tests::test_captures_index ... ok
[INFO] [stdout] test captures::tests::test_before ... ok
[INFO] [stdout] test captures::tests::test_captures_matches ... ok
[INFO] [stdout] test captures::tests::test_captures_into_iter ... ok
[INFO] [stdout] test check_macros::tests::test_check ... ignored, Testing in compile time
[INFO] [stdout] test captures::tests::test_matches ... ok
[INFO] [stdout] test needle::tests::test_any ... ok
[INFO] [stdout] test needle::tests::test_byte ... ok
[INFO] [stdout] test needle::tests::test_bytes ... ok
[INFO] [stdout] test needle::tests::test_bytes_ref ... ok
[INFO] [stdout] test needle::tests::test_char ... ok
[INFO] [stdout] test needle::tests::test_eof ... ok
[INFO] [stdout] test needle::tests::test_n_bytes ... ok
[INFO] [stdout] test needle::tests::test_str ... ok
[INFO] [stdout] test process::unix::tests::test_tokenize_command ... ok
[INFO] [stdout] test captures::tests::test_captures_get_panics_on_invalid_match - should panic ... ok
[INFO] [stdout] test captures::tests::test_captures_index_panics_on_empty_match - should panic ... ok
[INFO] [stdout] test captures::tests::test_captures_index_panics_on_invalid_match - should panic ... ok
[INFO] [stdout] test captures::tests::test_captures_index_panics_on_invalid_index - should panic ... ok
[INFO] [stdout] test captures::tests::test_captures_into_iter_panics_on_invalid_match - should panic ... ok
[INFO] [stdout] test captures::tests::test_captures_index_panics_on_empty_captures - should panic ... ok
[INFO] [stdout] test needle::tests::test_regex ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 22 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 0.18s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/check.rs (/opt/rustwide/target/debug/deps/check-38a1e22c705f7874)
[INFO] [stdout] 
[INFO] [stdout] running 10 tests
[INFO] [stdout] test check_eof_timeout ... ok
[INFO] [stdout] test check_eof ... ok
[INFO] [stdout] test check_macro_eof ... ok
[INFO] [stdout] test check_macro_doest_consume_missmatch ... ok
[INFO] [stdout] test check_n_bytes ... ok
[INFO] [stdout] test check_regex ... ok
[INFO] [stdout] test check_macro ... ok
[INFO] [stdout] test check_str ... ok
[INFO] [stdout] test check_macro_with_different_needles ... ok
[INFO] [stdout] test read_after_check_str ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 10 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 7.06s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/expect.rs (/opt/rustwide/target/debug/deps/expect-39d44c4696c9de5c)
[INFO] [stdout] 
[INFO] [stdout] running 7 tests
[INFO] [stdout] test expect_eof ... ok
[INFO] [stdout] test expect_eof_timeout ... ok
[INFO] [stdout] test expect_regex_lazy ... ok
[INFO] [stdout] test expect_n_bytes ... ok
[INFO] [stdout] test expect_str ... ok
[INFO] [stdout] test read_after_expect_str ... ok
[INFO] [stdout] test expect_regex ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 4.49s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/interact.rs (/opt/rustwide/target/debug/deps/interact-2139c881fc060460)
[INFO] [stdout] 
[INFO] [stdout] running 7 tests
[INFO] [stdout] test interact_callback ... ignored, It requires manual interaction; Or it's necessary to redirect an stdin of current process
[INFO] [stdout] test interact_output_callback ... ok
[INFO] [stdout] test interact_callbacks_called_after_exit ... ok
[INFO] [stdout] test interact_filters ... ok
[INFO] [stdout] test interact_on_output_not_matched ... ok
[INFO] [stdout] test interact_callbacks_with_stream_redirection ... ok
[INFO] [stdout] test interact_context ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 6 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 6.63s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/io.rs (/opt/rustwide/target/debug/deps/io-87c026479aea1dc9)
[INFO] [stdout] 
[INFO] [stdout] running 13 tests
[INFO] [stdout] test blocking_read_after_non_blocking ... ok
[INFO] [stdout] test send ... ok
[INFO] [stdout] test send_line ... ok
[INFO] [stdout] test read_line_test ... ok
[INFO] [stdout] test blocking_read_after_non_blocking_try_read ... ok
[INFO] [stdout] test send_controll ... ok
[INFO] [stdout] test try_read_after_process_exit ... ok
[INFO] [stdout] test try_read ... ok
[INFO] [stdout] test try_read_to_end ... ok
[INFO] [stdout] test automatic_stop_of_interact ... ok
[INFO] [stdout] test spawn_after_interact ... ok
[INFO] [stdout] test try_read_by_byte ... ok
[INFO] [stdout] test try_read_after_eof ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 13 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 9.45s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/is_matched.rs (/opt/rustwide/target/debug/deps/is_matched-083ba0620cadab63)
[INFO] [stdout] 
[INFO] [stdout] running 7 tests
[INFO] [stdout] test expect_after_is_matched_eof ... ok
[INFO] [stdout] test check_after_is_matched_eof ... ok
[INFO] [stdout] test is_matched_eof ... ok
[INFO] [stdout] test read_after_is_matched ... ok
[INFO] [stdout] test is_matched_regex ... ok
[INFO] [stdout] test is_matched_str ... ok
[INFO] [stdout] test is_matched_bytes ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 4.09s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/log.rs (/opt/rustwide/target/debug/deps/log-5c6c3b6751b529f6)
[INFO] [stdout] 
[INFO] [stdout] running 2 tests
[INFO] [stdout] test log_read_line ... ok
[INFO] [stderr]      Running tests/repl.rs (/opt/rustwide/target/debug/deps/repl-44731ed9da491142)
[INFO] [stdout] test log ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.52s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 5 tests
[INFO] [stdout] test bash_pwd ... ok
[INFO] [stderr] write: "echo Hello World\n"
[INFO] [stderr] read: "Hello World\r\nEXPECT_PROMPT"
[INFO] [stdout] test bash ... ok
[INFO] [stderr] write: "\u{4}"
[INFO] [stdout] test bash_with_log ... ok
[INFO] [stdout] test python ... ok
[INFO] [stdout] test bash_control_chars ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.26s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/session.rs (/opt/rustwide/target/debug/deps/session-bdb760af0fd05478)
[INFO] [stdout] 
[INFO] [stdout] running 5 tests
[INFO] [stdout] test test_session_as_writer ... ignored, it's a compile time check
[INFO] [stdout] test test_spawn_no_command ... ok
[INFO] [stdout] test send_line ... ok
[INFO] [stdout] test send ... ok
[INFO] [stderr]    Doc-tests expectrl
[INFO] [stdout] test send_multiline ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 4 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 1.92s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 19 tests
[INFO] [stdout] test src/lib.rs - (line 36) ... ignored
[INFO] [stdout] test src/lib.rs - (line 58) ... ignored
[INFO] [stdout] test src/lib.rs - (line 71) ... ignored
[INFO] [stdout] test src/lib.rs - (line 87) ... ignored
[INFO] [stdout] test src/lib.rs - (line 96) ... ignored
[INFO] [stdout] test src/lib.rs - spawn (line 145) ... ignored
[INFO] [stdout] test src/needle.rs - needle::Any (line 152) ... ignored
[INFO] [stdout] test src/needle.rs - needle::Any (line 161) ... ignored
[INFO] [stdout] test src/session/mod.rs - session (line 10) ... ignored
[INFO] [stdout] test src/check_macros.rs - check_macros::check (line 15) - compile ... ok
[INFO] [stdout] test src/session/mod.rs - session::Session::spawn (line 70) - compile ... ok
[INFO] [stdout] test src/session/mod.rs - session::Session<P,S>::interact (line 166) - compile ... ok
[INFO] [stdout] test src/session/mod.rs - session::Session<P,S>::with_log (line 109) - compile ... ok
[INFO] [stdout] test src/interact/mod.rs - interact (line 3) - compile ... ok
[INFO] [stdout] test src/session/sync_session.rs - session::sync_session::Session<P,S>::send_control (line 368) ... ok
[INFO] [stdout] test src/session/sync_session.rs - session::sync_session::Session<P,S>::expect (line 105) ... ok
[INFO] [stdout] test src/session/sync_session.rs - session::sync_session::Session<P,S>::expect (line 99) ... ok
[INFO] [stdout] test src/session/sync_session.rs - session::sync_session::Session<P,S>::check (line 229) ... ok
[INFO] [stdout] test src/session/sync_session.rs - session::sync_session::Session<P,S>::is_matched (line 284) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 10 passed; 0 failed; 9 ignored; 0 measured; 0 filtered out; finished in 5.79s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "f7d4bb119660fb56832e95a67cd6d68f57849f83fee9c2849ed1376c05e91759", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "f7d4bb119660fb56832e95a67cd6d68f57849f83fee9c2849ed1376c05e91759", kill_on_drop: false }`
[INFO] [stdout] f7d4bb119660fb56832e95a67cd6d68f57849f83fee9c2849ed1376c05e91759