2025-08-03 03:16:04.480518 | Job console starting 2025-08-03 03:16:04.514443 | Updating git repos 2025-08-03 03:16:04.550260 | Cloning repos into workspace 2025-08-03 03:16:04.625878 | Restoring repo states 2025-08-03 03:16:04.636521 | Merging changes 2025-08-03 03:16:04.636541 | Checking out repos 2025-08-03 03:16:04.686246 | Preparing playbooks 2025-08-03 03:16:05.332524 | Running Ansible setup 2025-08-03 03:17:30.144509 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-08-03 03:17:30.828238 | 2025-08-03 03:17:30.828373 | PLAY [Base pre] 2025-08-03 03:17:30.842996 | 2025-08-03 03:17:30.843117 | TASK [Setup log path fact] 2025-08-03 03:17:30.872346 | debian-bookworm | ok 2025-08-03 03:17:30.896401 | 2025-08-03 03:17:30.896538 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-08-03 03:17:30.925904 | debian-bookworm | ok 2025-08-03 03:17:30.936321 | 2025-08-03 03:17:30.936435 | TASK [emit-job-header : Print job information] 2025-08-03 03:17:30.966168 | # Job Information 2025-08-03 03:17:30.966411 | Ansible Version: 2.16.14 2025-08-03 03:17:30.966449 | Job: cfg-cookiecutter-tox-2023.2 2025-08-03 03:17:30.966480 | Pipeline: periodic-daily 2025-08-03 03:17:30.966504 | Executor: 521e9411259a 2025-08-03 03:17:30.966525 | Triggered by: https://github.com/osism/cfg-cookiecutter 2025-08-03 03:17:30.966547 | Event ID: 4f2acbb73b9c4e9ca9e2ae1c1b4bc4ae 2025-08-03 03:17:30.971568 | 2025-08-03 03:17:30.971681 | LOOP [emit-job-header : Print node information] 2025-08-03 03:17:31.073154 | debian-bookworm | ok: 2025-08-03 03:17:31.073396 | debian-bookworm | # Node Information 2025-08-03 03:17:31.073433 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-08-03 03:17:31.073460 | debian-bookworm | Hostname: debian 2025-08-03 03:17:31.073482 | debian-bookworm | Username: zuul 2025-08-03 03:17:31.073503 | debian-bookworm | Distro: Debian 12.11 2025-08-03 03:17:31.073527 | debian-bookworm | Provider: regiocloud-a 2025-08-03 03:17:31.073548 | debian-bookworm | Region: 2025-08-03 03:17:31.073570 | debian-bookworm | Label: debian-bookworm 2025-08-03 03:17:31.073590 | debian-bookworm | Product Name: OpenStack Nova 2025-08-03 03:17:31.073608 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe89:ceb9 2025-08-03 03:17:31.096522 | 2025-08-03 03:17:31.096634 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-08-03 03:17:31.560801 | debian-bookworm -> localhost | changed 2025-08-03 03:17:31.567587 | 2025-08-03 03:17:31.567699 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-08-03 03:17:33.302000 | debian-bookworm -> localhost | changed 2025-08-03 03:17:33.326200 | 2025-08-03 03:17:33.326312 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-08-03 03:17:33.740056 | debian-bookworm -> localhost | ok 2025-08-03 03:17:33.752577 | 2025-08-03 03:17:33.752702 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-08-03 03:17:33.786795 | debian-bookworm | ok 2025-08-03 03:17:33.826218 | debian-bookworm | included: /var/lib/zuul/builds/9a06c8391de8498d85dbabc96af0a562/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-08-03 03:17:33.837872 | 2025-08-03 03:17:33.838557 | TASK [add-build-sshkey : Create Temp SSH key] 2025-08-03 03:17:34.909553 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-08-03 03:17:34.909745 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/9a06c8391de8498d85dbabc96af0a562/work/9a06c8391de8498d85dbabc96af0a562_id_rsa 2025-08-03 03:17:34.909786 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/9a06c8391de8498d85dbabc96af0a562/work/9a06c8391de8498d85dbabc96af0a562_id_rsa.pub 2025-08-03 03:17:34.909815 | debian-bookworm -> localhost | The key fingerprint is: 2025-08-03 03:17:34.909843 | debian-bookworm -> localhost | SHA256:KKaN8uhiGGnlNMZfCGlf3yO5PmjBdni+gwq5ivE4xcI zuul-build-sshkey 2025-08-03 03:17:34.909866 | debian-bookworm -> localhost | The key's randomart image is: 2025-08-03 03:17:34.909897 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-08-03 03:17:34.909919 | debian-bookworm -> localhost | | . | 2025-08-03 03:17:34.909940 | debian-bookworm -> localhost | | + . | 2025-08-03 03:17:34.909961 | debian-bookworm -> localhost | | o o o . o | 2025-08-03 03:17:34.909981 | debian-bookworm -> localhost | | * o o + o | 2025-08-03 03:17:34.910001 | debian-bookworm -> localhost | |.o= = + S o . | 2025-08-03 03:17:34.910026 | debian-bookworm -> localhost | |+Eo*.o = + | 2025-08-03 03:17:34.910046 | debian-bookworm -> localhost | |=+oo. . O | 2025-08-03 03:17:34.910066 | debian-bookworm -> localhost | |=O o + = | 2025-08-03 03:17:34.910087 | debian-bookworm -> localhost | |B++. .o .+ | 2025-08-03 03:17:34.910108 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-08-03 03:17:34.910158 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.421408 2025-08-03 03:17:34.916506 | 2025-08-03 03:17:34.916647 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-08-03 03:17:34.954285 | debian-bookworm | ok 2025-08-03 03:17:34.963416 | debian-bookworm | included: /var/lib/zuul/builds/9a06c8391de8498d85dbabc96af0a562/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-08-03 03:17:34.982867 | 2025-08-03 03:17:34.982977 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-08-03 03:17:35.028398 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:17:35.034417 | 2025-08-03 03:17:35.034542 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-08-03 03:17:35.698000 | debian-bookworm | changed 2025-08-03 03:17:35.704513 | 2025-08-03 03:17:35.704618 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-08-03 03:17:35.955993 | debian-bookworm | ok 2025-08-03 03:17:35.961339 | 2025-08-03 03:17:35.961439 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-08-03 03:17:36.757461 | debian-bookworm | changed 2025-08-03 03:17:36.767358 | 2025-08-03 03:17:36.767475 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-08-03 03:17:37.434222 | debian-bookworm | changed 2025-08-03 03:17:37.443482 | 2025-08-03 03:17:37.443586 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-08-03 03:17:37.476434 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:17:37.481407 | 2025-08-03 03:17:37.481505 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-08-03 03:17:38.362585 | debian-bookworm -> localhost | changed 2025-08-03 03:17:38.375515 | 2025-08-03 03:17:38.375618 | TASK [add-build-sshkey : Add back temp key] 2025-08-03 03:17:38.972370 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/9a06c8391de8498d85dbabc96af0a562/work/9a06c8391de8498d85dbabc96af0a562_id_rsa (zuul-build-sshkey) 2025-08-03 03:17:38.972588 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.021429 2025-08-03 03:17:38.983495 | 2025-08-03 03:17:38.983619 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-08-03 03:17:39.505529 | debian-bookworm | ok 2025-08-03 03:17:39.509578 | 2025-08-03 03:17:39.509661 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-08-03 03:17:39.547201 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:17:39.556593 | 2025-08-03 03:17:39.556690 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-08-03 03:17:40.208996 | debian-bookworm | ok 2025-08-03 03:17:40.227138 | 2025-08-03 03:17:40.227261 | TASK [validate-host : Define zuul_info_dir fact] 2025-08-03 03:17:40.300259 | debian-bookworm | ok 2025-08-03 03:17:40.305164 | 2025-08-03 03:17:40.305268 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-08-03 03:17:40.944711 | debian-bookworm -> localhost | ok 2025-08-03 03:17:40.950410 | 2025-08-03 03:17:40.950517 | TASK [validate-host : Collect information about the host] 2025-08-03 03:18:22.451872 | debian-bookworm | ok 2025-08-03 03:18:22.482400 | 2025-08-03 03:18:22.482502 | TASK [validate-host : Sanitize hostname] 2025-08-03 03:18:22.733436 | debian-bookworm | ok 2025-08-03 03:18:22.809649 | 2025-08-03 03:18:22.809770 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-08-03 03:18:23.553370 | debian-bookworm -> localhost | changed 2025-08-03 03:18:23.558930 | 2025-08-03 03:18:23.559033 | TASK [validate-host : Collect information about zuul worker] 2025-08-03 03:18:24.094265 | debian-bookworm | ok 2025-08-03 03:18:24.098898 | 2025-08-03 03:18:24.099001 | TASK [validate-host : Write out all zuul information for each host] 2025-08-03 03:18:25.105826 | debian-bookworm -> localhost | changed 2025-08-03 03:18:25.116668 | 2025-08-03 03:18:25.116772 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-08-03 03:18:25.418897 | debian-bookworm | ok 2025-08-03 03:18:25.424436 | 2025-08-03 03:18:25.424539 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-08-03 03:18:26.366307 | debian-bookworm | changed: 2025-08-03 03:18:26.366482 | debian-bookworm | cd+++++++++ src/ 2025-08-03 03:18:26.366515 | debian-bookworm | cd+++++++++ src/github.com/ 2025-08-03 03:18:26.366539 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-08-03 03:18:26.366562 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-cookiecutter/ 2025-08-03 03:18:26.366582 | debian-bookworm | Containerfile 2025-08-03 03:18:26.366713 | debian-bookworm | localhost | changed 2025-08-03 03:20:47.333790 | 2025-08-03 03:20:47.333893 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-08-03 03:20:47.377198 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:20:47.382491 | 2025-08-03 03:20:47.382590 | TASK [fetch-tox-output : Set envlist fact] 2025-08-03 03:20:47.420602 | debian-bookworm | ok 2025-08-03 03:20:47.426013 | 2025-08-03 03:20:47.427660 | TASK [fetch-tox-output : Get tox version] 2025-08-03 03:20:47.957919 | debian-bookworm | ERROR 2025-08-03 03:20:47.958160 | debian-bookworm | { 2025-08-03 03:20:47.958198 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-08-03 03:20:47.958229 | debian-bookworm | "rc": 2 2025-08-03 03:20:47.958263 | debian-bookworm | } failure 2025-08-03 03:20:47.959558 | 2025-08-03 03:20:47.959621 | PLAY RECAP 2025-08-03 03:20:47.959680 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-08-03 03:20:47.959706 | 2025-08-03 03:20:48.109039 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-08-03 03:20:48.109949 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-08-03 03:20:48.969570 | 2025-08-03 03:20:48.969695 | PLAY [all] 2025-08-03 03:20:48.983843 | 2025-08-03 03:20:48.983981 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-08-03 03:20:49.198543 | debian-bookworm | changed: non-zero return code 2025-08-03 03:20:49.204231 | 2025-08-03 03:20:49.204351 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-08-03 03:20:49.228216 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:20:49.235582 | 2025-08-03 03:20:49.235731 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-08-03 03:20:49.266755 | 2025-08-03 03:20:49.267288 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-08-03 03:20:49.296582 | 2025-08-03 03:20:49.296747 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-08-03 03:20:49.309616 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:20:49.315103 | 2025-08-03 03:20:49.315244 | LOOP [fetch-subunit-output : Generate subunit file] 2025-08-03 03:20:49.334876 | 2025-08-03 03:20:49.335173 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-08-03 03:20:49.359955 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:20:49.365348 | 2025-08-03 03:20:49.365438 | TASK [fetch-subunit-output : Remove the temporary file] 2025-08-03 03:20:49.378059 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:20:49.383685 | 2025-08-03 03:20:49.383770 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-08-03 03:20:49.396280 | debian-bookworm | skipping: Conditional result was False 2025-08-03 03:20:49.402301 | 2025-08-03 03:20:49.402365 | PLAY RECAP 2025-08-03 03:20:49.402415 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-08-03 03:20:49.402440 | 2025-08-03 03:20:49.508712 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-08-03 03:20:49.509674 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-08-03 03:20:50.484278 | 2025-08-03 03:20:50.484406 | PLAY [Base post] 2025-08-03 03:20:50.496774 | 2025-08-03 03:20:50.496892 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-08-03 03:20:51.112745 | debian-bookworm | changed 2025-08-03 03:20:51.121503 | 2025-08-03 03:20:51.121602 | PLAY RECAP 2025-08-03 03:20:51.121664 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-08-03 03:20:51.121724 | 2025-08-03 03:20:51.221931 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-08-03 03:20:51.223125 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-08-03 03:20:51.982729 | 2025-08-03 03:20:51.982885 | PLAY [Base post-logs] 2025-08-03 03:20:51.993558 | 2025-08-03 03:20:51.993671 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-08-03 03:20:52.447965 | localhost | changed 2025-08-03 03:20:52.466232 | 2025-08-03 03:20:52.466422 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-08-03 03:20:52.492533 | localhost | ok 2025-08-03 03:20:52.496538 | 2025-08-03 03:20:52.496642 | TASK [Set zuul-log-path fact] 2025-08-03 03:20:52.524303 | localhost | ok 2025-08-03 03:20:52.537656 | 2025-08-03 03:20:52.537790 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-08-03 03:20:52.562756 | localhost | ok 2025-08-03 03:20:52.565421 | 2025-08-03 03:20:52.565501 | TASK [upload-logs : Create log directories] 2025-08-03 03:20:53.066306 | localhost | changed 2025-08-03 03:20:53.068785 | 2025-08-03 03:20:53.068873 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-08-03 03:20:53.528485 | localhost -> localhost | ok: Runtime: 0:00:00.006769 2025-08-03 03:20:53.532339 | 2025-08-03 03:20:53.532437 | TASK [upload-logs : Upload logs to log server] 2025-08-03 03:20:54.089533 | localhost | Output suppressed because no_log was given 2025-08-03 03:20:54.092702 | 2025-08-03 03:20:54.093031 | LOOP [upload-logs : Compress console log and json output] 2025-08-03 03:20:54.144446 | localhost | skipping: Conditional result was False 2025-08-03 03:20:54.150083 | localhost | skipping: Conditional result was False 2025-08-03 03:20:54.165230 | 2025-08-03 03:20:54.165473 | LOOP [upload-logs : Upload compressed console log and json output] 2025-08-03 03:20:54.210993 | localhost | skipping: Conditional result was False 2025-08-03 03:20:54.211518 | 2025-08-03 03:20:54.217777 | localhost | skipping: Conditional result was False 2025-08-03 03:20:54.228045 | 2025-08-03 03:20:54.228272 | LOOP [upload-logs : Upload console log and json output]