2025-09-09 20:45:07.953739 | Job console starting 2025-09-09 20:45:07.977362 | Updating git repos 2025-09-09 20:45:07.997305 | Cloning repos into workspace 2025-09-09 20:45:08.037679 | Restoring repo states 2025-09-09 20:45:08.043741 | Merging changes 2025-09-09 20:45:08.622701 | Checking out repos 2025-09-09 20:45:08.684097 | Preparing playbooks 2025-09-09 20:45:09.487161 | Running Ansible setup 2025-09-09 20:46:35.330390 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-09-09 20:46:36.091432 | 2025-09-09 20:46:36.091591 | PLAY [Base pre] 2025-09-09 20:46:36.107338 | 2025-09-09 20:46:36.107459 | TASK [Setup log path fact] 2025-09-09 20:46:36.136350 | debian-bookworm | ok 2025-09-09 20:46:36.150809 | 2025-09-09 20:46:36.150990 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-09 20:46:36.191974 | debian-bookworm | ok 2025-09-09 20:46:36.202032 | 2025-09-09 20:46:36.202131 | TASK [emit-job-header : Print job information] 2025-09-09 20:46:36.255328 | # Job Information 2025-09-09 20:46:36.255595 | Ansible Version: 2.16.14 2025-09-09 20:46:36.255669 | Job: cfg-cookiecutter-tox-2023.2 2025-09-09 20:46:36.255736 | Pipeline: check 2025-09-09 20:46:36.255784 | Executor: 521e9411259a 2025-09-09 20:46:36.255827 | Triggered by: https://github.com/osism/cfg-cookiecutter/pull/779 2025-09-09 20:46:36.255923 | Event ID: d9e3b680-8dbd-11f0-9327-19af8126118c 2025-09-09 20:46:36.263193 | 2025-09-09 20:46:36.263313 | LOOP [emit-job-header : Print node information] 2025-09-09 20:46:36.383920 | debian-bookworm | ok: 2025-09-09 20:46:36.384404 | debian-bookworm | # Node Information 2025-09-09 20:46:36.384552 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-09-09 20:46:36.384636 | debian-bookworm | Hostname: debian 2025-09-09 20:46:36.384702 | debian-bookworm | Username: zuul 2025-09-09 20:46:36.384764 | debian-bookworm | Distro: Debian 12.12 2025-09-09 20:46:36.384834 | debian-bookworm | Provider: regiocloud-a 2025-09-09 20:46:36.384965 | debian-bookworm | Region: 2025-09-09 20:46:36.385037 | debian-bookworm | Label: debian-bookworm 2025-09-09 20:46:36.385098 | debian-bookworm | Product Name: OpenStack Nova 2025-09-09 20:46:36.385156 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fed4:2c25 2025-09-09 20:46:36.405716 | 2025-09-09 20:46:36.405846 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-09 20:46:36.866970 | debian-bookworm -> localhost | changed 2025-09-09 20:46:36.874482 | 2025-09-09 20:46:36.874609 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-09 20:46:37.915673 | debian-bookworm -> localhost | changed 2025-09-09 20:46:37.939347 | 2025-09-09 20:46:37.939636 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-09 20:46:38.238133 | debian-bookworm -> localhost | ok 2025-09-09 20:46:38.244609 | 2025-09-09 20:46:38.244732 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-09 20:46:38.274685 | debian-bookworm | ok 2025-09-09 20:46:38.291936 | debian-bookworm | included: /var/lib/zuul/builds/d89a20dfb0dc45b19e7d5ba7a91114b0/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-09 20:46:38.297865 | 2025-09-09 20:46:38.298006 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-09 20:46:40.288128 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-09-09 20:46:40.288691 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/d89a20dfb0dc45b19e7d5ba7a91114b0/work/d89a20dfb0dc45b19e7d5ba7a91114b0_id_rsa 2025-09-09 20:46:40.288815 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/d89a20dfb0dc45b19e7d5ba7a91114b0/work/d89a20dfb0dc45b19e7d5ba7a91114b0_id_rsa.pub 2025-09-09 20:46:40.288945 | debian-bookworm -> localhost | The key fingerprint is: 2025-09-09 20:46:40.289025 | debian-bookworm -> localhost | SHA256:hTItAihmhzHiD5IpEs5LCxZVv09hYq85UQ00QyJKyLc zuul-build-sshkey 2025-09-09 20:46:40.289112 | debian-bookworm -> localhost | The key's randomart image is: 2025-09-09 20:46:40.289176 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-09-09 20:46:40.289236 | debian-bookworm -> localhost | |+=*o.o .o* | 2025-09-09 20:46:40.289296 | debian-bookworm -> localhost | |BX++. o...= | 2025-09-09 20:46:40.289353 | debian-bookworm -> localhost | |@Bo.o ++o+.. | 2025-09-09 20:46:40.289408 | debian-bookworm -> localhost | |B =E ..+*.. | 2025-09-09 20:46:40.289463 | debian-bookworm -> localhost | | o . oSo | 2025-09-09 20:46:40.289536 | debian-bookworm -> localhost | | * | 2025-09-09 20:46:40.289595 | debian-bookworm -> localhost | | + . | 2025-09-09 20:46:40.289651 | debian-bookworm -> localhost | | . | 2025-09-09 20:46:40.289788 | debian-bookworm -> localhost | | | 2025-09-09 20:46:40.289860 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-09-09 20:46:40.290044 | debian-bookworm -> localhost | ok: Runtime: 0:00:01.494865 2025-09-09 20:46:40.302814 | 2025-09-09 20:46:40.303046 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-09 20:46:40.335694 | debian-bookworm | ok 2025-09-09 20:46:40.347957 | debian-bookworm | included: /var/lib/zuul/builds/d89a20dfb0dc45b19e7d5ba7a91114b0/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-09 20:46:40.357095 | 2025-09-09 20:46:40.357195 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-09 20:46:40.380827 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:46:40.391009 | 2025-09-09 20:46:40.391158 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-09 20:46:40.988681 | debian-bookworm | changed 2025-09-09 20:46:40.997269 | 2025-09-09 20:46:40.997405 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-09 20:46:41.260130 | debian-bookworm | ok 2025-09-09 20:46:41.269097 | 2025-09-09 20:46:41.269230 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-09 20:46:41.922970 | debian-bookworm | changed 2025-09-09 20:46:41.932838 | 2025-09-09 20:46:41.932990 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-09 20:46:42.577005 | debian-bookworm | changed 2025-09-09 20:46:42.584809 | 2025-09-09 20:46:42.584951 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-09 20:46:42.608841 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:46:42.620287 | 2025-09-09 20:46:42.620433 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-09 20:46:43.073235 | debian-bookworm -> localhost | changed 2025-09-09 20:46:43.093358 | 2025-09-09 20:46:43.093504 | TASK [add-build-sshkey : Add back temp key] 2025-09-09 20:46:43.437444 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/d89a20dfb0dc45b19e7d5ba7a91114b0/work/d89a20dfb0dc45b19e7d5ba7a91114b0_id_rsa (zuul-build-sshkey) 2025-09-09 20:46:43.438030 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.011451 2025-09-09 20:46:43.455311 | 2025-09-09 20:46:43.455486 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-09 20:46:43.831383 | debian-bookworm | ok 2025-09-09 20:46:43.839290 | 2025-09-09 20:46:43.839420 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-09 20:46:43.874006 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:46:43.890335 | 2025-09-09 20:46:43.890445 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-09 20:46:44.310556 | debian-bookworm | ok 2025-09-09 20:46:44.325686 | 2025-09-09 20:46:44.325825 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-09 20:46:44.366921 | debian-bookworm | ok 2025-09-09 20:46:44.373186 | 2025-09-09 20:46:44.373302 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-09 20:46:44.670355 | debian-bookworm -> localhost | ok 2025-09-09 20:46:44.683422 | 2025-09-09 20:46:44.683571 | TASK [validate-host : Collect information about the host] 2025-09-09 20:47:25.837058 | debian-bookworm | ok 2025-09-09 20:47:25.852298 | 2025-09-09 20:47:25.852439 | TASK [validate-host : Sanitize hostname] 2025-09-09 20:47:25.961692 | debian-bookworm | ok 2025-09-09 20:47:26.003571 | 2025-09-09 20:47:26.003691 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-09 20:47:26.566353 | debian-bookworm -> localhost | changed 2025-09-09 20:47:26.580716 | 2025-09-09 20:47:26.580948 | TASK [validate-host : Collect information about zuul worker] 2025-09-09 20:47:27.012838 | debian-bookworm | ok 2025-09-09 20:47:27.020704 | 2025-09-09 20:47:27.020852 | TASK [validate-host : Write out all zuul information for each host] 2025-09-09 20:47:27.561820 | debian-bookworm -> localhost | changed 2025-09-09 20:47:27.581279 | 2025-09-09 20:47:27.581423 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-09-09 20:47:27.898439 | debian-bookworm | ok 2025-09-09 20:47:27.907283 | 2025-09-09 20:47:27.907421 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-09-09 20:47:28.780545 | debian-bookworm | changed: 2025-09-09 20:47:28.780804 | debian-bookworm | cd+++++++++ src/ 2025-09-09 20:47:28.780854 | debian-bookworm | cd+++++++++ src/github.com/ 2025-09-09 20:47:28.780909 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-09-09 20:47:28.780943 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-cookiecutter/ 2025-09-09 20:47:28.780973 | debian-bookworm | Containerfile 2025-09-09 20:47:28.781165 | debian-bookworm | localhost | changed 2025-09-09 20:49:47.404509 | 2025-09-09 20:49:47.404663 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-09-09 20:49:47.459700 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:49:47.472939 | 2025-09-09 20:49:47.473134 | TASK [fetch-tox-output : Set envlist fact] 2025-09-09 20:49:47.511592 | debian-bookworm | ok 2025-09-09 20:49:47.521403 | 2025-09-09 20:49:47.521539 | TASK [fetch-tox-output : Get tox version] 2025-09-09 20:49:48.055273 | debian-bookworm | ERROR 2025-09-09 20:49:48.055848 | debian-bookworm | { 2025-09-09 20:49:48.055980 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-09-09 20:49:48.056065 | debian-bookworm | "rc": 2 2025-09-09 20:49:48.056128 | debian-bookworm | } failure 2025-09-09 20:49:48.059285 | 2025-09-09 20:49:48.059446 | PLAY RECAP 2025-09-09 20:49:48.059567 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-09-09 20:49:48.059629 | 2025-09-09 20:49:48.177192 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-09-09 20:49:48.179829 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-09 20:49:48.897175 | 2025-09-09 20:49:48.897327 | PLAY [all] 2025-09-09 20:49:48.912481 | 2025-09-09 20:49:48.912610 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-09-09 20:49:49.151340 | debian-bookworm | changed: non-zero return code 2025-09-09 20:49:49.160014 | 2025-09-09 20:49:49.160208 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-09-09 20:49:49.185444 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:49:49.192963 | 2025-09-09 20:49:49.193103 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-09-09 20:49:49.227211 | 2025-09-09 20:49:49.227441 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-09-09 20:49:49.263125 | 2025-09-09 20:49:49.263354 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-09-09 20:49:49.287681 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:49:49.296135 | 2025-09-09 20:49:49.296267 | LOOP [fetch-subunit-output : Generate subunit file] 2025-09-09 20:49:49.335740 | 2025-09-09 20:49:49.336034 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-09-09 20:49:49.360650 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:49:49.372741 | 2025-09-09 20:49:49.372923 | TASK [fetch-subunit-output : Remove the temporary file] 2025-09-09 20:49:49.397538 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:49:49.409537 | 2025-09-09 20:49:49.409679 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-09-09 20:49:49.434317 | debian-bookworm | skipping: Conditional result was False 2025-09-09 20:49:49.444013 | 2025-09-09 20:49:49.444111 | PLAY RECAP 2025-09-09 20:49:49.444183 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-09-09 20:49:49.444218 | 2025-09-09 20:49:49.568223 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-09 20:49:49.570618 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-09 20:49:50.297073 | 2025-09-09 20:49:50.297242 | PLAY [Base post] 2025-09-09 20:49:50.310765 | 2025-09-09 20:49:50.310975 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-09 20:49:50.863709 | debian-bookworm | changed 2025-09-09 20:49:50.872501 | 2025-09-09 20:49:50.872620 | PLAY RECAP 2025-09-09 20:49:50.872698 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-09 20:49:50.872773 | 2025-09-09 20:49:50.983994 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-09 20:49:50.986674 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-09-09 20:49:51.768494 | 2025-09-09 20:49:51.768662 | PLAY [Base post-logs] 2025-09-09 20:49:51.779190 | 2025-09-09 20:49:51.779325 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-09 20:49:52.223716 | localhost | changed 2025-09-09 20:49:52.240289 | 2025-09-09 20:49:52.240468 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-09 20:49:52.279169 | localhost | ok 2025-09-09 20:49:52.286458 | 2025-09-09 20:49:52.286622 | TASK [Set zuul-log-path fact] 2025-09-09 20:49:52.304699 | localhost | ok 2025-09-09 20:49:52.319346 | 2025-09-09 20:49:52.319504 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-09 20:49:52.357396 | localhost | ok 2025-09-09 20:49:52.365293 | 2025-09-09 20:49:52.365449 | TASK [upload-logs : Create log directories] 2025-09-09 20:49:52.864674 | localhost | changed 2025-09-09 20:49:52.869892 | 2025-09-09 20:49:52.870056 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-09 20:49:53.354618 | localhost -> localhost | ok: Runtime: 0:00:00.006923 2025-09-09 20:49:53.364034 | 2025-09-09 20:49:53.364256 | TASK [upload-logs : Upload logs to log server] 2025-09-09 20:49:53.899467 | localhost | Output suppressed because no_log was given 2025-09-09 20:49:53.902311 | 2025-09-09 20:49:53.902457 | LOOP [upload-logs : Compress console log and json output] 2025-09-09 20:49:53.956406 | localhost | skipping: Conditional result was False 2025-09-09 20:49:53.961472 | localhost | skipping: Conditional result was False 2025-09-09 20:49:53.974072 | 2025-09-09 20:49:53.974291 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-09 20:49:54.019614 | localhost | skipping: Conditional result was False 2025-09-09 20:49:54.020235 | 2025-09-09 20:49:54.023676 | localhost | skipping: Conditional result was False 2025-09-09 20:49:54.037291 | 2025-09-09 20:49:54.037513 | LOOP [upload-logs : Upload console log and json output]