Dec 15 16:46:08.676 INFO testing dmenv-0.7.0 against try#aa49d8ef14939ddec0e34b346b60174a5673d48f for pr-56550 Dec 15 16:46:08.676 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-7/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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 15 16:46:08.901 INFO [stdout] be18c2d5686323851a4fa019d270a9e5bae9675fb9591b7f9c7fbee32d38bca5 Dec 15 16:46:08.908 INFO running `"docker" "start" "-a" "be18c2d5686323851a4fa019d270a9e5bae9675fb9591b7f9c7fbee32d38bca5"` Dec 15 16:46:09.351 INFO [stderr] usermod: no changes Dec 15 16:46:09.477 INFO [stderr] Compiling appdirs v0.2.0 Dec 15 16:46:09.477 INFO [stderr] Compiling structopt v0.2.14 Dec 15 16:46:10.573 INFO [stderr] Compiling dmenv v0.7.0 (/source) Dec 15 16:46:17.713 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 8.33s Dec 15 16:46:17.729 INFO [stderr] su: No module specific data is present Dec 15 16:46:18.878 INFO running `"docker" "inspect" "be18c2d5686323851a4fa019d270a9e5bae9675fb9591b7f9c7fbee32d38bca5"` Dec 15 16:46:19.203 INFO running `"docker" "rm" "-f" "be18c2d5686323851a4fa019d270a9e5bae9675fb9591b7f9c7fbee32d38bca5"` Dec 15 16:46:19.511 INFO [stdout] be18c2d5686323851a4fa019d270a9e5bae9675fb9591b7f9c7fbee32d38bca5 Dec 15 16:46:19.516 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-7/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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 15 16:46:19.984 INFO [stdout] 6921cbf8e8ffe504350b265c6afdc56eec5917a7cfbb3ab9f629238ae6215167 Dec 15 16:46:19.986 INFO running `"docker" "start" "-a" "6921cbf8e8ffe504350b265c6afdc56eec5917a7cfbb3ab9f629238ae6215167"` Dec 15 16:46:21.479 INFO [stderr] usermod: no changes Dec 15 16:46:21.721 INFO [stderr] Compiling dmenv v0.7.0 (/source) Dec 15 16:46:28.831 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 7.32s Dec 15 16:46:28.863 INFO [stderr] su: No module specific data is present Dec 15 16:46:29.590 INFO running `"docker" "inspect" "6921cbf8e8ffe504350b265c6afdc56eec5917a7cfbb3ab9f629238ae6215167"` Dec 15 16:46:29.766 INFO running `"docker" "rm" "-f" "6921cbf8e8ffe504350b265c6afdc56eec5917a7cfbb3ab9f629238ae6215167"` Dec 15 16:46:29.835 INFO [stdout] 6921cbf8e8ffe504350b265c6afdc56eec5917a7cfbb3ab9f629238ae6215167 Dec 15 16:46:29.837 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-7/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/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 +aa49d8ef14939ddec0e34b346b60174a5673d48f-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 15 16:46:30.066 INFO [stdout] 4769df3a1502033322e7376785fa4fa64cf07a19ca6b93925222e0528dafcf1e Dec 15 16:46:30.068 INFO running `"docker" "start" "-a" "4769df3a1502033322e7376785fa4fa64cf07a19ca6b93925222e0528dafcf1e"` Dec 15 16:46:30.561 INFO [stderr] usermod: no changes Dec 15 16:46:30.657 INFO [stderr] Finished dev [unoptimized + debuginfo] target(s) in 0.07s Dec 15 16:46:30.670 INFO [stderr] Running /target/debug/deps/dmenv-96ae253bfc41b4e5 Dec 15 16:46:30.677 INFO [stdout] Dec 15 16:46:30.677 INFO [stdout] running 4 tests Dec 15 16:46:30.677 INFO [stdout] test lock::tests::malformed_lock ... ok Dec 15 16:46:30.677 INFO [stdout] test lock::tests::simple_bump ... ok Dec 15 16:46:30.679 INFO [stdout] test lock::tests::dep_not_found ... ok Dec 15 16:46:30.686 INFO [stdout] test lock::tests::git_bump ... ok Dec 15 16:46:30.686 INFO [stderr] Running /target/debug/deps/dmenv-43c06b0c5064f278 Dec 15 16:46:30.686 INFO [stdout] Dec 15 16:46:30.686 INFO [stdout] test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Dec 15 16:46:30.686 INFO [stdout] Dec 15 16:46:30.688 INFO [stdout] Dec 15 16:46:30.688 INFO [stdout] running 0 tests Dec 15 16:46:30.688 INFO [stdout] Dec 15 16:46:30.688 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out Dec 15 16:46:30.688 INFO [stdout] Dec 15 16:46:30.688 INFO [stderr] Running /target/debug/deps/integration_tests-71baa3eb198e76f3 Dec 15 16:46:30.692 INFO [stdout] Dec 15 16:46:30.692 INFO [stdout] running 12 tests Dec 15 16:46:30.853 INFO [stdout] test init_generates_setup_py ... ok Dec 15 16:46:30.863 INFO [stdout] test bump_in_lock_git ... ok Dec 15 16:46:30.873 INFO [stdout] test run_without_args ... ok Dec 15 16:46:30.899 INFO [stdout] test bump_in_lock_simple ... ok Dec 15 16:46:30.949 INFO [stdout] test init_does_not_overwrite_existing_setup_py ... ok Dec 15 16:46:30.959 INFO [stdout] test install_without_lock ... ok Dec 15 16:46:30.996 INFO [stdout] test show_venv_path ... ok Dec 15 16:46:31.003 INFO [stdout] test lock_complains_if_setup_py_does_not_exist ... ok Dec 15 16:46:31.015 INFO [stdout] test run_without_virtualenv ... ok Dec 15 16:46:35.731 INFO [stderr] The directory '/home/crater/.cache/pip/http' or its parent directory is not owned by the current user and the cache has been disabled. Please check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag. Dec 15 16:46:35.731 INFO [stderr] The directory '/home/crater/.cache/pip' or its parent directory is not owned by the current user and caching wheels has been disabled. check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag. Dec 15 16:46:35.843 INFO [stdout] Collecting atomicwrites==1.2.1 (from -r /tmp/test-dmenv.bn281znrYBEZ/requirements.lock (line 2)) Dec 15 16:46:35.843 INFO [stderr] The directory '/home/crater/.cache/pip/http' or its parent directory is not owned by the current user and the cache has been disabled. Please check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag. Dec 15 16:46:35.843 INFO [stderr] The directory '/home/crater/.cache/pip' or its parent directory is not owned by the current user and caching wheels has been disabled. check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag. Dec 15 16:46:35.843 INFO [stderr] Exception: Dec 15 16:46:35.843 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:35.843 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 137, in _new_conn Dec 15 16:46:35.843 INFO [stderr] (self.host, self.port), self.timeout, **extra_kw) Dec 15 16:46:35.843 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/connection.py", line 67, in create_connection Dec 15 16:46:35.843 INFO [stderr] for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM): Dec 15 16:46:35.843 INFO [stderr] File "/usr/lib/python3.5/socket.py", line 732, in getaddrinfo Dec 15 16:46:35.843 INFO [stderr] for res in _socket.getaddrinfo(host, port, family, type, proto, flags): Dec 15 16:46:35.843 INFO [stderr] socket.gaierror: [Errno -3] Temporary failure in name resolution Dec 15 16:46:35.843 INFO [stderr] Dec 15 16:46:35.843 INFO [stderr] During handling of the above exception, another exception occurred: Dec 15 16:46:35.843 INFO [stderr] Dec 15 16:46:35.843 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:35.843 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 560, in urlopen Dec 15 16:46:35.843 INFO [stderr] body=body, headers=headers) Dec 15 16:46:35.843 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 346, in _make_request Dec 15 16:46:35.843 INFO [stderr] self._validate_conn(conn) Dec 15 16:46:35.843 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 787, in _validate_conn Dec 15 16:46:35.843 INFO [stderr] conn.connect() Dec 15 16:46:35.843 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 217, in connect Dec 15 16:46:35.844 INFO [stderr] conn = self._new_conn() Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 146, in _new_conn Dec 15 16:46:35.844 INFO [stderr] self, "Failed to establish a new connection: %s" % e) Dec 15 16:46:35.844 INFO [stderr] requests.packages.urllib3.exceptions.NewConnectionError: : Failed to establish a new connection: [Errno -3] Temporary failure in name resolution Dec 15 16:46:35.844 INFO [stderr] Dec 15 16:46:35.844 INFO [stderr] During handling of the above exception, another exception occurred: Dec 15 16:46:35.844 INFO [stderr] Dec 15 16:46:35.844 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/basecommand.py", line 209, in main Dec 15 16:46:35.844 INFO [stderr] status = self.run(options, args) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/commands/install.py", line 317, in run Dec 15 16:46:35.844 INFO [stderr] requirement_set.prepare_files(finder) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 360, in prepare_files Dec 15 16:46:35.844 INFO [stderr] ignore_dependencies=self.ignore_dependencies)) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 512, in _prepare_file Dec 15 16:46:35.844 INFO [stderr] finder, self.upgrade, require_hashes) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_install.py", line 273, in populate_link Dec 15 16:46:35.844 INFO [stderr] self.link = finder.find_requirement(self, upgrade) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 442, in find_requirement Dec 15 16:46:35.844 INFO [stderr] all_candidates = self.find_all_candidates(req.name) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 400, in find_all_candidates Dec 15 16:46:35.844 INFO [stderr] for page in self._get_pages(url_locations, project_name): Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 545, in _get_pages Dec 15 16:46:35.844 INFO [stderr] page = self._get_page(location) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 648, in _get_page Dec 15 16:46:35.844 INFO [stderr] return HTMLPage.get_page(link, session=self.session) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 757, in get_page Dec 15 16:46:35.844 INFO [stderr] "Cache-Control": "max-age=600", Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 480, in get Dec 15 16:46:35.844 INFO [stderr] return self.request('GET', url, **kwargs) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/lib/python3.5/site-packages/pip/download.py", line 378, in request Dec 15 16:46:35.844 INFO [stderr] return super(PipSession, self).request(method, url, *args, **kwargs) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 468, in request Dec 15 16:46:35.844 INFO [stderr] resp = self.send(prep, **send_kwargs) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 576, in send Dec 15 16:46:35.844 INFO [stderr] r = adapter.send(request, **kwargs) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/CacheControl-0.11.5-py2.py3-none-any.whl/cachecontrol/adapter.py", line 46, in send Dec 15 16:46:35.844 INFO [stderr] resp = super(CacheControlAdapter, self).send(request, **kw) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/adapters.py", line 376, in send Dec 15 16:46:35.844 INFO [stderr] timeout=timeout Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 610, in urlopen Dec 15 16:46:35.844 INFO [stderr] _stacktrace=sys.exc_info()[2]) Dec 15 16:46:35.844 INFO [stderr] File "/tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/retry.py", line 228, in increment Dec 15 16:46:35.844 INFO [stderr] total -= 1 Dec 15 16:46:35.844 INFO [stderr] TypeError: unsupported operand type(s) for -=: 'Retry' and 'int' Dec 15 16:46:35.906 INFO [stderr] Exception: Dec 15 16:46:35.907 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 137, in _new_conn Dec 15 16:46:35.907 INFO [stderr] (self.host, self.port), self.timeout, **extra_kw) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/connection.py", line 67, in create_connection Dec 15 16:46:35.907 INFO [stderr] for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM): Dec 15 16:46:35.907 INFO [stderr] File "/usr/lib/python3.5/socket.py", line 732, in getaddrinfo Dec 15 16:46:35.907 INFO [stderr] for res in _socket.getaddrinfo(host, port, family, type, proto, flags): Dec 15 16:46:35.907 INFO [stderr] socket.gaierror: [Errno -3] Temporary failure in name resolution Dec 15 16:46:35.907 INFO [stderr] Dec 15 16:46:35.907 INFO [stderr] During handling of the above exception, another exception occurred: Dec 15 16:46:35.907 INFO [stderr] Dec 15 16:46:35.907 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 560, in urlopen Dec 15 16:46:35.907 INFO [stderr] body=body, headers=headers) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 346, in _make_request Dec 15 16:46:35.907 INFO [stderr] self._validate_conn(conn) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 787, in _validate_conn Dec 15 16:46:35.907 INFO [stderr] conn.connect() Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 217, in connect Dec 15 16:46:35.907 INFO [stderr] conn = self._new_conn() Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 146, in _new_conn Dec 15 16:46:35.907 INFO [stderr] self, "Failed to establish a new connection: %s" % e) Dec 15 16:46:35.907 INFO [stderr] requests.packages.urllib3.exceptions.NewConnectionError: : Failed to establish a new connection: [Errno -3] Temporary failure in name resolution Dec 15 16:46:35.907 INFO [stderr] Dec 15 16:46:35.907 INFO [stderr] During handling of the above exception, another exception occurred: Dec 15 16:46:35.907 INFO [stderr] Dec 15 16:46:35.907 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/basecommand.py", line 209, in main Dec 15 16:46:35.907 INFO [stderr] status = self.run(options, args) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/commands/install.py", line 317, in run Dec 15 16:46:35.907 INFO [stderr] requirement_set.prepare_files(finder) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 360, in prepare_files Dec 15 16:46:35.907 INFO [stderr] ignore_dependencies=self.ignore_dependencies)) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 448, in _prepare_file Dec 15 16:46:35.907 INFO [stderr] req_to_install, finder) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 397, in _check_skip_installed Dec 15 16:46:35.907 INFO [stderr] finder.find_requirement(req_to_install, self.upgrade) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 442, in find_requirement Dec 15 16:46:35.907 INFO [stderr] all_candidates = self.find_all_candidates(req.name) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 400, in find_all_candidates Dec 15 16:46:35.907 INFO [stderr] for page in self._get_pages(url_locations, project_name): Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 545, in _get_pages Dec 15 16:46:35.907 INFO [stderr] page = self._get_page(location) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 648, in _get_page Dec 15 16:46:35.907 INFO [stderr] return HTMLPage.get_page(link, session=self.session) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 757, in get_page Dec 15 16:46:35.907 INFO [stderr] "Cache-Control": "max-age=600", Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 480, in get Dec 15 16:46:35.907 INFO [stderr] return self.request('GET', url, **kwargs) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/lib/python3.5/site-packages/pip/download.py", line 378, in request Dec 15 16:46:35.907 INFO [stderr] return super(PipSession, self).request(method, url, *args, **kwargs) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 468, in request Dec 15 16:46:35.907 INFO [stderr] resp = self.send(prep, **send_kwargs) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 576, in send Dec 15 16:46:35.907 INFO [stderr] r = adapter.send(request, **kwargs) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/CacheControl-0.11.5-py2.py3-none-any.whl/cachecontrol/adapter.py", line 46, in send Dec 15 16:46:35.907 INFO [stderr] resp = super(CacheControlAdapter, self).send(request, **kw) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/adapters.py", line 376, in send Dec 15 16:46:35.907 INFO [stderr] timeout=timeout Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 610, in urlopen Dec 15 16:46:35.907 INFO [stderr] _stacktrace=sys.exc_info()[2]) Dec 15 16:46:35.907 INFO [stderr] File "/tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/retry.py", line 228, in increment Dec 15 16:46:35.907 INFO [stderr] total -= 1 Dec 15 16:46:35.907 INFO [stderr] TypeError: unsupported operand type(s) for -=: 'Retry' and 'int' Dec 15 16:46:35.959 INFO [stderr] The directory '/home/crater/.cache/pip/http' or its parent directory is not owned by the current user and the cache has been disabled. Please check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag. Dec 15 16:46:35.959 INFO [stderr] The directory '/home/crater/.cache/pip' or its parent directory is not owned by the current user and caching wheels has been disabled. check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag. Dec 15 16:46:36.024 INFO [stderr] Exception: Dec 15 16:46:36.024 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 137, in _new_conn Dec 15 16:46:36.024 INFO [stderr] (self.host, self.port), self.timeout, **extra_kw) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/connection.py", line 67, in create_connection Dec 15 16:46:36.024 INFO [stderr] for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM): Dec 15 16:46:36.024 INFO [stderr] File "/usr/lib/python3.5/socket.py", line 732, in getaddrinfo Dec 15 16:46:36.024 INFO [stderr] for res in _socket.getaddrinfo(host, port, family, type, proto, flags): Dec 15 16:46:36.024 INFO [stderr] socket.gaierror: [Errno -3] Temporary failure in name resolution Dec 15 16:46:36.024 INFO [stderr] Dec 15 16:46:36.024 INFO [stderr] During handling of the above exception, another exception occurred: Dec 15 16:46:36.024 INFO [stderr] Dec 15 16:46:36.024 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 560, in urlopen Dec 15 16:46:36.024 INFO [stderr] body=body, headers=headers) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 346, in _make_request Dec 15 16:46:36.024 INFO [stderr] self._validate_conn(conn) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 787, in _validate_conn Dec 15 16:46:36.024 INFO [stderr] conn.connect() Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 217, in connect Dec 15 16:46:36.024 INFO [stderr] conn = self._new_conn() Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 146, in _new_conn Dec 15 16:46:36.024 INFO [stderr] self, "Failed to establish a new connection: %s" % e) Dec 15 16:46:36.024 INFO [stderr] requests.packages.urllib3.exceptions.NewConnectionError: : Failed to establish a new connection: [Errno -3] Temporary failure in name resolution Dec 15 16:46:36.024 INFO [stderr] Dec 15 16:46:36.024 INFO [stderr] During handling of the above exception, another exception occurred: Dec 15 16:46:36.024 INFO [stderr] Dec 15 16:46:36.024 INFO [stderr] Traceback (most recent call last): Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/basecommand.py", line 209, in main Dec 15 16:46:36.024 INFO [stderr] status = self.run(options, args) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/commands/install.py", line 317, in run Dec 15 16:46:36.024 INFO [stderr] requirement_set.prepare_files(finder) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 360, in prepare_files Dec 15 16:46:36.024 INFO [stderr] ignore_dependencies=self.ignore_dependencies)) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 448, in _prepare_file Dec 15 16:46:36.024 INFO [stderr] req_to_install, finder) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 397, in _check_skip_installed Dec 15 16:46:36.024 INFO [stderr] finder.find_requirement(req_to_install, self.upgrade) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 442, in find_requirement Dec 15 16:46:36.024 INFO [stderr] all_candidates = self.find_all_candidates(req.name) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 400, in find_all_candidates Dec 15 16:46:36.024 INFO [stderr] for page in self._get_pages(url_locations, project_name): Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 545, in _get_pages Dec 15 16:46:36.024 INFO [stderr] page = self._get_page(location) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 648, in _get_page Dec 15 16:46:36.024 INFO [stderr] return HTMLPage.get_page(link, session=self.session) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 757, in get_page Dec 15 16:46:36.024 INFO [stderr] "Cache-Control": "max-age=600", Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 480, in get Dec 15 16:46:36.024 INFO [stderr] return self.request('GET', url, **kwargs) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/lib/python3.5/site-packages/pip/download.py", line 378, in request Dec 15 16:46:36.024 INFO [stderr] return super(PipSession, self).request(method, url, *args, **kwargs) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 468, in request Dec 15 16:46:36.024 INFO [stderr] resp = self.send(prep, **send_kwargs) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 576, in send Dec 15 16:46:36.024 INFO [stderr] r = adapter.send(request, **kwargs) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/CacheControl-0.11.5-py2.py3-none-any.whl/cachecontrol/adapter.py", line 46, in send Dec 15 16:46:36.024 INFO [stderr] resp = super(CacheControlAdapter, self).send(request, **kw) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/adapters.py", line 376, in send Dec 15 16:46:36.024 INFO [stderr] timeout=timeout Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 610, in urlopen Dec 15 16:46:36.024 INFO [stderr] _stacktrace=sys.exc_info()[2]) Dec 15 16:46:36.024 INFO [stderr] File "/tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/retry.py", line 228, in increment Dec 15 16:46:36.025 INFO [stderr] total -= 1 Dec 15 16:46:36.025 INFO [stderr] TypeError: unsupported operand type(s) for -=: 'Retry' and 'int' Dec 15 16:46:36.087 INFO [stdout] test install_workflow_all_in_one ... FAILED Dec 15 16:46:36.098 INFO [stdout] test install_workflow_step_by_step ... FAILED Dec 15 16:46:36.114 INFO [stdout] test lock_workflow ... FAILED Dec 15 16:46:36.114 INFO [stdout] Dec 15 16:46:36.114 INFO [stdout] failures: Dec 15 16:46:36.114 INFO [stdout] Dec 15 16:46:36.114 INFO [stdout] ---- install_workflow_all_in_one stdout ---- Dec 15 16:46:36.114 INFO [stdout] :: Creating virtualenv in: /tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2 Dec 15 16:46:36.114 INFO [stdout] -> Running /usr/bin/python3 -m venv /tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2 Dec 15 16:46:36.114 INFO [stdout] -> Running /tmp/test-dmenv.croZ7b3tkMpe/.venv/3.5.2/bin/python -m pip install pip --upgrade Dec 15 16:46:36.114 INFO [stdout] thread 'install_workflow_all_in_one' panicked at ': Error { description: "command failed" }', src/libcore/result.rs:1009:5 Dec 15 16:46:36.114 INFO [stdout] stack backtrace: Dec 15 16:46:36.114 INFO [stdout] 0: 0x5609e1caca93 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h2c40bdfb30f25bdd Dec 15 16:46:36.114 INFO [stdout] at src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49 Dec 15 16:46:36.114 INFO [stdout] 1: 0x5609e1ca71d8 - std::sys_common::backtrace::_print::he11ceebc70626ac9 Dec 15 16:46:36.114 INFO [stdout] at src/libstd/sys_common/backtrace.rs:71 Dec 15 16:46:36.114 INFO [stdout] 2: 0x5609e1cab9b2 - std::panicking::default_hook::{{closure}}::h4fde3ffb19c01413 Dec 15 16:46:36.114 INFO [stdout] at src/libstd/sys_common/backtrace.rs:59 Dec 15 16:46:36.114 INFO [stdout] at src/libstd/panicking.rs:210 Dec 15 16:46:36.114 INFO [stdout] 3: 0x5609e1cab6a7 - std::panicking::default_hook::hf0c15a583008ed0d Dec 15 16:46:36.114 INFO [stdout] at src/libstd/panicking.rs:218 Dec 15 16:46:36.114 INFO [stdout] 4: 0x5609e1cac0c0 - std::panicking::rust_panic_with_hook::hc1663f6bc7813185 Dec 15 16:46:36.114 INFO [stdout] at src/libstd/panicking.rs:487 Dec 15 16:46:36.114 INFO [stdout] 5: 0x5609e1cabc41 - std::panicking::continue_panic_fmt::h42bc2d03ddf03b3e Dec 15 16:46:36.114 INFO [stdout] at src/libstd/panicking.rs:394 Dec 15 16:46:36.114 INFO [stdout] 6: 0x5609e1cabb25 - rust_begin_unwind Dec 15 16:46:36.115 INFO [stdout] at src/libstd/panicking.rs:321 Dec 15 16:46:36.115 INFO [stdout] 7: 0x5609e1cc264c - core::panicking::panic_fmt::h44df04385fc0c5a6 Dec 15 16:46:36.115 INFO [stdout] at src/libcore/panicking.rs:95 Dec 15 16:46:36.115 INFO [stdout] 8: 0x5609e1a7b270 - core::result::unwrap_failed::h72a07947344f6ec9 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/macros.rs:26 Dec 15 16:46:36.115 INFO [stdout] 9: 0x5609e1a152c8 - >::expect::h4c381e7eeede7514 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/result.rs:835 Dec 15 16:46:36.115 INFO [stdout] 10: 0x5609e1a14936 - integration_tests::helpers::TestApp::assert_run_ok::h3527c909f8cc249d Dec 15 16:46:36.115 INFO [stdout] at tests/helpers/mod.rs:57 Dec 15 16:46:36.115 INFO [stdout] 11: 0x5609e1a0c808 - integration_tests::install_workflow_all_in_one::hc047ff8a34401dc2 Dec 15 16:46:36.115 INFO [stdout] at tests/integration_tests.rs:98 Dec 15 16:46:36.115 INFO [stdout] 12: 0x5609e1a0c6b9 - integration_tests::install_workflow_all_in_one::{{closure}}::hc3db84908892b92a Dec 15 16:46:36.115 INFO [stdout] at tests/integration_tests.rs:93 Dec 15 16:46:36.115 INFO [stdout] 13: 0x5609e1a0708d - core::ops::function::FnOnce::call_once::h607140e29817cde0 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/ops/function.rs:238 Dec 15 16:46:36.115 INFO [stdout] 14: 0x5609e1a1ee9e - >::call_box::hac337ba1af72dc2b Dec 15 16:46:36.115 INFO [stdout] at src/libtest/lib.rs:1483 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/ops/function.rs:238 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:673 Dec 15 16:46:36.115 INFO [stdout] 15: 0x5609e1cbfb39 - __rust_maybe_catch_panic Dec 15 16:46:36.115 INFO [stdout] at src/libpanic_unwind/lib.rs:102 Dec 15 16:46:36.115 INFO [stdout] 16: 0x5609e1a3c6a7 - test::run_test::run_test_inner::{{closure}}::hfbfe4a58c0ebb01b Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:285 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:398 Dec 15 16:46:36.115 INFO [stdout] at src/libtest/lib.rs:1438 Dec 15 16:46:36.115 INFO [stdout] 17: 0x5609e1a175b4 - std::sys_common::backtrace::__rust_begin_short_backtrace::hd1f0cf202092f8d7 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/sys_common/backtrace.rs:136 Dec 15 16:46:36.115 INFO [stdout] 18: 0x5609e1a17ba4 - std::panicking::try::do_call::h5e99f92fbf448cf6 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/thread/mod.rs:479 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:319 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:306 Dec 15 16:46:36.115 INFO [stdout] 19: 0x5609e1cbfb39 - __rust_maybe_catch_panic Dec 15 16:46:36.115 INFO [stdout] at src/libpanic_unwind/lib.rs:102 Dec 15 16:46:36.115 INFO [stdout] 20: 0x5609e1a1ed7c - >::call_box::h8ae063aff93ccdb6 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:285 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:398 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/thread/mod.rs:478 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:673 Dec 15 16:46:36.115 INFO [stdout] 21: 0x5609e1cb3afd - std::sys::unix::thread::Thread::new::thread_start::h42c32b292fdd228f Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:683 Dec 15 16:46:36.115 INFO [stdout] at src/libstd/sys_common/thread.rs:24 Dec 15 16:46:36.115 INFO [stdout] at src/libstd/sys/unix/thread.rs:91 Dec 15 16:46:36.115 INFO [stdout] 22: 0x7f44707996b9 - start_thread Dec 15 16:46:36.115 INFO [stdout] 23: 0x7f44702b941c - clone Dec 15 16:46:36.115 INFO [stdout] 24: 0x0 - Dec 15 16:46:36.115 INFO [stdout] Dec 15 16:46:36.115 INFO [stdout] ---- install_workflow_step_by_step stdout ---- Dec 15 16:46:36.115 INFO [stdout] :: Creating virtualenv in: /tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2 Dec 15 16:46:36.115 INFO [stdout] -> Running /usr/bin/python3 -m venv /tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2 Dec 15 16:46:36.115 INFO [stdout] -> Running /tmp/test-dmenv.bn281znrYBEZ/.venv/3.5.2/bin/pip install --requirement /tmp/test-dmenv.bn281znrYBEZ/requirements.lock Dec 15 16:46:36.115 INFO [stdout] thread 'install_workflow_step_by_step' panicked at ': Error { description: "command failed" }', src/libcore/result.rs:1009:5 Dec 15 16:46:36.115 INFO [stdout] stack backtrace: Dec 15 16:46:36.115 INFO [stdout] 0: 0x5609e1caca93 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h2c40bdfb30f25bdd Dec 15 16:46:36.115 INFO [stdout] at src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49 Dec 15 16:46:36.115 INFO [stdout] 1: 0x5609e1ca71d8 - std::sys_common::backtrace::_print::he11ceebc70626ac9 Dec 15 16:46:36.115 INFO [stdout] at src/libstd/sys_common/backtrace.rs:71 Dec 15 16:46:36.115 INFO [stdout] 2: 0x5609e1cab9b2 - std::panicking::default_hook::{{closure}}::h4fde3ffb19c01413 Dec 15 16:46:36.115 INFO [stdout] at src/libstd/sys_common/backtrace.rs:59 Dec 15 16:46:36.115 INFO [stdout] at src/libstd/panicking.rs:210 Dec 15 16:46:36.115 INFO [stdout] 3: 0x5609e1cab6a7 - std::panicking::default_hook::hf0c15a583008ed0d Dec 15 16:46:36.115 INFO [stdout] at src/libstd/panicking.rs:218 Dec 15 16:46:36.115 INFO [stdout] 4: 0x5609e1cac0c0 - std::panicking::rust_panic_with_hook::hc1663f6bc7813185 Dec 15 16:46:36.115 INFO [stdout] at src/libstd/panicking.rs:487 Dec 15 16:46:36.115 INFO [stdout] 5: 0x5609e1cabc41 - std::panicking::continue_panic_fmt::h42bc2d03ddf03b3e Dec 15 16:46:36.115 INFO [stdout] at src/libstd/panicking.rs:394 Dec 15 16:46:36.115 INFO [stdout] 6: 0x5609e1cabb25 - rust_begin_unwind Dec 15 16:46:36.115 INFO [stdout] at src/libstd/panicking.rs:321 Dec 15 16:46:36.115 INFO [stdout] 7: 0x5609e1cc264c - core::panicking::panic_fmt::h44df04385fc0c5a6 Dec 15 16:46:36.115 INFO [stdout] at src/libcore/panicking.rs:95 Dec 15 16:46:36.115 INFO [stdout] 8: 0x5609e1a7b270 - core::result::unwrap_failed::h72a07947344f6ec9 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/macros.rs:26 Dec 15 16:46:36.115 INFO [stdout] 9: 0x5609e1a152c8 - >::expect::h4c381e7eeede7514 Dec 15 16:46:36.115 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/result.rs:835 Dec 15 16:46:36.115 INFO [stdout] 10: 0x5609e1a14936 - integration_tests::helpers::TestApp::assert_run_ok::h3527c909f8cc249d Dec 15 16:46:36.115 INFO [stdout] at tests/helpers/mod.rs:57 Dec 15 16:46:36.115 INFO [stdout] 11: 0x5609e1a0c9e0 - integration_tests::install_workflow_step_by_step::hcd318a84c80f3d5f Dec 15 16:46:36.116 INFO [stdout] at tests/integration_tests.rs:107 Dec 15 16:46:36.116 INFO [stdout] 12: 0x5609e1a0c869 - integration_tests::install_workflow_step_by_step::{{closure}}::hd2acd09d7cefbfe2 Dec 15 16:46:36.116 INFO [stdout] at tests/integration_tests.rs:102 Dec 15 16:46:36.116 INFO [stdout] 13: 0x5609e1a0714d - core::ops::function::FnOnce::call_once::haafb0c5fe78661b2 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/ops/function.rs:238 Dec 15 16:46:36.116 INFO [stdout] 14: 0x5609e1a1ee9e - >::call_box::hac337ba1af72dc2b Dec 15 16:46:36.116 INFO [stdout] at src/libtest/lib.rs:1483 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/ops/function.rs:238 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:673 Dec 15 16:46:36.116 INFO [stdout] 15: 0x5609e1cbfb39 - __rust_maybe_catch_panic Dec 15 16:46:36.116 INFO [stdout] at src/libpanic_unwind/lib.rs:102 Dec 15 16:46:36.116 INFO [stdout] 16: 0x5609e1a3c6a7 - test::run_test::run_test_inner::{{closure}}::hfbfe4a58c0ebb01b Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:285 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:398 Dec 15 16:46:36.116 INFO [stdout] at src/libtest/lib.rs:1438 Dec 15 16:46:36.116 INFO [stdout] 17: 0x5609e1a175b4 - std::sys_common::backtrace::__rust_begin_short_backtrace::hd1f0cf202092f8d7 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/sys_common/backtrace.rs:136 Dec 15 16:46:36.116 INFO [stdout] 18: 0x5609e1a17ba4 - std::panicking::try::do_call::h5e99f92fbf448cf6 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/thread/mod.rs:479 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:319 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:306 Dec 15 16:46:36.116 INFO [stdout] 19: 0x5609e1cbfb39 - __rust_maybe_catch_panic Dec 15 16:46:36.116 INFO [stdout] at src/libpanic_unwind/lib.rs:102 Dec 15 16:46:36.116 INFO [stdout] 20: 0x5609e1a1ed7c - >::call_box::h8ae063aff93ccdb6 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:285 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:398 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/thread/mod.rs:478 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:673 Dec 15 16:46:36.116 INFO [stdout] 21: 0x5609e1cb3afd - std::sys::unix::thread::Thread::new::thread_start::h42c32b292fdd228f Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:683 Dec 15 16:46:36.116 INFO [stdout] at src/libstd/sys_common/thread.rs:24 Dec 15 16:46:36.116 INFO [stdout] at src/libstd/sys/unix/thread.rs:91 Dec 15 16:46:36.116 INFO [stdout] 22: 0x7f44707996b9 - start_thread Dec 15 16:46:36.116 INFO [stdout] 23: 0x7f44702b941c - clone Dec 15 16:46:36.116 INFO [stdout] 24: 0x0 - Dec 15 16:46:36.116 INFO [stdout] Dec 15 16:46:36.116 INFO [stdout] ---- lock_workflow stdout ---- Dec 15 16:46:36.116 INFO [stdout] :: Creating virtualenv in: /tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2 Dec 15 16:46:36.116 INFO [stdout] -> Running /usr/bin/python3 -m venv /tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2 Dec 15 16:46:36.116 INFO [stdout] -> Running /tmp/test-dmenv.cmiNOn6VOhdS/.venv/3.5.2/bin/python -m pip install pip --upgrade Dec 15 16:46:36.116 INFO [stdout] thread 'lock_workflow' panicked at ': Error { description: "command failed" }', src/libcore/result.rs:1009:5 Dec 15 16:46:36.116 INFO [stdout] stack backtrace: Dec 15 16:46:36.116 INFO [stdout] 0: 0x5609e1caca93 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h2c40bdfb30f25bdd Dec 15 16:46:36.116 INFO [stdout] at src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49 Dec 15 16:46:36.116 INFO [stdout] 1: 0x5609e1ca71d8 - std::sys_common::backtrace::_print::he11ceebc70626ac9 Dec 15 16:46:36.116 INFO [stdout] at src/libstd/sys_common/backtrace.rs:71 Dec 15 16:46:36.116 INFO [stdout] 2: 0x5609e1cab9b2 - std::panicking::default_hook::{{closure}}::h4fde3ffb19c01413 Dec 15 16:46:36.116 INFO [stdout] at src/libstd/sys_common/backtrace.rs:59 Dec 15 16:46:36.116 INFO [stdout] at src/libstd/panicking.rs:210 Dec 15 16:46:36.116 INFO [stdout] 3: 0x5609e1cab6a7 - std::panicking::default_hook::hf0c15a583008ed0d Dec 15 16:46:36.116 INFO [stdout] at src/libstd/panicking.rs:218 Dec 15 16:46:36.116 INFO [stdout] 4: 0x5609e1cac0c0 - std::panicking::rust_panic_with_hook::hc1663f6bc7813185 Dec 15 16:46:36.116 INFO [stdout] at src/libstd/panicking.rs:487 Dec 15 16:46:36.116 INFO [stdout] 5: 0x5609e1cabc41 - std::panicking::continue_panic_fmt::h42bc2d03ddf03b3e Dec 15 16:46:36.116 INFO [stdout] at src/libstd/panicking.rs:394 Dec 15 16:46:36.116 INFO [stdout] 6: 0x5609e1cabb25 - rust_begin_unwind Dec 15 16:46:36.116 INFO [stdout] at src/libstd/panicking.rs:321 Dec 15 16:46:36.116 INFO [stdout] 7: 0x5609e1cc264c - core::panicking::panic_fmt::h44df04385fc0c5a6 Dec 15 16:46:36.116 INFO [stdout] at src/libcore/panicking.rs:95 Dec 15 16:46:36.116 INFO [stdout] 8: 0x5609e1a7b270 - core::result::unwrap_failed::h72a07947344f6ec9 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/macros.rs:26 Dec 15 16:46:36.116 INFO [stdout] 9: 0x5609e1a152c8 - >::expect::h4c381e7eeede7514 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/result.rs:835 Dec 15 16:46:36.116 INFO [stdout] 10: 0x5609e1a14936 - integration_tests::helpers::TestApp::assert_run_ok::h3527c909f8cc249d Dec 15 16:46:36.116 INFO [stdout] at tests/helpers/mod.rs:57 Dec 15 16:46:36.116 INFO [stdout] 11: 0x5609e1a0c3f5 - integration_tests::lock_workflow::hf67e2b33deb48ac0 Dec 15 16:46:36.116 INFO [stdout] at tests/integration_tests.rs:83 Dec 15 16:46:36.116 INFO [stdout] 12: 0x5609e1a0c2c9 - integration_tests::lock_workflow::{{closure}}::he3276caf757256ea Dec 15 16:46:36.116 INFO [stdout] at tests/integration_tests.rs:80 Dec 15 16:46:36.116 INFO [stdout] 13: 0x5609e1a071cd - core::ops::function::FnOnce::call_once::hca60cd3a0dc76fe6 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/ops/function.rs:238 Dec 15 16:46:36.116 INFO [stdout] 14: 0x5609e1a1ee9e - >::call_box::hac337ba1af72dc2b Dec 15 16:46:36.116 INFO [stdout] at src/libtest/lib.rs:1483 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libcore/ops/function.rs:238 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:673 Dec 15 16:46:36.116 INFO [stdout] 15: 0x5609e1cbfb39 - __rust_maybe_catch_panic Dec 15 16:46:36.116 INFO [stdout] at src/libpanic_unwind/lib.rs:102 Dec 15 16:46:36.116 INFO [stdout] 16: 0x5609e1a3c6a7 - test::run_test::run_test_inner::{{closure}}::hfbfe4a58c0ebb01b Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:285 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:398 Dec 15 16:46:36.116 INFO [stdout] at src/libtest/lib.rs:1438 Dec 15 16:46:36.116 INFO [stdout] 17: 0x5609e1a175b4 - std::sys_common::backtrace::__rust_begin_short_backtrace::hd1f0cf202092f8d7 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/sys_common/backtrace.rs:136 Dec 15 16:46:36.116 INFO [stdout] 18: 0x5609e1a17ba4 - std::panicking::try::do_call::h5e99f92fbf448cf6 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/thread/mod.rs:479 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:319 Dec 15 16:46:36.116 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:306 Dec 15 16:46:36.116 INFO [stdout] 19: 0x5609e1cbfb39 - __rust_maybe_catch_panic Dec 15 16:46:36.117 INFO [stdout] at src/libpanic_unwind/lib.rs:102 Dec 15 16:46:36.117 INFO [stdout] 20: 0x5609e1a1ed7c - >::call_box::h8ae063aff93ccdb6 Dec 15 16:46:36.117 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panicking.rs:285 Dec 15 16:46:36.117 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/panic.rs:398 Dec 15 16:46:36.117 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/libstd/thread/mod.rs:478 Dec 15 16:46:36.117 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:673 Dec 15 16:46:36.117 INFO [stdout] 21: 0x5609e1cb3afd - std::sys::unix::thread::Thread::new::thread_start::h42c32b292fdd228f Dec 15 16:46:36.117 INFO [stdout] at /rustc/aa49d8ef14939ddec0e34b346b60174a5673d48f/src/liballoc/boxed.rs:683 Dec 15 16:46:36.117 INFO [stdout] at src/libstd/sys_common/thread.rs:24 Dec 15 16:46:36.117 INFO [stdout] at src/libstd/sys/unix/thread.rs:91 Dec 15 16:46:36.117 INFO [stdout] 22: 0x7f44707996b9 - start_thread Dec 15 16:46:36.117 INFO [stdout] 23: 0x7f44702b941c - clone Dec 15 16:46:36.117 INFO [stdout] 24: 0x0 - Dec 15 16:46:36.117 INFO [stdout] Dec 15 16:46:36.117 INFO [stdout] Dec 15 16:46:36.117 INFO [stdout] failures: Dec 15 16:46:36.117 INFO [stdout] install_workflow_all_in_one Dec 15 16:46:36.117 INFO [stdout] install_workflow_step_by_step Dec 15 16:46:36.117 INFO [stdout] lock_workflow Dec 15 16:46:36.117 INFO [stdout] Dec 15 16:46:36.117 INFO [stdout] test result: FAILED. 9 passed; 3 failed; 0 ignored; 0 measured; 0 filtered out Dec 15 16:46:36.117 INFO [stdout] Dec 15 16:46:36.127 INFO [stderr] error: test failed, to rerun pass '--test integration_tests' Dec 15 16:46:36.127 INFO [stderr] su: No module specific data is present Dec 15 16:46:36.439 INFO running `"docker" "inspect" "4769df3a1502033322e7376785fa4fa64cf07a19ca6b93925222e0528dafcf1e"` Dec 15 16:46:36.656 INFO running `"docker" "rm" "-f" "4769df3a1502033322e7376785fa4fa64cf07a19ca6b93925222e0528dafcf1e"` Dec 15 16:46:36.792 INFO [stdout] 4769df3a1502033322e7376785fa4fa64cf07a19ca6b93925222e0528dafcf1e