2025-09-20 03:14:32.744040 | Job console starting 2025-09-20 03:14:32.761471 | Updating git repos 2025-09-20 03:14:32.792880 | Cloning repos into workspace 2025-09-20 03:14:32.849894 | Restoring repo states 2025-09-20 03:14:32.857869 | Merging changes 2025-09-20 03:14:32.857888 | Checking out repos 2025-09-20 03:14:32.940461 | Preparing playbooks 2025-09-20 03:14:33.739943 | Running Ansible setup 2025-09-20 03:15:58.618182 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-09-20 03:15:59.552435 | 2025-09-20 03:15:59.552590 | PLAY [Base pre] 2025-09-20 03:15:59.568278 | 2025-09-20 03:15:59.568474 | TASK [Setup log path fact] 2025-09-20 03:15:59.597790 | debian-bookworm | ok 2025-09-20 03:15:59.613985 | 2025-09-20 03:15:59.614155 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-20 03:15:59.654641 | debian-bookworm | ok 2025-09-20 03:15:59.664530 | 2025-09-20 03:15:59.664635 | TASK [emit-job-header : Print job information] 2025-09-20 03:15:59.703588 | # Job Information 2025-09-20 03:15:59.703760 | Ansible Version: 2.16.14 2025-09-20 03:15:59.703795 | Job: cfg-cookiecutter-tox-2023.2 2025-09-20 03:15:59.703825 | Pipeline: periodic-daily 2025-09-20 03:15:59.703847 | Executor: 521e9411259a 2025-09-20 03:15:59.703868 | Triggered by: https://github.com/osism/cfg-cookiecutter 2025-09-20 03:15:59.703891 | Event ID: b4338ff375e1406ebc0378d85d9bd614 2025-09-20 03:15:59.708756 | 2025-09-20 03:15:59.708867 | LOOP [emit-job-header : Print node information] 2025-09-20 03:15:59.812310 | debian-bookworm | ok: 2025-09-20 03:15:59.812558 | debian-bookworm | # Node Information 2025-09-20 03:15:59.812593 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-09-20 03:15:59.812619 | debian-bookworm | Hostname: debian 2025-09-20 03:15:59.812642 | debian-bookworm | Username: zuul 2025-09-20 03:15:59.812663 | debian-bookworm | Distro: Debian 12.12 2025-09-20 03:15:59.812688 | debian-bookworm | Provider: regiocloud-a 2025-09-20 03:15:59.812709 | debian-bookworm | Region: 2025-09-20 03:15:59.812731 | debian-bookworm | Label: debian-bookworm 2025-09-20 03:15:59.812751 | debian-bookworm | Product Name: OpenStack Nova 2025-09-20 03:15:59.812772 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe2f:a05 2025-09-20 03:15:59.833941 | 2025-09-20 03:15:59.834081 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-20 03:16:00.562928 | debian-bookworm -> localhost | changed 2025-09-20 03:16:00.571718 | 2025-09-20 03:16:00.571849 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-20 03:16:01.965387 | debian-bookworm -> localhost | changed 2025-09-20 03:16:01.979320 | 2025-09-20 03:16:01.979426 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-20 03:16:02.288054 | debian-bookworm -> localhost | ok 2025-09-20 03:16:02.305004 | 2025-09-20 03:16:02.305136 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-20 03:16:02.366767 | debian-bookworm | ok 2025-09-20 03:16:02.415949 | debian-bookworm | included: /var/lib/zuul/builds/fa52dffcb0104161bfa2ca1d7f029cce/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-20 03:16:02.436889 | 2025-09-20 03:16:02.436994 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-20 03:16:06.520608 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-09-20 03:16:06.520798 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/fa52dffcb0104161bfa2ca1d7f029cce/work/fa52dffcb0104161bfa2ca1d7f029cce_id_rsa 2025-09-20 03:16:06.520838 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/fa52dffcb0104161bfa2ca1d7f029cce/work/fa52dffcb0104161bfa2ca1d7f029cce_id_rsa.pub 2025-09-20 03:16:06.520865 | debian-bookworm -> localhost | The key fingerprint is: 2025-09-20 03:16:06.520890 | debian-bookworm -> localhost | SHA256:PdOfvZm6MRMGVie8kFvvFMUY3rwEEyRZgT0WSeHs8uU zuul-build-sshkey 2025-09-20 03:16:06.520913 | debian-bookworm -> localhost | The key's randomart image is: 2025-09-20 03:16:06.520941 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-09-20 03:16:06.520962 | debian-bookworm -> localhost | | .X&B=o| 2025-09-20 03:16:06.520983 | debian-bookworm -> localhost | | ==O*+.| 2025-09-20 03:16:06.521003 | debian-bookworm -> localhost | | o=o=.+| 2025-09-20 03:16:06.521034 | debian-bookworm -> localhost | | ..oo..o.| 2025-09-20 03:16:06.521056 | debian-bookworm -> localhost | | S +..+oo | 2025-09-20 03:16:06.521083 | debian-bookworm -> localhost | | o+.++ | 2025-09-20 03:16:06.521103 | debian-bookworm -> localhost | | =oE.| 2025-09-20 03:16:06.521122 | debian-bookworm -> localhost | | + +| 2025-09-20 03:16:06.521143 | debian-bookworm -> localhost | | oo+ | 2025-09-20 03:16:06.521163 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-09-20 03:16:06.521213 | debian-bookworm -> localhost | ok: Runtime: 0:00:03.476134 2025-09-20 03:16:06.527254 | 2025-09-20 03:16:06.527346 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-20 03:16:06.544774 | debian-bookworm | ok 2025-09-20 03:16:06.562705 | debian-bookworm | included: /var/lib/zuul/builds/fa52dffcb0104161bfa2ca1d7f029cce/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-20 03:16:06.570401 | 2025-09-20 03:16:06.570498 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-20 03:16:06.583600 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:16:06.601377 | 2025-09-20 03:16:06.601658 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-20 03:16:07.218256 | debian-bookworm | changed 2025-09-20 03:16:07.226061 | 2025-09-20 03:16:07.226153 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-20 03:16:07.523666 | debian-bookworm | ok 2025-09-20 03:16:07.530222 | 2025-09-20 03:16:07.530319 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-20 03:16:08.237759 | debian-bookworm | changed 2025-09-20 03:16:08.262647 | 2025-09-20 03:16:08.262756 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-20 03:16:09.030393 | debian-bookworm | changed 2025-09-20 03:16:09.040262 | 2025-09-20 03:16:09.040362 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-20 03:16:09.083509 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:16:09.089306 | 2025-09-20 03:16:09.089402 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-20 03:16:09.716899 | debian-bookworm -> localhost | changed 2025-09-20 03:16:09.725829 | 2025-09-20 03:16:09.725917 | TASK [add-build-sshkey : Add back temp key] 2025-09-20 03:16:10.143409 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/fa52dffcb0104161bfa2ca1d7f029cce/work/fa52dffcb0104161bfa2ca1d7f029cce_id_rsa (zuul-build-sshkey) 2025-09-20 03:16:10.143596 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.014775 2025-09-20 03:16:10.149910 | 2025-09-20 03:16:10.149987 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-20 03:16:10.553722 | debian-bookworm | ok 2025-09-20 03:16:10.561721 | 2025-09-20 03:16:10.561810 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-20 03:16:10.584425 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:16:10.593717 | 2025-09-20 03:16:10.593805 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-20 03:16:11.089713 | debian-bookworm | ok 2025-09-20 03:16:11.112822 | 2025-09-20 03:16:11.112932 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-20 03:16:11.170810 | debian-bookworm | ok 2025-09-20 03:16:11.175680 | 2025-09-20 03:16:11.175765 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-20 03:16:11.955108 | debian-bookworm -> localhost | ok 2025-09-20 03:16:11.961231 | 2025-09-20 03:16:11.961321 | TASK [validate-host : Collect information about the host] 2025-09-20 03:16:53.245028 | debian-bookworm | ok 2025-09-20 03:16:53.257613 | 2025-09-20 03:16:53.257699 | TASK [validate-host : Sanitize hostname] 2025-09-20 03:16:53.361877 | debian-bookworm | ok 2025-09-20 03:16:53.406344 | 2025-09-20 03:16:53.406446 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-20 03:16:53.959427 | debian-bookworm -> localhost | changed 2025-09-20 03:16:53.964772 | 2025-09-20 03:16:53.964868 | TASK [validate-host : Collect information about zuul worker] 2025-09-20 03:16:54.375215 | debian-bookworm | ok 2025-09-20 03:16:54.382975 | 2025-09-20 03:16:54.383137 | TASK [validate-host : Write out all zuul information for each host] 2025-09-20 03:16:54.861823 | debian-bookworm -> localhost | changed 2025-09-20 03:16:54.870785 | 2025-09-20 03:16:54.870891 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-09-20 03:16:55.156902 | debian-bookworm | ok 2025-09-20 03:16:55.165923 | 2025-09-20 03:16:55.166154 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-09-20 03:16:55.991530 | debian-bookworm | changed: 2025-09-20 03:16:55.991751 | debian-bookworm | cd+++++++++ src/ 2025-09-20 03:16:55.991800 | debian-bookworm | cd+++++++++ src/github.com/ 2025-09-20 03:16:55.992069 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-09-20 03:16:55.992107 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-cookiecutter/ 2025-09-20 03:16:55.992139 | debian-bookworm | Containerfile 2025-09-20 03:16:55.992330 | debian-bookworm | localhost | changed 2025-09-20 03:19:15.075411 | 2025-09-20 03:19:15.075504 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-09-20 03:19:15.119065 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:19:15.124728 | 2025-09-20 03:19:15.124822 | TASK [fetch-tox-output : Set envlist fact] 2025-09-20 03:19:15.152263 | debian-bookworm | ok 2025-09-20 03:19:15.158393 | 2025-09-20 03:19:15.158475 | TASK [fetch-tox-output : Get tox version] 2025-09-20 03:19:16.200369 | debian-bookworm | ERROR 2025-09-20 03:19:16.200625 | debian-bookworm | { 2025-09-20 03:19:16.200663 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-09-20 03:19:16.200692 | debian-bookworm | "rc": 2 2025-09-20 03:19:16.200715 | debian-bookworm | } failure 2025-09-20 03:19:16.201990 | 2025-09-20 03:19:16.202054 | PLAY RECAP 2025-09-20 03:19:16.202101 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-09-20 03:19:16.202127 | 2025-09-20 03:19:16.512712 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-09-20 03:19:16.513612 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-20 03:19:17.681521 | 2025-09-20 03:19:17.681632 | PLAY [all] 2025-09-20 03:19:17.696541 | 2025-09-20 03:19:17.696642 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-09-20 03:19:18.027621 | debian-bookworm | changed: non-zero return code 2025-09-20 03:19:18.045557 | 2025-09-20 03:19:18.045718 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-09-20 03:19:18.113824 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:19:18.123754 | 2025-09-20 03:19:18.123858 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-09-20 03:19:18.166252 | 2025-09-20 03:19:18.166467 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-09-20 03:19:18.196653 | 2025-09-20 03:19:18.196799 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-09-20 03:19:18.269528 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:19:18.275981 | 2025-09-20 03:19:18.276074 | LOOP [fetch-subunit-output : Generate subunit file] 2025-09-20 03:19:18.332241 | 2025-09-20 03:19:18.332563 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-09-20 03:19:18.415372 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:19:18.421176 | 2025-09-20 03:19:18.421271 | TASK [fetch-subunit-output : Remove the temporary file] 2025-09-20 03:19:18.475798 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:19:18.481843 | 2025-09-20 03:19:18.481952 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-09-20 03:19:18.504981 | debian-bookworm | skipping: Conditional result was False 2025-09-20 03:19:18.512578 | 2025-09-20 03:19:18.512647 | PLAY RECAP 2025-09-20 03:19:18.512690 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-09-20 03:19:18.512712 | 2025-09-20 03:19:18.625467 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-20 03:19:18.626516 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-20 03:19:19.840320 | 2025-09-20 03:19:19.840428 | PLAY [Base post] 2025-09-20 03:19:19.857380 | 2025-09-20 03:19:19.857530 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-20 03:19:20.490281 | debian-bookworm | changed 2025-09-20 03:19:20.495269 | 2025-09-20 03:19:20.495349 | PLAY RECAP 2025-09-20 03:19:20.495397 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-20 03:19:20.495446 | 2025-09-20 03:19:20.569050 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-20 03:19:20.569859 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-09-20 03:19:21.513694 | 2025-09-20 03:19:21.513805 | PLAY [Base post-logs] 2025-09-20 03:19:21.521616 | 2025-09-20 03:19:21.521713 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-20 03:19:22.162700 | localhost | changed 2025-09-20 03:19:22.170905 | 2025-09-20 03:19:22.171007 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-20 03:19:22.195657 | localhost | ok 2025-09-20 03:19:22.198261 | 2025-09-20 03:19:22.198328 | TASK [Set zuul-log-path fact] 2025-09-20 03:19:22.212384 | localhost | ok 2025-09-20 03:19:22.219057 | 2025-09-20 03:19:22.219135 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-20 03:19:22.252664 | localhost | ok 2025-09-20 03:19:22.255118 | 2025-09-20 03:19:22.255190 | TASK [upload-logs : Create log directories] 2025-09-20 03:19:22.656852 | localhost | changed 2025-09-20 03:19:22.659138 | 2025-09-20 03:19:22.659212 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-20 03:19:23.010111 | localhost -> localhost | ok: Runtime: 0:00:00.004597 2025-09-20 03:19:23.016026 | 2025-09-20 03:19:23.016171 | TASK [upload-logs : Upload logs to log server] 2025-09-20 03:19:23.476886 | localhost | Output suppressed because no_log was given 2025-09-20 03:19:23.478267 | 2025-09-20 03:19:23.478337 | LOOP [upload-logs : Compress console log and json output] 2025-09-20 03:19:23.528884 | localhost | skipping: Conditional result was False 2025-09-20 03:19:23.535165 | localhost | skipping: Conditional result was False 2025-09-20 03:19:23.543979 | 2025-09-20 03:19:23.544058 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-20 03:19:23.578813 | localhost | skipping: Conditional result was False 2025-09-20 03:19:23.579053 | 2025-09-20 03:19:23.584397 | localhost | skipping: Conditional result was False 2025-09-20 03:19:23.588183 | 2025-09-20 03:19:23.588273 | LOOP [upload-logs : Upload console log and json output]