Nov 17 07:33:12.660 INFO testing brocode/fw against master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c for pr-55982
Nov 17 07:33:12.660 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-5/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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"`
Nov 17 07:33:13.217 INFO [stdout] 6b660ecd924d90ba1911fb6f9ed709139f74a05db9279ddb25124b6fb5af7007
Nov 17 07:33:13.219 INFO running `"docker" "start" "-a" "6b660ecd924d90ba1911fb6f9ed709139f74a05db9279ddb25124b6fb5af7007"`
Nov 17 07:33:15.467 INFO [stderr] usermod: no changes
Nov 17 07:33:16.026 INFO [stderr]    Compiling gcc v0.3.55
Nov 17 07:33:16.069 INFO [stderr]    Compiling crossbeam-utils v0.6.0
Nov 17 07:33:16.092 INFO [stderr]    Compiling tokio-service v0.1.0
Nov 17 07:33:16.095 INFO [stderr]    Compiling relay v0.1.1
Nov 17 07:33:16.105 INFO [stderr]    Compiling base64 v0.6.0
Nov 17 07:33:16.136 INFO [stderr]    Compiling regex-syntax v0.6.3
Nov 17 07:33:16.139 INFO [stderr]    Compiling want v0.0.4
Nov 17 07:33:16.140 INFO [stderr]    Compiling crossbeam-epoch v0.3.1
Nov 17 07:33:18.510 INFO [stderr]    Compiling chrono v0.4.6
Nov 17 07:33:18.844 INFO [stderr]    Compiling libgit2-sys v0.7.10
Nov 17 07:33:19.757 INFO [stderr]    Compiling crossbeam-epoch v0.6.1
Nov 17 07:33:21.081 INFO [stderr]    Compiling tokio-reactor v0.1.6
Nov 17 07:33:24.468 INFO [stderr]    Compiling crossbeam-deque v0.2.0
Nov 17 07:33:30.210 INFO [stderr]    Compiling rayon-core v1.4.1
Nov 17 07:33:32.208 INFO [stderr]    Compiling crossbeam-deque v0.6.2
Nov 17 07:33:32.576 INFO [stderr]    Compiling crossbeam-channel v0.3.1
Nov 17 07:33:38.438 INFO [stderr]    Compiling tokio-threadpool v0.1.8
Nov 17 07:33:40.909 INFO [stderr]    Compiling tokio-udp v0.1.2
Nov 17 07:33:40.928 INFO [stderr]    Compiling tokio-uds v0.2.3
Nov 17 07:33:41.365 INFO [stderr]    Compiling tokio-tcp v0.1.2
Nov 17 07:33:50.055 INFO [stderr]    Compiling slog-term v2.4.0
Nov 17 07:33:50.796 INFO [stderr]    Compiling crossbeam v0.5.0
Nov 17 07:33:58.671 INFO [stderr]    Compiling rayon v0.8.2
Nov 17 07:34:00.391 INFO [stderr]    Compiling rayon v1.0.3
Nov 17 07:34:04.116 INFO [stderr]    Compiling tokio-fs v0.1.4
Nov 17 07:34:06.787 INFO [stderr]    Compiling regex v1.0.6
Nov 17 07:34:11.283 INFO [stderr]    Compiling tokio v0.1.11
Nov 17 07:34:12.135 INFO [stderr]    Compiling ring v0.12.1
Nov 17 07:34:24.597 INFO [stderr]    Compiling tokio-core v0.1.17
Nov 17 07:34:33.096 INFO [stderr]    Compiling console v0.6.2
Nov 17 07:34:38.063 INFO [stderr]    Compiling tokio-proto v0.1.1
Nov 17 07:34:40.203 INFO [stderr]    Compiling indicatif v0.9.0
Nov 17 07:34:42.647 INFO [stderr]    Compiling webpki v0.17.0
Nov 17 07:34:42.647 INFO [stderr]    Compiling sct v0.2.0
Nov 17 07:34:44.491 INFO [stderr]    Compiling ct-logs v0.2.0
Nov 17 07:34:44.583 INFO [stderr]    Compiling rustls v0.11.0
Nov 17 07:34:44.583 INFO [stderr]    Compiling webpki-roots v0.13.0
Nov 17 07:34:48.003 INFO [stderr]    Compiling hyper v0.11.27
Nov 17 07:34:55.535 INFO [stderr]    Compiling git2 v0.7.5
Nov 17 07:34:56.324 INFO [stderr]    Compiling tokio-rustls v0.4.0
Nov 17 07:35:05.906 INFO [stderr]    Compiling hyper-rustls v0.11.0
Nov 17 07:35:12.427 INFO [stderr]    Compiling github-gql-rs v0.0.1
Nov 17 07:35:16.135 INFO [stderr]    Compiling fw v1.14.1-alpha.0 (/source)
Nov 17 07:35:39.283 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 2m 23s
Nov 17 07:35:39.307 INFO [stderr] su: No module specific data is present
Nov 17 07:35:40.296 INFO running `"docker" "inspect" "6b660ecd924d90ba1911fb6f9ed709139f74a05db9279ddb25124b6fb5af7007"`
Nov 17 07:35:40.603 INFO running `"docker" "rm" "-f" "6b660ecd924d90ba1911fb6f9ed709139f74a05db9279ddb25124b6fb5af7007"`
Nov 17 07:35:40.962 INFO [stdout] 6b660ecd924d90ba1911fb6f9ed709139f74a05db9279ddb25124b6fb5af7007
Nov 17 07:35:40.967 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-5/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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"`
Nov 17 07:35:41.404 INFO [stdout] 506b574fd8ef9aa42164ae9aaa24c426a8537634c007caf1f68c204304409f0e
Nov 17 07:35:41.407 INFO running `"docker" "start" "-a" "506b574fd8ef9aa42164ae9aaa24c426a8537634c007caf1f68c204304409f0e"`
Nov 17 07:35:42.731 INFO [stderr] usermod: no changes
Nov 17 07:35:43.167 INFO [stderr]    Compiling fw v1.14.1-alpha.0 (/source)
Nov 17 07:35:58.243 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 15.46s
Nov 17 07:35:58.268 INFO [stderr] su: No module specific data is present
Nov 17 07:35:59.141 INFO running `"docker" "inspect" "506b574fd8ef9aa42164ae9aaa24c426a8537634c007caf1f68c204304409f0e"`
Nov 17 07:35:59.419 INFO running `"docker" "rm" "-f" "506b574fd8ef9aa42164ae9aaa24c426a8537634c007caf1f68c204304409f0e"`
Nov 17 07:35:59.747 INFO [stdout] 506b574fd8ef9aa42164ae9aaa24c426a8537634c007caf1f68c204304409f0e
Nov 17 07:35:59.754 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-5/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-55982/master#6b9b97bd9b704f85f0184f7a213cc4d62bd9654c:/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 +6b9b97bd9b704f85f0184f7a213cc4d62bd9654c-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"`
Nov 17 07:36:00.203 INFO [stdout] 5ba0a8fb280af27d2157df9d16b093b7f8902bb650237c5dc48a2b070e14a680
Nov 17 07:36:00.211 INFO running `"docker" "start" "-a" "5ba0a8fb280af27d2157df9d16b093b7f8902bb650237c5dc48a2b070e14a680"`
Nov 17 07:36:01.390 INFO [stderr] usermod: no changes
Nov 17 07:36:01.735 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.32s
Nov 17 07:36:01.779 INFO [stderr]      Running /target/debug/deps/fw-3a2a624b02001d23
Nov 17 07:36:01.827 INFO [stdout] 
Nov 17 07:36:01.827 INFO [stdout] running 19 tests
Nov 17 07:36:01.839 INFO [stdout] test config::tests::test_do_expand_path ... ok
Nov 17 07:36:01.839 INFO [stdout] test config::tests::test_do_not_expand_path_without_tilde ... ok
Nov 17 07:36:01.840 INFO [stdout] Nov 17 07:36:01.823 TRCE Resolving, tags: Some({"tag1", "tag2"})
Nov 17 07:36:01.840 INFO [stdout] Nov 17 07:36:01.824 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.840 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.841 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.841 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
Nov 17 07:36:01.841 INFO [stdout] Nov 17 07:36:01.824 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.841 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.842 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.842 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
Nov 17 07:36:01.842 INFO [stdout] Nov 17 07:36:01.824 TRCE before sort, tags: [("clone1", 50), ("clone2", 50)]
Nov 17 07:36:01.843 INFO [stdout] Nov 17 07:36:01.824 TRCE after sort, tags: [("clone1", 50), ("clone2", 50)]
Nov 17 07:36:01.843 INFO [stdout] test config::tests::test_after_clone_from_tags ... ok
Nov 17 07:36:01.844 INFO [stdout] Nov 17 07:36:01.824 TRCE Resolving, tags: Some({"tag-does-not-exist"})
Nov 17 07:36:01.844 INFO [stdout] Nov 17 07:36:01.824 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist"})
Nov 17 07:36:01.844 INFO [stdout] Nov 17 07:36:01.824 TRCE before sort, tags: []
Nov 17 07:36:01.845 INFO [stdout] Nov 17 07:36:01.824 TRCE after sort, tags: []
Nov 17 07:36:01.845 INFO [stdout] test config::tests::test_after_clone_from_tags_missing_all_tags_graceful ... ok
Nov 17 07:36:01.845 INFO [stdout] Nov 17 07:36:01.824 TRCE Resolving, tags: Some({"tag1"})
Nov 17 07:36:01.845 INFO [stdout] Nov 17 07:36:01.825 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.846 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.846 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.847 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
Nov 17 07:36:01.847 INFO [stdout] Nov 17 07:36:01.825 TRCE before sort, tags: [("clone1", 50)]
Nov 17 07:36:01.847 INFO [stdout] Nov 17 07:36:01.825 TRCE after sort, tags: [("clone1", 50)]
Nov 17 07:36:01.847 INFO [stdout] test config::tests::test_after_clone_override_from_project ... ok
Nov 17 07:36:01.848 INFO [stdout] Nov 17 07:36:01.825 TRCE Resolving, tags: Some({"tag-does-not-exist", "tag1"})
Nov 17 07:36:01.848 INFO [stdout] Nov 17 07:36:01.825 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist", "tag1"})
Nov 17 07:36:01.848 INFO [stdout] Nov 17 07:36:01.825 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.848 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.849 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.849 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
Nov 17 07:36:01.849 INFO [stdout] Nov 17 07:36:01.825 TRCE before sort, tags: [("clone1", 50)]
Nov 17 07:36:01.850 INFO [stdout] Nov 17 07:36:01.825 TRCE after sort, tags: [("clone1", 50)]
Nov 17 07:36:01.850 INFO [stdout] test config::tests::test_after_clone_from_tags_missing_one_tag_graceful ... ok
Nov 17 07:36:01.850 INFO [stdout] test config::tests::test_repo_name_from_ssh_pragma_with_multiple_git_endings ... ok
Nov 17 07:36:01.850 INFO [stdout] test config::tests::test_repo_name_from_url ... ok
Nov 17 07:36:01.851 INFO [stdout] Nov 17 07:36:01.826 TRCE Resolving, tags: Some({"tag1", "tag2"})
Nov 17 07:36:01.851 INFO [stdout] Nov 17 07:36:01.826 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.851 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.852 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.852 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
Nov 17 07:36:01.852 INFO [stdout] Nov 17 07:36:01.826 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.853 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.853 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.853 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
Nov 17 07:36:01.853 INFO [stdout] Nov 17 07:36:01.826 TRCE before sort, tags: [("workon1", 50), ("workon2", 50)]
Nov 17 07:36:01.854 INFO [stdout] Nov 17 07:36:01.826 TRCE after sort, tags: [("workon1", 50), ("workon2", 50)]
Nov 17 07:36:01.854 INFO [stdout] test config::tests::test_workon_from_tags ... ok
Nov 17 07:36:01.854 INFO [stdout] Nov 17 07:36:01.826 TRCE Resolving, tags: Some({"tag-does-not-exist", "tag1"})
Nov 17 07:36:01.855 INFO [stdout] Nov 17 07:36:01.826 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist", "tag1"})
Nov 17 07:36:01.855 INFO [stdout] Nov 17 07:36:01.826 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.855 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.855 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.856 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
Nov 17 07:36:01.856 INFO [stdout] Nov 17 07:36:01.827 TRCE before sort, tags: [("workon1", 50)]
Nov 17 07:36:01.856 INFO [stdout] Nov 17 07:36:01.827 TRCE after sort, tags: [("workon1", 50)]
Nov 17 07:36:01.857 INFO [stdout] Nov 17 07:36:01.827 TRCE Resolving, tags: Some({"tag3", "tag4"})
Nov 17 07:36:01.857 INFO [stdout] test config::tests::test_workon_from_tags_missing_one_tag_graceful ... ok
Nov 17 07:36:01.857 INFO [stdout] Nov 17 07:36:01.827 TRCE before sort, tags: [("clone3", 100), ("clone4", 0)]
Nov 17 07:36:01.857 INFO [stdout] Nov 17 07:36:01.827 TRCE after sort, tags: [("clone4", 0), ("clone3", 100)]
Nov 17 07:36:01.858 INFO [stdout] test config::tests::test_after_clone_from_tags_prioritized ... ok
Nov 17 07:36:01.858 INFO [stdout] Nov 17 07:36:01.827 TRCE Resolving, tags: Some({"tag3", "tag4"})
Nov 17 07:36:01.858 INFO [stdout] Nov 17 07:36:01.827 TRCE before sort, tags: [("workon3", 100), ("workon4", 0)]
Nov 17 07:36:01.858 INFO [stdout] Nov 17 07:36:01.827 TRCE after sort, tags: [("workon4", 0), ("workon3", 100)]
Nov 17 07:36:01.859 INFO [stdout] test config::tests::test_workon_from_tags_prioritized ... ok
Nov 17 07:36:01.859 INFO [stdout] Nov 17 07:36:01.827 TRCE Resolving, tags: Some({"tag-does-not-exist"})
Nov 17 07:36:01.859 INFO [stdout] Nov 17 07:36:01.827 WARN Ignoring tag since it was not found in the config, missing_tag: tag-does-not-exist, tags: Some({"tag-does-not-exist"})
Nov 17 07:36:01.859 INFO [stdout] Nov 17 07:36:01.827 TRCE before sort, tags: []
Nov 17 07:36:01.860 INFO [stdout] Nov 17 07:36:01.827 TRCE after sort, tags: []
Nov 17 07:36:01.860 INFO [stdout] test config::tests::test_workon_from_tags_missing_all_tags_graceful ... ok
Nov 17 07:36:01.860 INFO [stdout] test export::tests::test_workon_override_from_project ... ok
Nov 17 07:36:01.860 INFO [stdout] Nov 17 07:36:01.828 TRCE Resolving, tags: Some({"tag1"})
Nov 17 07:36:01.861 INFO [stdout] Nov 17 07:36:01.828 DEBG No tag priority set, will use default (50).
Nov 17 07:36:01.861 INFO [stdout] Tags with low priority are applied first and if they all have the same priority
Nov 17 07:36:01.861 INFO [stdout] they will be applied in alphabetical name order so it is recommended you make a
Nov 17 07:36:01.861 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
Nov 17 07:36:01.862 INFO [stdout] Nov 17 07:36:01.828 TRCE before sort, tags: [("workon1", 50)]
Nov 17 07:36:01.862 INFO [stdout] Nov 17 07:36:01.828 TRCE after sort, tags: [("workon1", 50)]
Nov 17 07:36:01.862 INFO [stdout] test config::tests::test_workon_override_from_project ... ok
Nov 17 07:36:01.862 INFO [stdout] Nov 17 07:36:01.829 DEBG Writing projectile entry, entry: /home/mriehl/test
Nov 17 07:36:01.863 INFO [stdout] Nov 17 07:36:01.830 DEBG Writing projectile entry, entry: /home/mriehl/go/src/github.com/test2
Nov 17 07:36:01.863 INFO [stdout] test projectile::tests::test_persists_projectile_config ... ok
Nov 17 07:36:01.863 INFO [stdout] test projectile::tests::test_replace_path_with_tilde ... ok
Nov 17 07:36:01.864 INFO [stdout] test config::tests::test_repo_name_from_ssh_pragma ... ok
Nov 17 07:36:01.896 INFO [stdout] test sync::tests::test_username_from_git_url ... ok
Nov 17 07:36:01.896 INFO [stdout] 
Nov 17 07:36:01.897 INFO [stdout] test result: ok. 19 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 17 07:36:01.897 INFO [stdout] 
Nov 17 07:36:01.907 INFO [stderr] su: No module specific data is present
Nov 17 07:36:02.453 INFO running `"docker" "inspect" "5ba0a8fb280af27d2157df9d16b093b7f8902bb650237c5dc48a2b070e14a680"`
Nov 17 07:36:02.753 INFO running `"docker" "rm" "-f" "5ba0a8fb280af27d2157df9d16b093b7f8902bb650237c5dc48a2b070e14a680"`
Nov 17 07:36:03.115 INFO [stdout] 5ba0a8fb280af27d2157df9d16b093b7f8902bb650237c5dc48a2b070e14a680