2025-09-23 16:02:49.142886 | Job console starting 2025-09-23 16:02:49.173823 | Updating git repos 2025-09-23 16:02:49.231602 | Cloning repos into workspace 2025-09-23 16:02:49.323287 | Restoring repo states 2025-09-23 16:02:49.350982 | Merging changes 2025-09-23 16:02:49.824705 | Checking out repos 2025-09-23 16:02:49.889200 | Preparing playbooks 2025-09-23 16:02:50.980252 | Running Ansible setup 2025-09-23 16:04:15.794635 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-09-23 16:04:16.567336 | 2025-09-23 16:04:16.567490 | PLAY [Base pre] 2025-09-23 16:04:16.583375 | 2025-09-23 16:04:16.583500 | TASK [Setup log path fact] 2025-09-23 16:04:16.602445 | debian-bookworm | ok 2025-09-23 16:04:16.618596 | 2025-09-23 16:04:16.618722 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-23 16:04:16.659426 | debian-bookworm | ok 2025-09-23 16:04:16.669838 | 2025-09-23 16:04:16.669951 | TASK [emit-job-header : Print job information] 2025-09-23 16:04:16.727348 | # Job Information 2025-09-23 16:04:16.727676 | Ansible Version: 2.16.14 2025-09-23 16:04:16.727748 | Job: cfg-generics-tox-test-stable-legacy 2025-09-23 16:04:16.727886 | Pipeline: check 2025-09-23 16:04:16.727937 | Executor: 521e9411259a 2025-09-23 16:04:16.728036 | Triggered by: https://github.com/osism/cfg-generics/pull/558 2025-09-23 16:04:16.728089 | Event ID: bb2f7010-9896-11f0-8f36-73fdb0768ffc 2025-09-23 16:04:16.736317 | 2025-09-23 16:04:16.736469 | LOOP [emit-job-header : Print node information] 2025-09-23 16:04:16.843119 | debian-bookworm | ok: 2025-09-23 16:04:16.843428 | debian-bookworm | # Node Information 2025-09-23 16:04:16.843474 | debian-bookworm | Inventory Hostname: debian-bookworm 2025-09-23 16:04:16.843501 | debian-bookworm | Hostname: debian 2025-09-23 16:04:16.843524 | debian-bookworm | Username: zuul 2025-09-23 16:04:16.843545 | debian-bookworm | Distro: Debian 12.12 2025-09-23 16:04:16.843571 | debian-bookworm | Provider: regiocloud-a 2025-09-23 16:04:16.843593 | debian-bookworm | Region: 2025-09-23 16:04:16.843614 | debian-bookworm | Label: debian-bookworm 2025-09-23 16:04:16.843634 | debian-bookworm | Product Name: OpenStack Nova 2025-09-23 16:04:16.843654 | debian-bookworm | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe1d:96c8 2025-09-23 16:04:16.872596 | 2025-09-23 16:04:16.872735 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-23 16:04:17.353010 | debian-bookworm -> localhost | changed 2025-09-23 16:04:17.366668 | 2025-09-23 16:04:17.366819 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-23 16:04:18.434066 | debian-bookworm -> localhost | changed 2025-09-23 16:04:18.455905 | 2025-09-23 16:04:18.456098 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-23 16:04:18.773583 | debian-bookworm -> localhost | ok 2025-09-23 16:04:18.780511 | 2025-09-23 16:04:18.780637 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-23 16:04:18.819889 | debian-bookworm | ok 2025-09-23 16:04:18.839131 | debian-bookworm | included: /var/lib/zuul/builds/0aa1ca1a95a54bf6887c59198c3025e1/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-23 16:04:18.845400 | 2025-09-23 16:04:18.845506 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-23 16:04:20.106275 | debian-bookworm -> localhost | Generating public/private rsa key pair. 2025-09-23 16:04:20.106509 | debian-bookworm -> localhost | Your identification has been saved in /var/lib/zuul/builds/0aa1ca1a95a54bf6887c59198c3025e1/work/0aa1ca1a95a54bf6887c59198c3025e1_id_rsa 2025-09-23 16:04:20.106550 | debian-bookworm -> localhost | Your public key has been saved in /var/lib/zuul/builds/0aa1ca1a95a54bf6887c59198c3025e1/work/0aa1ca1a95a54bf6887c59198c3025e1_id_rsa.pub 2025-09-23 16:04:20.106577 | debian-bookworm -> localhost | The key fingerprint is: 2025-09-23 16:04:20.106602 | debian-bookworm -> localhost | SHA256:nYawlYF5BFcCuQAkRKzdTCI7B6D2RaNHYjNNgmDs6zo zuul-build-sshkey 2025-09-23 16:04:20.106637 | debian-bookworm -> localhost | The key's randomart image is: 2025-09-23 16:04:20.106660 | debian-bookworm -> localhost | +---[RSA 3072]----+ 2025-09-23 16:04:20.106681 | debian-bookworm -> localhost | |@=+Bo=oB=.. | 2025-09-23 16:04:20.106703 | debian-bookworm -> localhost | |==o @.=..+ | 2025-09-23 16:04:20.106724 | debian-bookworm -> localhost | |+* * +.oo | 2025-09-23 16:04:20.106744 | debian-bookworm -> localhost | |=.+ = .+ o . | 2025-09-23 16:04:20.106764 | debian-bookworm -> localhost | | o.. . S + | 2025-09-23 16:04:20.106787 | debian-bookworm -> localhost | | . . | 2025-09-23 16:04:20.106807 | debian-bookworm -> localhost | |. | 2025-09-23 16:04:20.106827 | debian-bookworm -> localhost | |E. | 2025-09-23 16:04:20.106905 | debian-bookworm -> localhost | |o. | 2025-09-23 16:04:20.106927 | debian-bookworm -> localhost | +----[SHA256]-----+ 2025-09-23 16:04:20.107003 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.656100 2025-09-23 16:04:20.115590 | 2025-09-23 16:04:20.115708 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-23 16:04:20.145656 | debian-bookworm | ok 2025-09-23 16:04:20.159407 | debian-bookworm | included: /var/lib/zuul/builds/0aa1ca1a95a54bf6887c59198c3025e1/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-23 16:04:20.168693 | 2025-09-23 16:04:20.168793 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-23 16:04:20.190258 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:04:20.196123 | 2025-09-23 16:04:20.196231 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-23 16:04:20.871687 | debian-bookworm | changed 2025-09-23 16:04:20.877128 | 2025-09-23 16:04:20.877237 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-23 16:04:21.131485 | debian-bookworm | ok 2025-09-23 16:04:21.137693 | 2025-09-23 16:04:21.137808 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-23 16:04:21.812184 | debian-bookworm | changed 2025-09-23 16:04:21.822380 | 2025-09-23 16:04:21.822526 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-23 16:04:22.462476 | debian-bookworm | changed 2025-09-23 16:04:22.473853 | 2025-09-23 16:04:22.474121 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-23 16:04:22.511307 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:04:22.525680 | 2025-09-23 16:04:22.525807 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-23 16:04:22.977200 | debian-bookworm -> localhost | changed 2025-09-23 16:04:22.989032 | 2025-09-23 16:04:22.989162 | TASK [add-build-sshkey : Add back temp key] 2025-09-23 16:04:23.328111 | debian-bookworm -> localhost | Identity added: /var/lib/zuul/builds/0aa1ca1a95a54bf6887c59198c3025e1/work/0aa1ca1a95a54bf6887c59198c3025e1_id_rsa (zuul-build-sshkey) 2025-09-23 16:04:23.328385 | debian-bookworm -> localhost | ok: Runtime: 0:00:00.011188 2025-09-23 16:04:23.336797 | 2025-09-23 16:04:23.336918 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-23 16:04:23.739388 | debian-bookworm | ok 2025-09-23 16:04:23.745056 | 2025-09-23 16:04:23.745159 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-23 16:04:23.778981 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:04:23.795244 | 2025-09-23 16:04:23.795376 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-23 16:04:24.235710 | debian-bookworm | ok 2025-09-23 16:04:24.246818 | 2025-09-23 16:04:24.246980 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-23 16:04:24.293789 | debian-bookworm | ok 2025-09-23 16:04:24.301234 | 2025-09-23 16:04:24.301371 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-23 16:04:24.798499 | debian-bookworm -> localhost | ok 2025-09-23 16:04:24.805208 | 2025-09-23 16:04:24.805334 | TASK [validate-host : Collect information about the host] 2025-09-23 16:05:06.046543 | debian-bookworm | ok 2025-09-23 16:05:06.061425 | 2025-09-23 16:05:06.061557 | TASK [validate-host : Sanitize hostname] 2025-09-23 16:05:06.171234 | debian-bookworm | ok 2025-09-23 16:05:06.214013 | 2025-09-23 16:05:06.214147 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-23 16:05:06.776487 | debian-bookworm -> localhost | changed 2025-09-23 16:05:06.787844 | 2025-09-23 16:05:06.788106 | TASK [validate-host : Collect information about zuul worker] 2025-09-23 16:05:07.190267 | debian-bookworm | ok 2025-09-23 16:05:07.198227 | 2025-09-23 16:05:07.198374 | TASK [validate-host : Write out all zuul information for each host] 2025-09-23 16:05:07.744262 | debian-bookworm -> localhost | changed 2025-09-23 16:05:07.761450 | 2025-09-23 16:05:07.761675 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-09-23 16:05:08.040270 | debian-bookworm | ok 2025-09-23 16:05:08.049847 | 2025-09-23 16:05:08.050053 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-09-23 16:05:08.878618 | debian-bookworm | changed: 2025-09-23 16:05:08.878938 | debian-bookworm | cd+++++++++ src/ 2025-09-23 16:05:08.879050 | debian-bookworm | cd+++++++++ src/github.com/ 2025-09-23 16:05:08.879097 | debian-bookworm | cd+++++++++ src/github.com/osism/ 2025-09-23 16:05:08.879135 | debian-bookworm | cd+++++++++ src/github.com/osism/cfg-generics/ 2025-09-23 16:05:08.879172 | debian-bookworm | localhost | changed 2025-09-23 16:07:27.466984 | 2025-09-23 16:07:27.467102 | TASK [fetch-tox-output : Ensure zuul-output tox dir] 2025-09-23 16:07:27.521977 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:07:27.533144 | 2025-09-23 16:07:27.533299 | TASK [fetch-tox-output : Set envlist fact] 2025-09-23 16:07:27.577829 | debian-bookworm | ok 2025-09-23 16:07:27.585903 | 2025-09-23 16:07:27.586043 | TASK [fetch-tox-output : Get tox version] 2025-09-23 16:07:28.119787 | debian-bookworm | ERROR 2025-09-23 16:07:28.120395 | debian-bookworm | { 2025-09-23 16:07:28.120490 | debian-bookworm | "msg": "[Errno 2] No such file or directory: b'tox'", 2025-09-23 16:07:28.120554 | debian-bookworm | "rc": 2 2025-09-23 16:07:28.120601 | debian-bookworm | } failure 2025-09-23 16:07:28.123311 | 2025-09-23 16:07:28.123433 | PLAY RECAP 2025-09-23 16:07:28.123519 | debian-bookworm | ok: 3 changed: 1 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0 2025-09-23 16:07:28.123561 | 2025-09-23 16:07:28.251334 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/tox/post.yaml@master] 2025-09-23 16:07:28.253568 | POST-RUN START: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-23 16:07:28.973848 | 2025-09-23 16:07:28.974035 | PLAY [all] 2025-09-23 16:07:28.988899 | 2025-09-23 16:07:28.989065 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-09-23 16:07:29.235467 | debian-bookworm | changed: non-zero return code 2025-09-23 16:07:29.248207 | 2025-09-23 16:07:29.248492 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-09-23 16:07:29.274458 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:07:29.287673 | 2025-09-23 16:07:29.287847 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-09-23 16:07:29.323066 | 2025-09-23 16:07:29.323336 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-09-23 16:07:29.358336 | 2025-09-23 16:07:29.358561 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-09-23 16:07:29.382190 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:07:29.391556 | 2025-09-23 16:07:29.391695 | LOOP [fetch-subunit-output : Generate subunit file] 2025-09-23 16:07:29.425068 | 2025-09-23 16:07:29.425307 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-09-23 16:07:29.449260 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:07:29.460691 | 2025-09-23 16:07:29.460851 | TASK [fetch-subunit-output : Remove the temporary file] 2025-09-23 16:07:29.485076 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:07:29.496330 | 2025-09-23 16:07:29.496472 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-09-23 16:07:29.511841 | debian-bookworm | skipping: Conditional result was False 2025-09-23 16:07:29.521408 | 2025-09-23 16:07:29.521518 | PLAY RECAP 2025-09-23 16:07:29.521589 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-09-23 16:07:29.521625 | 2025-09-23 16:07:29.635764 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/osism/openinfra-zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-23 16:07:29.638323 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-23 16:07:30.347059 | 2025-09-23 16:07:30.347235 | PLAY [Base post] 2025-09-23 16:07:30.360559 | 2025-09-23 16:07:30.360696 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-23 16:07:30.922763 | debian-bookworm | changed 2025-09-23 16:07:30.931435 | 2025-09-23 16:07:30.931557 | PLAY RECAP 2025-09-23 16:07:30.931631 | debian-bookworm | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-23 16:07:30.931705 | 2025-09-23 16:07:31.045849 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-09-23 16:07:31.047027 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-09-23 16:07:31.843875 | 2025-09-23 16:07:31.844086 | PLAY [Base post-logs] 2025-09-23 16:07:31.854628 | 2025-09-23 16:07:31.854760 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-23 16:07:32.286149 | localhost | changed 2025-09-23 16:07:32.296225 | 2025-09-23 16:07:32.296374 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-23 16:07:32.331849 | localhost | ok 2025-09-23 16:07:32.334819 | 2025-09-23 16:07:32.334961 | TASK [Set zuul-log-path fact] 2025-09-23 16:07:32.349674 | localhost | ok 2025-09-23 16:07:32.357436 | 2025-09-23 16:07:32.357545 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-23 16:07:32.382048 | localhost | ok 2025-09-23 16:07:32.384989 | 2025-09-23 16:07:32.385092 | TASK [upload-logs : Create log directories] 2025-09-23 16:07:32.858395 | localhost | changed 2025-09-23 16:07:32.861590 | 2025-09-23 16:07:32.861699 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-23 16:07:33.362779 | localhost -> localhost | ok: Runtime: 0:00:00.006860 2025-09-23 16:07:33.369586 | 2025-09-23 16:07:33.369759 | TASK [upload-logs : Upload logs to log server] 2025-09-23 16:07:33.924548 | localhost | Output suppressed because no_log was given 2025-09-23 16:07:33.926704 | 2025-09-23 16:07:33.926882 | LOOP [upload-logs : Compress console log and json output] 2025-09-23 16:07:33.990303 | localhost | skipping: Conditional result was False 2025-09-23 16:07:33.995801 | localhost | skipping: Conditional result was False 2025-09-23 16:07:34.006885 | 2025-09-23 16:07:34.007037 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-23 16:07:34.055299 | localhost | skipping: Conditional result was False 2025-09-23 16:07:34.055630 | 2025-09-23 16:07:34.061253 | localhost | skipping: Conditional result was False 2025-09-23 16:07:34.071734 | 2025-09-23 16:07:34.071985 | LOOP [upload-logs : Upload console log and json output]