2025-11-13 00:06:46.311390 | Job console starting... 2025-11-13 00:06:46.319372 | Updating repositories 2025-11-13 00:06:47.284792 | Preparing job workspace 2025-11-13 00:06:51.551985 | Running Ansible setup... 2025-11-13 00:06:56.715015 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-13 00:06:57.340525 | 2025-11-13 00:06:57.340668 | PLAY [localhost] 2025-11-13 00:06:57.349239 | 2025-11-13 00:06:57.349318 | TASK [Gathering Facts] 2025-11-13 00:06:58.377045 | localhost | ok 2025-11-13 00:06:58.416699 | 2025-11-13 00:06:58.416950 | TASK [Setup log path fact] 2025-11-13 00:06:58.437371 | localhost | ok 2025-11-13 00:06:58.454661 | 2025-11-13 00:06:58.454780 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-13 00:06:58.475081 | localhost | ok 2025-11-13 00:06:58.485786 | 2025-11-13 00:06:58.485874 | TASK [emit-job-header : Print job information] 2025-11-13 00:06:58.515674 | # Job Information 2025-11-13 00:06:58.515948 | Ansible Version: 2.15.12 2025-11-13 00:06:58.516080 | Job: ansible-test-sanity-docker-devel 2025-11-13 00:06:58.516112 | Pipeline: periodic 2025-11-13 00:06:58.516137 | Executor: ze03.softwarefactory-project.io 2025-11-13 00:06:58.516161 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-11-13 00:06:58.516190 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/e75/ansible/e75f38ed06bc4d84986bff1706434d71/ 2025-11-13 00:06:58.516216 | Event ID: 81b75bab06fd44ecba554c97b6c93ff4 2025-11-13 00:06:58.521581 | 2025-11-13 00:06:58.521664 | LOOP [emit-job-header : Print node information] 2025-11-13 00:06:58.618623 | localhost | ok: 2025-11-13 00:06:58.618869 | localhost | # Node Information 2025-11-13 00:06:58.618900 | localhost | Inventory Hostname: controller 2025-11-13 00:06:58.618922 | localhost | Hostname: np0005520518 2025-11-13 00:06:58.618942 | localhost | Username: zuul 2025-11-13 00:06:58.618967 | localhost | Distro: Fedora 37 2025-11-13 00:06:58.618987 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-11-13 00:06:58.619004 | localhost | Region: ca-ymq-1 2025-11-13 00:06:58.619021 | localhost | Label: ansible-fedora-37-1vcpu 2025-11-13 00:06:58.619038 | localhost | Product Name: OpenStack Nova 2025-11-13 00:06:58.619056 | localhost | Interface IP: 162.253.55.186 2025-11-13 00:06:58.639755 | 2025-11-13 00:06:58.639918 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-13 00:06:59.053962 | localhost -> localhost | changed 2025-11-13 00:06:59.067003 | 2025-11-13 00:06:59.067146 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-13 00:06:59.914429 | localhost -> localhost | changed 2025-11-13 00:06:59.934854 | 2025-11-13 00:06:59.934954 | PLAY [all:!appliance*] 2025-11-13 00:06:59.955959 | 2025-11-13 00:06:59.956110 | TASK [include_role : start-zuul-console] 2025-11-13 00:06:59.976019 | controller | ok 2025-11-13 00:06:59.990890 | 2025-11-13 00:06:59.991009 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-13 00:07:00.400335 | controller | ok 2025-11-13 00:07:00.412416 | 2025-11-13 00:07:00.412517 | TASK [use-our-mirror : Retrieve the IP address] 2025-11-13 00:07:01.892046 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-11-13 00:07:01.905935 | 2025-11-13 00:07:01.906109 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-11-13 00:07:02.461601 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.468119 | 2025-11-13 00:07:02.468193 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-11-13 00:07:02.493361 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.500121 | 2025-11-13 00:07:02.500195 | TASK [use-our-mirror : Create the podman configuration directory] 2025-11-13 00:07:02.525689 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.532020 | 2025-11-13 00:07:02.532085 | TASK [use-our-mirror : Copy the podman configuration] 2025-11-13 00:07:02.556306 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.562936 | 2025-11-13 00:07:02.563004 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-11-13 00:07:02.587222 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.595673 | 2025-11-13 00:07:02.595769 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-11-13 00:07:02.620018 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.636009 | 2025-11-13 00:07:02.636100 | TASK [Disable Fedora Modular] 2025-11-13 00:07:02.897310 | controller | changed 2025-11-13 00:07:02.914789 | 2025-11-13 00:07:02.914937 | TASK [Enable EPEL] 2025-11-13 00:07:02.942773 | controller | skipping: Conditional result was False 2025-11-13 00:07:02.952135 | 2025-11-13 00:07:02.952257 | TASK [Register the RHEL node] 2025-11-13 00:07:03.507299 | 2025-11-13 00:07:03.507533 | TASK [Show the subscription-manager status] 2025-11-13 00:07:04.093147 | controller | skipping: Conditional result was False 2025-11-13 00:07:04.109085 | 2025-11-13 00:07:04.109242 | TASK [Enable EPEL on RHEL] 2025-11-13 00:07:04.666921 | controller | skipping: Conditional result was False 2025-11-13 00:07:04.682001 | 2025-11-13 00:07:04.682104 | TASK [Install git and tox] 2025-11-13 00:08:29.949798 | controller | changed 2025-11-13 00:08:29.960195 | 2025-11-13 00:08:29.960366 | TASK [include_role : prepare-workspace] 2025-11-13 00:08:29.995886 | controller | ok 2025-11-13 00:08:30.030345 | 2025-11-13 00:08:30.030520 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-13 00:08:30.280938 | controller | ok 2025-11-13 00:08:30.291020 | 2025-11-13 00:08:30.291197 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-13 00:08:42.861463 | controller | Output suppressed because no_log was given 2025-11-13 00:08:42.882850 | 2025-11-13 00:08:42.883022 | TASK [include_role : prepare-workspace-openshift] 2025-11-13 00:08:42.901698 | controller | skipping: Conditional result was False 2025-11-13 00:08:42.966068 | 2025-11-13 00:08:42.966172 | PLAY [all:!appliance] 2025-11-13 00:08:42.985910 | 2025-11-13 00:08:42.986059 | TASK [Run add-build-sshkey role (RSA)] 2025-11-13 00:08:43.018418 | controller | ok 2025-11-13 00:08:43.037762 | 2025-11-13 00:08:43.037910 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-13 00:08:43.299640 | controller -> localhost | ok 2025-11-13 00:08:43.316072 | 2025-11-13 00:08:43.316388 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-13 00:08:43.358390 | controller | ok 2025-11-13 00:08:43.389121 | controller | included: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-13 00:08:43.397252 | 2025-11-13 00:08:43.397360 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-13 00:08:43.953660 | controller -> localhost | Generating public/private rsa key pair. 2025-11-13 00:08:43.953918 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/e75f38ed06bc4d84986bff1706434d71_id_rsa. 2025-11-13 00:08:43.953948 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/e75f38ed06bc4d84986bff1706434d71_id_rsa.pub. 2025-11-13 00:08:43.953968 | controller -> localhost | The key fingerprint is: 2025-11-13 00:08:43.953987 | controller -> localhost | SHA256:Io5lezKcAI6ll6fSumv5LvJrA1nq2MjQSXSn1qYcUms zuul-build-sshkey 2025-11-13 00:08:43.954006 | controller -> localhost | The key's randomart image is: 2025-11-13 00:08:43.954024 | controller -> localhost | +---[RSA 2048]----+ 2025-11-13 00:08:43.954041 | controller -> localhost | | | 2025-11-13 00:08:43.954059 | controller -> localhost | | . o . | 2025-11-13 00:08:43.954077 | controller -> localhost | |...o = | 2025-11-13 00:08:43.954095 | controller -> localhost | |o++.E o | 2025-11-13 00:08:43.954112 | controller -> localhost | |oB+*=+. S | 2025-11-13 00:08:43.954139 | controller -> localhost | |=ooXo+ . | 2025-11-13 00:08:43.954161 | controller -> localhost | |*+= B . | 2025-11-13 00:08:43.954181 | controller -> localhost | |+O+ + | 2025-11-13 00:08:43.954200 | controller -> localhost | |*=*= | 2025-11-13 00:08:43.954221 | controller -> localhost | +----[SHA256]-----+ 2025-11-13 00:08:43.954276 | controller -> localhost | ok: Runtime: 0:00:00.129702 2025-11-13 00:08:43.963444 | 2025-11-13 00:08:43.963571 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-13 00:08:44.010289 | controller | ok 2025-11-13 00:08:44.033137 | controller | included: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-13 00:08:44.056911 | 2025-11-13 00:08:44.057066 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-13 00:08:44.075500 | controller | skipping: Conditional result was False 2025-11-13 00:08:44.088900 | 2025-11-13 00:08:44.089048 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-13 00:08:44.587252 | controller | changed 2025-11-13 00:08:44.598524 | 2025-11-13 00:08:44.598764 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-13 00:08:44.836688 | controller | ok 2025-11-13 00:08:44.853155 | 2025-11-13 00:08:44.853301 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-13 00:08:45.508717 | controller | changed 2025-11-13 00:08:45.525020 | 2025-11-13 00:08:45.525323 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-13 00:13:50.675563 | controller | changed 2025-11-13 00:13:50.686138 | 2025-11-13 00:13:50.686449 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-13 00:13:50.713410 | controller | skipping: Conditional result was False 2025-11-13 00:13:50.721011 | 2025-11-13 00:13:50.721094 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-13 00:13:51.103768 | controller -> localhost | changed 2025-11-13 00:13:51.117763 | 2025-11-13 00:13:51.117865 | TASK [add-build-sshkey : Add back temp key] 2025-11-13 00:13:51.427515 | controller -> localhost | Identity added: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/e75f38ed06bc4d84986bff1706434d71_id_rsa (zuul-build-sshkey) 2025-11-13 00:13:51.427832 | controller -> localhost | ok: Runtime: 0:00:00.009312 2025-11-13 00:13:51.438833 | 2025-11-13 00:13:51.438979 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-13 00:13:51.801560 | controller | ok 2025-11-13 00:13:51.809910 | 2025-11-13 00:13:51.810037 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-13 00:13:51.835544 | controller | skipping: Conditional result was False 2025-11-13 00:13:51.854291 | 2025-11-13 00:13:51.854425 | TASK [Run add-build-sshkey role (ECDSA)] 2025-11-13 00:13:51.878385 | controller | ok 2025-11-13 00:13:51.944915 | 2025-11-13 00:13:51.945057 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-13 00:13:52.176668 | controller -> localhost | ok 2025-11-13 00:13:52.183770 | 2025-11-13 00:13:52.183839 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-13 00:13:52.213605 | controller | ok 2025-11-13 00:13:52.242471 | controller | included: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-13 00:13:52.255983 | 2025-11-13 00:13:52.256125 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-13 00:13:52.526027 | controller -> localhost | Generating public/private ecdsa key pair. 2025-11-13 00:13:52.526254 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/e75f38ed06bc4d84986bff1706434d71_id_ecdsa. 2025-11-13 00:13:52.526285 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/e75f38ed06bc4d84986bff1706434d71_id_ecdsa.pub. 2025-11-13 00:13:52.526315 | controller -> localhost | The key fingerprint is: 2025-11-13 00:13:52.526336 | controller -> localhost | SHA256:WXKjWchIwRjGwjuwtVG0hH+LpnS1M48uIvGoD62BqvA zuul-build-sshkey 2025-11-13 00:13:52.526357 | controller -> localhost | The key's randomart image is: 2025-11-13 00:13:52.526376 | controller -> localhost | +---[ECDSA 521]---+ 2025-11-13 00:13:52.526394 | controller -> localhost | | . =*+o. | 2025-11-13 00:13:52.526411 | controller -> localhost | |. *ooo.o . | 2025-11-13 00:13:52.526429 | controller -> localhost | | + *. . + = | 2025-11-13 00:13:52.526446 | controller -> localhost | |. + . o O . | 2025-11-13 00:13:52.526463 | controller -> localhost | | . + oS | 2025-11-13 00:13:52.526481 | controller -> localhost | |o.. + = | 2025-11-13 00:13:52.526497 | controller -> localhost | |==.+ = | 2025-11-13 00:13:52.526514 | controller -> localhost | |==+ . . . | 2025-11-13 00:13:52.526530 | controller -> localhost | |BoE. o. | 2025-11-13 00:13:52.526547 | controller -> localhost | +----[SHA256]-----+ 2025-11-13 00:13:52.526606 | controller -> localhost | ok: Runtime: 0:00:00.009235 2025-11-13 00:13:52.535076 | 2025-11-13 00:13:52.535199 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-13 00:13:52.565161 | controller | ok 2025-11-13 00:13:52.574699 | controller | included: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-13 00:13:52.585680 | 2025-11-13 00:13:52.585805 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-13 00:13:52.610026 | controller | skipping: Conditional result was False 2025-11-13 00:13:52.619584 | 2025-11-13 00:13:52.619688 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-13 00:13:52.899066 | controller | changed 2025-11-13 00:13:52.907288 | 2025-11-13 00:13:52.907385 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-13 00:13:53.131941 | controller | ok 2025-11-13 00:13:53.139478 | 2025-11-13 00:13:53.139596 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-13 00:13:53.808893 | controller | changed 2025-11-13 00:13:53.816881 | 2025-11-13 00:13:53.816983 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-13 00:13:54.444643 | controller | changed 2025-11-13 00:13:54.450775 | 2025-11-13 00:13:54.450843 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-13 00:13:54.474767 | controller | skipping: Conditional result was False 2025-11-13 00:13:54.481485 | 2025-11-13 00:13:54.481575 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-13 00:13:54.750980 | controller -> localhost | changed 2025-11-13 00:13:54.763716 | 2025-11-13 00:13:54.763836 | TASK [add-build-sshkey : Add back temp key] 2025-11-13 00:13:55.145843 | controller -> localhost | Identity added: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/e75f38ed06bc4d84986bff1706434d71_id_ecdsa (zuul-build-sshkey) 2025-11-13 00:13:55.146255 | controller -> localhost | ok: Runtime: 0:00:00.014492 2025-11-13 00:13:55.162306 | 2025-11-13 00:13:55.162447 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-13 00:13:55.377570 | controller | ok 2025-11-13 00:13:55.391041 | 2025-11-13 00:13:55.391214 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-13 00:13:55.418096 | controller | skipping: Conditional result was False 2025-11-13 00:13:55.448221 | 2025-11-13 00:13:55.448411 | TASK [include_role : remove-zuul-sshkey] 2025-11-13 00:13:55.465544 | controller | skipping: Conditional result was False 2025-11-13 00:13:55.477634 | 2025-11-13 00:13:55.477793 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-13 00:13:55.710059 | controller | ok: "logs" 2025-11-13 00:13:55.710337 | controller | ok: All items complete 2025-11-13 00:13:55.710368 | 2025-11-13 00:13:55.889307 | controller | ok: "artifacts" 2025-11-13 00:13:56.070223 | controller | ok: "docs" 2025-11-13 00:13:56.091044 | 2025-11-13 00:13:56.091268 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-13 00:13:56.342361 | controller | changed: "logs" 2025-11-13 00:13:56.528413 | controller | changed: "artifacts" 2025-11-13 00:13:56.709349 | controller | changed: "docs" 2025-11-13 00:13:56.775405 | 2025-11-13 00:13:56.775532 | PLAY RECAP 2025-11-13 00:13:56.775599 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-11-13 00:13:56.775650 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-13 00:13:56.775685 | 2025-11-13 00:13:56.895468 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-13 00:13:56.896381 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-13 00:13:57.496627 | 2025-11-13 00:13:57.496780 | PLAY [all] 2025-11-13 00:13:57.519718 | 2025-11-13 00:13:57.519858 | TASK [Install binary dependencies] 2025-11-13 00:13:57.593832 | controller | ok 2025-11-13 00:13:57.621944 | 2025-11-13 00:13:57.622099 | TASK [bindep : Include find tasks] 2025-11-13 00:13:57.667449 | controller | ok 2025-11-13 00:13:57.680566 | controller | included: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-13 00:13:57.690869 | 2025-11-13 00:13:57.691012 | TASK [bindep : Look for bindep.txt] 2025-11-13 00:13:58.287221 | controller | ok 2025-11-13 00:13:58.302301 | 2025-11-13 00:13:58.302494 | TASK [bindep : Define bindep_file fact] 2025-11-13 00:13:58.331390 | controller | skipping: Conditional result was False 2025-11-13 00:13:58.344846 | 2025-11-13 00:13:58.345002 | TASK [bindep : Look for other-requirements.txt] 2025-11-13 00:13:58.564991 | controller | ok 2025-11-13 00:13:58.571697 | 2025-11-13 00:13:58.571823 | TASK [bindep : Define bindep_file fact] 2025-11-13 00:13:58.596992 | controller | skipping: Conditional result was False 2025-11-13 00:13:58.605148 | 2025-11-13 00:13:58.605226 | TASK [bindep : Look for bindep fallback file] 2025-11-13 00:13:58.630360 | controller | skipping: Conditional result was False 2025-11-13 00:13:58.640532 | 2025-11-13 00:13:58.640651 | TASK [bindep : Define bindep_file fact] 2025-11-13 00:13:58.665681 | controller | skipping: Conditional result was False 2025-11-13 00:13:58.674252 | 2025-11-13 00:13:58.674340 | TASK [bindep : Include bindep tasks] 2025-11-13 00:13:58.699083 | controller | skipping: Conditional result was False 2025-11-13 00:13:58.705201 | 2025-11-13 00:13:58.705263 | TASK [bindep : Include install tasks] 2025-11-13 00:13:58.729122 | controller | skipping: Conditional result was False 2025-11-13 00:13:58.737664 | 2025-11-13 00:13:58.737780 | LOOP [bindep : Include package tasks] 2025-11-13 00:13:58.807010 | 2025-11-13 00:13:58.807326 | TASK [Run test-setup role] 2025-11-13 00:13:58.833389 | controller | ok 2025-11-13 00:13:58.858595 | 2025-11-13 00:13:58.858755 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-13 00:13:59.066902 | controller | ok 2025-11-13 00:13:59.076363 | 2025-11-13 00:13:59.076483 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-13 00:13:59.626225 | controller | skipping: Conditional result was False 2025-11-13 00:13:59.682144 | 2025-11-13 00:13:59.682369 | PLAY RECAP 2025-11-13 00:13:59.682439 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-13 00:13:59.682468 | 2025-11-13 00:13:59.880042 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-13 00:13:59.881957 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-13 00:14:00.594611 | 2025-11-13 00:14:00.594852 | PLAY [controller] 2025-11-13 00:14:00.621546 | 2025-11-13 00:14:00.621755 | TASK [Create the /root directory] 2025-11-13 00:14:01.158934 | controller | ok 2025-11-13 00:14:01.169220 | 2025-11-13 00:14:01.169358 | TASK [Install glibc-langpack-en] 2025-11-13 00:14:05.012582 | controller | ok: Nothing to do 2025-11-13 00:14:05.025325 | 2025-11-13 00:14:05.025520 | TASK [Ensure controller directory exists] 2025-11-13 00:14:05.250245 | controller | changed 2025-11-13 00:14:05.265875 | 2025-11-13 00:14:05.266196 | TASK [Install container runtime] 2025-11-13 00:14:05.327769 | controller | ok 2025-11-13 00:14:05.385106 | 2025-11-13 00:14:05.385245 | LOOP [ensure-podman : Find distribution installation] 2025-11-13 00:14:05.415958 | controller | ok: "/var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-11-13 00:14:05.440596 | controller | included: /var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-11-13 00:14:05.458837 | 2025-11-13 00:14:05.459063 | TASK [ensure-podman : Install podman (RedHat)] 2025-11-13 00:15:11.160325 | controller | changed 2025-11-13 00:15:11.167124 | 2025-11-13 00:15:11.167220 | TASK [ensure-podman : Fetch podman version] 2025-11-13 00:15:11.730352 | controller | Client: Podman Engine 2025-11-13 00:15:11.730426 | controller | Version: 4.6.2 2025-11-13 00:15:11.730458 | controller | API Version: 4.6.2 2025-11-13 00:15:11.730489 | controller | Go Version: go1.19.12 2025-11-13 00:15:11.730530 | controller | Built: Mon Aug 28 19:38:31 2023 2025-11-13 00:15:11.730562 | controller | OS/Arch: linux/amd64 2025-11-13 00:15:12.217555 | controller | ok: Runtime: 0:00:00.187352 2025-11-13 00:15:12.224244 | 2025-11-13 00:15:12.224315 | TASK [ensure-podman : Print podman version installed] 2025-11-13 00:15:12.254302 | Podman version: Client: Podman Engine 2025-11-13 00:15:12.254462 | Version: 4.6.2 2025-11-13 00:15:12.254490 | API Version: 4.6.2 2025-11-13 00:15:12.254510 | Go Version: go1.19.12 2025-11-13 00:15:12.254529 | Built: Mon Aug 28 19:38:31 2023 2025-11-13 00:15:12.254548 | OS/Arch: linux/amd64 2025-11-13 00:15:12.260333 | 2025-11-13 00:15:12.260400 | TASK [ensure-podman : Validate podman engine] 2025-11-13 00:15:12.792122 | controller | skipping: Conditional result was False 2025-11-13 00:15:12.801655 | 2025-11-13 00:15:12.801790 | TASK [ensure-podman : Set up docker compatability socket] 2025-11-13 00:15:12.827779 | controller | skipping: Conditional result was False 2025-11-13 00:15:12.844517 | 2025-11-13 00:15:12.844627 | TASK [Ensure python3.8 is present] 2025-11-13 00:15:12.870065 | controller | skipping: Conditional result was False 2025-11-13 00:15:12.877161 | 2025-11-13 00:15:12.877244 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-11-13 00:15:12.898220 | controller | ok 2025-11-13 00:15:12.919601 | 2025-11-13 00:15:12.919715 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-11-13 00:15:14.346360 | controller | ok: Nothing to do 2025-11-13 00:15:14.362553 | 2025-11-13 00:15:14.362800 | TASK [our-ensure-python : Also install python3-devel] 2025-11-13 00:15:23.957962 | controller | changed 2025-11-13 00:15:23.975650 | 2025-11-13 00:15:23.975816 | TASK [Run ensure-virtualenv role] 2025-11-13 00:15:24.000355 | controller | ok 2025-11-13 00:15:24.036893 | 2025-11-13 00:15:24.037018 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-11-13 00:15:24.278582 | controller | /usr/bin/virtualenv 2025-11-13 00:15:24.605179 | controller | ok: Runtime: 0:00:00.004464 2025-11-13 00:15:24.612455 | 2025-11-13 00:15:24.612551 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-11-13 00:15:24.634969 | controller | skipping: Conditional result was False 2025-11-13 00:15:24.635259 | controller | ok: All items complete 2025-11-13 00:15:24.635303 | 2025-11-13 00:15:24.654064 | 2025-11-13 00:15:24.654206 | TASK [Find the full path of the Python interpreter] 2025-11-13 00:15:24.859410 | controller | /usr/bin/python3 2025-11-13 00:15:25.195378 | controller | ok 2025-11-13 00:15:25.209481 | 2025-11-13 00:15:25.209655 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-11-13 00:15:26.020591 | controller | created virtual environment CPython3.11.0.final.0-64 in 423ms 2025-11-13 00:15:26.035841 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-11-13 00:15:26.035878 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2025-11-13 00:15:26.035887 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-11-13 00:15:26.035900 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-11-13 00:15:26.268296 | controller | changed 2025-11-13 00:15:26.281585 | 2025-11-13 00:15:26.281803 | TASK [Set selinux package] 2025-11-13 00:15:26.323186 | controller | ok 2025-11-13 00:15:26.334930 | 2025-11-13 00:15:26.335065 | TASK [Set selinux package (Fedora)] 2025-11-13 00:15:26.379871 | controller | ok 2025-11-13 00:15:26.389561 | 2025-11-13 00:15:26.389810 | TASK [Install selinux into virtualenv] 2025-11-13 00:15:51.846774 | controller | Collecting selinux-please-lie-to-me 2025-11-13 00:16:04.112179 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-11-13 00:16:04.414252 | controller | Collecting setuptools<50.0.0 2025-11-13 00:16:04.419349 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-11-13 00:16:04.461063 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 20.7 MB/s eta 0:00:00 2025-11-13 00:16:04.542438 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-11-13 00:16:04.542650 | controller | Attempting uninstall: setuptools 2025-11-13 00:16:04.545125 | controller | Found existing installation: setuptools 62.6.0 2025-11-13 00:16:04.603581 | controller | Uninstalling setuptools-62.6.0: 2025-11-13 00:16:04.611400 | controller | Successfully uninstalled setuptools-62.6.0 2025-11-13 00:16:04.964985 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-11-13 00:16:18.406872 | controller | 2025-11-13 00:16:18.488945 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-13 00:16:18.488999 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-13 00:16:18.975872 | controller | ok: Runtime: 0:00:51.880083 2025-11-13 00:16:18.982113 | 2025-11-13 00:16:18.982202 | TASK [Install pytest-forked into virtualenv] 2025-11-13 00:16:34.930050 | controller | Collecting pytest-forked 2025-11-13 00:16:47.179057 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-11-13 00:16:47.233632 | controller | Collecting py 2025-11-13 00:16:47.237304 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-11-13 00:16:47.258291 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00 2025-11-13 00:16:47.370273 | controller | Collecting pytest>=3.10 2025-11-13 00:16:47.374002 | controller | Downloading pytest-9.0.1-py3-none-any.whl (373 kB) 2025-11-13 00:16:47.399429 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 16.4 MB/s eta 0:00:00 2025-11-13 00:16:47.439171 | controller | Collecting iniconfig>=1.0.1 2025-11-13 00:16:47.443124 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-11-13 00:16:47.511443 | controller | Collecting packaging>=22 2025-11-13 00:16:47.514916 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-11-13 00:16:47.522989 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.7 MB/s eta 0:00:00 2025-11-13 00:16:47.559593 | controller | Collecting pluggy<2,>=1.5 2025-11-13 00:16:47.562888 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-11-13 00:16:47.611871 | controller | Collecting pygments>=2.7.2 2025-11-13 00:16:47.616029 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-11-13 00:16:47.649245 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 40.8 MB/s eta 0:00:00 2025-11-13 00:16:47.719166 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-11-13 00:16:48.798923 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.1 pytest-forked-1.6.0 2025-11-13 00:16:48.807522 | controller | 2025-11-13 00:16:48.875419 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-13 00:16:48.875548 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-13 00:16:49.033962 | controller | ok: Runtime: 0:00:29.678908 2025-11-13 00:16:49.040894 | 2025-11-13 00:16:49.041063 | TASK [Update pip] 2025-11-13 00:16:49.557462 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-11-13 00:16:59.574606 | controller | Collecting pip 2025-11-13 00:17:11.748282 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-11-13 00:17:11.810910 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 30.9 MB/s eta 0:00:00 2025-11-13 00:17:11.876703 | controller | Installing collected packages: pip 2025-11-13 00:17:11.876825 | controller | Attempting uninstall: pip 2025-11-13 00:17:11.879010 | controller | Found existing installation: pip 22.2.2 2025-11-13 00:17:12.018017 | controller | Uninstalling pip-22.2.2: 2025-11-13 00:17:12.032904 | controller | Successfully uninstalled pip-22.2.2 2025-11-13 00:17:12.818689 | controller | Successfully installed pip-25.3 2025-11-13 00:17:13.094728 | controller | ok: Runtime: 0:00:23.634911 2025-11-13 00:17:13.113130 | 2025-11-13 00:17:13.113371 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-11-13 00:17:13.345793 | controller | changed 2025-11-13 00:17:13.355703 | 2025-11-13 00:17:13.355909 | TASK [Install ansible into virtualenv] 2025-11-13 00:17:13.943791 | controller | Processing ./src/github.com/ansible/ansible 2025-11-13 00:17:13.947050 | controller | Installing build dependencies: started 2025-11-13 00:17:34.918046 | controller | Installing build dependencies: finished with status 'done' 2025-11-13 00:17:34.918658 | controller | Getting requirements to build wheel: started 2025-11-13 00:17:35.654894 | controller | Getting requirements to build wheel: finished with status 'done' 2025-11-13 00:17:35.655797 | controller | Preparing metadata (pyproject.toml): started 2025-11-13 00:17:36.117078 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-11-13 00:17:36.122391 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2025-11-13 00:17:36.126671 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-11-13 00:17:36.475909 | controller | ERROR 2025-11-13 00:17:36.476078 | controller | { 2025-11-13 00:17:36.476121 | controller | "delta": "0:00:22.525594", 2025-11-13 00:17:36.476152 | controller | "end": "2025-11-13 00:17:36.187207", 2025-11-13 00:17:36.476178 | controller | "msg": "non-zero return code", 2025-11-13 00:17:36.476216 | controller | "rc": 1, 2025-11-13 00:17:36.476243 | controller | "start": "2025-11-13 00:17:13.661613" 2025-11-13 00:17:36.476269 | controller | } failure 2025-11-13 00:17:36.477994 | 2025-11-13 00:17:36.478059 | PLAY RECAP 2025-11-13 00:17:36.478118 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-11-13 00:17:36.478151 | 2025-11-13 00:17:36.605585 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-13 00:17:36.606651 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-13 00:17:37.314502 | 2025-11-13 00:17:37.314625 | PLAY [all] 2025-11-13 00:17:37.340348 | 2025-11-13 00:17:37.340520 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-13 00:17:37.746621 | controller | changed: non-zero return code 2025-11-13 00:17:37.756515 | 2025-11-13 00:17:37.756698 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-13 00:17:37.782439 | controller | skipping: Conditional result was False 2025-11-13 00:17:37.791936 | 2025-11-13 00:17:37.792101 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-13 00:17:37.828110 | 2025-11-13 00:17:37.828300 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-13 00:17:37.862045 | 2025-11-13 00:17:37.862244 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-13 00:17:37.877769 | controller | skipping: Conditional result was False 2025-11-13 00:17:37.890282 | 2025-11-13 00:17:37.890416 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-13 00:17:37.924315 | 2025-11-13 00:17:37.924521 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-13 00:17:37.938951 | controller | skipping: Conditional result was False 2025-11-13 00:17:37.945868 | 2025-11-13 00:17:37.945948 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-13 00:17:37.970478 | controller | skipping: Conditional result was False 2025-11-13 00:17:37.977373 | 2025-11-13 00:17:37.977461 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-13 00:17:37.991405 | controller | skipping: Conditional result was False 2025-11-13 00:17:38.019326 | 2025-11-13 00:17:38.019443 | PLAY RECAP 2025-11-13 00:17:38.019497 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-13 00:17:38.019525 | 2025-11-13 00:17:38.131831 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-13 00:17:38.132705 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-11-13 00:17:38.776616 | 2025-11-13 00:17:38.776769 | PLAY [all:!appliance*] 2025-11-13 00:17:38.801621 | 2025-11-13 00:17:38.801749 | TASK [unregister the node] 2025-11-13 00:17:39.333256 | controller | skipping: Conditional result was False 2025-11-13 00:17:39.347132 | 2025-11-13 00:17:39.347316 | TASK [include_role : fetch-output] 2025-11-13 00:17:39.387295 | controller | ok 2025-11-13 00:17:39.449544 | 2025-11-13 00:17:39.449667 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-13 00:17:39.541001 | controller | skipping: Conditional result was False 2025-11-13 00:17:39.551351 | 2025-11-13 00:17:39.551505 | TASK [fetch-output : Set log path for single node] 2025-11-13 00:17:39.597244 | controller | ok 2025-11-13 00:17:39.605828 | 2025-11-13 00:17:39.605935 | LOOP [fetch-output : Ensure local output dirs] 2025-11-13 00:17:40.050386 | controller -> localhost | ok: "/var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/logs" 2025-11-13 00:17:40.339397 | controller -> localhost | changed: "/var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/artifacts" 2025-11-13 00:17:40.618861 | controller -> localhost | changed: "/var/lib/zuul/builds/e75f38ed06bc4d84986bff1706434d71/work/docs" 2025-11-13 00:17:40.658605 | 2025-11-13 00:17:40.658828 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-13 00:17:41.357688 | controller | changed: 2025-11-13 00:17:41.358059 | controller | .d..t...... ./ 2025-11-13 00:17:41.358122 | controller | cd+++++++++ controller/ 2025-11-13 00:17:41.358190 | controller | changed: All items complete 2025-11-13 00:17:41.358235 | 2025-11-13 00:17:41.818263 | controller | changed: .d..t...... ./ 2025-11-13 00:17:42.333880 | controller | changed: .d..t...... ./ 2025-11-13 00:17:42.364918 | 2025-11-13 00:17:42.365060 | TASK [include_role : fetch-output-openshift] 2025-11-13 00:17:42.393796 | controller | skipping: Conditional result was False 2025-11-13 00:17:42.403396 | 2025-11-13 00:17:42.403583 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-13 00:17:42.456259 | controller | skipping: Conditional result was False 2025-11-13 00:17:42.469623 | controller | skipping: Conditional result was False 2025-11-13 00:17:42.521121 | 2025-11-13 00:17:42.521247 | PLAY [localhost] 2025-11-13 00:17:42.538088 | 2025-11-13 00:17:42.538215 | TASK [Run Zuul manifest role] 2025-11-13 00:17:42.557944 | localhost | ok 2025-11-13 00:17:42.575894 | 2025-11-13 00:17:42.576014 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-13 00:17:42.982415 | localhost | changed 2025-11-13 00:17:42.988100 | 2025-11-13 00:17:42.988203 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-13 00:17:43.016709 | localhost | ok 2025-11-13 00:17:43.024691 | 2025-11-13 00:17:43.024796 | TASK [Set zuul-log-path fact] 2025-11-13 00:17:43.043170 | localhost | ok 2025-11-13 00:17:43.058093 | 2025-11-13 00:17:43.058202 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-13 00:17:43.086688 | localhost | ok 2025-11-13 00:17:43.095105 | 2025-11-13 00:17:43.095180 | LOOP [Run upload-logs-swift role] 2025-11-13 00:17:43.130082 | localhost | Output suppressed because no_log was given 2025-11-13 00:17:43.162312 | 2025-11-13 00:17:43.162427 | TASK [Set zuul-log-path fact] 2025-11-13 00:17:43.186865 | localhost | skipping: Conditional result was False 2025-11-13 00:17:43.201607 | 2025-11-13 00:17:43.201775 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-11-13 00:17:43.680773 | localhost -> localhost | ok: Runtime: 0:00:00.005820 2025-11-13 00:17:43.714075 | 2025-11-13 00:17:43.714190 | TASK [upload-logs-swift : Upload logs to swift]