Dec 03 12:07:08.294 INFO testing ffizer-0.3.0 against 1.30.1 for beta-1.31-5
Dec 03 12:07:08.294 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-5/1.30.1:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/beta-1.31-5/1.30.1:/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 +1.30.1 build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 12:07:08.715 INFO [stdout] 1750e48c3e018d10fea4f0180714ba60cb5d024079a96daa300465599e2ec871
Dec 03 12:07:08.717 INFO running `"docker" "start" "-a" "1750e48c3e018d10fea4f0180714ba60cb5d024079a96daa300465599e2ec871"`
Dec 03 12:07:11.018 INFO [stderr] usermod: no changes
Dec 03 12:07:11.417 INFO [stderr]    Compiling slog-async v2.3.0
Dec 03 12:07:11.417 INFO [stderr]    Compiling slog-term v2.4.0
Dec 03 12:07:11.487 INFO [stderr]    Compiling handlebars v1.1.0
Dec 03 12:07:24.960 INFO [stderr]    Compiling ffizer v0.3.0 (/source)
Dec 03 12:07:47.570 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 36.52s
Dec 03 12:07:47.587 INFO [stderr] su: No module specific data is present
Dec 03 12:07:48.651 INFO running `"docker" "inspect" "1750e48c3e018d10fea4f0180714ba60cb5d024079a96daa300465599e2ec871"`
Dec 03 12:07:48.883 INFO running `"docker" "rm" "-f" "1750e48c3e018d10fea4f0180714ba60cb5d024079a96daa300465599e2ec871"`
Dec 03 12:07:49.188 INFO [stdout] 1750e48c3e018d10fea4f0180714ba60cb5d024079a96daa300465599e2ec871
Dec 03 12:07:49.193 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-5/1.30.1:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/beta-1.31-5/1.30.1:/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 +1.30.1 test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 12:07:49.555 INFO [stdout] 1123649f82715f1774b154ec08d9477f7c9fc6efb974f998319ab4df5f63ff3f
Dec 03 12:07:49.559 INFO running `"docker" "start" "-a" "1123649f82715f1774b154ec08d9477f7c9fc6efb974f998319ab4df5f63ff3f"`
Dec 03 12:07:50.580 INFO [stderr] usermod: no changes
Dec 03 12:07:50.855 INFO [stderr]    Compiling ffizer v0.3.0 (/source)
Dec 03 12:08:10.694 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 20.07s
Dec 03 12:08:10.713 INFO [stderr] su: No module specific data is present
Dec 03 12:08:11.020 INFO running `"docker" "inspect" "1123649f82715f1774b154ec08d9477f7c9fc6efb974f998319ab4df5f63ff3f"`
Dec 03 12:08:11.105 INFO running `"docker" "rm" "-f" "1123649f82715f1774b154ec08d9477f7c9fc6efb974f998319ab4df5f63ff3f"`
Dec 03 12:08:11.239 INFO [stdout] 1123649f82715f1774b154ec08d9477f7c9fc6efb974f998319ab4df5f63ff3f
Dec 03 12:08:11.241 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-5/1.30.1:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/beta-1.31-5/1.30.1:/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 +1.30.1 test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 12:08:11.446 INFO [stdout] 05942c4e64f490daeab27d3b6f693fe0e07c06ac75c42555aa9c6f1db2567ced
Dec 03 12:08:11.448 INFO running `"docker" "start" "-a" "05942c4e64f490daeab27d3b6f693fe0e07c06ac75c42555aa9c6f1db2567ced"`
Dec 03 12:08:11.895 INFO [stderr] usermod: no changes
Dec 03 12:08:12.052 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.14s
Dec 03 12:08:12.072 INFO [stderr]      Running /target/debug/deps/ffizer-032640edbbb2cdbc
Dec 03 12:08:12.074 INFO [stdout] 
Dec 03 12:08:12.074 INFO [stdout] running 7 tests
Dec 03 12:08:12.075 INFO [stdout] test tests::test_is_ffizer_handlebars ... ok
Dec 03 12:08:12.075 INFO [stdout] test tests::test_compute_dst_path_asis ... ok
Dec 03 12:08:12.076 INFO [stdout] test tests::test_compute_dst_path_rendered_filename ... ok
Dec 03 12:08:12.076 INFO [stdout] test tests::test_compute_dst_path_rendered_folder ... ok
Dec 03 12:08:12.082 INFO [stdout] test tests::test_compute_dst_path_ffizer_handlebars ... ok
Dec 03 12:08:12.082 INFO [stderr]      Running /target/debug/deps/ffizer-a9ada7fb2911d8b6
Dec 03 12:08:12.082 INFO [stdout] test tests::test_path_extension_extraction ... ok
Dec 03 12:08:12.082 INFO [stdout] test template_cfg::tests::test_deserialize_cfg_yaml ... ok
Dec 03 12:08:12.082 INFO [stdout] 
Dec 03 12:08:12.082 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:12.082 INFO [stdout] 
Dec 03 12:08:12.084 INFO [stdout] 
Dec 03 12:08:12.084 INFO [stdout] running 0 tests
Dec 03 12:08:12.084 INFO [stdout] 
Dec 03 12:08:12.084 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:12.084 INFO [stdout] 
Dec 03 12:08:12.084 INFO [stderr]      Running /target/debug/deps/dir_diff-021f05dcd62ddfb8
Dec 03 12:08:12.091 INFO [stderr]      Running /target/debug/deps/e2e-cd50d570164c53cc
Dec 03 12:08:12.091 INFO [stdout] 
Dec 03 12:08:12.091 INFO [stdout] running 0 tests
Dec 03 12:08:12.091 INFO [stdout] 
Dec 03 12:08:12.091 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:12.091 INFO [stdout] 
Dec 03 12:08:12.093 INFO [stdout] 
Dec 03 12:08:12.093 INFO [stdout] running 2 tests
Dec 03 12:08:12.096 INFO [stdout] test empty_template ... ok
Dec 03 12:08:12.159 INFO [stdout] test test_1 ... FAILED
Dec 03 12:08:12.159 INFO [stdout] 
Dec 03 12:08:12.159 INFO [stdout] failures:
Dec 03 12:08:12.160 INFO [stdout] 
Dec 03 12:08:12.160 INFO [stdout] ---- test_1 stdout ----
Dec 03 12:08:12.160 INFO [stdout] Plan
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: Keep }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "dir_1", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_1", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: MkDir }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "dir_1/file_1_1.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_1/file_1_1.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "dir_2_{{ project_name }}", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_2_", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: MkDir }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "dir_2_{{ project_name }}/file_1_2.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_2_/file_1_2.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_1.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_1.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_2.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_2.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_2.txt.ffizer.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_2.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: Keep }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_3.txt.ffizer.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_3.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRender }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_4_{{ project_name }}.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_4_.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_5_{{ project_name }}.txt.ffizer.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_5_.txt", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRender }
Dec 03 12:08:12.160 INFO [stdout] Action { src_path: ChildPath { relative: "file_6.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_6.hbs", base: "/tmp/.tmpQ5OvNx", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:12.160 INFO [stdout] thread 'test_1' panicked at 'TODO: RenderError(RenderError { desc: "Variable \"project_name\" not found in strict mode.", template_name: None, line_no: Some(1), column_no: Some(12), cause: None })', libcore/result.rs:1009:5
Dec 03 12:08:12.160 INFO [stdout] stack backtrace:
Dec 03 12:08:12.160 INFO [stdout]    0:     0x562d913fd6de - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h15749a98198ba25f
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 03 12:08:12.160 INFO [stdout]    1:     0x562d913ee066 - std::sys_common::backtrace::print::h0ba65c811294dbf0
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 03 12:08:12.160 INFO [stdout]    2:     0x562d913ec48d - std::panicking::default_hook::{{closure}}::h42bb31757f0fee64
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:211
Dec 03 12:08:12.160 INFO [stdout]    3:     0x562d913ec19b - std::panicking::default_hook::hebc8848d7aa7dbd9
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:221
Dec 03 12:08:12.160 INFO [stdout]    4:     0x562d913ecb3c - std::panicking::rust_panic_with_hook::h86e619a638415243
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:477
Dec 03 12:08:12.160 INFO [stdout]    5:     0x562d913ec6f9 - std::panicking::continue_panic_fmt::h2d2d2bfb065a70b2
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:391
Dec 03 12:08:12.160 INFO [stdout]    6:     0x562d913ec5f5 - rust_begin_unwind
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:326
Dec 03 12:08:12.160 INFO [stdout]    7:     0x562d914441eb - core::panicking::panic_fmt::h2155aa66b67fe83c
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/panicking.rs:77
Dec 03 12:08:12.160 INFO [stdout]    8:     0x562d90dc4583 - core::result::unwrap_failed::h9dd38e7a6b909cfb
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/macros.rs:26
Dec 03 12:08:12.160 INFO [stdout]    9:     0x562d90dc1959 - <core::result::Result<T, E>>::expect::h4946f68945422bea
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/result.rs:835
Dec 03 12:08:12.160 INFO [stdout]   10:     0x562d90db2d44 - ffizer::execute::{{closure}}::had8b8f7a85ab5a0a
Dec 03 12:08:12.160 INFO [stdout]                                at src/lib.rs:186
Dec 03 12:08:12.160 INFO [stdout]   11:     0x562d90dbacf6 - core::iter::iterator::Iterator::for_each::{{closure}}::h61fda7e02d99a700
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/iter/iterator.rs:553
Dec 03 12:08:12.160 INFO [stdout]   12:     0x562d90dbaa84 - core::iter::iterator::Iterator::fold::{{closure}}::ha847615ccdc827e8
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/iter/iterator.rs:1634
Dec 03 12:08:12.160 INFO [stdout]   13:     0x562d90de7ba2 - core::iter::iterator::Iterator::try_fold::h0a5308fda677843b
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/iter/iterator.rs:1522
Dec 03 12:08:12.160 INFO [stdout]   14:     0x562d90de7a70 - core::iter::iterator::Iterator::fold::h235a94639906ab0c
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/iter/iterator.rs:1634
Dec 03 12:08:12.160 INFO [stdout]   15:     0x562d90de7aef - core::iter::iterator::Iterator::for_each::h3c2cc132ebd17c37
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/iter/iterator.rs:553
Dec 03 12:08:12.160 INFO [stdout]   16:     0x562d90db29cf - ffizer::execute::ha212b1714d2062f3
Dec 03 12:08:12.160 INFO [stdout]                                at src/lib.rs:176
Dec 03 12:08:12.160 INFO [stdout]   17:     0x562d90db1a12 - ffizer::process::hd38bc385846e9596
Dec 03 12:08:12.160 INFO [stdout]                                at src/lib.rs:101
Dec 03 12:08:12.160 INFO [stdout]   18:     0x562d90d60563 - e2e::test_1::hf892362e9c108ad4
Dec 03 12:08:12.160 INFO [stdout]                                at tests/e2e.rs:59
Dec 03 12:08:12.160 INFO [stdout]   19:     0x562d90d5fe4d - e2e::test_1::{{closure}}::ha9bfd9f3757134c5
Dec 03 12:08:12.160 INFO [stdout]                                at tests/e2e.rs:40
Dec 03 12:08:12.160 INFO [stdout]   20:     0x562d90d6221d - core::ops::function::FnOnce::call_once::hfae113132388a9cb
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 03 12:08:12.160 INFO [stdout]   21:     0x562d90d6525e - <F as alloc::boxed::FnBox<A>>::call_box::hbea525814fa423cc
Dec 03 12:08:12.160 INFO [stdout]                                at libtest/lib.rs:1461
Dec 03 12:08:12.160 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 03 12:08:12.160 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 03 12:08:12.160 INFO [stdout]   22:     0x562d9140df19 - __rust_maybe_catch_panic
Dec 03 12:08:12.160 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 03 12:08:12.160 INFO [stdout]   23:     0x562d90d70bbd - std::sys_common::backtrace::__rust_begin_short_backtrace::h0ff507d7422944d3
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:289
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panic.rs:392
Dec 03 12:08:12.160 INFO [stdout]                                at libtest/lib.rs:1416
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 03 12:08:12.160 INFO [stdout]   24:     0x562d90d891f4 - std::panicking::try::do_call::hba0bdcc3670471cc
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panic.rs:313
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:310
Dec 03 12:08:12.160 INFO [stdout]   25:     0x562d9140df19 - __rust_maybe_catch_panic
Dec 03 12:08:12.160 INFO [stdout]                                at libpanic_unwind/lib.rs:103
Dec 03 12:08:12.160 INFO [stdout]   26:     0x562d90d79ac6 - <F as alloc::boxed::FnBox<A>>::call_box::hdac52587b00591af
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panicking.rs:289
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/panic.rs:392
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 03 12:08:12.160 INFO [stdout]                                at liballoc/boxed.rs:646
Dec 03 12:08:12.160 INFO [stdout]   27:     0x562d913ff0aa - std::sys_common::thread::start_thread::h75d887c7d2cc4479
Dec 03 12:08:12.160 INFO [stdout]                                at liballoc/boxed.rs:656
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 03 12:08:12.160 INFO [stdout]   28:     0x562d913ed2a5 - std::sys::unix::thread::Thread::new::thread_start::h8414caee632bf9ed
Dec 03 12:08:12.160 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 03 12:08:12.160 INFO [stdout]   29:     0x7f2f6a07b6b9 - start_thread
Dec 03 12:08:12.160 INFO [stdout]   30:     0x7f2f6a59c41c - clone
Dec 03 12:08:12.160 INFO [stdout]   31:                0x0 - <unknown>
Dec 03 12:08:12.160 INFO [stdout] 
Dec 03 12:08:12.160 INFO [stdout] 
Dec 03 12:08:12.160 INFO [stdout] failures:
Dec 03 12:08:12.160 INFO [stdout]     test_1
Dec 03 12:08:12.160 INFO [stdout] 
Dec 03 12:08:12.161 INFO [stdout] test result: FAILED. 1 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:12.161 INFO [stdout] 
Dec 03 12:08:12.163 INFO [stderr] error: test failed, to rerun pass '--test e2e'
Dec 03 12:08:12.165 INFO [stderr] su: No module specific data is present
Dec 03 12:08:12.459 INFO running `"docker" "inspect" "05942c4e64f490daeab27d3b6f693fe0e07c06ac75c42555aa9c6f1db2567ced"`
Dec 03 12:08:12.584 INFO running `"docker" "rm" "-f" "05942c4e64f490daeab27d3b6f693fe0e07c06ac75c42555aa9c6f1db2567ced"`
Dec 03 12:08:12.679 INFO [stdout] 05942c4e64f490daeab27d3b6f693fe0e07c06ac75c42555aa9c6f1db2567ced
