2019-09-05 21:07:37.235559 | Job console starting...
2019-09-05 21:07:40.898483 | Running Ansible setup...
2019-09-05 21:07:50.033462 | PRE-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base-test/pre.yaml@master]
2019-09-05 21:07:55.459711 | 
2019-09-05 21:07:55.459984 | PLAY [localhost]
2019-09-05 21:07:55.485470 | 
2019-09-05 21:07:55.485667 | TASK [Gathering Facts]
2019-09-05 21:07:57.180059 | localhost | ok
2019-09-05 21:07:57.294025 | 
2019-09-05 21:07:57.294342 | TASK [Setup log path fact]
2019-09-05 21:07:57.379361 | localhost | ok
2019-09-05 21:07:57.491736 | 
2019-09-05 21:07:57.492026 | TASK [set-zuul-log-path-fact : Set log path for a change]
2019-09-05 21:07:57.561022 | localhost | skipping: Conditional result was False
2019-09-05 21:07:57.615224 | 
2019-09-05 21:07:57.615533 | TASK [set-zuul-log-path-fact : Set log path for a ref update]
2019-09-05 21:07:57.676510 | localhost | skipping: Conditional result was False
2019-09-05 21:07:57.725651 | 
2019-09-05 21:07:57.725967 | TASK [set-zuul-log-path-fact : Set log path for a periodic job]
2019-09-05 21:07:57.783972 | localhost | skipping: Conditional result was False
2019-09-05 21:07:57.842932 | 
2019-09-05 21:07:57.843316 | TASK [set-zuul-log-path-fact : Set log path for a change]
2019-09-05 21:07:57.959177 | localhost | ok
2019-09-05 21:07:58.008655 | 
2019-09-05 21:07:58.008968 | TASK [set-zuul-log-path-fact : Set log path for a ref update]
2019-09-05 21:07:58.076923 | localhost | skipping: Conditional result was False
2019-09-05 21:07:58.133483 | 
2019-09-05 21:07:58.133797 | TASK [set-zuul-log-path-fact : Set log path for a periodic job]
2019-09-05 21:07:58.193554 | localhost | skipping: Conditional result was False
2019-09-05 21:07:58.248801 | 
2019-09-05 21:07:58.249139 | TASK [emit-job-header : Print job information]
2019-09-05 21:07:58.345914 | # Job Information
2019-09-05 21:07:58.346642 | Ansible Version: 2.8.0
2019-09-05 21:07:58.346760 | Job: tox-py35
2019-09-05 21:07:58.346902 | Pipeline: check
2019-09-05 21:07:58.347025 | Executor: ze08.openstack.org
2019-09-05 21:07:58.347149 | Triggered by: https://review.opendev.org/680178
2019-09-05 21:07:58.397596 | 
2019-09-05 21:07:58.397905 | LOOP [emit-job-header : Print node information]
2019-09-05 21:07:58.579771 | localhost | ok:
2019-09-05 21:07:58.580384 | localhost | # Node Information
2019-09-05 21:07:58.580516 | localhost | Hostname: ubuntu-bionic-rax-dfw-0010847561
2019-09-05 21:07:58.580624 | localhost | Provider: rax-dfw
2019-09-05 21:07:58.580728 | localhost | Label: ubuntu-bionic
2019-09-05 21:07:58.580829 | localhost | Interface IP: 104.239.142.130
2019-09-05 21:07:58.668228 | 
2019-09-05 21:07:58.668541 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2019-09-05 21:07:59.445903 | localhost | changed
2019-09-05 21:07:59.525371 | 
2019-09-05 21:07:59.525702 | TASK [log-inventory : Copy ansible inventory to logs dir]
2019-09-05 21:08:01.129457 | localhost | changed
2019-09-05 21:08:01.162018 | 
2019-09-05 21:08:01.162251 | PLAY [all]
2019-09-05 21:08:01.210264 | 
2019-09-05 21:08:01.210572 | TASK [Gathering Facts]
2019-09-05 21:08:01.857453 | ubuntu-bionic | ok
2019-09-05 21:08:01.963015 | 
2019-09-05 21:08:01.963339 | TASK [Gather network facts]
2019-09-05 21:08:02.583434 | ubuntu-bionic | ok
2019-09-05 21:08:02.696320 | 
2019-09-05 21:08:02.696651 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2019-09-05 21:08:03.047626 | ubuntu-bionic | ok
2019-09-05 21:08:03.123051 | 
2019-09-05 21:08:03.123334 | TASK [add-build-sshkey : Create Temp SSH key]
2019-09-05 21:08:04.264423 | ubuntu-bionic | ok: Runtime: 0:00:00.010251
2019-09-05 21:08:04.313643 | 
2019-09-05 21:08:04.313918 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2019-09-05 21:08:04.374629 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:04.434501 | 
2019-09-05 21:08:04.434848 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2019-09-05 21:08:05.131686 | ubuntu-bionic | changed
2019-09-05 21:08:05.187148 | 
2019-09-05 21:08:05.187547 | TASK [add-build-sshkey : Make sure user has a .ssh]
2019-09-05 21:08:05.441773 | ubuntu-bionic | ok
2019-09-05 21:08:05.495245 | 
2019-09-05 21:08:05.495581 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2019-09-05 21:08:06.036435 | ubuntu-bionic | changed
2019-09-05 21:08:06.090443 | 
2019-09-05 21:08:06.090774 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2019-09-05 21:08:06.592059 | ubuntu-bionic | changed
2019-09-05 21:08:06.672615 | 
2019-09-05 21:08:06.672907 | TASK [add-build-sshkey : Remove master key from local agent]
2019-09-05 21:08:07.400403 | ubuntu-bionic | changed
2019-09-05 21:08:07.483898 | 
2019-09-05 21:08:07.484312 | TASK [add-build-sshkey : Add back temp key]
2019-09-05 21:08:07.879752 | ubuntu-bionic | ok: Runtime: 0:00:00.004682
2019-09-05 21:08:07.936364 | 
2019-09-05 21:08:07.936702 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2019-09-05 21:08:08.561234 | ubuntu-bionic | ok
2019-09-05 21:08:08.612012 | 
2019-09-05 21:08:08.612335 | TASK [start-zuul-console : Start zuul_console daemon.]
2019-09-05 21:08:09.226596 | ubuntu-bionic | ok
2019-09-05 21:08:09.274670 | 
2019-09-05 21:08:09.274958 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2019-09-05 21:08:09.528939 | ubuntu-bionic | changed: "logs"
2019-09-05 21:08:09.529635 | ubuntu-bionic | ok: All items complete
2019-09-05 21:08:09.529745 | 
2019-09-05 21:08:09.671514 | ubuntu-bionic | changed: "artifacts"
2019-09-05 21:08:09.811922 | ubuntu-bionic | changed: "docs"
2019-09-05 21:08:09.850702 | 
2019-09-05 21:08:09.850923 | PLAY [all]
2019-09-05 21:08:09.901661 | 
2019-09-05 21:08:09.901901 | TASK [configure-unbound : Check that Unbound is installed]
2019-09-05 21:08:10.138485 | ubuntu-bionic | ok
2019-09-05 21:08:10.197455 | 
2019-09-05 21:08:10.197786 | TASK [configure-unbound : Ensure that Unbound is installed]
2019-09-05 21:08:10.296720 | ubuntu-bionic | ok: All assertions passed
2019-09-05 21:08:10.347050 | 
2019-09-05 21:08:10.347356 | TASK [configure-unbound : Check for IPv6]
2019-09-05 21:08:10.472601 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:10.557084 | 
2019-09-05 21:08:10.557436 | TASK [configure-unbound : Set IPv6 nameservers]
2019-09-05 21:08:10.672107 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:10.733739 | 
2019-09-05 21:08:10.734085 | TASK [configure-unbound : Set IPv4 nameservers]
2019-09-05 21:08:10.835407 | ubuntu-bionic | ok
2019-09-05 21:08:10.892643 | 
2019-09-05 21:08:10.893021 | LOOP [configure-unbound : Include OS-specific variables]
2019-09-05 21:08:11.004370 | ubuntu-bionic | ok: "/var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/trusted/project_0/opendev.org/opendev/base-jobs/roles/configure-unbound/vars/Debian.yaml"
2019-09-05 21:08:11.054132 | 
2019-09-05 21:08:11.054415 | TASK [configure-unbound : Ensure Unbound conf.d directory exists]
2019-09-05 21:08:11.293797 | ubuntu-bionic | ok
2019-09-05 21:08:11.345684 | 
2019-09-05 21:08:11.345966 | TASK [configure-unbound : Configure unbound forwarding]
2019-09-05 21:08:11.883932 | ubuntu-bionic | changed
2019-09-05 21:08:11.932058 | 
2019-09-05 21:08:11.932389 | TASK [configure-unbound : Configure unbound TTL]
2019-09-05 21:08:12.430790 | ubuntu-bionic | changed
2019-09-05 21:08:12.485643 | 
2019-09-05 21:08:12.485918 | TASK [configure-unbound : Start unbound]
2019-09-05 21:08:13.550503 | ubuntu-bionic | ok
2019-09-05 21:08:13.584163 | 
2019-09-05 21:08:13.584573 | TASK [configure-unbound : Restart unbound]
2019-09-05 21:08:14.119900 | ubuntu-bionic | changed
2019-09-05 21:08:14.163106 | 
2019-09-05 21:08:14.163331 | PLAY [all]
2019-09-05 21:08:14.223415 | 
2019-09-05 21:08:14.223714 | TASK [validate-host : Define zuul_info_dir fact]
2019-09-05 21:08:14.312334 | ubuntu-bionic | ok
2019-09-05 21:08:14.394928 | 
2019-09-05 21:08:14.395257 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2019-09-05 21:08:14.753202 | ubuntu-bionic | ok
2019-09-05 21:08:14.801471 | 
2019-09-05 21:08:14.801759 | TASK [validate-host : Collect information about the host]
2019-09-05 21:08:15.500277 | ubuntu-bionic | ok
2019-09-05 21:08:15.617229 | 
2019-09-05 21:08:15.617513 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2019-09-05 21:08:16.392818 | ubuntu-bionic | changed
2019-09-05 21:08:16.443750 | 
2019-09-05 21:08:16.444046 | TASK [validate-host : Collect information about zuul worker]
2019-09-05 21:08:17.418636 | ubuntu-bionic | ok
2019-09-05 21:08:17.493300 | 
2019-09-05 21:08:17.493588 | TASK [validate-host : Write out all zuul information for each host]
2019-09-05 21:08:18.195541 | ubuntu-bionic | changed
2019-09-05 21:08:18.245664 | 
2019-09-05 21:08:18.245957 | LOOP [use-cached-repos : Find locally cached git repos]
2019-09-05 21:08:18.532170 | ubuntu-bionic | ok:
2019-09-05 21:08:18.532744 | ubuntu-bionic | {
2019-09-05 21:08:18.532859 | ubuntu-bionic |   "canonical_hostname": "opendev.org",
2019-09-05 21:08:18.532967 | ubuntu-bionic |   "canonical_name": "opendev.org/zuul/zuul-jobs",
2019-09-05 21:08:18.533086 | ubuntu-bionic |   "checkout": "master",
2019-09-05 21:08:18.533190 | ubuntu-bionic |   "name": "zuul/zuul-jobs",
2019-09-05 21:08:18.533291 | ubuntu-bionic |   "required": false,
2019-09-05 21:08:18.533390 | ubuntu-bionic |   "short_name": "zuul-jobs",
2019-09-05 21:08:18.533490 | ubuntu-bionic |   "src_dir": "src/opendev.org/zuul/zuul-jobs"
2019-09-05 21:08:18.533589 | ubuntu-bionic | }
2019-09-05 21:08:18.533723 | ubuntu-bionic | ok: All items complete
2019-09-05 21:08:18.533821 | 
2019-09-05 21:08:18.596335 | 
2019-09-05 21:08:18.596764 | LOOP [use-cached-repos : Clone cached repo to workspace]
2019-09-05 21:08:19.009678 | ubuntu-bionic | Cloning into '/home/zuul/src/opendev.org/zuul/zuul-jobs'...
2019-09-05 21:08:19.010210 | ubuntu-bionic | done.
2019-09-05 21:08:19.010355 | ubuntu-bionic | ok: Item: Runtime: 0:00:00.102232
2019-09-05 21:08:19.088976 | 
2019-09-05 21:08:19.089263 | LOOP [use-cached-repos : Clone upstream repo to workspace]
2019-09-05 21:08:19.364033 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:19.365096 | ubuntu-bionic | changed: All items complete
2019-09-05 21:08:19.365270 | 
2019-09-05 21:08:19.426336 | 
2019-09-05 21:08:19.426678 | LOOP [use-cached-repos : Remove origin from local git repos]
2019-09-05 21:08:19.845334 | ubuntu-bionic | origin	/opt/git/zuul/zuul-jobs (fetch)
2019-09-05 21:08:19.845915 | ubuntu-bionic | origin	/opt/git/zuul/zuul-jobs (push)
2019-09-05 21:08:19.846062 | ubuntu-bionic | ok: Item: Runtime: 0:00:00.010942
2019-09-05 21:08:19.846177 | 
2019-09-05 21:08:19.900334 | 
2019-09-05 21:08:19.900734 | LOOP [mirror-workspace-git-repos : Allow pushing to non-bare repo]
2019-09-05 21:08:20.400635 | ubuntu-bionic | changed: setting changed
2019-09-05 21:08:20.493743 | 
2019-09-05 21:08:20.494046 | LOOP [mirror-workspace-git-repos : Synchronize src repos to workspace directory]
2019-09-05 21:08:21.130129 | ubuntu-bionic | To git+ssh://zuul@104.239.142.130:22//home/zuul/src/opendev.org/zuul/zuul-jobs
2019-09-05 21:08:21.130693 | ubuntu-bionic |    fa2cbea..838a71b  master -> master
2019-09-05 21:08:21.130806 | ubuntu-bionic |  * [new branch]      origin/master -> origin/master
2019-09-05 21:08:21.130950 | ubuntu-bionic | ok: Item: Runtime: 0:00:00.243650
2019-09-05 21:08:21.131091 | ubuntu-bionic | changed: All items complete
2019-09-05 21:08:21.131191 | 
2019-09-05 21:08:21.183159 | 
2019-09-05 21:08:21.183462 | LOOP [mirror-workspace-git-repos : Update remote repository state correctly]
2019-09-05 21:08:21.554572 | ubuntu-bionic | HEAD is now at 838a71b Merge commit 'refs/changes/78/680178/1' of ssh://review.opendev.org:29418/zuul/zuul-jobs into HEAD
2019-09-05 21:08:21.555114 | ubuntu-bionic | Already on 'master'
2019-09-05 21:08:21.555228 | ubuntu-bionic | opendev.org/zuul/zuul-jobs checked out to:
2019-09-05 21:08:21.555340 | ubuntu-bionic | 838a71b7360afde382c8ac78f8f15436ebc2d5a7 Merge commit 'refs/changes/78/680178/1' of ssh://review.opendev.org:29418/zuul/zuul-jobs into HEAD
2019-09-05 21:08:21.555492 | ubuntu-bionic | ok: Item: Runtime: 0:00:00.064633
2019-09-05 21:08:21.608603 | 
2019-09-05 21:08:21.608899 | TASK [mirror-info : Create /etc/ci]
2019-09-05 21:08:21.845834 | ubuntu-bionic | changed
2019-09-05 21:08:21.892165 | 
2019-09-05 21:08:21.892471 | TASK [mirror-info : Install ci_mirror script]
2019-09-05 21:08:22.401343 | ubuntu-bionic | changed
2019-09-05 21:08:22.455537 | 
2019-09-05 21:08:22.455867 | TASK [configure-mirrors : Set up infrastructure mirrors]
2019-09-05 21:08:22.572386 | ubuntu-bionic | ok
2019-09-05 21:08:22.637403 | ubuntu-bionic | included: /var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2019-09-05 21:08:22.666535 | 
2019-09-05 21:08:22.666829 | TASK [configure-mirrors : Install .pydistutils.cfg configuration in homedir]
2019-09-05 21:08:23.195903 | ubuntu-bionic | changed
2019-09-05 21:08:23.246870 | 
2019-09-05 21:08:23.247113 | LOOP [configure-mirrors : Include OS-specific variables]
2019-09-05 21:08:23.363280 | ubuntu-bionic | ok: "/var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/Ubuntu.yaml"
2019-09-05 21:08:23.363839 | ubuntu-bionic | changed: All items complete
2019-09-05 21:08:23.363949 | 
2019-09-05 21:08:23.415171 | 
2019-09-05 21:08:23.415488 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2019-09-05 21:08:23.960878 | ubuntu-bionic | changed
2019-09-05 21:08:24.018670 | 
2019-09-05 21:08:24.019075 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2019-09-05 21:08:24.142784 | ubuntu-bionic | ok: "/var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/Ubuntu.yaml"
2019-09-05 21:08:24.201448 | ubuntu-bionic | included: /var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/Ubuntu.yaml
2019-09-05 21:08:24.237420 | 
2019-09-05 21:08:24.237764 | LOOP [configure-mirrors : Install Ubuntu repository files]
2019-09-05 21:08:24.814932 | ubuntu-bionic | changed: "etc/apt/sources.list"
2019-09-05 21:08:24.815924 | ubuntu-bionic | ok: All items complete
2019-09-05 21:08:24.816037 | 
2019-09-05 21:08:25.224911 | ubuntu-bionic | changed: "etc/apt/apt.conf.d/99unauthenticated"
2019-09-05 21:08:25.256782 | 
2019-09-05 21:08:25.257050 | TASK [configure-mirrors : Update apt cache]
2019-09-05 21:08:25.644795 | ubuntu-bionic | Ign:1 http://mirror.dfw.rax.opendev.org/ubuntu bionic InRelease
2019-09-05 21:08:25.645383 | ubuntu-bionic | Ign:2 http://mirror.dfw.rax.opendev.org/ubuntu bionic-updates InRelease
2019-09-05 21:08:25.646315 | ubuntu-bionic | Ign:3 http://mirror.dfw.rax.opendev.org/ubuntu bionic-backports InRelease
2019-09-05 21:08:25.646864 | ubuntu-bionic | Ign:4 http://mirror.dfw.rax.opendev.org/ubuntu bionic-security InRelease
2019-09-05 21:08:25.647572 | ubuntu-bionic | Get:5 http://mirror.dfw.rax.opendev.org/ubuntu bionic Release [4633 B]
2019-09-05 21:08:25.648507 | ubuntu-bionic | Get:6 http://mirror.dfw.rax.opendev.org/ubuntu bionic-updates Release [4646 B]
2019-09-05 21:08:25.649426 | ubuntu-bionic | Get:7 http://mirror.dfw.rax.opendev.org/ubuntu bionic-backports Release [4556 B]
2019-09-05 21:08:25.650319 | ubuntu-bionic | Get:8 http://mirror.dfw.rax.opendev.org/ubuntu bionic-security Release [4633 B]
2019-09-05 21:08:25.652299 | ubuntu-bionic | Ign:9 http://mirror.dfw.rax.opendev.org/ubuntu bionic Release.gpg
2019-09-05 21:08:25.653270 | ubuntu-bionic | Ign:10 http://mirror.dfw.rax.opendev.org/ubuntu bionic-updates Release.gpg
2019-09-05 21:08:25.654298 | ubuntu-bionic | Ign:11 http://mirror.dfw.rax.opendev.org/ubuntu bionic-backports Release.gpg
2019-09-05 21:08:25.655573 | ubuntu-bionic | Ign:12 http://mirror.dfw.rax.opendev.org/ubuntu bionic-security Release.gpg
2019-09-05 21:08:25.656720 | ubuntu-bionic | Get:13 http://mirror.dfw.rax.opendev.org/ubuntu bionic/universe amd64 Packages [12.3 MB]
2019-09-05 21:08:25.990515 | ubuntu-bionic | Get:14 http://mirror.dfw.rax.opendev.org/ubuntu bionic/main amd64 Packages [1547 kB]
2019-09-05 21:08:26.032586 | ubuntu-bionic | Get:15 http://mirror.dfw.rax.opendev.org/ubuntu bionic-updates/universe amd64 Packages [1388 kB]
2019-09-05 21:08:26.076483 | ubuntu-bionic | Get:16 http://mirror.dfw.rax.opendev.org/ubuntu bionic-updates/main amd64 Packages [1026 kB]
2019-09-05 21:08:26.102369 | ubuntu-bionic | Get:17 http://mirror.dfw.rax.opendev.org/ubuntu bionic-backports/universe amd64 Packages [4678 B]
2019-09-05 21:08:26.102729 | ubuntu-bionic | Get:18 http://mirror.dfw.rax.opendev.org/ubuntu bionic-backports/main amd64 Packages [3398 B]
2019-09-05 21:08:26.104172 | ubuntu-bionic | Get:19 http://mirror.dfw.rax.opendev.org/ubuntu bionic-security/universe amd64 Packages [868 kB]
2019-09-05 21:08:26.123660 | ubuntu-bionic | Get:20 http://mirror.dfw.rax.opendev.org/ubuntu bionic-security/main amd64 Packages [677 kB]
2019-09-05 21:08:27.972644 | ubuntu-bionic | Fetched 17.8 MB in 2s (7602 kB/s)
2019-09-05 21:08:29.195065 | ubuntu-bionic | Reading package lists...
2019-09-05 21:08:29.338008 | ubuntu-bionic | ok: Runtime: 0:00:03.691231
2019-09-05 21:08:29.365067 | 
2019-09-05 21:08:29.365283 | PLAY RECAP
2019-09-05 21:08:29.365433 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2019-09-05 21:08:29.365572 | ubuntu-bionic | ok: 43 changed: 23 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 0
2019-09-05 21:08:29.365676 | 
2019-09-05 21:08:30.063363 | PRE-RUN END RESULT_NORMAL: [trusted : opendev.org/opendev/base-jobs/playbooks/base-test/pre.yaml@master]
2019-09-05 21:08:30.063685 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2019-09-05 21:08:35.210788 | 
2019-09-05 21:08:35.211047 | PLAY [all]
2019-09-05 21:08:35.273283 | 
2019-09-05 21:08:35.273577 | TASK [Install binary dependencies]
2019-09-05 21:08:35.369097 | ubuntu-bionic | ok
2019-09-05 21:08:35.614189 | 
2019-09-05 21:08:35.614480 | TASK [bindep : Look for bindep.txt]
2019-09-05 21:08:36.141292 | ubuntu-bionic | ok
2019-09-05 21:08:36.204455 | 
2019-09-05 21:08:36.204785 | TASK [bindep : Define bindep_file fact]
2019-09-05 21:08:36.314763 | ubuntu-bionic | ok
2019-09-05 21:08:36.382017 | 
2019-09-05 21:08:36.382516 | TASK [bindep : Look for other-requirements.txt]
2019-09-05 21:08:36.455949 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:36.516340 | 
2019-09-05 21:08:36.516662 | TASK [bindep : Define bindep_file fact]
2019-09-05 21:08:36.599000 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:36.668791 | 
2019-09-05 21:08:36.669124 | TASK [bindep : Look for bindep fallback file]
2019-09-05 21:08:36.746692 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:36.801572 | 
2019-09-05 21:08:36.801937 | TASK [bindep : Define bindep_file fact]
2019-09-05 21:08:36.883648 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:36.940883 | 
2019-09-05 21:08:36.941238 | TASK [bindep : Look for bindep command]
2019-09-05 21:08:37.220518 | ubuntu-bionic | ok
2019-09-05 21:08:37.280280 | 
2019-09-05 21:08:37.280696 | TASK [bindep : Check for system bindep]
2019-09-05 21:08:37.444859 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:37.503399 | 
2019-09-05 21:08:37.503750 | TASK [bindep : Define bindep_command fact]
2019-09-05 21:08:37.572788 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:37.656204 | 
2019-09-05 21:08:37.656729 | TASK [bindep : create temp dir for bindep]
2019-09-05 21:08:37.740386 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:37.791052 | 
2019-09-05 21:08:37.791416 | TASK [bindep : install bindep into temporary venv]
2019-09-05 21:08:37.858397 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:37.916110 | 
2019-09-05 21:08:37.916506 | TASK [bindep : Define bindep_command]
2019-09-05 21:08:37.982288 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:38.033749 | 
2019-09-05 21:08:38.034054 | TASK [bindep : Define bindep_run fact]
2019-09-05 21:08:48.393298 | ubuntu-bionic | ok
2019-09-05 21:08:48.441978 | 
2019-09-05 21:08:48.442287 | TASK [bindep : Get list of packages to install from bindep]
2019-09-05 21:08:49.879518 | ubuntu-bionic | libffi-dev
2019-09-05 21:08:49.879655 | ubuntu-bionic | libre2-4
2019-09-05 21:08:49.879702 | ubuntu-bionic | libre2-dev
2019-09-05 21:08:49.879744 | ubuntu-bionic | libssl-dev
2019-09-05 21:08:50.022365 | ubuntu-bionic | ok: Runtime: 0:00:00.801653
2019-09-05 21:08:50.077160 | 
2019-09-05 21:08:50.077554 | TASK [bindep : Install distro packages from bindep]
2019-09-05 21:08:53.323122 | ubuntu-bionic | changed
2019-09-05 21:08:53.379311 | 
2019-09-05 21:08:53.379679 | TASK [bindep : Check that packages are installed]
2019-09-05 21:08:54.469150 | ubuntu-bionic | ok: Runtime: 0:00:00.716705
2019-09-05 21:08:54.520226 | 
2019-09-05 21:08:54.520543 | TASK [bindep : Fail if we cannot install all packages]
2019-09-05 21:08:54.598030 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:54.655602 | 
2019-09-05 21:08:54.655942 | TASK [Run test-setup role]
2019-09-05 21:08:54.739982 | ubuntu-bionic | ok
2019-09-05 21:08:54.878742 | 
2019-09-05 21:08:54.879042 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2019-09-05 21:08:55.120700 | ubuntu-bionic | ok
2019-09-05 21:08:55.168304 | 
2019-09-05 21:08:55.168671 | TASK [test-setup : Run tools/test-setup.sh]
2019-09-05 21:08:55.320487 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:08:55.351736 | 
2019-09-05 21:08:55.351992 | PLAY RECAP
2019-09-05 21:08:55.352175 | ubuntu-bionic | ok: 8 changed: 3 unreachable: 0 failed: 0 skipped: 11 rescued: 0 ignored: 0
2019-09-05 21:08:55.352309 | 
2019-09-05 21:08:55.830390 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2019-09-05 21:08:55.830720 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/tox/pre.yaml@master]
2019-09-05 21:09:00.978711 | 
2019-09-05 21:09:00.979135 | PLAY [all]
2019-09-05 21:09:01.027694 | 
2019-09-05 21:09:01.028003 | TASK [ensure-tox : Ensure tox is installed]
2019-09-05 21:09:01.551050 | ubuntu-bionic | tox is /usr/local/bin/tox
2019-09-05 21:09:01.623483 | ubuntu-bionic | ok: Runtime: 0:00:00.004105
2019-09-05 21:09:01.692822 | 
2019-09-05 21:09:01.693138 | TASK [ensure-python : Install specified version of python interpreter and development files]
2019-09-05 21:09:01.769677 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:09:01.792734 | 
2019-09-05 21:09:01.792923 | PLAY RECAP
2019-09-05 21:09:01.793098 | ubuntu-bionic | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2019-09-05 21:09:01.793248 | 
2019-09-05 21:09:02.286374 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/tox/pre.yaml@master]
2019-09-05 21:09:02.286844 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/tox/run.yaml@master]
2019-09-05 21:09:07.470016 | 
2019-09-05 21:09:07.470314 | PLAY [all]
2019-09-05 21:09:07.545819 | 
2019-09-05 21:09:07.546133 | TASK [revoke-sudo : Check if zuul is sudoer]
2019-09-05 21:09:08.625360 | ubuntu-bionic | ok: Runtime: 0:00:00.009688
2019-09-05 21:09:08.718397 | 
2019-09-05 21:09:08.718715 | TASK [revoke-sudo : Remove sudo access for zuul user.]
2019-09-05 21:09:09.193877 | ubuntu-bionic | changed
2019-09-05 21:09:09.257750 | 
2019-09-05 21:09:09.258361 | TASK [revoke-sudo : Prove that general sudo access is actually revoked.]
2019-09-05 21:09:09.514259 | ubuntu-bionic | sudo: a password is required
2019-09-05 21:09:09.848854 | ubuntu-bionic | ok: Runtime: 0:00:00.008704
2019-09-05 21:09:10.035911 | 
2019-09-05 21:09:10.036230 | TASK [tox : Require tox_envlist variable]
2019-09-05 21:09:10.343240 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:09:10.412136 | 
2019-09-05 21:09:10.412512 | TASK [tox : Check to see if the constraints file exists]
2019-09-05 21:09:10.477918 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:09:10.557560 | 
2019-09-05 21:09:10.557928 | TASK [tox : Fail if constraints file is missing]
2019-09-05 21:09:10.751825 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:09:10.879887 | 
2019-09-05 21:09:10.881030 | TASK [tox : Record file location]
2019-09-05 21:09:11.010401 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:09:11.083048 | 
2019-09-05 21:09:11.083385 | TASK [tox : Run tox without tests]
2019-09-05 21:09:11.753545 | ubuntu-bionic | /usr/local/lib/python2.7/dist-packages/tox/config/__init__.py:578: UserWarning: conflicting basepython version (set 36, should be 35) for env 'py35';resolve conflict or set ignore_basepython_conflict
2019-09-05 21:09:11.753740 | ubuntu-bionic |   proposed_version, implied_version, testenv_config.envname
2019-09-05 21:09:11.804578 | ubuntu-bionic | py35 create: /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35
2019-09-05 21:09:16.352054 | ubuntu-bionic | py35 installdeps: -r/home/zuul/src/opendev.org/zuul/zuul-jobs/test-requirements.txt
2019-09-05 21:10:05.308581 | ubuntu-bionic | py35 installed: alembic==1.1.0,ansible==2.5.15,ansible-lint==4.1.1a0,appdirs==1.4.3,APScheduler==3.6.1,asn1crypto==0.24.0,attrs==19.1.0,Babel==2.7.0,backports.functools-lru-cache==1.5,bashate==0.6.0,bcrypt==3.1.7,beautifulsoup4==4.8.0,bs4==0.0.1,CacheControl==0.12.5,cachetools==3.1.1,certifi==2019.6.16,cffi==1.12.3,chardet==3.0.4,cheroot==6.5.8,CherryPy==18.2.0,cliff==2.15.0,cmd2==0.9.16,colorama==0.4.1,cryptography==2.7,decorator==4.4.0,docutils==0.15.2,dogpile.cache==0.7.1,entrypoints==0.3,extras==1.0.0,fb-re2==1.0.7,fixtures==3.0.0,flake8==3.7.8,future==0.17.1,gear==0.14.0,gitdb2==2.0.5,github3.py==1.3.0,GitPython==2.1.11,idna==2.8,iso8601==0.1.12,jaraco.functools==2.0,Jinja2==2.10.1,jmespath==0.9.4,jsonpatch==1.24,jsonpath-rw==1.4.0,jsonpointer==2.0,jwcrypto==0.6.0,kazoo==2.6.1,keystoneauth1==3.17.0,linecache2==1.0.0,lockfile==0.12.2,Mako==1.1.0,MarkupSafe==1.1.1,mccabe==0.6.1,more-itertools==7.2.0,msgpack==0.6.1,munch==2.3.2,netaddr==0.7.19,netifaces==0.10.9,openstacksdk==0.35.0,os-service-types==1.7.0,paho-mqtt==1.4.0,paramiko==2.6.0,pbr==5.4.3,ply==3.11,portend==2.5,prettytable==0.7.2,psutil==5.6.3,pycodestyle==2.5.0,pycparser==2.19,pyflakes==2.1.1,PyJWT==1.7.1,PyNaCl==1.3.0,pyparsing==2.4.2,pyperclip==1.7.0,python-daemon==2.0.6,python-dateutil==2.8.0,python-editor==1.0.4,python-mimeparse==1.6.0,python-subunit==1.3.0,pytz==2019.2,PyYAML==5.1.2,repoze.lru==0.7,requests==2.22.0,requestsexceptions==1.4.0,Routes==2.4.1,ruamel.yaml==0.16.5,ruamel.yaml.clib==0.1.2,six==1.12.0,smmap2==2.0.5,soupsieve==1.9.3,SQLAlchemy==1.3.8,statsd==3.3.0,stestr==2.5.1,stevedore==1.31.0,tempora==1.14.1,testtools==2.3.0,traceback2==1.4.0,tzlocal==2.0.0,unittest2==1.1.0,uritemplate==3.0.0,urllib3==1.25.3,virtualenv==16.7.5,voluptuous==0.11.7,wcwidth==0.1.7,ws4py==0.5.1,zc.lockfile==2.0,zuul==3.10.1
2019-09-05 21:10:05.308836 | ubuntu-bionic | ___________________________________ summary ____________________________________
2019-09-05 21:10:05.308908 | ubuntu-bionic |   py35: skipped tests
2019-09-05 21:10:05.308965 | ubuntu-bionic |   congratulations :)
2019-09-05 21:10:05.758078 | ubuntu-bionic | ok: Runtime: 0:00:53.982944
2019-09-05 21:10:05.825344 | 
2019-09-05 21:10:05.825694 | TASK [tox : Install any sibling python packages]
2019-09-05 21:10:07.707963 | ubuntu-bionic | ok:
2019-09-05 21:10:07.708561 | ubuntu-bionic | Processing siblings for zuul-jobs from src/opendev.org/zuul/zuul-jobs
2019-09-05 21:10:07.708676 | ubuntu-bionic | Found alembic python package installed
2019-09-05 21:10:07.708797 | ubuntu-bionic | Found ansible python package installed
2019-09-05 21:10:07.708901 | ubuntu-bionic | Found ansible-lint python package installed
2019-09-05 21:10:07.709546 | ubuntu-bionic | Found appdirs python package installed
2019-09-05 21:10:07.709734 | ubuntu-bionic | Found APScheduler python package installed
2019-09-05 21:10:07.709900 | ubuntu-bionic | Found asn1crypto python package installed
2019-09-05 21:10:07.710081 | ubuntu-bionic | Found attrs python package installed
2019-09-05 21:10:07.710251 | ubuntu-bionic | Found Babel python package installed
2019-09-05 21:10:07.710416 | ubuntu-bionic | Found backports.functools-lru-cache python package installed
2019-09-05 21:10:07.710581 | ubuntu-bionic | Found bashate python package installed
2019-09-05 21:10:07.710741 | ubuntu-bionic | Found bcrypt python package installed
2019-09-05 21:10:07.711026 | ubuntu-bionic | Found beautifulsoup4 python package installed
2019-09-05 21:10:07.711188 | ubuntu-bionic | Found bs4 python package installed
2019-09-05 21:10:07.711351 | ubuntu-bionic | Found CacheControl python package installed
2019-09-05 21:10:07.711510 | ubuntu-bionic | Found cachetools python package installed
2019-09-05 21:10:07.711668 | ubuntu-bionic | Found certifi python package installed
2019-09-05 21:10:07.711825 | ubuntu-bionic | Found cffi python package installed
2019-09-05 21:10:07.712008 | ubuntu-bionic | Found chardet python package installed
2019-09-05 21:10:07.712166 | ubuntu-bionic | Found cheroot python package installed
2019-09-05 21:10:07.712359 | ubuntu-bionic | Found CherryPy python package installed
2019-09-05 21:10:07.712518 | ubuntu-bionic | Found cliff python package installed
2019-09-05 21:10:07.712674 | ubuntu-bionic | Found cmd2 python package installed
2019-09-05 21:10:07.713061 | ubuntu-bionic | Found colorama python package installed
2019-09-05 21:10:07.713223 | ubuntu-bionic | Found cryptography python package installed
2019-09-05 21:10:07.713381 | ubuntu-bionic | Found decorator python package installed
2019-09-05 21:10:07.713537 | ubuntu-bionic | Found docutils python package installed
2019-09-05 21:10:07.713696 | ubuntu-bionic | Found dogpile.cache python package installed
2019-09-05 21:10:07.724159 | ubuntu-bionic | Found entrypoints python package installed
2019-09-05 21:10:07.724345 | ubuntu-bionic | Found extras python package installed
2019-09-05 21:10:07.724451 | ubuntu-bionic | Found fb-re2 python package installed
2019-09-05 21:10:07.724552 | ubuntu-bionic | Found fixtures python package installed
2019-09-05 21:10:07.724651 | ubuntu-bionic | Found flake8 python package installed
2019-09-05 21:10:07.724764 | ubuntu-bionic | Found future python package installed
2019-09-05 21:10:07.724865 | ubuntu-bionic | Found gear python package installed
2019-09-05 21:10:07.724964 | ubuntu-bionic | Found gitdb2 python package installed
2019-09-05 21:10:07.725081 | ubuntu-bionic | Found github3.py python package installed
2019-09-05 21:10:07.725183 | ubuntu-bionic | Found GitPython python package installed
2019-09-05 21:10:07.725282 | ubuntu-bionic | Found idna python package installed
2019-09-05 21:10:07.725379 | ubuntu-bionic | Found iso8601 python package installed
2019-09-05 21:10:07.725477 | ubuntu-bionic | Found jaraco.functools python package installed
2019-09-05 21:10:07.725575 | ubuntu-bionic | Found Jinja2 python package installed
2019-09-05 21:10:07.725673 | ubuntu-bionic | Found jmespath python package installed
2019-09-05 21:10:07.725786 | ubuntu-bionic | Found jsonpatch python package installed
2019-09-05 21:10:07.725885 | ubuntu-bionic | Found jsonpath-rw python package installed
2019-09-05 21:10:07.725991 | ubuntu-bionic | Found jsonpointer python package installed
2019-09-05 21:10:07.726099 | ubuntu-bionic | Found jwcrypto python package installed
2019-09-05 21:10:07.726203 | ubuntu-bionic | Found kazoo python package installed
2019-09-05 21:10:07.726301 | ubuntu-bionic | Found keystoneauth1 python package installed
2019-09-05 21:10:07.726399 | ubuntu-bionic | Found linecache2 python package installed
2019-09-05 21:10:07.726497 | ubuntu-bionic | Found lockfile python package installed
2019-09-05 21:10:07.726594 | ubuntu-bionic | Found Mako python package installed
2019-09-05 21:10:07.726692 | ubuntu-bionic | Found MarkupSafe python package installed
2019-09-05 21:10:07.726804 | ubuntu-bionic | Found mccabe python package installed
2019-09-05 21:10:07.726903 | ubuntu-bionic | Found more-itertools python package installed
2019-09-05 21:10:07.727031 | ubuntu-bionic | Found msgpack python package installed
2019-09-05 21:10:07.727132 | ubuntu-bionic | Found munch python package installed
2019-09-05 21:10:07.727231 | ubuntu-bionic | Found netaddr python package installed
2019-09-05 21:10:07.727328 | ubuntu-bionic | Found netifaces python package installed
2019-09-05 21:10:07.727425 | ubuntu-bionic | Found openstacksdk python package installed
2019-09-05 21:10:07.727522 | ubuntu-bionic | Found os-service-types python package installed
2019-09-05 21:10:07.727620 | ubuntu-bionic | Found paho-mqtt python package installed
2019-09-05 21:10:07.727722 | ubuntu-bionic | Found paramiko python package installed
2019-09-05 21:10:07.727829 | ubuntu-bionic | Found pbr python package installed
2019-09-05 21:10:07.727927 | ubuntu-bionic | Found ply python package installed
2019-09-05 21:10:07.728045 | ubuntu-bionic | Found portend python package installed
2019-09-05 21:10:07.728144 | ubuntu-bionic | Found prettytable python package installed
2019-09-05 21:10:07.728242 | ubuntu-bionic | Found psutil python package installed
2019-09-05 21:10:07.728372 | ubuntu-bionic | Found pycodestyle python package installed
2019-09-05 21:10:07.728470 | ubuntu-bionic | Found pycparser python package installed
2019-09-05 21:10:07.728567 | ubuntu-bionic | Found pyflakes python package installed
2019-09-05 21:10:07.728664 | ubuntu-bionic | Found PyJWT python package installed
2019-09-05 21:10:07.728778 | ubuntu-bionic | Found PyNaCl python package installed
2019-09-05 21:10:07.728876 | ubuntu-bionic | Found pyparsing python package installed
2019-09-05 21:10:07.728979 | ubuntu-bionic | Found pyperclip python package installed
2019-09-05 21:10:07.729090 | ubuntu-bionic | Found python-daemon python package installed
2019-09-05 21:10:07.729194 | ubuntu-bionic | Found python-dateutil python package installed
2019-09-05 21:10:07.729293 | ubuntu-bionic | Found python-editor python package installed
2019-09-05 21:10:07.729390 | ubuntu-bionic | Found python-mimeparse python package installed
2019-09-05 21:10:07.729841 | ubuntu-bionic | Found python-subunit python package installed
2019-09-05 21:10:07.729942 | ubuntu-bionic | Found pytz python package installed
2019-09-05 21:10:07.730063 | ubuntu-bionic | Found PyYAML python package installed
2019-09-05 21:10:07.730162 | ubuntu-bionic | Found repoze.lru python package installed
2019-09-05 21:10:07.730263 | ubuntu-bionic | Found requests python package installed
2019-09-05 21:10:07.730361 | ubuntu-bionic | Found requestsexceptions python package installed
2019-09-05 21:10:07.730458 | ubuntu-bionic | Found Routes python package installed
2019-09-05 21:10:07.730557 | ubuntu-bionic | Found ruamel.yaml python package installed
2019-09-05 21:10:07.730654 | ubuntu-bionic | Found ruamel.yaml.clib python package installed
2019-09-05 21:10:07.730767 | ubuntu-bionic | Found six python package installed
2019-09-05 21:10:07.730867 | ubuntu-bionic | Found smmap2 python package installed
2019-09-05 21:10:07.730965 | ubuntu-bionic | Found soupsieve python package installed
2019-09-05 21:10:07.731080 | ubuntu-bionic | Found SQLAlchemy python package installed
2019-09-05 21:10:07.731287 | ubuntu-bionic | Found statsd python package installed
2019-09-05 21:10:07.731388 | ubuntu-bionic | Found stestr python package installed
2019-09-05 21:10:07.731485 | ubuntu-bionic | Found stevedore python package installed
2019-09-05 21:10:07.731583 | ubuntu-bionic | Found tempora python package installed
2019-09-05 21:10:07.731681 | ubuntu-bionic | Found testtools python package installed
2019-09-05 21:10:07.731795 | ubuntu-bionic | Found traceback2 python package installed
2019-09-05 21:10:07.731893 | ubuntu-bionic | Found tzlocal python package installed
2019-09-05 21:10:07.732004 | ubuntu-bionic | Found unittest2 python package installed
2019-09-05 21:10:07.732111 | ubuntu-bionic | Found uritemplate python package installed
2019-09-05 21:10:07.732210 | ubuntu-bionic | Found urllib3 python package installed
2019-09-05 21:10:07.732334 | ubuntu-bionic | Found virtualenv python package installed
2019-09-05 21:10:07.732666 | ubuntu-bionic | Found voluptuous python package installed
2019-09-05 21:10:07.732783 | ubuntu-bionic | Found wcwidth python package installed
2019-09-05 21:10:07.732883 | ubuntu-bionic | Found ws4py python package installed
2019-09-05 21:10:07.732988 | ubuntu-bionic | Found zc.lockfile python package installed
2019-09-05 21:10:07.733097 | ubuntu-bionic | Found zuul python package installed
2019-09-05 21:10:07.787352 | 
2019-09-05 21:10:07.787699 | TASK [tox : Emit tox command]
2019-09-05 21:10:07.928176 | Running tox: tox -epy35 -vv
2019-09-05 21:10:07.993614 | 
2019-09-05 21:10:07.993936 | TASK [tox : Run tox]
2019-09-05 21:10:08.488366 | ubuntu-bionic | using tox.ini: /home/zuul/src/opendev.org/zuul/zuul-jobs/tox.ini (pid 1424)
2019-09-05 21:10:08.489765 | ubuntu-bionic |   removing /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/log
2019-09-05 21:10:08.566175 | ubuntu-bionic | python3 (/usr/bin/python3) is {u'executable': u'/usr/bin/python3', u'name': u'python', u'version_info': [3, 6, 8, u'final', 0], u'sysplatform': u'linux', u'version': u'3.6.8 (default, Jan 14 2019, 11:02:34) \n[GCC 8.0.1 20180414 (experimental) [trunk revision 259383]]', u'is_64': True}
2019-09-05 21:10:08.566341 | ubuntu-bionic | py35 uses /usr/bin/python3
2019-09-05 21:10:08.609510 | ubuntu-bionic | /usr/local/lib/python2.7/dist-packages/tox/config/__init__.py:578: UserWarning: conflicting basepython version (set 36, should be 35) for env 'py35';resolve conflict or set ignore_basepython_conflict
2019-09-05 21:10:08.609689 | ubuntu-bionic |   proposed_version, implied_version, testenv_config.envname
2019-09-05 21:10:08.656201 | ubuntu-bionic | using tox-3.13.2 from /usr/local/lib/python2.7/dist-packages/tox/__init__.pyc (pid 1424)
2019-09-05 21:10:08.656322 | ubuntu-bionic | skipping sdist step
2019-09-05 21:10:08.656763 | ubuntu-bionic | py35 start: getenv /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35
2019-09-05 21:10:08.669499 | ubuntu-bionic | py35 reusing: /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35
2019-09-05 21:10:08.714657 | ubuntu-bionic | py35 finish: getenv /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35 after 0.06 seconds
2019-09-05 21:10:08.714877 | ubuntu-bionic | py35 start: finishvenv
2019-09-05 21:10:08.726773 | ubuntu-bionic | py35 finish: finishvenv  after 0.01 seconds
2019-09-05 21:10:08.726994 | ubuntu-bionic | py35 start: envreport
2019-09-05 21:10:08.727485 | ubuntu-bionic | setting PATH=/home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
2019-09-05 21:10:08.732498 | ubuntu-bionic | [1437] /home/zuul/src/opendev.org/zuul/zuul-jobs$ /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35/bin/python -m pip freeze >.tox/py35/log/py35-3.log
2019-09-05 21:10:09.405386 | ubuntu-bionic | py35 finish: envreport  after 0.68 seconds
2019-09-05 21:10:09.408667 | ubuntu-bionic | py35 installed: alembic==1.1.0,ansible==2.5.15,ansible-lint==4.1.1a0,appdirs==1.4.3,APScheduler==3.6.1,asn1crypto==0.24.0,attrs==19.1.0,Babel==2.7.0,backports.functools-lru-cache==1.5,bashate==0.6.0,bcrypt==3.1.7,beautifulsoup4==4.8.0,bs4==0.0.1,CacheControl==0.12.5,cachetools==3.1.1,certifi==2019.6.16,cffi==1.12.3,chardet==3.0.4,cheroot==6.5.8,CherryPy==18.2.0,cliff==2.15.0,cmd2==0.9.16,colorama==0.4.1,cryptography==2.7,decorator==4.4.0,docutils==0.15.2,dogpile.cache==0.7.1,entrypoints==0.3,extras==1.0.0,fb-re2==1.0.7,fixtures==3.0.0,flake8==3.7.8,future==0.17.1,gear==0.14.0,gitdb2==2.0.5,github3.py==1.3.0,GitPython==2.1.11,idna==2.8,iso8601==0.1.12,jaraco.functools==2.0,Jinja2==2.10.1,jmespath==0.9.4,jsonpatch==1.24,jsonpath-rw==1.4.0,jsonpointer==2.0,jwcrypto==0.6.0,kazoo==2.6.1,keystoneauth1==3.17.0,linecache2==1.0.0,lockfile==0.12.2,Mako==1.1.0,MarkupSafe==1.1.1,mccabe==0.6.1,more-itertools==7.2.0,msgpack==0.6.1,munch==2.3.2,netaddr==0.7.19,netifaces==0.10.9,openstacksdk==0.35.0,os-service-types==1.7.0,paho-mqtt==1.4.0,paramiko==2.6.0,pbr==5.4.3,ply==3.11,portend==2.5,prettytable==0.7.2,psutil==5.6.3,pycodestyle==2.5.0,pycparser==2.19,pyflakes==2.1.1,PyJWT==1.7.1,PyNaCl==1.3.0,pyparsing==2.4.2,pyperclip==1.7.0,python-daemon==2.0.6,python-dateutil==2.8.0,python-editor==1.0.4,python-mimeparse==1.6.0,python-subunit==1.3.0,pytz==2019.2,PyYAML==5.1.2,repoze.lru==0.7,requests==2.22.0,requestsexceptions==1.4.0,Routes==2.4.1,ruamel.yaml==0.16.5,ruamel.yaml.clib==0.1.2,six==1.12.0,smmap2==2.0.5,soupsieve==1.9.3,SQLAlchemy==1.3.8,statsd==3.3.0,stestr==2.5.1,stevedore==1.31.0,tempora==1.14.1,testtools==2.3.0,traceback2==1.4.0,tzlocal==2.0.0,unittest2==1.1.0,uritemplate==3.0.0,urllib3==1.25.3,virtualenv==16.7.5,voluptuous==0.11.7,wcwidth==0.1.7,ws4py==0.5.1,zc.lockfile==2.0,zuul==3.10.1
2019-09-05 21:10:09.408810 | ubuntu-bionic | py35 start: run-test-pre
2019-09-05 21:10:09.408949 | ubuntu-bionic | py35 run-test-pre: PYTHONHASHSEED='933110646'
2019-09-05 21:10:09.409083 | ubuntu-bionic | py35 finish: run-test-pre  after 0.00 seconds
2019-09-05 21:10:09.409175 | ubuntu-bionic | py35 start: run-test
2019-09-05 21:10:09.409302 | ubuntu-bionic | py35 run-test: commands[0] | stestr run
2019-09-05 21:10:09.409649 | ubuntu-bionic | setting PATH=/home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
2019-09-05 21:10:09.409909 | ubuntu-bionic | [1438] /home/zuul/src/opendev.org/zuul/zuul-jobs$ /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35/bin/stestr run
2019-09-05 21:10:12.022541 | ubuntu-bionic | {1} roles.htmlify-logs.library.test_htmlify.TestHTMLify.test_htmlify [0.003790s] ... ok
2019-09-05 21:10:12.023302 | ubuntu-bionic | {1} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileDetail.test_get_file_detail [0.000881s] ... ok
2019-09-05 21:10:12.027878 | ubuntu-bionic | {1} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_single_dir_trailing_slash [0.004351s] ... ok
2019-09-05 21:10:12.032708 | ubuntu-bionic | {0} roles.write-inventory.library.test_write_inventory.TestWriteInventory.test_all [0.004680s] ... ok
2019-09-05 21:10:12.033056 | ubuntu-bionic | {3} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_no_parent_links [0.013051s] ... ok
2019-09-05 21:10:12.036570 | ubuntu-bionic | {0} roles.generate-zuul-manifest.library.test_generate_manifest.TestFileList.test_single_dir [0.004172s] ... ok
2019-09-05 21:10:12.037425 | ubuntu-bionic | {6} roles.write-inventory.library.test_write_inventory.TestWriteInventory.test_include [0.005425s] ... ok
2019-09-05 21:10:12.039002 | ubuntu-bionic | {3} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_single_dir [0.005736s] ... ok
2019-09-05 21:10:12.039295 | ubuntu-bionic | {5} roles.write-inventory.library.test_write_inventory.TestWriteInventory.test_exclude [0.004411s] ... ok
2019-09-05 21:10:12.048739 | ubuntu-bionic | {2} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileDetail.test_get_file_detail_missing_file [0.000455s] ... ok
2019-09-05 21:10:12.049673 | ubuntu-bionic | {4} roles.generate-zuul-manifest.library.test_generate_manifest.TestFileList.test_symlinks [0.003752s] ... ok
2019-09-05 21:10:12.050212 | ubuntu-bionic | {4} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_single_file [0.000347s] ... ok
2019-09-05 21:10:12.050503 | ubuntu-bionic | {5} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_index_files [0.011245s] ... ok
2019-09-05 21:10:12.054718 | ubuntu-bionic | {6} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_topdir_parent_link [0.016129s] ... ok
2019-09-05 21:10:12.061760 | ubuntu-bionic | {2} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_index_files_trailing_slash [0.012549s] ... ok
2019-09-05 21:10:12.071985 | ubuntu-bionic | Identity added: /tmp/tmph9j14evh/key1 (/tmp/tmph9j14evh/key1)
2019-09-05 21:10:12.083007 | ubuntu-bionic | {7} roles.upload-forge.library.test_forge_upload.TestForgeUpload.test_get_url [0.000282s] ... ok
2019-09-05 21:10:12.089401 | ubuntu-bionic | {7} roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_symlinks [0.006086s] ... ok
2019-09-05 21:10:12.098862 | ubuntu-bionic | {0} roles.add-build-sshkey.library.test_sshagent_remove_keys.TestAgent.test_agent [0.061170s] ... ok
2019-09-05 21:10:12.222826 | ubuntu-bionic |
2019-09-05 21:10:12.222929 | ubuntu-bionic | ======
2019-09-05 21:10:12.222979 | ubuntu-bionic | Totals
2019-09-05 21:10:12.223018 | ubuntu-bionic | ======
2019-09-05 21:10:12.223085 | ubuntu-bionic | Ran: 18 tests in 0.0800 sec.
2019-09-05 21:10:12.223131 | ubuntu-bionic |  - Passed: 18
2019-09-05 21:10:12.223177 | ubuntu-bionic |  - Skipped: 0
2019-09-05 21:10:12.223231 | ubuntu-bionic |  - Expected Fail: 0
2019-09-05 21:10:12.223295 | ubuntu-bionic |  - Unexpected Success: 0
2019-09-05 21:10:12.223340 | ubuntu-bionic |  - Failed: 0
2019-09-05 21:10:12.223429 | ubuntu-bionic | Sum of execute time for each test: 0.1585 sec.
2019-09-05 21:10:12.223458 | ubuntu-bionic |
2019-09-05 21:10:12.223504 | ubuntu-bionic | ==============
2019-09-05 21:10:12.223551 | ubuntu-bionic | Worker Balance
2019-09-05 21:10:12.223603 | ubuntu-bionic | ==============
2019-09-05 21:10:12.223683 | ubuntu-bionic |  - Worker 0 (3 tests) => 0:00:00.070794
2019-09-05 21:10:12.223764 | ubuntu-bionic |  - Worker 1 (3 tests) => 0:00:00.009501
2019-09-05 21:10:12.223843 | ubuntu-bionic |  - Worker 2 (2 tests) => 0:00:00.013268
2019-09-05 21:10:12.223923 | ubuntu-bionic |  - Worker 3 (2 tests) => 0:00:00.019027
2019-09-05 21:10:12.224003 | ubuntu-bionic |  - Worker 4 (2 tests) => 0:00:00.004526
2019-09-05 21:10:12.224083 | ubuntu-bionic |  - Worker 5 (2 tests) => 0:00:00.016103
2019-09-05 21:10:12.224162 | ubuntu-bionic |  - Worker 6 (2 tests) => 0:00:00.023094
2019-09-05 21:10:12.224251 | ubuntu-bionic |  - Worker 7 (2 tests) => 0:00:00.006773
2019-09-05 21:10:12.257276 | ubuntu-bionic | py35 run-test: commands[1] | stestr slowest
2019-09-05 21:10:12.257679 | ubuntu-bionic | setting PATH=/home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
2019-09-05 21:10:12.260390 | ubuntu-bionic | [1487] /home/zuul/src/opendev.org/zuul/zuul-jobs$ /home/zuul/src/opendev.org/zuul/zuul-jobs/.tox/py35/bin/stestr slowest
2019-09-05 21:10:12.708081 | ubuntu-bionic | Test id                                                                                              Runtime (s)
2019-09-05 21:10:12.708333 | ubuntu-bionic | ---------------------------------------------------------------------------------------------------  -----------
2019-09-05 21:10:12.708510 | ubuntu-bionic | roles.add-build-sshkey.library.test_sshagent_remove_keys.TestAgent.test_agent                        0.061
2019-09-05 21:10:12.708682 | ubuntu-bionic | roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_topdir_parent_link          0.016
2019-09-05 21:10:12.708879 | ubuntu-bionic | roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_no_parent_links             0.013
2019-09-05 21:10:12.709072 | ubuntu-bionic | roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_index_files_trailing_slash  0.013
2019-09-05 21:10:12.709249 | ubuntu-bionic | roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_index_files                 0.011
2019-09-05 21:10:12.709419 | ubuntu-bionic | roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_symlinks                    0.006
2019-09-05 21:10:12.709589 | ubuntu-bionic | roles.upload-logs-swift.library.test_zuul_swift_upload.TestFileList.test_single_dir                  0.006
2019-09-05 21:10:12.709759 | ubuntu-bionic | roles.write-inventory.library.test_write_inventory.TestWriteInventory.test_include                   0.005
2019-09-05 21:10:12.709928 | ubuntu-bionic | roles.write-inventory.library.test_write_inventory.TestWriteInventory.test_all                       0.005
2019-09-05 21:10:12.710110 | ubuntu-bionic | roles.write-inventory.library.test_write_inventory.TestWriteInventory.test_exclude                   0.004
2019-09-05 21:10:12.733229 | ubuntu-bionic | py35 finish: run-test  after 3.33 seconds
2019-09-05 21:10:12.733600 | ubuntu-bionic | py35 start: run-test-post
2019-09-05 21:10:12.733744 | ubuntu-bionic | py35 finish: run-test-post  after 0.00 seconds
2019-09-05 21:10:12.734030 | ubuntu-bionic | ___________________________________ summary ____________________________________
2019-09-05 21:10:12.734120 | ubuntu-bionic |   py35: commands succeeded
2019-09-05 21:10:12.734179 | ubuntu-bionic |   congratulations :)
2019-09-05 21:10:13.091423 | ubuntu-bionic | ok: Runtime: 0:00:04.494056
2019-09-05 21:10:13.128199 | 
2019-09-05 21:10:13.128572 | PLAY RECAP
2019-09-05 21:10:13.128786 | ubuntu-bionic | ok: 7 changed: 5 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 0
2019-09-05 21:10:13.128956 | 
2019-09-05 21:10:13.732249 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/tox/run.yaml@master]
2019-09-05 21:10:13.732816 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/tox/post.yaml@master]
2019-09-05 21:10:24.764518 | 
2019-09-05 21:10:24.765284 | PLAY [all]
2019-09-05 21:10:24.859890 | 
2019-09-05 21:10:24.860215 | TASK [fetch-tox-output : Set tox log path for multiple nodes]
2019-09-05 21:10:24.942096 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:10:25.014921 | 
2019-09-05 21:10:25.015236 | TASK [fetch-tox-output : Set tox log path for single node]
2019-09-05 21:10:25.118374 | ubuntu-bionic | ok
2019-09-05 21:10:25.209132 | 
2019-09-05 21:10:25.209419 | TASK [fetch-tox-output : Ensure local tox dir]
2019-09-05 21:10:26.240938 | ubuntu-bionic | changed
2019-09-05 21:10:26.294858 | 
2019-09-05 21:10:26.295168 | TASK [fetch-tox-output : Set envlist fact]
2019-09-05 21:10:26.395268 | ubuntu-bionic | ok
2019-09-05 21:10:26.460381 | 
2019-09-05 21:10:26.460711 | TASK [fetch-tox-output : Find all environments]
2019-09-05 21:10:26.620740 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:10:26.674303 | 
2019-09-05 21:10:26.674636 | TASK [fetch-tox-output : Set envlist fact]
2019-09-05 21:10:26.743244 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:10:26.803180 | 
2019-09-05 21:10:26.803490 | LOOP [fetch-tox-output : Collect tox logs]
2019-09-05 21:10:29.221776 | ubuntu-bionic | changed:
2019-09-05 21:10:29.222410 | ubuntu-bionic | .d..tp..... ./
2019-09-05 21:10:29.222527 | ubuntu-bionic | >f+++++++++ .lock
2019-09-05 21:10:29.222635 | ubuntu-bionic | >f+++++++++ py35-0.log
2019-09-05 21:10:29.222741 | ubuntu-bionic | >f+++++++++ py35-1.log
2019-09-05 21:10:29.222845 | ubuntu-bionic | >f+++++++++ py35-2.log
2019-09-05 21:10:29.223521 | ubuntu-bionic | >f+++++++++ py35-3.log
2019-09-05 21:10:29.224414 | ubuntu-bionic | >f+++++++++ py35-siblings.txt
2019-09-05 21:10:29.357706 | 
2019-09-05 21:10:29.357924 | PLAY RECAP
2019-09-05 21:10:29.358082 | ubuntu-bionic | ok: 4 changed: 2 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2019-09-05 21:10:29.358189 | 
2019-09-05 21:10:29.971151 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/tox/post.yaml@master]
2019-09-05 21:10:29.971439 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2019-09-05 21:10:35.987261 | 
2019-09-05 21:10:35.987563 | PLAY [all]
2019-09-05 21:10:36.047431 | 
2019-09-05 21:10:36.047732 | TASK [fetch-subunit-output : Find stestr or testr executable]
2019-09-05 21:10:36.328095 | ubuntu-bionic | changed
2019-09-05 21:10:36.406553 | 
2019-09-05 21:10:36.406855 | TASK [fetch-subunit-output : Generate subunit file]
2019-09-05 21:10:38.689443 | ubuntu-bionic | ok: Runtime: 0:00:00.479900
2019-09-05 21:10:38.801781 | 
2019-09-05 21:10:38.802748 | TASK [fetch-subunit-output : Look for subunit2html command]
2019-09-05 21:10:39.817952 | ubuntu-bionic | changed
2019-09-05 21:10:39.880665 | 
2019-09-05 21:10:39.880984 | TASK [fetch-subunit-output : Define subunit_html_command fact]
2019-09-05 21:10:40.031940 | ubuntu-bionic | ok
2019-09-05 21:10:40.081104 | 
2019-09-05 21:10:40.081387 | TASK [fetch-subunit-output : Emit a debug line so we can search logstash for fallback hits]
2019-09-05 21:10:40.202135 | subunit2html found in: /usr/os-testr-env/bin/subunit2html
2019-09-05 21:10:40.262813 | 
2019-09-05 21:10:40.263422 | TASK [fetch-subunit-output : Generate testr_results.html file]
2019-09-05 21:10:41.368507 | ubuntu-bionic | ok: Runtime: 0:00:00.342678
2019-09-05 21:10:41.423539 | 
2019-09-05 21:10:41.423851 | TASK [fetch-subunit-output : Find subunit files]
2019-09-05 21:10:42.098205 | ubuntu-bionic | ok
2019-09-05 21:10:42.167394 | 
2019-09-05 21:10:42.167705 | LOOP [fetch-subunit-output : Compress subunit files]
2019-09-05 21:10:42.960671 | ubuntu-bionic | changed:
2019-09-05 21:10:42.961293 | ubuntu-bionic | {
2019-09-05 21:10:42.961408 | ubuntu-bionic |   "atime": 1567717840.9074678,
2019-09-05 21:10:42.961514 | ubuntu-bionic |   "ctime": 1567717840.9074678,
2019-09-05 21:10:42.961619 | ubuntu-bionic |   "dev": 51713,
2019-09-05 21:10:42.961722 | ubuntu-bionic |   "gid": 1000,
2019-09-05 21:10:42.961823 | ubuntu-bionic |   "gr_name": "zuul",
2019-09-05 21:10:42.961924 | ubuntu-bionic |   "inode": 4187612,
2019-09-05 21:10:42.962024 | ubuntu-bionic |   "isblk": false,
2019-09-05 21:10:42.962123 | ubuntu-bionic |   "ischr": false,
2019-09-05 21:10:42.962237 | ubuntu-bionic |   "isdir": false,
2019-09-05 21:10:42.962337 | ubuntu-bionic |   "isfifo": false,
2019-09-05 21:10:42.962435 | ubuntu-bionic |   "isgid": false,
2019-09-05 21:10:42.962533 | ubuntu-bionic |   "islnk": false,
2019-09-05 21:10:42.962631 | ubuntu-bionic |   "isreg": true,
2019-09-05 21:10:42.962729 | ubuntu-bionic |   "issock": false,
2019-09-05 21:10:42.962827 | ubuntu-bionic |   "isuid": false,
2019-09-05 21:10:42.962932 | ubuntu-bionic |   "mode": "0664",
2019-09-05 21:10:42.963031 | ubuntu-bionic |   "mtime": 1567717840.9074678,
2019-09-05 21:10:42.963129 | ubuntu-bionic |   "nlink": 1,
2019-09-05 21:10:42.963431 | ubuntu-bionic |   "path": "/home/zuul/src/opendev.org/zuul/zuul-jobs/testr_results.html",
2019-09-05 21:10:42.963595 | ubuntu-bionic |   "pw_name": "zuul",
2019-09-05 21:10:42.963705 | ubuntu-bionic |   "rgrp": true,
2019-09-05 21:10:42.963810 | ubuntu-bionic |   "roth": true,
2019-09-05 21:10:42.963914 | ubuntu-bionic |   "rusr": true,
2019-09-05 21:10:42.964016 | ubuntu-bionic |   "size": 21351,
2019-09-05 21:10:42.964125 | ubuntu-bionic |   "uid": 1000,
2019-09-05 21:10:42.964255 | ubuntu-bionic |   "wgrp": true,
2019-09-05 21:10:42.964386 | ubuntu-bionic |   "woth": false,
2019-09-05 21:10:42.964486 | ubuntu-bionic |   "wusr": true,
2019-09-05 21:10:42.964589 | ubuntu-bionic |   "xgrp": false,
2019-09-05 21:10:42.964688 | ubuntu-bionic |   "xoth": false,
2019-09-05 21:10:42.964786 | ubuntu-bionic |   "xusr": false
2019-09-05 21:10:42.964884 | ubuntu-bionic | }
2019-09-05 21:10:43.138430 | ubuntu-bionic | changed:
2019-09-05 21:10:43.138686 | ubuntu-bionic | {
2019-09-05 21:10:43.138797 | ubuntu-bionic |   "atime": 1567717840.903468,
2019-09-05 21:10:43.138904 | ubuntu-bionic |   "ctime": 1567717837.955401,
2019-09-05 21:10:43.139076 | ubuntu-bionic |   "dev": 51713,
2019-09-05 21:10:43.139211 | ubuntu-bionic |   "gid": 1000,
2019-09-05 21:10:43.139316 | ubuntu-bionic |   "gr_name": "zuul",
2019-09-05 21:10:43.139417 | ubuntu-bionic |   "inode": 4187611,
2019-09-05 21:10:43.139519 | ubuntu-bionic |   "isblk": false,
2019-09-05 21:10:43.139619 | ubuntu-bionic |   "ischr": false,
2019-09-05 21:10:43.139718 | ubuntu-bionic |   "isdir": false,
2019-09-05 21:10:43.139817 | ubuntu-bionic |   "isfifo": false,
2019-09-05 21:10:43.139916 | ubuntu-bionic |   "isgid": false,
2019-09-05 21:10:43.140015 | ubuntu-bionic |   "islnk": false,
2019-09-05 21:10:43.140113 | ubuntu-bionic |   "isreg": true,
2019-09-05 21:10:43.140210 | ubuntu-bionic |   "issock": false,
2019-09-05 21:10:43.140353 | ubuntu-bionic |   "isuid": false,
2019-09-05 21:10:43.140453 | ubuntu-bionic |   "mode": "0664",
2019-09-05 21:10:43.140551 | ubuntu-bionic |   "mtime": 1567717837.955401,
2019-09-05 21:10:43.140648 | ubuntu-bionic |   "nlink": 1,
2019-09-05 21:10:43.140867 | ubuntu-bionic |   "path": "/home/zuul/src/opendev.org/zuul/zuul-jobs/testrepository.subunit",
2019-09-05 21:10:43.141034 | ubuntu-bionic |   "pw_name": "zuul",
2019-09-05 21:10:43.141193 | ubuntu-bionic |   "rgrp": true,
2019-09-05 21:10:43.141348 | ubuntu-bionic |   "roth": true,
2019-09-05 21:10:43.141506 | ubuntu-bionic |   "rusr": true,
2019-09-05 21:10:43.141666 | ubuntu-bionic |   "size": 3926,
2019-09-05 21:10:43.141826 | ubuntu-bionic |   "uid": 1000,
2019-09-05 21:10:43.142017 | ubuntu-bionic |   "wgrp": true,
2019-09-05 21:10:43.142153 | ubuntu-bionic |   "woth": false,
2019-09-05 21:10:43.142270 | ubuntu-bionic |   "wusr": true,
2019-09-05 21:10:43.142379 | ubuntu-bionic |   "xgrp": false,
2019-09-05 21:10:43.142598 | ubuntu-bionic |   "xoth": false,
2019-09-05 21:10:43.142708 | ubuntu-bionic |   "xusr": false
2019-09-05 21:10:43.142814 | ubuntu-bionic | }
2019-09-05 21:10:43.239816 | 
2019-09-05 21:10:43.240099 | LOOP [fetch-subunit-output : Collect test-results]
2019-09-05 21:10:44.897946 | ubuntu-bionic | changed: >f+++++++++ testr_results.html.gz
2019-09-05 21:10:44.898579 | ubuntu-bionic | changed: All items complete
2019-09-05 21:10:44.898690 | 
2019-09-05 21:10:45.500496 | ubuntu-bionic | changed: >f+++++++++ testrepository.subunit.gz
2019-09-05 21:10:45.545346 | 
2019-09-05 21:10:45.545560 | PLAY RECAP
2019-09-05 21:10:45.545726 | ubuntu-bionic | ok: 9 changed: 6 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2019-09-05 21:10:45.545831 | 
2019-09-05 21:10:46.038367 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2019-09-05 21:10:46.038696 | POST-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base-test/post.yaml@master]
2019-09-05 21:10:52.574323 | 
2019-09-05 21:10:52.574952 | PLAY [all]
2019-09-05 21:10:52.625351 | 
2019-09-05 21:10:52.625737 | TASK [fetch-output : Set log path for multiple nodes]
2019-09-05 21:10:52.694986 | ubuntu-bionic | skipping: Conditional result was False
2019-09-05 21:10:52.774462 | 
2019-09-05 21:10:52.774874 | TASK [fetch-output : Set log path for single node]
2019-09-05 21:10:52.892246 | ubuntu-bionic | ok
2019-09-05 21:10:53.002975 | 
2019-09-05 21:10:53.003275 | LOOP [fetch-output : Ensure local output dirs]
2019-09-05 21:10:54.389441 | ubuntu-bionic | ok: "/var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/work/logs"
2019-09-05 21:10:54.732941 | ubuntu-bionic | changed: "/var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/work/artifacts"
2019-09-05 21:10:54.989929 | ubuntu-bionic | changed: "/var/lib/zuul/builds/e5c7f4766e554b2796e471abd292c398/work/docs"
2019-09-05 21:10:55.050833 | 
2019-09-05 21:10:55.051128 | TASK [fetch-output : Collect log output]
2019-09-05 21:10:56.140686 | ubuntu-bionic | changed: .d..tp..... ./
2019-09-05 21:10:56.192528 | 
2019-09-05 21:10:56.192862 | TASK [fetch-output : Collect artifacts]
2019-09-05 21:10:57.120539 | ubuntu-bionic | changed: .d..tp..... ./
2019-09-05 21:10:57.171935 | 
2019-09-05 21:10:57.172224 | TASK [fetch-output : Collect docs]
2019-09-05 21:10:58.033744 | ubuntu-bionic | changed: .d..tp..... ./
2019-09-05 21:10:58.120528 | 
2019-09-05 21:10:58.120877 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2019-09-05 21:10:58.982310 | ubuntu-bionic | ok: Item: artifacts Runtime: 0:00:00.008572
2019-09-05 21:10:58.982949 | ubuntu-bionic | changed: All items complete
2019-09-05 21:10:58.983062 | 
2019-09-05 21:10:59.294611 | ubuntu-bionic | ok: Item: docs Runtime: 0:00:00.006741
2019-09-05 21:10:59.332681 | 
2019-09-05 21:10:59.332950 | PLAY [all]
2019-09-05 21:10:59.385403 | 
2019-09-05 21:10:59.385713 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2019-09-05 21:11:00.170900 | ubuntu-bionic | changed
2019-09-05 21:11:00.202182 | 
2019-09-05 21:11:00.202466 | PLAY RECAP
2019-09-05 21:11:00.202716 | ubuntu-bionic | ok: 7 changed: 6 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2019-09-05 21:11:00.202878 | 
2019-09-05 21:11:00.895984 | POST-RUN END RESULT_NORMAL: [trusted : opendev.org/opendev/base-jobs/playbooks/base-test/post.yaml@master]
2019-09-05 21:11:00.896498 | POST-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base-test/post-logs.yaml@master]
2019-09-05 21:11:07.142937 | 
2019-09-05 21:11:07.143239 | PLAY [localhost]
2019-09-05 21:11:07.210454 | 
2019-09-05 21:11:07.210845 | TASK [Include Zuul manifest role]
2019-09-05 21:11:07.286620 | localhost | ok
2019-09-05 21:11:07.655439 | 
2019-09-05 21:11:07.655818 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2019-09-05 21:11:08.303789 | localhost | changed
2019-09-05 21:11:08.380626 | 
2019-09-05 21:11:08.380971 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2019-09-05 21:11:08.485906 | localhost | ok
2019-09-05 21:11:08.545664 | 
2019-09-05 21:11:08.546031 | LOOP [Include upload logs role]
2019-09-05 21:11:08.680381 | localhost | Output suppressed because no_log was given
2019-09-05 21:11:09.054036 | 
2019-09-05 21:11:09.054356 | TASK [Set zuul-log-path fact]
2019-09-05 21:11:09.157471 | localhost | ok
2019-09-05 21:11:09.283348 | 
2019-09-05 21:11:09.283694 | TASK [set-zuul-log-path-fact : Set log path for a change]
2019-09-05 21:11:09.360803 | localhost | skipping: Conditional result was False
2019-09-05 21:11:09.415417 | 
2019-09-05 21:11:09.415741 | TASK [set-zuul-log-path-fact : Set log path for a ref update]
2019-09-05 21:11:09.478475 | localhost | skipping: Conditional result was False
2019-09-05 21:11:09.532402 | 
2019-09-05 21:11:09.532737 | TASK [set-zuul-log-path-fact : Set log path for a periodic job]
2019-09-05 21:11:09.612760 | localhost | skipping: Conditional result was False
2019-09-05 21:11:09.662618 | 
2019-09-05 21:11:09.662995 | TASK [set-zuul-log-path-fact : Set log path for a change]
2019-09-05 21:11:09.784042 | localhost | ok
2019-09-05 21:11:09.845598 | 
2019-09-05 21:11:09.846238 | TASK [set-zuul-log-path-fact : Set log path for a ref update]
2019-09-05 21:11:09.920577 | localhost | skipping: Conditional result was False
2019-09-05 21:11:09.984440 | 
2019-09-05 21:11:09.984952 | TASK [set-zuul-log-path-fact : Set log path for a periodic job]
2019-09-05 21:11:10.060512 | localhost | skipping: Conditional result was False
2019-09-05 21:11:10.161366 | 
2019-09-05 21:11:10.161697 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2019-09-05 21:11:11.447011 | localhost | ok: Runtime: 0:00:00.004712
2019-09-05 21:11:11.561150 | 
2019-09-05 21:11:11.561495 | TASK [upload-logs-swift : Upload logs to swift]