2025-08-06 02:24:53.876519 | Job console starting 2025-08-06 02:24:53.893367 | Updating git repos 2025-08-06 02:24:54.731543 | Cloning repos into workspace 2025-08-06 02:24:54.827470 | Restoring repo states 2025-08-06 02:24:54.835488 | Merging changes 2025-08-06 02:24:55.566435 | Checking out repos 2025-08-06 02:24:55.629980 | Preparing playbooks 2025-08-06 02:24:56.954171 | Running Ansible setup 2025-08-06 02:26:23.264220 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-08-06 02:26:24.409838 | 2025-08-06 02:26:24.410015 | PLAY [Base pre] 2025-08-06 02:26:24.426347 | 2025-08-06 02:26:24.426491 | TASK [Setup log path fact] 2025-08-06 02:26:24.446401 | debian-bookworm | ok 2025-08-06 02:26:24.471214 | 2025-08-06 02:26:24.471381 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-08-06 02:26:24.502323 | debian-bookworm | ok 2025-08-06 02:26:24.513528 | 2025-08-06 02:26:24.513679 | TASK [emit-job-header : Print job information] 2025-08-06 02:26:24.554455 | # Job Information 2025-08-06 02:26:24.554664 | Ansible Version: 2.16.14 2025-08-06 02:26:24.554701 | Job: cfg-cookiecutter-tox-2024.1 2025-08-06 02:26:24.554734 | Pipeline: check 2025-08-06 02:26:24.554758 | Executor: 521e9411259a 2025-08-06 02:26:24.554778 | Triggered by: https://github.com/osism/cfg-cookiecutter/pull/769 2025-08-06 02:26:24.554800 | Event ID: 83fb3c00-726c-11f0-874c-ae1ecedd34e6 2025-08-06 02:26:24.559936 | 2025-08-06 02:26:24.560062 | LOOP [emit-job-header : Print node information] 2025-08-06 02:26:24.672677 | debian-bookworm | ok: 2025-08-06 02:26:24.672954 | debian-bookworm | # Node Information 2025-08-06 02:26:24.672995 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-08-06 02:26:24.673020 | debian-bookworm | Hostname: debian 2025-08-06 02:26:24.673043 | debian-bookworm | Username: zuul 2025-08-06 02:26:24.673064 | debian-bookworm | Distro: Debian 12.11 2025-08-06 02:26:24.673094 | debian-bookworm | Provider: regiocloud-a 2025-08-06 02:26:24.673120 | debian-bookworm | Region: 2025-08-06 02:26:24.673141 | debian-bookworm | Label: debian-bookworm 2025-08-06 02:26:24.673161 | debian-bookworm | Product Name: OpenStack Nova 2025-08-06 02:26:24.673180 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe0f:c8c1 2025-08-06 02:26:24.699080 | 2025-08-06 02:26:24.699218 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-08-06 02:26:25.237243 | debian-bookworm -> localhost | changed 2025-08-06 02:26:25.245995 | 2025-08-06 02:26:25.246124 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-08-06 02:26:26.543713 | debian-bookworm -> localhost | changed 2025-08-06 02:26:26.566990 | 2025-08-06 02:26:26.567142 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-08-06 02:26:26.892584 | debian-bookworm -> localhost | ok 2025-08-06 02:26:26.906957 | 2025-08-06 02:26:26.907141 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-08-06 02:26:26.933429 | debian-bookworm | ok 2025-08-06 02:26:26.964873 | debian-bookworm | included: /var/lib/zuul/builds/db393c15be5c42f290c9285fe8bd598c/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-08-06 02:26:26.971953 | 2025-08-06 02:26:26.972154 | TASK [add-build-sshkey : Create Temp SSH key] 2025-08-06 02:26:28.343766 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-08-06 02:26:28.344371 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/db393c15be5c42f290c9285fe8bd598c/work/db393c15be5c42f290c9285fe8bd598c_id_rsa 2025-08-06 02:26:28.344493 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/db393c15be5c42f290c9285fe8bd598c/work/db393c15be5c42f290c9285fe8bd598c_id_rsa.pub 2025-08-06 02:26:28.344571 | debian-bookworm -> localhost | The key fingerprint is: 2025-08-06 02:26:28.344692 | debian-bookworm -> localhost | SHA256:AMMKzJBpftQ9a2BejblNa5RI3BtX0OKQoNgPNurbdxs zuul-build-sshkey 2025-08-06 02:26:28.344780 | debian-bookworm -> localhost | The key's randomart image is: 2025-08-06 02:26:28.344849 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-08-06 02:26:28.344947 | debian-bookworm -> localhost | |=o .+ +oB o.+. | 2025-08-06 02:26:28.345053 | debian-bookworm -> localhost | |++ .+*.O X o . | 2025-08-06 02:26:28.345130 | debian-bookworm -> localhost | |o..oo*+ B B . | 2025-08-06 02:26:28.345190 | debian-bookworm -> localhost | | ...o.+= = . | 2025-08-06 02:26:28.345246 | debian-bookworm -> localhost | | .. ..S | 2025-08-06 02:26:28.345319 | debian-bookworm -> localhost | | . | 2025-08-06 02:26:28.345377 | debian-bookworm -> localhost | | . E | 2025-08-06 02:26:28.345434 | debian-bookworm -> localhost | | o . .. | 2025-08-06 02:26:28.345494 | debian-bookworm -> localhost | | . .. ... | 2025-08-06 02:26:28.345551 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-08-06 02:26:28.345723 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.801582 2025-08-06 02:26:28.360456 | 2025-08-06 02:26:28.360663 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-08-06 02:26:28.396024 | debian-bookworm | ok 2025-08-06 02:26:28.418088 | debian-bookworm | included: /var/lib/zuul/builds/db393c15be5c42f290c9285fe8bd598c/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-08-06 02:26:28.430050 | 2025-08-06 02:26:28.430153 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-08-06 02:26:28.454037 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:26:28.464798 | 2025-08-06 02:26:28.464945 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-08-06 02:26:29.175249 | debian-bookworm | changed 2025-08-06 02:26:29.183903 | 2025-08-06 02:26:29.184032 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-08-06 02:26:29.465908 | debian-bookworm | ok 2025-08-06 02:26:29.475510 | 2025-08-06 02:26:29.475688 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-08-06 02:26:30.126212 | debian-bookworm | changed 2025-08-06 02:26:30.133792 | 2025-08-06 02:26:30.133912 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-08-06 02:26:30.794122 | debian-bookworm | changed 2025-08-06 02:26:30.800977 | 2025-08-06 02:26:30.801101 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-08-06 02:26:30.825791 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:26:30.834893 | 2025-08-06 02:26:30.835031 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-08-06 02:26:31.281162 | debian-bookworm -> localhost | changed 2025-08-06 02:26:31.293588 | 2025-08-06 02:26:31.293753 | TASK [add-build-sshkey : Add back temp key] 2025-08-06 02:26:31.633375 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/db393c15be5c42f290c9285fe8bd598c/work/db393c15be5c42f290c9285fe8bd598c_id_rsa (zuul-build-sshkey) 2025-08-06 02:26:31.633959 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.016868 2025-08-06 02:26:31.652213 | 2025-08-06 02:26:31.652352 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-08-06 02:26:32.071539 | debian-bookworm | ok 2025-08-06 02:26:32.078930 | 2025-08-06 02:26:32.079074 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-08-06 02:26:32.113553 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:26:32.124659 | 2025-08-06 02:26:32.124775 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-08-06 02:26:32.579697 | debian-bookworm | ok 2025-08-06 02:26:32.590537 | 2025-08-06 02:26:32.590671 | TASK [validate-host : Define zuul_info_dir fact] 2025-08-06 02:26:32.630232 | debian-bookworm | ok 2025-08-06 02:26:32.636075 | 2025-08-06 02:26:32.636180 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-08-06 02:26:32.993872 | debian-bookworm -> localhost | ok 2025-08-06 02:26:33.002524 | 2025-08-06 02:26:33.002959 | TASK [validate-host : Collect information about the host] 2025-08-06 02:27:15.221284 | debian-bookworm | ok 2025-08-06 02:27:15.233433 | 2025-08-06 02:27:15.233553 | TASK [validate-host : Sanitize hostname] 2025-08-06 02:27:15.344688 | debian-bookworm | ok 2025-08-06 02:27:15.393368 | 2025-08-06 02:27:15.393506 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-08-06 02:27:16.003235 | debian-bookworm -> localhost | changed 2025-08-06 02:27:16.009354 | 2025-08-06 02:27:16.009477 | TASK [validate-host : Collect information about zuul worker] 2025-08-06 02:27:16.450724 | debian-bookworm | ok 2025-08-06 02:27:16.458063 | 2025-08-06 02:27:16.458203 | TASK [validate-host : Write out all zuul information for each host] 2025-08-06 02:27:16.967629 | debian-bookworm -> localhost | changed 2025-08-06 02:27:16.979349 | 2025-08-06 02:27:16.979478 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-08-06 02:27:17.273817 | debian-bookworm | ok 2025-08-06 02:27:17.286220 | 2025-08-06 02:27:17.286543 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-08-06 02:27:18.173396 | debian-bookworm | changed: 2025-08-06 02:27:18.173641 | debian-bookworm | cd+++++++++ src/ 2025-08-06 02:27:18.173680 | debian-bookworm | cd+++++++++ src/github.com/ 2025-08-06 02:27:18.173705 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-08-06 02:27:18.173726 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-cookiecutter/ 2025-08-06 02:27:18.173746 | debian-bookworm | Containerfile 2025-08-06 02:27:18.173876 | debian-bookworm | localhost | changed 2025-08-06 02:29:36.858972 | 2025-08-06 02:29:36.859097 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-08-06 02:29:36.913117 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:29:36.925372 | 2025-08-06 02:29:36.925537 | TASK [fetch-tox-output : Set envlist fact] 2025-08-06 02:29:36.965346 | debian-bookworm | ok 2025-08-06 02:29:36.971044 | 2025-08-06 02:29:36.971150 | TASK [fetch-tox-output : Get tox version] 2025-08-06 02:29:37.502438 | debian-bookworm | ERROR 2025-08-06 02:29:37.503114 | debian-bookworm | { 2025-08-06 02:29:37.503230 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-08-06 02:29:37.503316 | debian-bookworm | "rc": 2 2025-08-06 02:29:37.503380 | debian-bookworm | } failure 2025-08-06 02:29:37.506699 | 2025-08-06 02:29:37.506915 | PLAY RECAP 2025-08-06 02:29:37.507044 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-08-06 02:29:37.507129 | 2025-08-06 02:29:37.630896 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-08-06 02:29:37.633601 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-08-06 02:29:38.354680 | 2025-08-06 02:29:38.354873 | PLAY [all] 2025-08-06 02:29:38.370210 | 2025-08-06 02:29:38.370337 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-08-06 02:29:38.620071 | debian-bookworm | changed: non-zero return code 2025-08-06 02:29:38.629677 | 2025-08-06 02:29:38.629844 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-08-06 02:29:38.655277 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:29:38.668923 | 2025-08-06 02:29:38.669117 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-08-06 02:29:38.708465 | 2025-08-06 02:29:38.708777 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-08-06 02:29:38.744990 | 2025-08-06 02:29:38.745232 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-08-06 02:29:38.769122 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:29:38.779449 | 2025-08-06 02:29:38.779608 | LOOP [fetch-subunit-output : Generate subunit file] 2025-08-06 02:29:38.817910 | 2025-08-06 02:29:38.818236 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-08-06 02:29:38.843004 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:29:38.855732 | 2025-08-06 02:29:38.855897 | TASK [fetch-subunit-output : Remove the temporary file] 2025-08-06 02:29:38.880027 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:29:38.890210 | 2025-08-06 02:29:38.890357 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-08-06 02:29:38.914387 | debian-bookworm | skipping: Conditional result was False 2025-08-06 02:29:38.922251 | 2025-08-06 02:29:38.922340 | PLAY RECAP 2025-08-06 02:29:38.922399 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-08-06 02:29:38.922430 | 2025-08-06 02:29:39.058386 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-08-06 02:29:39.061006 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-08-06 02:29:39.786218 | 2025-08-06 02:29:39.786375 | PLAY [Base post] 2025-08-06 02:29:39.800297 | 2025-08-06 02:29:39.800452 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-08-06 02:29:40.354766 | debian-bookworm | changed 2025-08-06 02:29:40.364091 | 2025-08-06 02:29:40.364219 | PLAY RECAP 2025-08-06 02:29:40.364299 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-08-06 02:29:40.364378 | 2025-08-06 02:29:40.481542 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-08-06 02:29:40.483045 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-08-06 02:29:41.270097 | 2025-08-06 02:29:41.270261 | PLAY [Base post-logs] 2025-08-06 02:29:41.281205 | 2025-08-06 02:29:41.281345 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-08-06 02:29:41.733894 | localhost | changed 2025-08-06 02:29:41.744777 | 2025-08-06 02:29:41.744928 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-08-06 02:29:41.781599 | localhost | ok 2025-08-06 02:29:41.786297 | 2025-08-06 02:29:41.786431 | TASK [Set zuul-log-path fact] 2025-08-06 02:29:41.808102 | localhost | ok 2025-08-06 02:29:41.823071 | 2025-08-06 02:29:41.823205 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-08-06 02:29:41.849158 | localhost | ok 2025-08-06 02:29:41.854247 | 2025-08-06 02:29:41.854396 | TASK [upload-logs : Create log directories] 2025-08-06 02:29:42.349148 | localhost | changed 2025-08-06 02:29:42.352463 | 2025-08-06 02:29:42.352584 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-08-06 02:29:42.832827 | localhost -> localhost | ok: Runtime: 0:00:00.006701 2025-08-06 02:29:42.842497 | 2025-08-06 02:29:42.842708 | TASK [upload-logs : Upload logs to log server] 2025-08-06 02:29:43.421266 | localhost | Output suppressed because no_log was given 2025-08-06 02:29:43.424433 | 2025-08-06 02:29:43.424589 | LOOP [upload-logs : Compress console log and json output] 2025-08-06 02:29:43.480849 | localhost | skipping: Conditional result was False 2025-08-06 02:29:43.485888 | localhost | skipping: Conditional result was False 2025-08-06 02:29:43.498997 | 2025-08-06 02:29:43.499302 | LOOP [upload-logs : Upload compressed console log and json output] 2025-08-06 02:29:43.546287 | localhost | skipping: Conditional result was False 2025-08-06 02:29:43.547174 | 2025-08-06 02:29:43.550237 | localhost | skipping: Conditional result was False 2025-08-06 02:29:43.564004 | 2025-08-06 02:29:43.564241 | LOOP [upload-logs : Upload console log and json output]