2025-08-14 21:24:48.839552 | Job console starting 2025-08-14 21:24:48.862291 | Updating git repos 2025-08-14 21:24:48.889708 | Cloning repos into workspace 2025-08-14 21:24:48.984104 | Restoring repo states 2025-08-14 21:24:48.993168 | Merging changes 2025-08-14 21:24:49.742896 | Checking out repos 2025-08-14 21:24:49.836110 | Preparing playbooks 2025-08-14 21:24:51.204662 | Running Ansible setup 2025-08-14 21:26:19.392896 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-08-14 21:26:20.161193 | 2025-08-14 21:26:20.161313 | PLAY [Base pre] 2025-08-14 21:26:20.179662 | 2025-08-14 21:26:20.179849 | TASK [Setup log path fact] 2025-08-14 21:26:20.197540 | debian-bookworm | ok 2025-08-14 21:26:20.211172 | 2025-08-14 21:26:20.211309 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-08-14 21:26:20.240451 | debian-bookworm | ok 2025-08-14 21:26:20.249669 | 2025-08-14 21:26:20.249781 | TASK [emit-job-header : Print job information] 2025-08-14 21:26:20.277803 | # Job Information 2025-08-14 21:26:20.277967 | Ansible Version: 2.16.14 2025-08-14 21:26:20.278005 | Job: cfg-cookiecutter-tox-2024.2 2025-08-14 21:26:20.278040 | Pipeline: check 2025-08-14 21:26:20.278065 | Executor: 521e9411259a 2025-08-14 21:26:20.278088 | Triggered by: https://github.com/osism/cfg-cookiecutter/pull/770 2025-08-14 21:26:20.278112 | Event ID: 1609d6d0-7955-11f0-80ff-c382b998567e 2025-08-14 21:26:20.283369 | 2025-08-14 21:26:20.283469 | LOOP [emit-job-header : Print node information] 2025-08-14 21:26:20.391463 | debian-bookworm | ok: 2025-08-14 21:26:20.391602 | debian-bookworm | # Node Information 2025-08-14 21:26:20.391631 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-08-14 21:26:20.391652 | debian-bookworm | Hostname: debian 2025-08-14 21:26:20.391670 | debian-bookworm | Username: zuul 2025-08-14 21:26:20.391688 | debian-bookworm | Distro: Debian 12.11 2025-08-14 21:26:20.391708 | debian-bookworm | Provider: regiocloud-a 2025-08-14 21:26:20.391726 | debian-bookworm | Region: 2025-08-14 21:26:20.391744 | debian-bookworm | Label: debian-bookworm 2025-08-14 21:26:20.391783 | debian-bookworm | Product Name: OpenStack Nova 2025-08-14 21:26:20.391904 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe86:572f 2025-08-14 21:26:20.412638 | 2025-08-14 21:26:20.412728 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-08-14 21:26:20.779942 | debian-bookworm -> localhost | changed 2025-08-14 21:26:20.785694 | 2025-08-14 21:26:20.785861 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-08-14 21:26:21.750215 | debian-bookworm -> localhost | changed 2025-08-14 21:26:21.762525 | 2025-08-14 21:26:21.762785 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-08-14 21:26:21.988165 | debian-bookworm -> localhost | ok 2025-08-14 21:26:21.994144 | 2025-08-14 21:26:21.994248 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-08-14 21:26:22.011645 | debian-bookworm | ok 2025-08-14 21:26:22.034446 | debian-bookworm | included: /var/lib/zuul/builds/e0a316df5aab4a538eef0fd21a1a64e0/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-08-14 21:26:22.044812 | 2025-08-14 21:26:22.044915 | TASK [add-build-sshkey : Create Temp SSH key] 2025-08-14 21:26:23.205104 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-08-14 21:26:23.205337 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/e0a316df5aab4a538eef0fd21a1a64e0/work/e0a316df5aab4a538eef0fd21a1a64e0_id_rsa 2025-08-14 21:26:23.205380 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/e0a316df5aab4a538eef0fd21a1a64e0/work/e0a316df5aab4a538eef0fd21a1a64e0_id_rsa.pub 2025-08-14 21:26:23.205406 | debian-bookworm -> localhost | The key fingerprint is: 2025-08-14 21:26:23.205430 | debian-bookworm -> localhost | SHA256:4X3Wir3JdkNXzIPKY5bW5ESB9EnYYcekaS4yiWpX6LE zuul-build-sshkey 2025-08-14 21:26:23.205463 | debian-bookworm -> localhost | The key's randomart image is: 2025-08-14 21:26:23.205487 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-08-14 21:26:23.205507 | debian-bookworm -> localhost | | ..+==o | 2025-08-14 21:26:23.205528 | debian-bookworm -> localhost | | o+o=. | 2025-08-14 21:26:23.205549 | debian-bookworm -> localhost | | . .*.o | 2025-08-14 21:26:23.205568 | debian-bookworm -> localhost | | .oo. o= .+| 2025-08-14 21:26:23.205588 | debian-bookworm -> localhost | | +S=o.X.. o| 2025-08-14 21:26:23.205612 | debian-bookworm -> localhost | | o + o&.+. .| 2025-08-14 21:26:23.205633 | debian-bookworm -> localhost | | o E = +. . | 2025-08-14 21:26:23.205653 | debian-bookworm -> localhost | | . . ..oo | 2025-08-14 21:26:23.205674 | debian-bookworm -> localhost | | .+. . | 2025-08-14 21:26:23.205694 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-08-14 21:26:23.205749 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.640618 2025-08-14 21:26:23.211930 | 2025-08-14 21:26:23.212027 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-08-14 21:26:23.235481 | debian-bookworm | ok 2025-08-14 21:26:23.258135 | debian-bookworm | included: /var/lib/zuul/builds/e0a316df5aab4a538eef0fd21a1a64e0/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-08-14 21:26:23.278068 | 2025-08-14 21:26:23.278172 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-08-14 21:26:23.311300 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:26:23.317128 | 2025-08-14 21:26:23.317225 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-08-14 21:26:24.016330 | debian-bookworm | changed 2025-08-14 21:26:24.021693 | 2025-08-14 21:26:24.021798 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-08-14 21:26:24.271403 | debian-bookworm | ok 2025-08-14 21:26:24.276881 | 2025-08-14 21:26:24.276973 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-08-14 21:26:25.075840 | debian-bookworm | changed 2025-08-14 21:26:25.099347 | 2025-08-14 21:26:25.099814 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-08-14 21:26:25.897732 | debian-bookworm | changed 2025-08-14 21:26:25.902238 | 2025-08-14 21:26:25.902311 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-08-14 21:26:25.926630 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:26:25.932378 | 2025-08-14 21:26:25.932469 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-08-14 21:26:26.724311 | debian-bookworm -> localhost | changed 2025-08-14 21:26:26.738709 | 2025-08-14 21:26:26.738877 | TASK [add-build-sshkey : Add back temp key] 2025-08-14 21:26:27.340978 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/e0a316df5aab4a538eef0fd21a1a64e0/work/e0a316df5aab4a538eef0fd21a1a64e0_id_rsa (zuul-build-sshkey) 2025-08-14 21:26:27.341190 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.009371 2025-08-14 21:26:27.348615 | 2025-08-14 21:26:27.348716 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-08-14 21:26:27.900874 | debian-bookworm | ok 2025-08-14 21:26:27.905931 | 2025-08-14 21:26:27.906021 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-08-14 21:26:27.966644 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:26:27.977669 | 2025-08-14 21:26:27.977786 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-08-14 21:26:28.480959 | debian-bookworm | ok 2025-08-14 21:26:28.507861 | 2025-08-14 21:26:28.507974 | TASK [validate-host : Define zuul_info_dir fact] 2025-08-14 21:26:28.536041 | debian-bookworm | ok 2025-08-14 21:26:28.540951 | 2025-08-14 21:26:28.541048 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-08-14 21:26:29.007111 | debian-bookworm -> localhost | ok 2025-08-14 21:26:29.013729 | 2025-08-14 21:26:29.013846 | TASK [validate-host : Collect information about the host] 2025-08-14 21:27:10.533290 | debian-bookworm | ok 2025-08-14 21:27:10.547061 | 2025-08-14 21:27:10.547188 | TASK [validate-host : Sanitize hostname] 2025-08-14 21:27:10.665222 | debian-bookworm | ok 2025-08-14 21:27:10.707446 | 2025-08-14 21:27:10.707582 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-08-14 21:27:11.248047 | debian-bookworm -> localhost | changed 2025-08-14 21:27:11.259906 | 2025-08-14 21:27:11.260061 | TASK [validate-host : Collect information about zuul worker] 2025-08-14 21:27:11.698416 | debian-bookworm | ok 2025-08-14 21:27:11.705907 | 2025-08-14 21:27:11.706034 | TASK [validate-host : Write out all zuul information for each host] 2025-08-14 21:27:12.215900 | debian-bookworm -> localhost | changed 2025-08-14 21:27:12.228907 | 2025-08-14 21:27:12.229013 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-08-14 21:27:12.528032 | debian-bookworm | ok 2025-08-14 21:27:12.537018 | 2025-08-14 21:27:12.537144 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-08-14 21:27:13.384080 | debian-bookworm | changed: 2025-08-14 21:27:13.384429 | debian-bookworm | cd+++++++++ src/ 2025-08-14 21:27:13.384502 | debian-bookworm | cd+++++++++ src/github.com/ 2025-08-14 21:27:13.384552 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-08-14 21:27:13.384598 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-cookiecutter/ 2025-08-14 21:27:13.384642 | debian-bookworm | Containerfile 2025-08-14 21:27:13.384986 | debian-bookworm | localhost | changed 2025-08-14 21:29:31.841090 | 2025-08-14 21:29:31.841275 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-08-14 21:29:31.896684 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:29:31.910448 | 2025-08-14 21:29:31.910631 | TASK [fetch-tox-output : Set envlist fact] 2025-08-14 21:29:31.957055 | debian-bookworm | ok 2025-08-14 21:29:31.965582 | 2025-08-14 21:29:31.965697 | TASK [fetch-tox-output : Get tox version] 2025-08-14 21:29:32.500664 | debian-bookworm | ERROR 2025-08-14 21:29:32.501388 | debian-bookworm | { 2025-08-14 21:29:32.501505 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-08-14 21:29:32.501594 | debian-bookworm | "rc": 2 2025-08-14 21:29:32.501656 | debian-bookworm | } failure 2025-08-14 21:29:32.504911 | 2025-08-14 21:29:32.505066 | PLAY RECAP 2025-08-14 21:29:32.505184 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-08-14 21:29:32.505245 | 2025-08-14 21:29:32.629921 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-08-14 21:29:32.632633 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-08-14 21:29:33.377829 | 2025-08-14 21:29:33.377984 | PLAY [all] 2025-08-14 21:29:33.393486 | 2025-08-14 21:29:33.393615 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-08-14 21:29:33.634660 | debian-bookworm | changed: non-zero return code 2025-08-14 21:29:33.645058 | 2025-08-14 21:29:33.645234 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-08-14 21:29:33.672199 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:29:33.685504 | 2025-08-14 21:29:33.685670 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-08-14 21:29:33.723236 | 2025-08-14 21:29:33.723507 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-08-14 21:29:33.765180 | 2025-08-14 21:29:33.765443 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-08-14 21:29:33.790458 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:29:33.803829 | 2025-08-14 21:29:33.803994 | LOOP [fetch-subunit-output : Generate subunit file] 2025-08-14 21:29:33.842685 | 2025-08-14 21:29:33.843017 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-08-14 21:29:33.868473 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:29:33.877144 | 2025-08-14 21:29:33.877288 | TASK [fetch-subunit-output : Remove the temporary file] 2025-08-14 21:29:33.901912 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:29:33.913115 | 2025-08-14 21:29:33.913270 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-08-14 21:29:33.938148 | debian-bookworm | skipping: Conditional result was False 2025-08-14 21:29:33.950561 | 2025-08-14 21:29:33.950674 | PLAY RECAP 2025-08-14 21:29:33.950755 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-08-14 21:29:33.950821 | 2025-08-14 21:29:34.081290 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-08-14 21:29:34.082372 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-08-14 21:29:34.809177 | 2025-08-14 21:29:34.809334 | PLAY [Base post] 2025-08-14 21:29:34.823040 | 2025-08-14 21:29:34.823171 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-08-14 21:29:35.377643 | debian-bookworm | changed 2025-08-14 21:29:35.387617 | 2025-08-14 21:29:35.387775 | PLAY RECAP 2025-08-14 21:29:35.387862 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-08-14 21:29:35.387941 | 2025-08-14 21:29:35.513496 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-08-14 21:29:35.514609 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-08-14 21:29:36.301609 | 2025-08-14 21:29:36.301808 | PLAY [Base post-logs] 2025-08-14 21:29:36.312269 | 2025-08-14 21:29:36.312399 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-08-14 21:29:36.766403 | localhost | changed 2025-08-14 21:29:36.784944 | 2025-08-14 21:29:36.785122 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-08-14 21:29:36.823110 | localhost | ok 2025-08-14 21:29:36.829291 | 2025-08-14 21:29:36.829438 | TASK [Set zuul-log-path fact] 2025-08-14 21:29:36.846499 | localhost | ok 2025-08-14 21:29:36.859830 | 2025-08-14 21:29:36.859986 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-08-14 21:29:36.885389 | localhost | ok 2025-08-14 21:29:36.889355 | 2025-08-14 21:29:36.889461 | TASK [upload-logs : Create log directories] 2025-08-14 21:29:37.386489 | localhost | changed 2025-08-14 21:29:37.391873 | 2025-08-14 21:29:37.392042 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-08-14 21:29:37.887203 | localhost -> localhost | ok: Runtime: 0:00:00.006845 2025-08-14 21:29:37.898169 | 2025-08-14 21:29:37.898382 | TASK [upload-logs : Upload logs to log server] 2025-08-14 21:29:38.477961 | localhost | Output suppressed because no_log was given 2025-08-14 21:29:38.482200 | 2025-08-14 21:29:38.482404 | LOOP [upload-logs : Compress console log and json output] 2025-08-14 21:29:38.541156 | localhost | skipping: Conditional result was False 2025-08-14 21:29:38.546552 | localhost | skipping: Conditional result was False 2025-08-14 21:29:38.552699 | 2025-08-14 21:29:38.552937 | LOOP [upload-logs : Upload compressed console log and json output] 2025-08-14 21:29:38.598273 | localhost | skipping: Conditional result was False 2025-08-14 21:29:38.599002 | 2025-08-14 21:29:38.602488 | localhost | skipping: Conditional result was False 2025-08-14 21:29:38.614701 | 2025-08-14 21:29:38.614939 | LOOP [upload-logs : Upload console log and json output]