2025-09-10 03:14:01.163243 | Job console starting 2025-09-10 03:14:01.190944 | Updating git repos 2025-09-10 03:14:01.222784 | Cloning repos into workspace 2025-09-10 03:14:01.329566 | Restoring repo states 2025-09-10 03:14:01.352325 | Merging changes 2025-09-10 03:14:01.352347 | Checking out repos 2025-09-10 03:14:01.451202 | Preparing playbooks 2025-09-10 03:14:02.629440 | Running Ansible setup 2025-09-10 03:15:27.781230 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-09-10 03:15:28.681718 | 2025-09-10 03:15:28.681895 | PLAY [Base pre] 2025-09-10 03:15:28.704326 | 2025-09-10 03:15:28.704461 | TASK [Setup log path fact] 2025-09-10 03:15:28.736916 | debian-bookworm | ok 2025-09-10 03:15:28.757137 | 2025-09-10 03:15:28.757275 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-10 03:15:28.797332 | debian-bookworm | ok 2025-09-10 03:15:28.807956 | 2025-09-10 03:15:28.808083 | TASK [emit-job-header : Print job information] 2025-09-10 03:15:28.851339 | # Job Information 2025-09-10 03:15:28.851537 | Ansible Version: 2.16.14 2025-09-10 03:15:28.851578 | Job: cfg-cookiecutter-tox-2024.1 2025-09-10 03:15:28.851613 | Pipeline: periodic-daily 2025-09-10 03:15:28.851638 | Executor: 521e9411259a 2025-09-10 03:15:28.851661 | Triggered by: https://github.com/osism/cfg-cookiecutter 2025-09-10 03:15:28.851687 | Event ID: 7536b9add5e740809ae45d28d238a041 2025-09-10 03:15:28.856919 | 2025-09-10 03:15:28.857031 | LOOP [emit-job-header : Print node information] 2025-09-10 03:15:28.993408 | debian-bookworm | ok: 2025-09-10 03:15:28.993616 | debian-bookworm | # Node Information 2025-09-10 03:15:28.993651 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-09-10 03:15:28.993677 | debian-bookworm | Hostname: debian 2025-09-10 03:15:28.993699 | debian-bookworm | Username: zuul 2025-09-10 03:15:28.993721 | debian-bookworm | Distro: Debian 12.12 2025-09-10 03:15:28.993745 | debian-bookworm | Provider: regiocloud-a 2025-09-10 03:15:28.993767 | debian-bookworm | Region: 2025-09-10 03:15:28.993789 | debian-bookworm | Label: debian-bookworm 2025-09-10 03:15:28.993827 | debian-bookworm | Product Name: OpenStack Nova 2025-09-10 03:15:28.993850 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe01:706b 2025-09-10 03:15:29.007773 | 2025-09-10 03:15:29.007930 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-10 03:15:29.663586 | debian-bookworm -> localhost | changed 2025-09-10 03:15:29.671779 | 2025-09-10 03:15:29.672259 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-10 03:15:30.850553 | debian-bookworm -> localhost | changed 2025-09-10 03:15:30.865950 | 2025-09-10 03:15:30.866078 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-10 03:15:31.208906 | debian-bookworm -> localhost | ok 2025-09-10 03:15:31.215613 | 2025-09-10 03:15:31.215738 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-10 03:15:31.257969 | debian-bookworm | ok 2025-09-10 03:15:31.285049 | debian-bookworm | included: /var/lib/zuul/builds/74870ec4c47b402fa5e1c3a5406ce1eb/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-10 03:15:31.291362 | 2025-09-10 03:15:31.291467 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-10 03:15:33.776521 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-09-10 03:15:33.776800 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/74870ec4c47b402fa5e1c3a5406ce1eb/work/74870ec4c47b402fa5e1c3a5406ce1eb_id_rsa 2025-09-10 03:15:33.776857 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/74870ec4c47b402fa5e1c3a5406ce1eb/work/74870ec4c47b402fa5e1c3a5406ce1eb_id_rsa.pub 2025-09-10 03:15:33.776884 | debian-bookworm -> localhost | The key fingerprint is: 2025-09-10 03:15:33.776909 | debian-bookworm -> localhost | SHA256:lpxECCx7RlsPBwSVgnsl7zta6+G4PgFzMMHRUAASF8U zuul-build-sshkey 2025-09-10 03:15:33.776931 | debian-bookworm -> localhost | The key's randomart image is: 2025-09-10 03:15:33.776964 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-09-10 03:15:33.776986 | debian-bookworm -> localhost | |++B&==++. | 2025-09-10 03:15:33.777006 | debian-bookworm -> localhost | |..* E *.. | 2025-09-10 03:15:33.777026 | debian-bookworm -> localhost | | B B +. | 2025-09-10 03:15:33.777045 | debian-bookworm -> localhost | | = * .o.o | 2025-09-10 03:15:33.777065 | debian-bookworm -> localhost | | B . S | 2025-09-10 03:15:33.777088 | debian-bookworm -> localhost | | . .. | 2025-09-10 03:15:33.777109 | debian-bookworm -> localhost | | .o. | 2025-09-10 03:15:33.777129 | debian-bookworm -> localhost | | .+oo | 2025-09-10 03:15:33.777149 | debian-bookworm -> localhost | | .==+. | 2025-09-10 03:15:33.777170 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-09-10 03:15:33.777218 | debian-bookworm -> localhost | ok: Runtime: 0:00:01.940130 2025-09-10 03:15:33.784194 | 2025-09-10 03:15:33.784309 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-10 03:15:33.823677 | debian-bookworm | ok 2025-09-10 03:15:33.843190 | debian-bookworm | included: /var/lib/zuul/builds/74870ec4c47b402fa5e1c3a5406ce1eb/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-10 03:15:33.864028 | 2025-09-10 03:15:33.864158 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-10 03:15:33.916012 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:15:33.923596 | 2025-09-10 03:15:33.923738 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-10 03:15:34.616642 | debian-bookworm | changed 2025-09-10 03:15:34.624176 | 2025-09-10 03:15:34.624289 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-10 03:15:34.920474 | debian-bookworm | ok 2025-09-10 03:15:34.938782 | 2025-09-10 03:15:34.938952 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-10 03:15:35.701767 | debian-bookworm | changed 2025-09-10 03:15:35.710393 | 2025-09-10 03:15:35.710478 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-10 03:15:36.494093 | debian-bookworm | changed 2025-09-10 03:15:36.501566 | 2025-09-10 03:15:36.501664 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-10 03:15:36.519213 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:15:36.526063 | 2025-09-10 03:15:36.526163 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-10 03:15:37.069909 | debian-bookworm -> localhost | changed 2025-09-10 03:15:37.082036 | 2025-09-10 03:15:37.082130 | TASK [add-build-sshkey : Add back temp key] 2025-09-10 03:15:37.463199 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/74870ec4c47b402fa5e1c3a5406ce1eb/work/74870ec4c47b402fa5e1c3a5406ce1eb_id_rsa (zuul-build-sshkey) 2025-09-10 03:15:37.463402 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.025112 2025-09-10 03:15:37.470615 | 2025-09-10 03:15:37.470703 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-10 03:15:37.945705 | debian-bookworm | ok 2025-09-10 03:15:37.951801 | 2025-09-10 03:15:37.951929 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-10 03:15:37.975360 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:15:37.987436 | 2025-09-10 03:15:37.987556 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-10 03:15:38.419697 | debian-bookworm | ok 2025-09-10 03:15:38.446959 | 2025-09-10 03:15:38.447106 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-10 03:15:38.487545 | debian-bookworm | ok 2025-09-10 03:15:38.492682 | 2025-09-10 03:15:38.492766 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-10 03:15:38.942255 | debian-bookworm -> localhost | ok 2025-09-10 03:15:38.949280 | 2025-09-10 03:15:38.949372 | TASK [validate-host : Collect information about the host] 2025-09-10 03:16:20.142030 | debian-bookworm | ok 2025-09-10 03:16:20.151997 | 2025-09-10 03:16:20.152078 | TASK [validate-host : Sanitize hostname] 2025-09-10 03:16:20.301384 | debian-bookworm | ok 2025-09-10 03:16:20.372270 | 2025-09-10 03:16:20.372375 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-10 03:16:21.377612 | debian-bookworm -> localhost | changed 2025-09-10 03:16:21.383158 | 2025-09-10 03:16:21.383254 | TASK [validate-host : Collect information about zuul worker] 2025-09-10 03:16:21.855498 | debian-bookworm | ok 2025-09-10 03:16:21.860175 | 2025-09-10 03:16:21.860263 | TASK [validate-host : Write out all zuul information for each host] 2025-09-10 03:16:22.663275 | debian-bookworm -> localhost | changed 2025-09-10 03:16:22.672235 | 2025-09-10 03:16:22.672323 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-09-10 03:16:22.944112 | debian-bookworm | ok 2025-09-10 03:16:22.949271 | 2025-09-10 03:16:22.949356 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-09-10 03:16:23.852192 | debian-bookworm | changed: 2025-09-10 03:16:23.852365 | debian-bookworm | cd+++++++++ src/ 2025-09-10 03:16:23.852398 | debian-bookworm | cd+++++++++ src/github.com/ 2025-09-10 03:16:23.852423 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-09-10 03:16:23.852443 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-cookiecutter/ 2025-09-10 03:16:23.852463 | debian-bookworm | Containerfile 2025-09-10 03:16:23.852590 | debian-bookworm | localhost | changed 2025-09-10 03:18:43.237898 | 2025-09-10 03:18:43.237990 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-09-10 03:18:43.280931 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:18:43.286043 | 2025-09-10 03:18:43.286135 | TASK [fetch-tox-output : Set envlist fact] 2025-09-10 03:18:43.315665 | debian-bookworm | ok 2025-09-10 03:18:43.321264 | 2025-09-10 03:18:43.321348 | TASK [fetch-tox-output : Get tox version] 2025-09-10 03:18:43.849742 | debian-bookworm | ERROR 2025-09-10 03:18:43.850049 | debian-bookworm | { 2025-09-10 03:18:43.850088 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-09-10 03:18:43.850119 | debian-bookworm | "rc": 2 2025-09-10 03:18:43.850141 | debian-bookworm | } failure 2025-09-10 03:18:43.851351 | 2025-09-10 03:18:43.851414 | PLAY RECAP 2025-09-10 03:18:43.851462 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-09-10 03:18:43.851487 | 2025-09-10 03:18:43.984746 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-09-10 03:18:43.990139 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-10 03:18:45.043456 | 2025-09-10 03:18:45.043580 | PLAY [all] 2025-09-10 03:18:45.057322 | 2025-09-10 03:18:45.057435 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-09-10 03:18:45.266198 | debian-bookworm | changed: non-zero return code 2025-09-10 03:18:45.272231 | 2025-09-10 03:18:45.272344 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-09-10 03:18:45.295896 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:18:45.301530 | 2025-09-10 03:18:45.301628 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-09-10 03:18:45.331028 | 2025-09-10 03:18:45.331206 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-09-10 03:18:45.361283 | 2025-09-10 03:18:45.361450 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-09-10 03:18:45.384819 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:18:45.392357 | 2025-09-10 03:18:45.392476 | LOOP [fetch-subunit-output : Generate subunit file] 2025-09-10 03:18:45.428551 | 2025-09-10 03:18:45.428873 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-09-10 03:18:45.453444 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:18:45.463366 | 2025-09-10 03:18:45.463475 | TASK [fetch-subunit-output : Remove the temporary file] 2025-09-10 03:18:45.478200 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:18:45.483893 | 2025-09-10 03:18:45.483980 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-09-10 03:18:45.496969 | debian-bookworm | skipping: Conditional result was False 2025-09-10 03:18:45.502677 | 2025-09-10 03:18:45.502738 | PLAY RECAP 2025-09-10 03:18:45.502797 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-09-10 03:18:45.502823 | 2025-09-10 03:18:45.586611 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-10 03:18:45.587603 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-10 03:18:46.246259 | 2025-09-10 03:18:46.246386 | PLAY [Base post] 2025-09-10 03:18:46.258395 | 2025-09-10 03:18:46.258505 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-10 03:18:46.781701 | debian-bookworm | changed 2025-09-10 03:18:46.788364 | 2025-09-10 03:18:46.788453 | PLAY RECAP 2025-09-10 03:18:46.788512 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-10 03:18:46.788576 | 2025-09-10 03:18:46.879896 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-10 03:18:46.880704 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-09-10 03:18:48.010726 | 2025-09-10 03:18:48.010911 | PLAY [Base post-logs] 2025-09-10 03:18:48.028801 | 2025-09-10 03:18:48.028930 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-10 03:18:48.557711 | localhost | changed 2025-09-10 03:18:48.568155 | 2025-09-10 03:18:48.568284 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-10 03:18:48.592873 | localhost | ok 2025-09-10 03:18:48.595570 | 2025-09-10 03:18:48.595647 | TASK [Set zuul-log-path fact] 2025-09-10 03:18:48.620029 | localhost | ok 2025-09-10 03:18:48.628557 | 2025-09-10 03:18:48.628644 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-10 03:18:48.662877 | localhost | ok 2025-09-10 03:18:48.665570 | 2025-09-10 03:18:48.665651 | TASK [upload-logs : Create log directories] 2025-09-10 03:18:49.280002 | localhost | changed 2025-09-10 03:18:49.282610 | 2025-09-10 03:18:49.282696 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-10 03:18:49.695495 | localhost -> localhost | ok: Runtime: 0:00:00.003855 2025-09-10 03:18:49.703982 | 2025-09-10 03:18:49.704117 | TASK [upload-logs : Upload logs to log server] 2025-09-10 03:18:50.144983 | localhost | Output suppressed because no_log was given 2025-09-10 03:18:50.146742 | 2025-09-10 03:18:50.146866 | LOOP [upload-logs : Compress console log and json output] 2025-09-10 03:18:50.194197 | localhost | skipping: Conditional result was False 2025-09-10 03:18:50.198636 | localhost | skipping: Conditional result was False 2025-09-10 03:18:50.206517 | 2025-09-10 03:18:50.206749 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-10 03:18:50.259426 | localhost | skipping: Conditional result was False 2025-09-10 03:18:50.259715 | 2025-09-10 03:18:50.260816 | localhost | skipping: Conditional result was False 2025-09-10 03:18:50.275004 | 2025-09-10 03:18:50.275235 | LOOP [upload-logs : Upload console log and json output]