Dec 06 04:51:11.422 INFO testing brocode/fw against master#906deae0790bd18681b937fe9a141a3c26cf1855 for pr-56514
Dec 06 04:51:11.422 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 06 04:51:11.919 INFO [stdout] b9c681b12ac0013e8a7f8e879e42271e74d4581ec3028f3ffc317bd3ed5ae3f0
Dec 06 04:51:11.921 INFO running `"docker" "start" "-a" "b9c681b12ac0013e8a7f8e879e42271e74d4581ec3028f3ffc317bd3ed5ae3f0"`
Dec 06 04:51:13.860 INFO [stderr] usermod: no changes
Dec 06 04:51:14.446 INFO [stderr]    Compiling tokio-threadpool v0.1.8
Dec 06 04:51:14.449 INFO [stderr]    Compiling curl-sys v0.4.15
Dec 06 04:51:14.458 INFO [stderr]    Compiling rayon v0.8.2
Dec 06 04:51:14.462 INFO [stderr]    Compiling slog-term v2.4.0
Dec 06 04:51:14.464 INFO [stderr]    Compiling error-chain v0.11.0
Dec 06 04:51:14.472 INFO [stderr]    Compiling crossbeam-channel v0.3.1
Dec 06 04:51:14.483 INFO [stderr]    Compiling console v0.6.2
Dec 06 04:51:17.057 INFO [stderr]    Compiling libgit2-sys v0.7.10
Dec 06 04:51:24.352 INFO [stderr]    Compiling git2 v0.7.5
Dec 06 04:51:24.368 INFO [stderr]    Compiling indicatif v0.9.0
Dec 06 04:51:24.584 INFO [stderr]    Compiling crossbeam v0.5.0
Dec 06 04:51:24.609 INFO [stderr]    Compiling tokio-fs v0.1.4
Dec 06 04:51:25.715 INFO [stderr]    Compiling ring v0.12.1
Dec 06 04:51:31.170 INFO [stderr]    Compiling tokio v0.1.11
Dec 06 04:51:40.689 INFO [stderr]    Compiling tokio-core v0.1.17
Dec 06 04:51:45.000 INFO [stderr]    Compiling sct v0.2.0
Dec 06 04:51:45.000 INFO [stderr]    Compiling webpki v0.17.0
Dec 06 04:51:46.300 INFO [stderr]    Compiling ct-logs v0.2.0
Dec 06 04:51:47.889 INFO [stderr]    Compiling rustls v0.11.0
Dec 06 04:51:47.889 INFO [stderr]    Compiling webpki-roots v0.13.0
Dec 06 04:51:48.776 INFO [stderr]    Compiling tokio-proto v0.1.1
Dec 06 04:51:53.591 INFO [stderr]    Compiling hyper v0.11.27
Dec 06 04:51:58.924 INFO [stderr]    Compiling tokio-rustls v0.4.0
Dec 06 04:52:07.140 INFO [stderr]    Compiling hyper-rustls v0.11.0
Dec 06 04:52:10.996 INFO [stderr]    Compiling github-gql-rs v0.0.1
Dec 06 04:52:14.995 INFO [stderr]    Compiling fw v1.16.1-alpha.0 (/source)
Dec 06 04:52:35.012 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1m 21s
Dec 06 04:52:35.038 INFO [stderr] su: No module specific data is present
Dec 06 04:52:36.293 INFO running `"docker" "inspect" "b9c681b12ac0013e8a7f8e879e42271e74d4581ec3028f3ffc317bd3ed5ae3f0"`
Dec 06 04:52:36.586 INFO running `"docker" "rm" "-f" "b9c681b12ac0013e8a7f8e879e42271e74d4581ec3028f3ffc317bd3ed5ae3f0"`
Dec 06 04:52:36.971 INFO [stdout] b9c681b12ac0013e8a7f8e879e42271e74d4581ec3028f3ffc317bd3ed5ae3f0
Dec 06 04:52:36.974 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 06 04:52:37.417 INFO [stdout] 02e90126ebafba2b33eac6bf2fe905655c33c346f1e6b14ca66e283d06953926
Dec 06 04:52:37.422 INFO running `"docker" "start" "-a" "02e90126ebafba2b33eac6bf2fe905655c33c346f1e6b14ca66e283d06953926"`
Dec 06 04:52:38.733 INFO [stderr] usermod: no changes
Dec 06 04:52:39.084 INFO [stderr]    Compiling fw v1.16.1-alpha.0 (/source)
Dec 06 04:52:54.468 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 15.69s
Dec 06 04:52:54.492 INFO [stderr] su: No module specific data is present
Dec 06 04:52:55.203 INFO running `"docker" "inspect" "02e90126ebafba2b33eac6bf2fe905655c33c346f1e6b14ca66e283d06953926"`
Dec 06 04:52:55.414 INFO running `"docker" "rm" "-f" "02e90126ebafba2b33eac6bf2fe905655c33c346f1e6b14ca66e283d06953926"`
Dec 06 04:52:55.920 INFO [stdout] 02e90126ebafba2b33eac6bf2fe905655c33c346f1e6b14ca66e283d06953926
Dec 06 04:52:55.922 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-3/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-3/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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 06 04:52:56.354 INFO [stdout] cdabcfbd7ad08f68f2a90c3484cc7f77976126301bc52e8e8676d32039ba54e5
Dec 06 04:52:56.362 INFO running `"docker" "start" "-a" "cdabcfbd7ad08f68f2a90c3484cc7f77976126301bc52e8e8676d32039ba54e5"`
Dec 06 04:52:57.412 INFO [stderr] usermod: no changes
Dec 06 04:52:57.764 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.31s
Dec 06 04:52:57.777 INFO [stderr]      Running /target/debug/deps/fw-bc46f4938fc3af55
Dec 06 04:52:57.868 INFO [stdout] 
Dec 06 04:52:57.868 INFO [stdout] running 19 tests
Dec 06 04:52:57.898 INFO [stdout] Dec 06 04:52:57.896 TRCE Resolving, tags: Some({"tag-does-not-exist", "tag1"})
Dec 06 04:52:57.898 INFO [stdout] Dec 06 04:52:57.896 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist", "tag1"})
Dec 06 04:52:57.898 INFO [stdout] Dec 06 04:52:57.896 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.898 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.898 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.898 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone1"), after_workon: Some("workon1"), priority: None, workspace: None }, tag_name: tag1
Dec 06 04:52:57.898 INFO [stdout] Dec 06 04:52:57.896 TRCE before sort, tags: [("clone1", 50)]
Dec 06 04:52:57.899 INFO [stdout] Dec 06 04:52:57.896 TRCE after sort, tags: [("clone1", 50)]
Dec 06 04:52:57.899 INFO [stdout] Dec 06 04:52:57.896 TRCE Resolving, tags: Some({"tag1", "tag2"})
Dec 06 04:52:57.899 INFO [stdout] Dec 06 04:52:57.896 TRCE Resolving, tags: Some({"tag1"})
Dec 06 04:52:57.899 INFO [stdout] Dec 06 04:52:57.896 TRCE Resolving, tags: Some({"tag-does-not-exist"})
Dec 06 04:52:57.899 INFO [stdout] Dec 06 04:52:57.897 TRCE Resolving, tags: Some({"tag3", "tag4"})
Dec 06 04:52:57.904 INFO [stdout] test config::tests::test_do_expand_path ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_after_clone_from_tags_missing_one_tag_graceful ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone1"), after_workon: Some("workon1"), priority: None, workspace: None }, tag_name: tag1
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone2"), after_workon: Some("workon2"), priority: None, workspace: None }, tag_name: tag2
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 TRCE before sort, tags: [("clone1", 50), ("clone2", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 TRCE after sort, tags: [("clone1", 50), ("clone2", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 TRCE before sort, tags: [("clone3", 100), ("clone4", 0)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 TRCE after sort, tags: [("clone4", 0), ("clone3", 100)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone1"), after_workon: Some("workon1"), priority: None, workspace: None }, tag_name: tag1
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE before sort, tags: [("clone1", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE after sort, tags: [("clone1", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.897 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE before sort, tags: []
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE after sort, tags: []
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_after_clone_from_tags ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_after_clone_from_tags_prioritized ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_after_clone_override_from_project ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE Resolving, tags: Some({"tag1", "tag2"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone1"), after_workon: Some("workon1"), priority: None, workspace: None }, tag_name: tag1
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone2"), after_workon: Some("workon2"), priority: None, workspace: None }, tag_name: tag2
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE before sort, tags: [("workon1", 50), ("workon2", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.898 TRCE after sort, tags: [("workon1", 50), ("workon2", 50)]
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_after_clone_from_tags_missing_all_tags_graceful ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_workon_from_tags ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_repo_name_from_url ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_repo_name_from_ssh_pragma_with_multiple_git_endings ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.899 TRCE Resolving, tags: Some({"tag-does-not-exist"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.899 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.899 TRCE before sort, tags: []
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.899 TRCE after sort, tags: []
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_workon_from_tags_missing_all_tags_graceful ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 TRCE Resolving, tags: Some({"tag3", "tag4"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 TRCE before sort, tags: [("workon3", 100), ("workon4", 0)]
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_do_not_expand_path_without_tilde ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 TRCE after sort, tags: [("workon4", 0), ("workon3", 100)]
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_repo_name_from_ssh_pragma ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_workon_from_tags_prioritized ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 TRCE Resolving, tags: Some({"tag-does-not-exist", "tag1"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 TRCE Resolving, tags: Some({"tag1"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist", "tag1"})
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.900 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone1"), after_workon: Some("workon1"), priority: None, workspace: None }, tag_name: tag1
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.901 DEBG No tag priority set, will use default (50).
Dec 06 04:52:57.905 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Dec 06 04:52:57.905 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Dec 06 04:52:57.905 INFO [stdout] conscious choice and set the value., tag_def: Tag { after_clone: Some("clone1"), after_workon: Some("workon1"), priority: None, workspace: None }, tag_name: tag1
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.901 TRCE before sort, tags: [("workon1", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.901 TRCE before sort, tags: [("workon1", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.901 TRCE after sort, tags: [("workon1", 50)]
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.901 TRCE after sort, tags: [("workon1", 50)]
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_workon_override_from_project ... ok
Dec 06 04:52:57.905 INFO [stdout] test config::tests::test_workon_from_tags_missing_one_tag_graceful ... ok
Dec 06 04:52:57.905 INFO [stdout] test export::tests::test_workon_override_from_project ... ok
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.901 DEBG Writing projectile entry, entry: /home/mriehl/test
Dec 06 04:52:57.905 INFO [stdout] Dec 06 04:52:57.902 DEBG Writing projectile entry, entry: /home/mriehl/go/src/github.com/test2
Dec 06 04:52:57.905 INFO [stdout] test projectile::tests::test_persists_projectile_config ... ok
Dec 06 04:52:57.905 INFO [stdout] test projectile::tests::test_replace_path_with_tilde ... ok
Dec 06 04:52:57.928 INFO [stdout] test sync::tests::test_username_from_git_url ... ok
Dec 06 04:52:57.928 INFO [stdout] 
Dec 06 04:52:57.928 INFO [stdout] test result: ok. 19 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 06 04:52:57.928 INFO [stdout] 
Dec 06 04:52:57.939 INFO [stderr] su: No module specific data is present
Dec 06 04:52:58.674 INFO running `"docker" "inspect" "cdabcfbd7ad08f68f2a90c3484cc7f77976126301bc52e8e8676d32039ba54e5"`
Dec 06 04:52:58.960 INFO running `"docker" "rm" "-f" "cdabcfbd7ad08f68f2a90c3484cc7f77976126301bc52e8e8676d32039ba54e5"`
Dec 06 04:52:59.184 INFO [stdout] cdabcfbd7ad08f68f2a90c3484cc7f77976126301bc52e8e8676d32039ba54e5