2025-11-06 00:21:27.746466 | Job console starting...
2025-11-06 00:21:27.766174 | Updating repositories
2025-11-06 00:21:27.936831 | Preparing job workspace
2025-11-06 00:21:31.451817 | Running Ansible setup...
2025-11-06 00:21:39.116461 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-06 00:21:39.753619 | 
2025-11-06 00:21:39.753797 | PLAY [localhost]
2025-11-06 00:21:39.764724 | 
2025-11-06 00:21:39.764859 | TASK [Gathering Facts]
2025-11-06 00:21:40.770618 | localhost | ok
2025-11-06 00:21:40.796749 | 
2025-11-06 00:21:40.796936 | TASK [Setup log path fact]
2025-11-06 00:21:40.821183 | localhost | ok
2025-11-06 00:21:40.840435 | 
2025-11-06 00:21:40.840574 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-06 00:21:40.872344 | localhost | ok
2025-11-06 00:21:40.885985 | 
2025-11-06 00:21:40.886165 | TASK [emit-job-header : Print job information]
2025-11-06 00:21:40.937906 | # Job Information
2025-11-06 00:21:40.938138 | Ansible Version: 2.15.12
2025-11-06 00:21:40.938199 | Job: ansible-test-sanity-docker-stable-2.10
2025-11-06 00:21:40.938242 | Pipeline: periodic
2025-11-06 00:21:40.938282 | Executor: ze01.softwarefactory-project.io
2025-11-06 00:21:40.938312 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-06 00:21:40.938346 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0fa/ansible/0fa85b9d7445435990f6f44f7e423d06/
2025-11-06 00:21:40.938377 | Event ID: 06b8e19d0def49e3b59e004861f83875
2025-11-06 00:21:40.944479 | 
2025-11-06 00:21:40.944583 | LOOP [emit-job-header : Print node information]
2025-11-06 00:21:41.056730 | localhost | ok:
2025-11-06 00:21:41.056893 | localhost | # Node Information
2025-11-06 00:21:41.056925 | localhost | Inventory Hostname: controller
2025-11-06 00:21:41.056950 | localhost | Hostname: np0005512847
2025-11-06 00:21:41.056975 | localhost | Username: zuul
2025-11-06 00:21:41.057002 | localhost | Distro: Fedora 37
2025-11-06 00:21:41.057046 | localhost | Provider: ansible-vexxhost-ams1
2025-11-06 00:21:41.057077 | localhost | Region: ams1
2025-11-06 00:21:41.057100 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-06 00:21:41.057123 | localhost | Product Name: OpenStack Nova
2025-11-06 00:21:41.057147 | localhost | Interface IP: 38.129.16.88
2025-11-06 00:21:41.075678 | 
2025-11-06 00:21:41.075840 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-06 00:21:41.477668 | localhost -> localhost | changed
2025-11-06 00:21:41.483796 | 
2025-11-06 00:21:41.483890 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-06 00:21:42.384651 | localhost -> localhost | changed
2025-11-06 00:21:42.409933 | 
2025-11-06 00:21:42.410046 | PLAY [all:!appliance*]
2025-11-06 00:21:42.433458 | 
2025-11-06 00:21:42.433634 | TASK [include_role : start-zuul-console]
2025-11-06 00:21:42.456106 | controller | ok
2025-11-06 00:21:42.475553 | 
2025-11-06 00:21:42.475681 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-06 00:21:43.441481 | controller | ok
2025-11-06 00:21:43.468958 | 
2025-11-06 00:21:43.469163 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-06 00:21:45.630778 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-06 00:21:45.641839 | 
2025-11-06 00:21:45.641977 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-06 00:21:46.009379 | controller | skipping: Conditional result was False
2025-11-06 00:21:46.019658 | 
2025-11-06 00:21:46.019782 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-06 00:21:46.034452 | controller | skipping: Conditional result was False
2025-11-06 00:21:46.045645 | 
2025-11-06 00:21:46.045785 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-06 00:21:46.071171 | controller | skipping: Conditional result was False
2025-11-06 00:21:46.081797 | 
2025-11-06 00:21:46.081939 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-06 00:21:46.107244 | controller | skipping: Conditional result was False
2025-11-06 00:21:46.116991 | 
2025-11-06 00:21:46.117142 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-06 00:21:46.143702 | controller | skipping: Conditional result was False
2025-11-06 00:21:46.153713 | 
2025-11-06 00:21:46.153847 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-06 00:21:46.179653 | controller | skipping: Conditional result was False
2025-11-06 00:21:46.192449 | 
2025-11-06 00:21:46.192561 | TASK [Disable Fedora Modular]
2025-11-06 00:21:47.040818 | controller | changed
2025-11-06 00:21:47.047275 | 
2025-11-06 00:21:47.047370 | TASK [Enable EPEL]
2025-11-06 00:21:47.081736 | controller | skipping: Conditional result was False
2025-11-06 00:21:47.088567 | 
2025-11-06 00:21:47.088667 | TASK [Register the RHEL node]
2025-11-06 00:21:47.485788 | 
2025-11-06 00:21:47.485930 | TASK [Show the subscription-manager status]
2025-11-06 00:21:47.846163 | controller | skipping: Conditional result was False
2025-11-06 00:21:47.857497 | 
2025-11-06 00:21:47.857666 | TASK [Enable EPEL on RHEL]
2025-11-06 00:21:48.228599 | controller | skipping: Conditional result was False
2025-11-06 00:21:48.241202 | 
2025-11-06 00:21:48.241357 | TASK [Install git and tox]
2025-11-06 00:23:58.887591 | controller | changed
2025-11-06 00:23:58.907689 | 
2025-11-06 00:23:58.907854 | TASK [include_role : prepare-workspace]
2025-11-06 00:23:58.941805 | controller | ok
2025-11-06 00:23:58.972879 | 
2025-11-06 00:23:58.973044 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-06 00:23:59.831109 | controller | ok
2025-11-06 00:23:59.846454 | 
2025-11-06 00:23:59.846631 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-06 00:24:15.058822 | controller | Output suppressed because no_log was given
2025-11-06 00:24:15.069389 | 
2025-11-06 00:24:15.069468 | TASK [include_role : prepare-workspace-openshift]
2025-11-06 00:24:15.085563 | controller | skipping: Conditional result was False
2025-11-06 00:24:15.136130 | 
2025-11-06 00:24:15.136233 | PLAY [all:!appliance]
2025-11-06 00:24:15.151526 | 
2025-11-06 00:24:15.151609 | TASK [Run add-build-sshkey role (RSA)]
2025-11-06 00:24:15.174285 | controller | ok
2025-11-06 00:24:15.189583 | 
2025-11-06 00:24:15.189718 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-06 00:24:15.438369 | controller -> localhost | ok
2025-11-06 00:24:15.445485 | 
2025-11-06 00:24:15.445562 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-06 00:24:15.465797 | controller | ok
2025-11-06 00:24:15.480646 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-06 00:24:15.486784 | 
2025-11-06 00:24:15.486850 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-06 00:24:15.887373 | controller -> localhost | Generating public/private rsa key pair.
2025-11-06 00:24:15.887628 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/0fa85b9d7445435990f6f44f7e423d06_id_rsa.
2025-11-06 00:24:15.887672 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/0fa85b9d7445435990f6f44f7e423d06_id_rsa.pub.
2025-11-06 00:24:15.887706 | controller -> localhost | The key fingerprint is:
2025-11-06 00:24:15.887740 | controller -> localhost | SHA256:PIadshP3AdvkfXAVul4aOe9Qcq7A425fVbqhKZTYZrk zuul-build-sshkey
2025-11-06 00:24:15.887773 | controller -> localhost | The key's randomart image is:
2025-11-06 00:24:15.887804 | controller -> localhost | +---[RSA 2048]----+
2025-11-06 00:24:15.887831 | controller -> localhost | |               .o|
2025-11-06 00:24:15.887859 | controller -> localhost | |              .. |
2025-11-06 00:24:15.887884 | controller -> localhost | |        . . ... .|
2025-11-06 00:24:15.887908 | controller -> localhost | |       + X + oo..|
2025-11-06 00:24:15.887935 | controller -> localhost | |      + S @ .*++.|
2025-11-06 00:24:15.887971 | controller -> localhost | |       * *.o.+@o.|
2025-11-06 00:24:15.888067 | controller -> localhost | |      o   E+o+.+ |
2025-11-06 00:24:15.888110 | controller -> localhost | |       .  .oo =  |
2025-11-06 00:24:15.888141 | controller -> localhost | |          oo.o . |
2025-11-06 00:24:15.888169 | controller -> localhost | +----[SHA256]-----+
2025-11-06 00:24:15.888233 | controller -> localhost | ok: Runtime: 0:00:00.054100
2025-11-06 00:24:15.896631 | 
2025-11-06 00:24:15.896727 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-06 00:24:15.916493 | controller | ok
2025-11-06 00:24:15.926500 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-06 00:24:15.937954 | 
2025-11-06 00:24:15.938082 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-06 00:24:15.962047 | controller | skipping: Conditional result was False
2025-11-06 00:24:15.968228 | 
2025-11-06 00:24:15.968294 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-06 00:24:16.997318 | controller | changed
2025-11-06 00:24:17.011680 | 
2025-11-06 00:24:17.011876 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-06 00:24:17.648361 | controller | ok
2025-11-06 00:24:17.662202 | 
2025-11-06 00:24:17.662388 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-06 00:24:20.607985 | controller | changed
2025-11-06 00:24:20.614446 | 
2025-11-06 00:24:20.614533 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-06 00:24:23.577542 | controller | changed
2025-11-06 00:24:23.590274 | 
2025-11-06 00:24:23.590439 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-06 00:24:23.607212 | controller | skipping: Conditional result was False
2025-11-06 00:24:23.618912 | 
2025-11-06 00:24:23.619118 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-06 00:24:24.053684 | controller -> localhost | changed
2025-11-06 00:24:24.081798 | 
2025-11-06 00:24:24.081971 | TASK [add-build-sshkey : Add back temp key]
2025-11-06 00:24:24.371694 | controller -> localhost | Identity added: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/0fa85b9d7445435990f6f44f7e423d06_id_rsa (zuul-build-sshkey)
2025-11-06 00:24:24.371954 | controller -> localhost | ok: Runtime: 0:00:00.007728
2025-11-06 00:24:24.382847 | 
2025-11-06 00:24:24.382979 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-06 00:24:25.290512 | controller | ok
2025-11-06 00:24:25.296945 | 
2025-11-06 00:24:25.297099 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-06 00:24:25.322169 | controller | skipping: Conditional result was False
2025-11-06 00:24:25.339776 | 
2025-11-06 00:24:25.339912 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-06 00:24:25.363395 | controller | ok
2025-11-06 00:24:25.385950 | 
2025-11-06 00:24:25.386139 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-06 00:24:25.637753 | controller -> localhost | ok
2025-11-06 00:24:25.648209 | 
2025-11-06 00:24:25.648357 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-06 00:24:25.675172 | controller | ok
2025-11-06 00:24:25.693296 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-06 00:24:25.703768 | 
2025-11-06 00:24:25.703899 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-06 00:24:25.964833 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-06 00:24:25.965152 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/0fa85b9d7445435990f6f44f7e423d06_id_ecdsa.
2025-11-06 00:24:25.965194 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/0fa85b9d7445435990f6f44f7e423d06_id_ecdsa.pub.
2025-11-06 00:24:25.965229 | controller -> localhost | The key fingerprint is:
2025-11-06 00:24:25.965250 | controller -> localhost | SHA256:yyJr4eTklFyXS9MsLd3OUtbAngj7ZW00DAkj0ttl648 zuul-build-sshkey
2025-11-06 00:24:25.965270 | controller -> localhost | The key's randomart image is:
2025-11-06 00:24:25.965290 | controller -> localhost | +---[ECDSA 521]---+
2025-11-06 00:24:25.965309 | controller -> localhost | |      ... oo.+   |
2025-11-06 00:24:25.965329 | controller -> localhost | |       .o. .* +  |
2025-11-06 00:24:25.965348 | controller -> localhost | |         @ * B . |
2025-11-06 00:24:25.965367 | controller -> localhost | |      . X B X +  |
2025-11-06 00:24:25.965386 | controller -> localhost | |   . o oS* O .   |
2025-11-06 00:24:25.965405 | controller -> localhost | |    B  ...o +    |
2025-11-06 00:24:25.965424 | controller -> localhost | |   B... o  . o   |
2025-11-06 00:24:25.965443 | controller -> localhost | |    =o .    E .  |
2025-11-06 00:24:25.965469 | controller -> localhost | |   ..            |
2025-11-06 00:24:25.965518 | controller -> localhost | +----[SHA256]-----+
2025-11-06 00:24:25.965600 | controller -> localhost | ok: Runtime: 0:00:00.008014
2025-11-06 00:24:25.973374 | 
2025-11-06 00:24:25.973481 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-06 00:24:26.003987 | controller | ok
2025-11-06 00:24:26.016842 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-06 00:24:26.027555 | 
2025-11-06 00:24:26.027741 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-06 00:24:26.043532 | controller | skipping: Conditional result was False
2025-11-06 00:24:26.051294 | 
2025-11-06 00:24:26.051418 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-06 00:24:26.898238 | controller | changed
2025-11-06 00:24:26.905663 | 
2025-11-06 00:24:26.905775 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-06 00:24:27.567217 | controller | ok
2025-11-06 00:24:27.573812 | 
2025-11-06 00:24:27.573933 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-06 00:24:30.516234 | controller | changed
2025-11-06 00:24:30.530191 | 
2025-11-06 00:24:30.530380 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-06 00:24:33.453217 | controller | changed
2025-11-06 00:24:33.459366 | 
2025-11-06 00:24:33.459452 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-06 00:24:33.483755 | controller | skipping: Conditional result was False
2025-11-06 00:24:33.490966 | 
2025-11-06 00:24:33.491068 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-06 00:24:33.740219 | controller -> localhost | changed
2025-11-06 00:24:33.752881 | 
2025-11-06 00:24:33.752996 | TASK [add-build-sshkey : Add back temp key]
2025-11-06 00:24:34.053892 | controller -> localhost | Identity added: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/0fa85b9d7445435990f6f44f7e423d06_id_ecdsa (zuul-build-sshkey)
2025-11-06 00:24:34.054224 | controller -> localhost | ok: Runtime: 0:00:00.022161
2025-11-06 00:24:34.061138 | 
2025-11-06 00:24:34.061220 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-06 00:24:34.735068 | controller | ok
2025-11-06 00:24:34.740716 | 
2025-11-06 00:24:34.740784 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-06 00:24:34.775353 | controller | skipping: Conditional result was False
2025-11-06 00:24:34.788097 | 
2025-11-06 00:24:34.788184 | TASK [include_role : remove-zuul-sshkey]
2025-11-06 00:24:34.812789 | controller | skipping: Conditional result was False
2025-11-06 00:24:34.819653 | 
2025-11-06 00:24:34.819745 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-06 00:24:35.441920 | controller | ok: "logs"
2025-11-06 00:24:35.442397 | controller | ok: All items complete
2025-11-06 00:24:35.442466 | 
2025-11-06 00:24:36.040489 | controller | ok: "artifacts"
2025-11-06 00:24:36.638817 | controller | ok: "docs"
2025-11-06 00:24:36.649606 | 
2025-11-06 00:24:36.649742 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-06 00:24:37.281931 | controller | changed: "logs"
2025-11-06 00:24:37.885816 | controller | changed: "artifacts"
2025-11-06 00:24:38.482201 | controller | changed: "docs"
2025-11-06 00:24:38.543471 | 
2025-11-06 00:24:38.543741 | PLAY RECAP
2025-11-06 00:24:38.543947 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-06 00:24:38.544159 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-06 00:24:38.544201 | 
2025-11-06 00:24:38.674535 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-06 00:24:38.675554 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-06 00:24:39.323375 | 
2025-11-06 00:24:39.323563 | PLAY [all]
2025-11-06 00:24:39.348180 | 
2025-11-06 00:24:39.348313 | TASK [Install binary dependencies]
2025-11-06 00:24:39.409678 | controller | ok
2025-11-06 00:24:39.430537 | 
2025-11-06 00:24:39.430674 | TASK [bindep : Include find tasks]
2025-11-06 00:24:39.460432 | controller | ok
2025-11-06 00:24:39.468810 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-06 00:24:39.475570 | 
2025-11-06 00:24:39.475645 | TASK [bindep : Look for bindep.txt]
2025-11-06 00:24:40.403051 | controller | ok
2025-11-06 00:24:40.409644 | 
2025-11-06 00:24:40.409728 | TASK [bindep : Define bindep_file fact]
2025-11-06 00:24:40.424885 | controller | skipping: Conditional result was False
2025-11-06 00:24:40.432660 | 
2025-11-06 00:24:40.432769 | TASK [bindep : Look for other-requirements.txt]
2025-11-06 00:24:41.032564 | controller | ok
2025-11-06 00:24:41.042774 | 
2025-11-06 00:24:41.042928 | TASK [bindep : Define bindep_file fact]
2025-11-06 00:24:41.069031 | controller | skipping: Conditional result was False
2025-11-06 00:24:41.079262 | 
2025-11-06 00:24:41.079395 | TASK [bindep : Look for bindep fallback file]
2025-11-06 00:24:41.107516 | controller | skipping: Conditional result was False
2025-11-06 00:24:41.117145 | 
2025-11-06 00:24:41.117291 | TASK [bindep : Define bindep_file fact]
2025-11-06 00:24:41.142204 | controller | skipping: Conditional result was False
2025-11-06 00:24:41.151923 | 
2025-11-06 00:24:41.152056 | TASK [bindep : Include bindep tasks]
2025-11-06 00:24:41.177418 | controller | skipping: Conditional result was False
2025-11-06 00:24:41.185453 | 
2025-11-06 00:24:41.185575 | TASK [bindep : Include install tasks]
2025-11-06 00:24:41.211208 | controller | skipping: Conditional result was False
2025-11-06 00:24:41.219980 | 
2025-11-06 00:24:41.220140 | LOOP [bindep : Include package tasks]
2025-11-06 00:24:41.301180 | 
2025-11-06 00:24:41.301391 | TASK [Run test-setup role]
2025-11-06 00:24:41.323167 | controller | ok
2025-11-06 00:24:41.347589 | 
2025-11-06 00:24:41.347698 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-06 00:24:42.024247 | controller | ok
2025-11-06 00:24:42.032322 | 
2025-11-06 00:24:42.032427 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-06 00:24:42.387503 | controller | skipping: Conditional result was False
2025-11-06 00:24:42.416195 | 
2025-11-06 00:24:42.416310 | PLAY RECAP
2025-11-06 00:24:42.416363 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-06 00:24:42.416392 | 
2025-11-06 00:24:42.560637 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-06 00:24:42.561575 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-06 00:24:43.187659 | 
2025-11-06 00:24:43.187795 | PLAY [controller]
2025-11-06 00:24:43.210851 | 
2025-11-06 00:24:43.210985 | TASK [Create the /root directory]
2025-11-06 00:24:44.225079 | controller | ok
2025-11-06 00:24:44.235160 | 
2025-11-06 00:24:44.235338 | TASK [Install glibc-langpack-en]
2025-11-06 00:24:51.598100 | controller | ok: Nothing to do
2025-11-06 00:24:51.610546 | 
2025-11-06 00:24:51.610690 | TASK [Ensure controller directory exists]
2025-11-06 00:24:52.396131 | controller | changed
2025-11-06 00:24:52.404270 | 
2025-11-06 00:24:52.404409 | TASK [Install container runtime]
2025-11-06 00:24:52.457403 | controller | ok
2025-11-06 00:24:52.500683 | 
2025-11-06 00:24:52.500825 | LOOP [ensure-docker : Gather variables for each operating system]
2025-11-06 00:24:52.539795 | controller | ok: "/var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml"
2025-11-06 00:24:52.554251 | 
2025-11-06 00:24:52.554385 | TASK [ensure-docker : Sanity check for distro selection]
2025-11-06 00:24:52.569079 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.575657 | 
2025-11-06 00:24:52.575726 | TASK [ensure-docker : Sanity check for distro install]
2025-11-06 00:24:52.599867 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.609253 | 
2025-11-06 00:24:52.609373 | TASK [ensure-docker : Sanity check for upstream install]
2025-11-06 00:24:52.634511 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.643428 | 
2025-11-06 00:24:52.643539 | TASK [ensure-docker : Sanity check for upstream install mirrors]
2025-11-06 00:24:52.668113 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.677761 | 
2025-11-06 00:24:52.677886 | TASK [ensure-docker : Include tasks for docker install]
2025-11-06 00:24:52.701101 | controller | ok
2025-11-06 00:24:52.714093 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml
2025-11-06 00:24:52.727231 | 
2025-11-06 00:24:52.727323 | TASK [ensure-docker : Not Implemented]
2025-11-06 00:24:52.741770 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.749276 | 
2025-11-06 00:24:52.749360 | TASK [Set up docker mirrors]
2025-11-06 00:24:52.771033 | controller | ok
2025-11-06 00:24:52.791873 | 
2025-11-06 00:24:52.791978 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info]
2025-11-06 00:24:52.826712 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.833726 | 
2025-11-06 00:24:52.833805 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info]
2025-11-06 00:24:52.868550 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.875388 | 
2025-11-06 00:24:52.875458 | TASK [use-docker-mirror : Set docker_mirror fact]
2025-11-06 00:24:52.910256 | controller | skipping: Conditional result was False
2025-11-06 00:24:52.917952 | 
2025-11-06 00:24:52.918083 | TASK [use-docker-mirror : Set up docker mirrors]
2025-11-06 00:24:52.983669 | controller | skipping: Conditional result was False
2025-11-06 00:24:53.070657 | 
2025-11-06 00:24:53.070882 | TASK [Add all repositories]
2025-11-06 00:24:53.098189 | controller | ok
2025-11-06 00:24:53.136888 | 
2025-11-06 00:24:53.137137 | LOOP [ensure-package-repositories : Install repositories]
2025-11-06 00:24:53.169377 | controller | ok: "/var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml"
2025-11-06 00:24:53.169711 | controller | ok: All items complete
2025-11-06 00:24:53.169764 | 
2025-11-06 00:24:53.184576 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml
2025-11-06 00:24:53.194139 | 
2025-11-06 00:24:53.194258 | TASK [ensure-package-repositories : Create GPG key temp directory]
2025-11-06 00:24:54.108848 | controller | changed
2025-11-06 00:24:54.120129 | 
2025-11-06 00:24:54.120345 | LOOP [ensure-package-repositories : Upload GPG keys]
2025-11-06 00:24:57.274259 | controller | changed:
2025-11-06 00:24:57.274592 | controller | {
2025-11-06 00:24:57.274654 | controller |   "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n"
2025-11-06 00:24:57.274707 | controller | }
2025-11-06 00:24:57.294575 | 
2025-11-06 00:24:57.294742 | LOOP [ensure-package-repositories : Import GPG keys]
2025-11-06 00:24:58.609695 | controller | changed:
2025-11-06 00:24:58.610397 | controller | {
2025-11-06 00:24:58.610450 | controller |   "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n"
2025-11-06 00:24:58.610486 | controller | }
2025-11-06 00:24:58.610537 | controller | changed: All items complete
2025-11-06 00:24:58.610568 | 
2025-11-06 00:24:58.627740 | 
2025-11-06 00:24:58.627887 | TASK [ensure-package-repositories : Remove GPG temp directory]
2025-11-06 00:24:59.277069 | controller | changed
2025-11-06 00:24:59.289803 | 
2025-11-06 00:24:59.289954 | LOOP [ensure-package-repositories : Add repositories]
2025-11-06 00:25:00.108110 | controller | changed:
2025-11-06 00:25:00.108369 | controller | {
2025-11-06 00:25:00.108403 | controller |   "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable",
2025-11-06 00:25:00.108423 | controller |   "description": "Docker CE Stable - $basearch",
2025-11-06 00:25:00.108441 | controller |   "gpgcheck": true,
2025-11-06 00:25:00.108458 | controller |   "name": "docker-ce-stable"
2025-11-06 00:25:00.108474 | controller | }
2025-11-06 00:25:00.129729 | 
2025-11-06 00:25:00.129863 | TASK [ensure-docker : Install pre-reqs]
2025-11-06 00:25:04.907700 | controller | ok: Nothing to do
2025-11-06 00:25:04.920685 | 
2025-11-06 00:25:04.920776 | TASK [ensure-docker : Remove packages]
2025-11-06 00:25:08.053172 | controller | ok: Nothing to do
2025-11-06 00:25:08.061837 | 
2025-11-06 00:25:08.061993 | TASK [ensure-docker : Install upstream docker using package]
2025-11-06 00:26:24.073352 | controller | changed
2025-11-06 00:26:24.079564 | 
2025-11-06 00:26:24.079679 | TASK [ensure-docker : Setup docker]
2025-11-06 00:26:24.117058 | controller | ok
2025-11-06 00:26:24.139230 | controller | included: /var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml
2025-11-06 00:26:24.160110 | 
2025-11-06 00:26:24.160234 | TASK [ensure-docker : Ensure "docker" group exists]
2025-11-06 00:26:25.157910 | controller | ok
2025-11-06 00:26:25.209485 | 
2025-11-06 00:26:25.209652 | TASK [ensure-docker : Add user to docker group]
2025-11-06 00:26:26.132900 | controller | changed
2025-11-06 00:26:26.140070 | 
2025-11-06 00:26:26.140138 | TASK [Update docker daemon proxy configuration]
2025-11-06 00:26:26.164755 | controller | skipping: Conditional result was False
2025-11-06 00:26:26.171970 | 
2025-11-06 00:26:26.172070 | TASK [Lower default MTU]
2025-11-06 00:26:26.185968 | controller | skipping: Conditional result was False
2025-11-06 00:26:26.193436 | 
2025-11-06 00:26:26.193513 | TASK [ensure-docker : Get the status of the docket.socket unit]
2025-11-06 00:26:26.929353 | controller | inactive
2025-11-06 00:26:27.552121 | controller | ok: Runtime: 0:00:00.020399
2025-11-06 00:26:27.558676 | 
2025-11-06 00:26:27.558753 | TASK [ensure-docker : Get the status of the docket unit]
2025-11-06 00:26:28.236323 | controller | inactive
2025-11-06 00:26:28.414663 | controller | ok: Runtime: 0:00:00.017633
2025-11-06 00:26:28.424295 | 
2025-11-06 00:26:28.424476 | TASK [ensure-docker : Restart docker]
2025-11-06 00:26:28.489050 | Trigger a Docker restart
2025-11-06 00:26:28.496623 | 
2025-11-06 00:26:28.496715 | TASK [ensure-docker : Reset ssh connection to pick up docker group]
2025-11-06 00:26:28.531522 | 
2025-11-06 00:26:28.531632 | TASK [ensure-docker : Install docker-compose]
2025-11-06 00:26:28.555708 | controller | skipping: Conditional result was False
2025-11-06 00:26:28.562489 | 
2025-11-06 00:26:28.562577 | TASK [ensure-docker : Flush handlers before role exit]
2025-11-06 00:26:28.573493 | 
2025-11-06 00:26:28.573643 | TASK [ensure-docker : Stop docker.socket to avoid any conflict]
2025-11-06 00:26:31.920344 | controller | changed
2025-11-06 00:26:31.938413 | 
2025-11-06 00:26:31.938566 | TASK [ensure-docker : Assure docker service is running]
2025-11-06 00:26:35.550293 | controller | changed
2025-11-06 00:26:35.573976 | 
2025-11-06 00:26:35.574163 | TASK [ensure-docker : Assure docker.socket service is running]
2025-11-06 00:26:37.420214 | controller | ok
2025-11-06 00:26:37.431692 | 
2025-11-06 00:26:37.431838 | TASK [ensure-docker : Correct group ownership on docker sock]
2025-11-06 00:26:38.280113 | controller | ok
2025-11-06 00:26:38.291116 | 
2025-11-06 00:26:38.291259 | TASK [ensure-docker : Validate ability to talk with docker]
2025-11-06 00:26:38.969640 | controller | CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
2025-11-06 00:26:39.166742 | controller | ok: Runtime: 0:00:00.045862
2025-11-06 00:26:39.182702 | 
2025-11-06 00:26:39.182907 | TASK [ensure-docker : Get version details]
2025-11-06 00:26:39.814162 | controller | Client: Docker Engine - Community
2025-11-06 00:26:39.814244 | controller |  Version:           24.0.7
2025-11-06 00:26:39.814318 | controller |  API version:       1.43
2025-11-06 00:26:39.814342 | controller |  Go version:        go1.20.10
2025-11-06 00:26:39.814364 | controller |  Git commit:        afdd53b
2025-11-06 00:26:39.814372 | controller |  Built:             Thu Oct 26 09:09:39 2023
2025-11-06 00:26:39.814379 | controller |  OS/Arch:           linux/amd64
2025-11-06 00:26:39.814387 | controller |  Context:           default
2025-11-06 00:26:39.814396 | controller |
2025-11-06 00:26:39.814404 | controller | Server: Docker Engine - Community
2025-11-06 00:26:39.814411 | controller |  Engine:
2025-11-06 00:26:39.814421 | controller |   Version:          24.0.7
2025-11-06 00:26:39.814428 | controller |   API version:      1.43 (minimum version 1.12)
2025-11-06 00:26:39.814434 | controller |   Go version:       go1.20.10
2025-11-06 00:26:39.814440 | controller |   Git commit:       311b9ff
2025-11-06 00:26:39.814457 | controller |   Built:            Thu Oct 26 09:08:11 2023
2025-11-06 00:26:39.814463 | controller |   OS/Arch:          linux/amd64
2025-11-06 00:26:39.814469 | controller |   Experimental:     false
2025-11-06 00:26:39.814475 | controller |  containerd:
2025-11-06 00:26:39.814481 | controller |   Version:          1.6.25
2025-11-06 00:26:39.814487 | controller |   GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
2025-11-06 00:26:39.814493 | controller |  runc:
2025-11-06 00:26:39.814499 | controller |   Version:          1.1.10
2025-11-06 00:26:39.814505 | controller |   GitCommit:        v1.1.10-0-g18a0cb0
2025-11-06 00:26:39.814514 | controller |  docker-init:
2025-11-06 00:26:39.814523 | controller |   Version:          0.19.0
2025-11-06 00:26:39.816326 | controller |   GitCommit:        de40ad0
2025-11-06 00:26:40.067531 | controller | ok: Runtime: 0:00:00.044597
2025-11-06 00:26:40.115239 | 
2025-11-06 00:26:40.115394 | TASK [ensure-docker : Dump installed docker details]
2025-11-06 00:26:40.150451 | {'changed': True, 'stdout': 'Client: Docker Engine - Community\n Version:           24.0.7\n API version:       1.43\n Go version:        go1.20.10\n Git commit:        afdd53b\n Built:             Thu Oct 26 09:09:39 2023\n OS/Arch:           linux/amd64\n Context:           default\n\nServer: Docker Engine - Community\n Engine:\n  Version:          24.0.7\n  API version:      1.43 (minimum version 1.12)\n  Go version:       go1.20.10\n  Git commit:       311b9ff\n  Built:            Thu Oct 26 09:08:11 2023\n  OS/Arch:          linux/amd64\n  Experimental:     false\n containerd:\n  Version:          1.6.25\n  GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f\n runc:\n  Version:          1.1.10\n  GitCommit:        v1.1.10-0-g18a0cb0\n docker-init:\n  Version:          0.19.0\n  GitCommit:        de40ad0', 'stderr': '', 'rc': 0, 'cmd': ['docker', 'version'], 'start': '2025-11-06 00:26:39.772190', 'end': '2025-11-06 00:26:39.816787', 'delta': '0:00:00.044597', 'msg': '', 'zuul_log_id': 'fa163ec2-ffbe-1a2f-458c-000000000061-1-controller', 'stdout_lines': ['Client: Docker Engine - Community', ' Version:           24.0.7', ' API version:       1.43', ' Go version:        go1.20.10', ' Git commit:        afdd53b', ' Built:             Thu Oct 26 09:09:39 2023', ' OS/Arch:           linux/amd64', ' Context:           default', '', 'Server: Docker Engine - Community', ' Engine:', '  Version:          24.0.7', '  API version:      1.43 (minimum version 1.12)', '  Go version:       go1.20.10', '  Git commit:       311b9ff', '  Built:            Thu Oct 26 09:08:11 2023', '  OS/Arch:          linux/amd64', '  Experimental:     false', ' containerd:', '  Version:          1.6.25', '  GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f', ' runc:', '  Version:          1.1.10', '  GitCommit:        v1.1.10-0-g18a0cb0', ' docker-init:', '  Version:          0.19.0', '  GitCommit:        de40ad0'], 'stderr_lines': [], 'failed': False}
2025-11-06 00:26:40.159651 | 
2025-11-06 00:26:40.159788 | TASK [Use buildset registry]
2025-11-06 00:26:40.186958 | controller | skipping: Conditional result was False
2025-11-06 00:26:40.205909 | 
2025-11-06 00:26:40.206121 | TASK [Ensure python3.8 is present]
2025-11-06 00:26:40.232930 | controller | skipping: Conditional result was False
2025-11-06 00:26:40.241327 | 
2025-11-06 00:26:40.241464 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-06 00:26:40.270142 | controller | ok
2025-11-06 00:26:40.296694 | 
2025-11-06 00:26:40.296833 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-06 00:26:47.196135 | controller | ok: Nothing to do
2025-11-06 00:26:47.203816 | 
2025-11-06 00:26:47.203932 | TASK [our-ensure-python : Also install python3-devel]
2025-11-06 00:27:00.856240 | controller | changed
2025-11-06 00:27:00.880531 | 
2025-11-06 00:27:00.880672 | TASK [Run ensure-virtualenv role]
2025-11-06 00:27:00.904224 | controller | ok
2025-11-06 00:27:00.937714 | 
2025-11-06 00:27:00.937888 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-06 00:27:01.655476 | controller | /usr/bin/virtualenv
2025-11-06 00:27:01.794129 | controller | ok: Runtime: 0:00:00.007427
2025-11-06 00:27:01.803175 | 
2025-11-06 00:27:01.803294 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-06 00:27:01.829719 | controller | skipping: Conditional result was False
2025-11-06 00:27:01.830230 | controller | changed: All items complete
2025-11-06 00:27:01.830289 | 
2025-11-06 00:27:01.856129 | 
2025-11-06 00:27:01.856423 | TASK [Find the full path of the Python interpreter]
2025-11-06 00:27:02.440482 | controller | /usr/bin/python3.8
2025-11-06 00:27:02.719107 | controller | ok
2025-11-06 00:27:02.728321 | 
2025-11-06 00:27:02.728484 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-06 00:27:05.442155 | controller | created virtual environment CPython3.8.18.final.0-64 in 1224ms
2025-11-06 00:27:05.482803 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-06 00:27:05.482859 | 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-06 00:27:05.482872 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-06 00:27:05.482893 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-06 00:27:06.101231 | controller | changed
2025-11-06 00:27:06.107283 | 
2025-11-06 00:27:06.107406 | TASK [Set selinux package]
2025-11-06 00:27:06.128949 | controller | ok
2025-11-06 00:27:06.135513 | 
2025-11-06 00:27:06.135644 | TASK [Set selinux package (Fedora)]
2025-11-06 00:27:06.214681 | controller | ok
2025-11-06 00:27:06.222724 | 
2025-11-06 00:27:06.222870 | TASK [Install selinux into virtualenv]
2025-11-06 00:27:11.339248 | controller | Collecting selinux-please-lie-to-me
2025-11-06 00:27:11.465032 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-06 00:27:12.775859 | controller | Collecting setuptools<50.0.0
2025-11-06 00:27:12.781179 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-06 00:27:12.867033 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 10.5 MB/s eta 0:00:00
2025-11-06 00:27:12.977062 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-06 00:27:12.977381 | controller |   Attempting uninstall: setuptools
2025-11-06 00:27:12.978423 | controller |     Found existing installation: setuptools 62.6.0
2025-11-06 00:27:13.085477 | controller |     Uninstalling setuptools-62.6.0:
2025-11-06 00:27:13.098612 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-06 00:27:13.751446 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-06 00:27:13.941406 | controller |
2025-11-06 00:27:14.312073 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-11-06 00:27:14.312118 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-11-06 00:27:14.597797 | controller | ok: Runtime: 0:00:06.997410
2025-11-06 00:27:14.611086 | 
2025-11-06 00:27:14.611243 | TASK [Install pytest-forked into virtualenv]
2025-11-06 00:27:16.596853 | controller | Collecting pytest-forked
2025-11-06 00:27:16.651698 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-06 00:27:16.836966 | controller | Collecting pytest>=3.10
2025-11-06 00:27:16.843841 | controller |   Downloading pytest-8.3.5-py3-none-any.whl (343 kB)
2025-11-06 00:27:16.878879 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 11.7 MB/s eta 0:00:00
2025-11-06 00:27:16.930240 | controller | Collecting py
2025-11-06 00:27:16.935946 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-06 00:27:16.949141 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 10.3 MB/s eta 0:00:00
2025-11-06 00:27:17.035209 | controller | Collecting tomli>=1
2025-11-06 00:27:17.040715 | controller |   Downloading tomli-2.3.0-py3-none-any.whl (14 kB)
2025-11-06 00:27:17.091110 | controller | Collecting exceptiongroup>=1.0.0rc8
2025-11-06 00:27:17.096939 | controller |   Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB)
2025-11-06 00:27:17.161536 | controller | Collecting packaging
2025-11-06 00:27:17.167349 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-06 00:27:17.178426 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.5 MB/s eta 0:00:00
2025-11-06 00:27:17.207046 | controller | Collecting iniconfig
2025-11-06 00:27:17.212431 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-11-06 00:27:17.263034 | controller | Collecting pluggy<2,>=1.5
2025-11-06 00:27:17.268308 | controller |   Downloading pluggy-1.5.0-py3-none-any.whl (20 kB)
2025-11-06 00:27:17.340557 | controller | Collecting typing-extensions>=4.6.0
2025-11-06 00:27:17.345970 | controller |   Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB)
2025-11-06 00:27:17.354229 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 7.6 MB/s eta 0:00:00
2025-11-06 00:27:17.439855 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked
2025-11-06 00:27:18.107295 | controller | Successfully installed exceptiongroup-1.3.0 iniconfig-2.1.0 packaging-25.0 pluggy-1.5.0 py-1.11.0 pytest-8.3.5 pytest-forked-1.6.0 tomli-2.3.0 typing-extensions-4.13.2
2025-11-06 00:27:18.112164 | controller |
2025-11-06 00:27:18.285047 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-11-06 00:27:18.285105 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-11-06 00:27:18.495442 | controller | ok: Runtime: 0:00:02.663305
2025-11-06 00:27:18.510075 | 
2025-11-06 00:27:18.510249 | TASK [Update pip]
2025-11-06 00:27:21.102589 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2)
2025-11-06 00:27:21.571214 | controller | Collecting pip
2025-11-06 00:27:21.687389 | controller |   Downloading pip-25.0.1-py3-none-any.whl (1.8 MB)
2025-11-06 00:27:21.820565 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 15.3 MB/s eta 0:00:00
2025-11-06 00:27:22.029569 | controller | Installing collected packages: pip
2025-11-06 00:27:22.029834 | controller |   Attempting uninstall: pip
2025-11-06 00:27:22.030876 | controller |     Found existing installation: pip 22.2.2
2025-11-06 00:27:22.703843 | controller |     Uninstalling pip-22.2.2:
2025-11-06 00:27:22.774303 | controller |       Successfully uninstalled pip-22.2.2
2025-11-06 00:27:25.447594 | controller | Successfully installed pip-25.0.1
2025-11-06 00:27:25.892232 | controller | ok: Runtime: 0:00:05.925699
2025-11-06 00:27:25.904652 | 
2025-11-06 00:27:25.904795 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-06 00:27:27.152944 | controller | changed
2025-11-06 00:27:27.166931 | 
2025-11-06 00:27:27.167135 | TASK [Install ansible into virtualenv]
2025-11-06 00:27:28.857505 | controller | Processing ./src/github.com/ansible/ansible
2025-11-06 00:27:28.858965 | controller |   Preparing metadata (setup.py): started
2025-11-06 00:27:29.538734 | controller |   Preparing metadata (setup.py): finished with status 'done'
2025-11-06 00:27:29.599541 | controller | Collecting jinja2 (from ansible-base==2.10.17.post0)
2025-11-06 00:27:29.614622 | controller |   Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB)
2025-11-06 00:27:29.698299 | controller | Collecting PyYAML (from ansible-base==2.10.17.post0)
2025-11-06 00:27:29.704136 | controller |   Downloading PyYAML-6.0.3-cp38-cp38-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl.metadata (2.1 kB)
2025-11-06 00:27:30.077679 | controller | Collecting cryptography (from ansible-base==2.10.17.post0)
2025-11-06 00:27:30.082464 | controller |   Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB)
2025-11-06 00:27:30.107139 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.8/site-packages (from ansible-base==2.10.17.post0) (25.0)
2025-11-06 00:27:30.308957 | controller | Collecting cffi>=1.14 (from cryptography->ansible-base==2.10.17.post0)
2025-11-06 00:27:30.313845 | controller |   Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB)
2025-11-06 00:27:30.321839 | controller | Requirement already satisfied: typing-extensions>=4.13.2 in ./venv/lib/python3.8/site-packages (from cryptography->ansible-base==2.10.17.post0) (4.13.2)
2025-11-06 00:27:30.418213 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible-base==2.10.17.post0)
2025-11-06 00:27:30.423237 | controller |   Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB)
2025-11-06 00:27:30.450125 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible-base==2.10.17.post0)
2025-11-06 00:27:30.455101 | controller |   Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes)
2025-11-06 00:27:30.469222 | controller | Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl (4.5 MB)
2025-11-06 00:27:30.512225 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.5/4.5 MB 121.8 MB/s eta 0:00:00
2025-11-06 00:27:30.516978 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB)
2025-11-06 00:27:30.533151 | controller | Downloading PyYAML-6.0.3-cp38-cp38-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl (806 kB)
2025-11-06 00:27:30.551341 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 806.0/806.0 kB 41.3 MB/s eta 0:00:00
2025-11-06 00:27:30.557451 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB)
2025-11-06 00:27:30.573005 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB)
2025-11-06 00:27:30.583299 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB)
2025-11-06 00:27:30.606732 | controller | Building wheels for collected packages: ansible-base
2025-11-06 00:27:30.607738 | controller |   Building wheel for ansible-base (setup.py): started
2025-11-06 00:27:32.580446 | controller |   Building wheel for ansible-base (setup.py): finished with status 'done'
2025-11-06 00:27:32.583932 | controller |   Created wheel for ansible-base: filename=ansible_base-2.10.17.post0-py3-none-any.whl size=1881569 sha256=72af5fc22156d431f163f3de3a5e48750adb076f58f470ac08ed9047ace30133
2025-11-06 00:27:32.584302 | controller |   Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-4r07_311/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7
2025-11-06 00:27:32.597459 | controller | Successfully built ansible-base
2025-11-06 00:27:32.649145 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible-base
2025-11-06 00:27:35.248471 | controller | Successfully installed MarkupSafe-2.1.5 PyYAML-6.0.3 ansible-base-2.10.17.post0 cffi-1.17.1 cryptography-46.0.3 jinja2-3.1.6 pycparser-2.23
2025-11-06 00:27:35.556868 | controller | ok: Runtime: 0:00:07.206448
2025-11-06 00:27:35.564095 | 
2025-11-06 00:27:35.564168 | TASK [Setup download-artifact-fork role]
2025-11-06 00:27:35.587752 | controller | ok
2025-11-06 00:27:35.608989 | 
2025-11-06 00:27:35.609163 | TASK [download-artifact-fork : Parse inventory response]
2025-11-06 00:27:35.651301 | controller | ok
2025-11-06 00:27:35.659295 | 
2025-11-06 00:27:35.659371 | TASK [download-artifact-fork : Fetch info from Zuul API]
2025-11-06 00:27:35.685256 | controller | skipping: Conditional result was False
2025-11-06 00:27:35.692745 | 
2025-11-06 00:27:35.692823 | TASK [download-artifact-fork : Parse build response]
2025-11-06 00:27:35.718289 | controller | skipping: Conditional result was False
2025-11-06 00:27:35.726283 | 
2025-11-06 00:27:35.726361 | TASK [download-artifact-fork : Ensure artifacts directory exists]
2025-11-06 00:27:36.902765 | controller | changed
2025-11-06 00:27:36.910269 | 
2025-11-06 00:27:36.910399 | LOOP [download-artifact-fork : Download archive by type]
2025-11-06 00:27:36.942833 | controller | skipping: Conditional result was False
2025-11-06 00:27:36.943139 | 
2025-11-06 00:27:38.690207 | controller | changed: OK (20211 bytes)
2025-11-06 00:27:38.730800 | 
2025-11-06 00:27:38.731111 | TASK [deploy-artifacts : define __collections]
2025-11-06 00:27:38.776489 | controller | ok
2025-11-06 00:27:38.793302 | 
2025-11-06 00:27:38.793580 | LOOP [deploy-artifacts : Create list of collections]
2025-11-06 00:27:38.844229 | controller | skipping: Conditional result was False
2025-11-06 00:27:38.865917 | controller | ok:
2025-11-06 00:27:38.866060 | controller | {
2025-11-06 00:27:38.866119 | controller |   "branch": "main",
2025-11-06 00:27:38.866360 | controller |   "job": "build-ansible-collection",
2025-11-06 00:27:38.866419 | controller |   "metadata": {
2025-11-06 00:27:38.866457 | controller |     "type": "ansible_collection",
2025-11-06 00:27:38.866493 | controller |     "version": "5.0.0"
2025-11-06 00:27:38.866529 | controller |   },
2025-11-06 00:27:38.866564 | controller |   "name": "ansible.network",
2025-11-06 00:27:38.866598 | controller |   "project": "ansible-collections/ansible.network",
2025-11-06 00:27:38.866642 | controller |   "url": "https://afef0049e3bd46ac12fd-ab533af6698d02ce303c9e3b76f9b3bd.ssl.cf1.rackcdn.com/ansible/d7b91412e09548c79ee2d6511d508b50/artifacts/ansible-network-5.0.0.tar.gz"
2025-11-06 00:27:38.866692 | controller | }
2025-11-06 00:27:38.884472 | 
2025-11-06 00:27:38.884690 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy]
2025-11-06 00:27:40.157164 | controller | Starting galaxy collection install process
2025-11-06 00:27:40.157848 | controller | Process install dependency map
2025-11-06 00:27:53.263801 | controller | Starting collection install process
2025-11-06 00:27:53.263971 | controller | Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network'
2025-11-06 00:27:53.276357 | controller | ansible.network (5.0.0) was installed successfully
2025-11-06 00:27:53.276455 | controller | Installing 'ansible.netcommon:8.1.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2025-11-06 00:27:53.276639 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-netcommon-8.1.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:27:54.793483 | controller | ansible.netcommon (8.1.0) was installed successfully
2025-11-06 00:27:54.793608 | controller | Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2025-11-06 00:27:54.793621 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-utils-6.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:27:56.293520 | controller | ansible.utils (6.0.0) was installed successfully
2025-11-06 00:27:56.293644 | controller | Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos'
2025-11-06 00:27:56.293859 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/arista-eos-12.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:27:58.920524 | controller | arista.eos (12.0.0) was installed successfully
2025-11-06 00:27:58.920647 | controller | Installing 'cisco.ios:11.1.1' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios'
2025-11-06 00:27:58.920895 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-ios-11.1.1.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:28:01.704218 | controller | cisco.ios (11.1.1) was installed successfully
2025-11-06 00:28:01.704344 | controller | Installing 'cisco.iosxr:12.1.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/iosxr'
2025-11-06 00:28:01.704560 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-iosxr-12.1.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:28:04.547027 | controller | cisco.iosxr (12.1.0) was installed successfully
2025-11-06 00:28:04.547202 | controller | Installing 'cisco.nxos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/nxos'
2025-11-06 00:28:04.547458 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-nxos-11.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:28:07.708156 | controller | cisco.nxos (11.0.0) was installed successfully
2025-11-06 00:28:07.708330 | controller | Installing 'junipernetworks.junos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/junipernetworks/junos'
2025-11-06 00:28:07.708689 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/junipernetworks-junos-11.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4146dsqwez09/tmp6ccfphmm
2025-11-06 00:28:10.138541 | controller | junipernetworks.junos (11.0.0) was installed successfully
2025-11-06 00:28:10.813996 | controller | ok: Runtime: 0:00:30.649891
2025-11-06 00:28:10.842785 | 
2025-11-06 00:28:10.842987 | TASK [podman may need iptables kernel modules]
2025-11-06 00:28:12.216597 | controller | ok: Runtime: 0:00:00.006056
2025-11-06 00:28:12.263289 | 
2025-11-06 00:28:12.263429 | PLAY RECAP
2025-11-06 00:28:12.263488 | controller | ok: 46 changed: 26 unreachable: 0 failed: 0 skipped: 17 rescued: 0 ignored: 0
2025-11-06 00:28:12.263628 | 
2025-11-06 00:28:12.412574 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-06 00:28:12.415257 | RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-11-06 00:28:13.083919 | 
2025-11-06 00:28:13.084073 | PLAY [controller]
2025-11-06 00:28:13.107378 | 
2025-11-06 00:28:13.107554 | TASK [Copy the galaxy.yml on the controller]
2025-11-06 00:28:16.834914 | controller | changed
2025-11-06 00:28:16.844787 | 
2025-11-06 00:28:16.844978 | TASK [Load information from galaxy.yml]
2025-11-06 00:28:16.880815 | controller | ok
2025-11-06 00:28:16.889285 | 
2025-11-06 00:28:16.889449 | LOOP [Enable FIPS mode]
2025-11-06 00:28:16.914444 | 
2025-11-06 00:28:16.915161 | LOOP [ansible-test : Include branch specific variables.]
2025-11-06 00:28:16.945492 | controller | ok: "/var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/untrusted/project_2/github.com/ansible/ansible-zuul-jobs/roles/ansible-test/vars/default.yaml"
2025-11-06 00:28:16.945745 | 
2025-11-06 00:28:16.957561 | 
2025-11-06 00:28:16.957694 | TASK [ansible-test : Setup --skip-tags for test_options]
2025-11-06 00:28:16.989644 | controller | ok
2025-11-06 00:28:16.995638 | 
2025-11-06 00:28:16.995743 | TASK [ansible-test : Enable --inventory for network-integration]
2025-11-06 00:28:17.021774 | controller | skipping: Conditional result was False
2025-11-06 00:28:17.033250 | 
2025-11-06 00:28:17.033433 | TASK [ansible-test : Enable --retry-on-error]
2025-11-06 00:28:17.061562 | controller | skipping: Conditional result was False
2025-11-06 00:28:17.069235 | 
2025-11-06 00:28:17.069364 | TASK [ansible-test : Enable --continue-on-error]
2025-11-06 00:28:17.101324 | controller | ok
2025-11-06 00:28:17.107153 | 
2025-11-06 00:28:17.107233 | TASK [ansible-test : Enable --requirements]
2025-11-06 00:28:17.133328 | controller | skipping: Conditional result was False
2025-11-06 00:28:17.140414 | 
2025-11-06 00:28:17.140533 | TASK [ansible-test : Adjust options for unit tests]
2025-11-06 00:28:17.156078 | controller | skipping: Conditional result was False
2025-11-06 00:28:17.163735 | 
2025-11-06 00:28:17.163834 | TASK [ansible-test : Install requirements with unit tests]
2025-11-06 00:28:17.227209 | controller | ok
2025-11-06 00:28:17.233747 | 
2025-11-06 00:28:17.233869 | TASK [ansible-test : Set --skip-test]
2025-11-06 00:28:17.289788 | controller | skipping: Conditional result was False
2025-11-06 00:28:17.300524 | 
2025-11-06 00:28:17.300684 | TASK [ansible-test : Reduce verbosity]
2025-11-06 00:28:17.345452 | controller | ok
2025-11-06 00:28:17.351359 | 
2025-11-06 00:28:17.351448 | TASK [ansible-test : Setup --python option]
2025-11-06 00:28:17.382106 | controller | skipping: Conditional result was False
2025-11-06 00:28:17.390900 | 
2025-11-06 00:28:17.391039 | TASK [ansible-test : Setup --docker option]
2025-11-06 00:28:17.425583 | controller | ok
2025-11-06 00:28:17.435751 | 
2025-11-06 00:28:17.435881 | TASK [ansible-test : check if MANIFEST.json exists]
2025-11-06 00:28:18.645191 | controller | ok
2025-11-06 00:28:18.653394 | 
2025-11-06 00:28:18.653555 | TASK [ansible-test : Copy the MANIFEST.json on the controller]
2025-11-06 00:28:18.680512 | controller | skipping: Conditional result was False
2025-11-06 00:28:18.690848 | 
2025-11-06 00:28:18.690982 | TASK [ansible-test : Load information from MANIFEST.json]
2025-11-06 00:28:18.720874 | controller | skipping: Conditional result was False
2025-11-06 00:28:18.732113 | 
2025-11-06 00:28:18.732239 | TASK [ansible-test : Setup location of project for integration tests]
2025-11-06 00:28:18.758192 | controller | skipping: Conditional result was False
2025-11-06 00:28:18.768716 | 
2025-11-06 00:28:18.768867 | TASK [ansible-test : Copy the galaxy.yml on the controller]
2025-11-06 00:28:20.490255 | controller | ok
2025-11-06 00:28:20.503331 | 
2025-11-06 00:28:20.503502 | TASK [ansible-test : Load information from galaxy.yml]
2025-11-06 00:28:20.544654 | controller | ok
2025-11-06 00:28:20.557844 | 
2025-11-06 00:28:20.557989 | TASK [ansible-test : Setup location of project for integration tests]
2025-11-06 00:28:20.593139 | controller | ok
2025-11-06 00:28:20.601333 | 
2025-11-06 00:28:20.601429 | TASK [ansible-test : Setup minimum test requirements]
2025-11-06 00:28:20.645478 | controller | ok
2025-11-06 00:28:20.654823 | 
2025-11-06 00:28:20.654949 | TASK [ansible-test : Ensure pip temp directory exists in /var/tmp]
2025-11-06 00:28:21.616785 | controller | ok
2025-11-06 00:28:21.629306 | 
2025-11-06 00:28:21.629473 | TASK [ansible-test : Install python requirements]
2025-11-06 00:28:22.925395 | controller | Collecting yamllint (from -r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-11-06 00:28:22.944811 | controller |   Downloading yamllint-1.35.1-py3-none-any.whl.metadata (4.2 kB)
2025-11-06 00:28:22.976221 | controller | Collecting pathspec>=0.5.3 (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-11-06 00:28:22.981261 | controller |   Downloading pathspec-0.12.1-py3-none-any.whl.metadata (21 kB)
2025-11-06 00:28:22.990160 | controller | Requirement already satisfied: pyyaml in ./venv/lib64/python3.8/site-packages (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1)) (6.0.3)
2025-11-06 00:28:22.998419 | controller | Downloading yamllint-1.35.1-py3-none-any.whl (66 kB)
2025-11-06 00:28:23.012486 | controller | Downloading pathspec-0.12.1-py3-none-any.whl (31 kB)
2025-11-06 00:28:23.060797 | controller | Installing collected packages: pathspec, yamllint
2025-11-06 00:28:23.141006 | controller | Successfully installed pathspec-0.12.1 yamllint-1.35.1
2025-11-06 00:28:23.488976 | controller | ok: Runtime: 0:00:00.933884
2025-11-06 00:28:23.499004 | 
2025-11-06 00:28:23.499209 | TASK [ansible-test : Fetch the integration_config.yml file from the controller]
2025-11-06 00:28:25.025521 | controller | ERROR
2025-11-06 00:28:25.025930 | controller | {
2025-11-06 00:28:25.025992 | controller |   "msg": "the remote file does not exist, not transferring, ignored"
2025-11-06 00:28:25.026072 | controller | }
2025-11-06 00:28:25.026123 | controller | ERROR: Ignoring Errors
2025-11-06 00:28:25.039008 | 
2025-11-06 00:28:25.039197 | TASK [ansible-test : Copy potential cloud provider configuration for ansible-test in the collection]
2025-11-06 00:28:25.410175 | controller | skipping: Conditional result was False
2025-11-06 00:28:25.426141 | 
2025-11-06 00:28:25.426323 | TASK [ansible-test : Enable persistent connection logging]
2025-11-06 00:28:26.716258 | controller | changed: section and option added
2025-11-06 00:28:26.732555 | 
2025-11-06 00:28:26.732770 | TASK [ansible-test : Set persistent ssh_type value]
2025-11-06 00:28:27.835215 | controller | changed: option added
2025-11-06 00:28:27.850611 | 
2025-11-06 00:28:27.850809 | TASK [ansible-test : Set ansible log path]
2025-11-06 00:28:29.025316 | controller | changed: section and option added
2025-11-06 00:28:29.040655 | 
2025-11-06 00:28:29.040842 | TASK [ansible-test : Identify the changed targets]
2025-11-06 00:28:29.409120 | controller | skipping: Conditional result was False
2025-11-06 00:28:29.417192 | 
2025-11-06 00:28:29.417328 | TASK [ansible-test : set_fact]
2025-11-06 00:28:29.483867 | controller | skipping: Conditional result was False
2025-11-06 00:28:29.497954 | 
2025-11-06 00:28:29.498165 | TASK [ansible-test : Set the targets]
2025-11-06 00:28:29.540930 | controller | ok
2025-11-06 00:28:29.547230 | 
2025-11-06 00:28:29.547309 | TASK [ansible-test : set_fact]
2025-11-06 00:28:29.582457 | controller | skipping: Conditional result was False
2025-11-06 00:28:29.598784 | 
2025-11-06 00:28:29.599005 | TASK [ansible-test : List the targets]
2025-11-06 00:28:30.010041 | controller | skipping: Conditional result was False
2025-11-06 00:28:30.019945 | 
2025-11-06 00:28:30.020076 | TASK [ansible-test : set_fact]
2025-11-06 00:28:30.057185 | controller | skipping: Conditional result was False
2025-11-06 00:28:30.066373 | 
2025-11-06 00:28:30.066474 | TASK [ansible-test : set_fact]
2025-11-06 00:28:30.101986 | controller | skipping: Conditional result was False
2025-11-06 00:28:30.111435 | 
2025-11-06 00:28:30.111532 | LOOP [ansible-test : set_fact]
2025-11-06 00:28:30.194091 | 
2025-11-06 00:28:30.194364 | TASK [ansible-test : set_fact]
2025-11-06 00:28:30.220312 | controller | skipping: Conditional result was False
2025-11-06 00:28:30.232184 | 
2025-11-06 00:28:30.232321 | TASK [ansible-test : debug]
2025-11-06 00:28:30.259105 | controller | skipping: Conditional result was False
2025-11-06 00:28:30.266772 | 
2025-11-06 00:28:30.266861 | TASK [ansible-test : debug]
2025-11-06 00:28:30.308779 | About to run: ansible-test sanity --requirements --docker -v
2025-11-06 00:28:30.314634 | 
2025-11-06 00:28:30.314714 | TASK [ansible-test : Run the test suite]
2025-11-06 00:28:31.592016 | controller | Run command: docker images quay.io/ansible/default-test-container:2.9.0 --format '{{json .}}'
2025-11-06 00:28:31.713245 | controller | Run command: docker pull quay.io/ansible/default-test-container:2.9.0
2025-11-06 00:28:33.222531 | controller | 2.9.0: Pulling from ansible/default-test-container
2025-11-06 00:28:33.224997 | controller | 171857c49d0f: Pulling fs layer
2025-11-06 00:28:33.225157 | controller | 419640447d26: Pulling fs layer
2025-11-06 00:28:33.225172 | controller | 61e52f862619: Pulling fs layer
2025-11-06 00:28:33.225180 | controller | 851de0426e26: Pulling fs layer
2025-11-06 00:28:33.225196 | controller | 37425716ea5b: Pulling fs layer
2025-11-06 00:28:33.225760 | controller | cd9b0c439616: Pulling fs layer
2025-11-06 00:28:33.225774 | controller | d4612dbd8855: Pulling fs layer
2025-11-06 00:28:33.225781 | controller | 554699364730: Pulling fs layer
2025-11-06 00:28:33.225787 | controller | 1ff15d4bdb3e: Pulling fs layer
2025-11-06 00:28:33.225793 | controller | 5f2e4724adea: Pulling fs layer
2025-11-06 00:28:33.225799 | controller | a02d9a95ccb8: Pulling fs layer
2025-11-06 00:28:33.225805 | controller | 989f4ce370cb: Pulling fs layer
2025-11-06 00:28:33.225815 | controller | 0d7f52cdf9df: Pulling fs layer
2025-11-06 00:28:33.583648 | controller | c423742351d5: Pulling fs layer
2025-11-06 00:28:33.583727 | controller | 109236341d21: Pulling fs layer
2025-11-06 00:28:33.583735 | controller | 07a2f61c96b8: Pulling fs layer
2025-11-06 00:28:33.583741 | controller | 041f122f27ae: Pulling fs layer
2025-11-06 00:28:33.583747 | controller | ca6f5098b12e: Pulling fs layer
2025-11-06 00:28:33.583753 | controller | 1eb3e7b2afd9: Pulling fs layer
2025-11-06 00:28:33.583759 | controller | 18a0b750727a: Pulling fs layer
2025-11-06 00:28:33.583765 | controller | 17f2f596716c: Pulling fs layer
2025-11-06 00:28:33.583777 | controller | f35a9998a9bd: Pulling fs layer
2025-11-06 00:28:33.583788 | controller | fdfc10566405: Pulling fs layer
2025-11-06 00:28:33.583795 | controller | 1ff1c442c5fe: Pulling fs layer
2025-11-06 00:28:33.583801 | controller | a3443c4a17ed: Pulling fs layer
2025-11-06 00:28:33.583807 | controller | 0edcf9fb2b15: Pulling fs layer
2025-11-06 00:28:33.583813 | controller | 5af43b69e845: Pulling fs layer
2025-11-06 00:28:33.583820 | controller | 1651773effb2: Pulling fs layer
2025-11-06 00:28:33.583827 | controller | 79e23c5c0fe4: Pulling fs layer
2025-11-06 00:28:33.583839 | controller | e5058b1faaa6: Pulling fs layer
2025-11-06 00:28:33.583845 | controller | 846775490569: Pulling fs layer
2025-11-06 00:28:33.583852 | controller | 851de0426e26: Waiting
2025-11-06 00:28:33.583857 | controller | 37425716ea5b: Waiting
2025-11-06 00:28:33.583863 | controller | cd9b0c439616: Waiting
2025-11-06 00:28:33.583869 | controller | d4612dbd8855: Waiting
2025-11-06 00:28:33.583875 | controller | 554699364730: Waiting
2025-11-06 00:28:33.583880 | controller | 1ff15d4bdb3e: Waiting
2025-11-06 00:28:33.583890 | controller | 5f2e4724adea: Waiting
2025-11-06 00:28:33.583896 | controller | a02d9a95ccb8: Waiting
2025-11-06 00:28:33.583902 | controller | 989f4ce370cb: Waiting
2025-11-06 00:28:33.583908 | controller | 0d7f52cdf9df: Waiting
2025-11-06 00:28:33.583914 | controller | c423742351d5: Waiting
2025-11-06 00:28:33.583920 | controller | 109236341d21: Waiting
2025-11-06 00:28:33.583926 | controller | 07a2f61c96b8: Waiting
2025-11-06 00:28:33.583932 | controller | 041f122f27ae: Waiting
2025-11-06 00:28:33.583938 | controller | ca6f5098b12e: Waiting
2025-11-06 00:28:33.583944 | controller | 1eb3e7b2afd9: Waiting
2025-11-06 00:28:33.583949 | controller | 18a0b750727a: Waiting
2025-11-06 00:28:33.583956 | controller | 17f2f596716c: Waiting
2025-11-06 00:28:33.583965 | controller | f35a9998a9bd: Waiting
2025-11-06 00:28:33.583971 | controller | fdfc10566405: Waiting
2025-11-06 00:28:33.583977 | controller | 1ff1c442c5fe: Waiting
2025-11-06 00:28:33.583983 | controller | a3443c4a17ed: Waiting
2025-11-06 00:28:33.583989 | controller | 0edcf9fb2b15: Waiting
2025-11-06 00:28:33.583995 | controller | 5af43b69e845: Waiting
2025-11-06 00:28:33.584001 | controller | 1651773effb2: Waiting
2025-11-06 00:28:33.584007 | controller | 79e23c5c0fe4: Waiting
2025-11-06 00:28:33.584013 | controller | e5058b1faaa6: Waiting
2025-11-06 00:28:33.584019 | controller | 846775490569: Waiting
2025-11-06 00:28:33.584035 | controller | 61e52f862619: Verifying Checksum
2025-11-06 00:28:33.614296 | controller | 61e52f862619: Download complete
2025-11-06 00:28:33.614363 | controller | 419640447d26: Download complete
2025-11-06 00:28:33.911237 | controller | 171857c49d0f: Verifying Checksum
2025-11-06 00:28:33.911493 | controller | 171857c49d0f: Download complete
2025-11-06 00:28:34.719923 | controller | cd9b0c439616: Download complete
2025-11-06 00:28:34.764390 | controller | 851de0426e26: Verifying Checksum
2025-11-06 00:28:35.748294 | controller | 851de0426e26: Download complete
2025-11-06 00:28:35.748373 | controller | d4612dbd8855: Verifying Checksum
2025-11-06 00:28:37.008556 | controller | d4612dbd8855: Download complete
2025-11-06 00:28:37.008621 | controller | 1ff15d4bdb3e: Verifying Checksum
2025-11-06 00:28:37.249835 | controller | 1ff15d4bdb3e: Download complete
2025-11-06 00:28:37.249905 | controller | 171857c49d0f: Pull complete
2025-11-06 00:28:37.280244 | controller | 419640447d26: Pull complete
2025-11-06 00:28:37.307770 | controller | 61e52f862619: Pull complete
2025-11-06 00:28:37.330163 | controller | 851de0426e26: Pull complete
2025-11-06 00:28:38.158271 | controller | 5f2e4724adea: Verifying Checksum
2025-11-06 00:28:39.913025 | controller | 5f2e4724adea: Download complete
2025-11-06 00:28:39.913090 | controller | a02d9a95ccb8: Verifying Checksum
2025-11-06 00:28:39.913291 | controller | a02d9a95ccb8: Download complete
2025-11-06 00:28:40.992117 | controller | 989f4ce370cb: Download complete
2025-11-06 00:28:42.337358 | controller | 0d7f52cdf9df: Download complete
2025-11-06 00:28:43.190465 | controller | c423742351d5: Verifying Checksum
2025-11-06 00:28:49.488265 | controller | c423742351d5: Download complete
2025-11-06 00:28:49.488346 | controller | 554699364730: Verifying Checksum
2025-11-06 00:28:50.591605 | controller | 554699364730: Download complete
2025-11-06 00:28:50.591706 | controller | 07a2f61c96b8: Verifying Checksum
2025-11-06 00:28:51.708092 | controller | 07a2f61c96b8: Download complete
2025-11-06 00:28:51.708167 | controller | 041f122f27ae: Verifying Checksum
2025-11-06 00:28:52.949580 | controller | 041f122f27ae: Download complete
2025-11-06 00:28:52.949669 | controller | 109236341d21: Verifying Checksum
2025-11-06 00:28:53.907547 | controller | 109236341d21: Download complete
2025-11-06 00:28:53.907615 | controller | ca6f5098b12e: Verifying Checksum
2025-11-06 00:28:54.549354 | controller | ca6f5098b12e: Download complete
2025-11-06 00:28:54.549476 | controller | 1eb3e7b2afd9: Verifying Checksum
2025-11-06 00:28:55.387271 | controller | 1eb3e7b2afd9: Download complete
2025-11-06 00:28:55.387341 | controller | 17f2f596716c: Verifying Checksum
2025-11-06 00:28:55.387497 | controller | 17f2f596716c: Download complete
2025-11-06 00:28:55.825771 | controller | 18a0b750727a: Verifying Checksum
2025-11-06 00:28:55.825824 | controller | 18a0b750727a: Download complete
2025-11-06 00:28:56.430070 | controller | f35a9998a9bd: Verifying Checksum
2025-11-06 00:28:57.004438 | controller | f35a9998a9bd: Download complete
2025-11-06 00:28:57.004505 | controller | fdfc10566405: Verifying Checksum
2025-11-06 00:28:57.416673 | controller | fdfc10566405: Download complete
2025-11-06 00:28:57.416770 | controller | 1ff1c442c5fe: Verifying Checksum
2025-11-06 00:29:03.586475 | controller | 1ff1c442c5fe: Download complete
2025-11-06 00:29:03.586565 | controller | 0edcf9fb2b15: Verifying Checksum
2025-11-06 00:29:04.668464 | controller | 0edcf9fb2b15: Download complete
2025-11-06 00:29:04.668531 | controller | a3443c4a17ed: Verifying Checksum
2025-11-06 00:29:06.945077 | controller | a3443c4a17ed: Download complete
2025-11-06 00:29:06.945163 | controller | 37425716ea5b: Verifying Checksum
2025-11-06 00:29:06.945204 | controller | 37425716ea5b: Download complete
2025-11-06 00:29:08.501721 | controller | 5af43b69e845: Verifying Checksum
2025-11-06 00:29:08.502158 | controller | 5af43b69e845: Download complete
2025-11-06 00:29:10.434437 | controller | 79e23c5c0fe4: Verifying Checksum
2025-11-06 00:29:10.435373 | controller | 79e23c5c0fe4: Download complete
2025-11-06 00:29:12.927757 | controller | 1651773effb2: Verifying Checksum
2025-11-06 00:29:12.929289 | controller | 1651773effb2: Download complete
2025-11-06 00:29:16.541289 | controller | 846775490569: Verifying Checksum
2025-11-06 00:29:16.541532 | controller | 846775490569: Download complete
2025-11-06 00:29:22.848617 | controller | e5058b1faaa6: Verifying Checksum
2025-11-06 00:29:22.848820 | controller | e5058b1faaa6: Download complete
2025-11-06 00:29:26.091803 | controller | 37425716ea5b: Pull complete
2025-11-06 00:29:26.119355 | controller | cd9b0c439616: Pull complete
2025-11-06 00:29:26.153956 | controller | d4612dbd8855: Pull complete
2025-11-06 00:29:32.060685 | controller | 554699364730: Pull complete
2025-11-06 00:29:32.081578 | controller | 1ff15d4bdb3e: Pull complete
2025-11-06 00:29:32.103228 | controller | 5f2e4724adea: Pull complete
2025-11-06 00:29:32.161896 | controller | a02d9a95ccb8: Pull complete
2025-11-06 00:29:32.183827 | controller | 989f4ce370cb: Pull complete
2025-11-06 00:29:32.205755 | controller | 0d7f52cdf9df: Pull complete
2025-11-06 00:29:32.226245 | controller | c423742351d5: Pull complete
2025-11-06 00:29:35.164892 | controller | 109236341d21: Pull complete
2025-11-06 00:29:35.183789 | controller | 07a2f61c96b8: Pull complete
2025-11-06 00:29:35.204188 | controller | 041f122f27ae: Pull complete
2025-11-06 00:29:35.383758 | controller | ca6f5098b12e: Pull complete
2025-11-06 00:29:35.431035 | controller | 1eb3e7b2afd9: Pull complete
2025-11-06 00:29:35.481437 | controller | 18a0b750727a: Pull complete
2025-11-06 00:29:35.505695 | controller | 17f2f596716c: Pull complete
2025-11-06 00:29:35.526786 | controller | f35a9998a9bd: Pull complete
2025-11-06 00:29:35.563434 | controller | fdfc10566405: Pull complete
2025-11-06 00:29:35.582675 | controller | 1ff1c442c5fe: Pull complete
2025-11-06 00:29:37.645739 | controller | a3443c4a17ed: Pull complete
2025-11-06 00:29:39.659298 | controller | 0edcf9fb2b15: Pull complete
2025-11-06 00:29:42.709929 | controller | 5af43b69e845: Pull complete
2025-11-06 00:29:45.953950 | controller | 1651773effb2: Pull complete
2025-11-06 00:29:49.513035 | controller | 79e23c5c0fe4: Pull complete
2025-11-06 00:29:52.103062 | controller | e5058b1faaa6: Pull complete
2025-11-06 00:29:55.534102 | controller | 846775490569: Pull complete
2025-11-06 00:29:55.559314 | controller | Digest: sha256:923f4b465456ae05243474faf9061abbefa2c2c5b88f24455fa2d5ce3d8d2ab4
2025-11-06 00:29:55.563004 | controller | Status: Downloaded newer image for quay.io/ansible/default-test-container:2.9.0
2025-11-06 00:29:55.569895 | controller | quay.io/ansible/default-test-container:2.9.0
2025-11-06 00:29:55.574009 | controller | Run command: docker images quay.io/ansible/pypi-test-container:1.0.0 --format '{{json .}}'
2025-11-06 00:29:55.605703 | controller | Run command: docker pull quay.io/ansible/pypi-test-container:1.0.0
2025-11-06 00:29:57.080223 | controller | 1.0.0: Pulling from ansible/pypi-test-container
2025-11-06 00:29:57.081001 | controller | 04a5f4cda3ee: Pulling fs layer
2025-11-06 00:29:57.081033 | controller | ff496a88c8ed: Pulling fs layer
2025-11-06 00:29:57.081040 | controller | 0ce83f459fe7: Pulling fs layer
2025-11-06 00:29:57.081049 | controller | 2e5170e1f099: Pulling fs layer
2025-11-06 00:29:57.081164 | controller | 7641eb41b08c: Pulling fs layer
2025-11-06 00:29:57.081174 | controller | ad15fa9da398: Pulling fs layer
2025-11-06 00:29:57.081184 | controller | 087d91352424: Pulling fs layer
2025-11-06 00:29:57.081280 | controller | 8b92efd6a100: Pulling fs layer
2025-11-06 00:29:57.081290 | controller | 2e5170e1f099: Waiting
2025-11-06 00:29:57.081300 | controller | 7641eb41b08c: Waiting
2025-11-06 00:29:57.081335 | controller | ad15fa9da398: Waiting
2025-11-06 00:29:57.081412 | controller | 087d91352424: Waiting
2025-11-06 00:29:57.081454 | controller | 8b92efd6a100: Waiting
2025-11-06 00:29:57.455272 | controller | 0ce83f459fe7: Verifying Checksum
2025-11-06 00:29:57.455504 | controller | 0ce83f459fe7: Download complete
2025-11-06 00:29:57.485704 | controller | ff496a88c8ed: Verifying Checksum
2025-11-06 00:29:57.741505 | controller | ff496a88c8ed: Download complete
2025-11-06 00:29:57.741587 | controller | 04a5f4cda3ee: Verifying Checksum
2025-11-06 00:29:57.957508 | controller | 04a5f4cda3ee: Download complete
2025-11-06 00:29:57.957583 | controller | 7641eb41b08c: Verifying Checksum
2025-11-06 00:29:58.134734 | controller | 7641eb41b08c: Download complete
2025-11-06 00:29:58.134810 | controller | 2e5170e1f099: Verifying Checksum
2025-11-06 00:29:58.154290 | controller | 2e5170e1f099: Download complete
2025-11-06 00:29:58.154357 | controller | ad15fa9da398: Verifying Checksum
2025-11-06 00:29:58.526314 | controller | ad15fa9da398: Download complete
2025-11-06 00:29:58.526402 | controller | 8b92efd6a100: Verifying Checksum
2025-11-06 00:29:58.544539 | controller | 8b92efd6a100: Download complete
2025-11-06 00:29:58.544618 | controller | 087d91352424: Verifying Checksum
2025-11-06 00:30:00.672506 | controller | 087d91352424: Download complete
2025-11-06 00:30:00.672591 | controller | 04a5f4cda3ee: Pull complete
2025-11-06 00:30:00.704039 | controller | ff496a88c8ed: Pull complete
2025-11-06 00:30:00.726959 | controller | 0ce83f459fe7: Pull complete
2025-11-06 00:30:02.764019 | controller | 2e5170e1f099: Pull complete
2025-11-06 00:30:02.814505 | controller | 7641eb41b08c: Pull complete
2025-11-06 00:30:02.846386 | controller | ad15fa9da398: Pull complete
2025-11-06 00:30:04.180838 | controller | 087d91352424: Pull complete
2025-11-06 00:30:04.202814 | controller | 8b92efd6a100: Pull complete
2025-11-06 00:30:04.244150 | controller | Digest: sha256:71042ab0a14971b5608fe75706de54f367fc31db573e3b3955182037f73cadb6
2025-11-06 00:30:04.251792 | controller | Status: Downloaded newer image for quay.io/ansible/pypi-test-container:1.0.0
2025-11-06 00:30:04.262725 | controller | quay.io/ansible/pypi-test-container:1.0.0
2025-11-06 00:30:04.265716 | controller | Run command: docker run --detach quay.io/ansible/pypi-test-container:1.0.0
2025-11-06 00:30:04.883777 | controller | Run command: docker inspect d14058a61be644980f9ee8ca82544b1c8fd56aa30f5134002a8097f496fcf0f9
2025-11-06 00:30:04.961347 | controller | Scanning collection root: /home/zuul/.ansible/collections/ansible_collections
2025-11-06 00:30:04.975681 | controller | Including collection: ansible.netcommon (288 files)
2025-11-06 00:30:04.988978 | controller | Including collection: ansible.network (23 files)
2025-11-06 00:30:04.989026 | controller | Including collection: ansible.utils (442 files)
2025-11-06 00:30:05.026643 | controller | Including collection: arista.eos (1022 files)
2025-11-06 00:30:05.075442 | controller | Including collection: cisco.ios (1172 files)
2025-11-06 00:30:05.121104 | controller | Including collection: cisco.iosxr (1043 files)
2025-11-06 00:30:05.193826 | controller | Including collection: cisco.nxos (1680 files)
2025-11-06 00:30:05.232935 | controller | Including collection: junipernetworks.junos (963 files)
2025-11-06 00:30:05.270689 | controller | Creating a payload archive containing 7359 files...
2025-11-06 00:30:07.277211 | controller | Created a 5970375 byte payload archive containing 7359 files in 2 seconds.
2025-11-06 00:30:07.283488 | controller | Assuming Docker is available on localhost.
2025-11-06 00:30:07.284081 | controller | Run command: docker run --detach --volume /sys/fs/cgroup:/sys/fs/cgroup:ro --privileged=false --security-opt seccomp=unconfined --volume /var/run/docker.sock:/var/run/docker.sock quay.io/ansible/default-test-container:2.9.0
2025-11-06 00:30:07.769594 | controller | Run command: docker exec -i be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 dd of=/root/docker.sh bs=65536
2025-11-06 00:30:07.861132 | controller | Run command: docker exec be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 /bin/bash /root/docker.sh
2025-11-06 00:30:07.935282 | controller | Run command: docker exec -i be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 dd of=/root/test.tgz bs=65536
2025-11-06 00:30:08.045931 | controller | Run command: docker exec be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 tar oxzf /root/test.tgz -C /root
2025-11-06 00:30:09.544525 | controller | Run command: docker exec be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 /usr/bin/env ANSIBLE_TEST_CONTENT_ROOT=/root/ansible_collections/ansible/network LC_ALL=en_US.UTF-8 /usr/bin/python3.6 /root/ansible/bin/ansible-test sanity -v --metadata tests/output/.tmp/metadata-apathrrz.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/
2025-11-06 00:30:09.937788 | controller | Injecting custom PyPI hosts entries: /etc/hosts
2025-11-06 00:30:09.938325 | controller | Injecting custom PyPI config: /root/.pip/pip.conf
2025-11-06 00:30:09.940293 | controller | Injecting custom PyPI config: /root/.pydistutils.cfg
2025-11-06 00:30:09.943240 | controller | Running sanity test 'action-plugin-docs' with Python 3.6
2025-11-06 00:30:09.944194 | controller | Read 0 sanity test ignore line(s) for Ansible 2.10 from: tests/sanity/ignore-2.10.txt
2025-11-06 00:30:09.951108 | controller | No tests applicable.
2025-11-06 00:30:09.951299 | controller | Running sanity test 'ansible-doc' with Python 3.6
2025-11-06 00:30:09.951614 | controller | No tests applicable.
2025-11-06 00:30:09.951821 | controller | Running sanity test 'changelog' with Python 3.6
2025-11-06 00:30:09.952458 | controller | Run command: /usr/bin/python3.6 /root/ansible/test/lib/ansible_test/_data/quiet_pip.py install --disable-pip-version-check -r /root/ansible/test/lib/ansible_test/_data/requirements/ansible-test.txt
2025-11-06 00:30:10.837097 | controller | Run command: /usr/bin/python3.6 /root/ansible/test/lib/ansible_test/_data/quiet_pip.py install --disable-pip-version-check -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt -c /root/ansible/test/lib/ansible_test/_data/requirements/constraints.txt
2025-11-06 00:30:11.387313 | controller | Collecting antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-11-06 00:30:26.395834 | controller |   WARNING: Retrying (Retry(total=4, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-11-06 00:30:41.912965 | controller |   WARNING: Retrying (Retry(total=3, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-11-06 00:30:57.918608 | controller |   WARNING: Retrying (Retry(total=2, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-11-06 00:31:14.938026 | controller |   WARNING: Retrying (Retry(total=1, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-11-06 00:31:33.958291 | controller |   WARNING: Retrying (Retry(total=0, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-11-06 00:31:48.973216 | controller |   ERROR: Could not find a version that satisfies the requirement antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2)) (from versions: none)
2025-11-06 00:31:49.068236 | controller | ERROR: No matching distribution found for antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-11-06 00:31:49.068296 | controller | ERROR: Command "/usr/bin/python3.6 /root/ansible/test/lib/ansible_test/_data/quiet_pip.py install --disable-pip-version-check -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt -c /root/ansible/test/lib/ansible_test/_data/requirements/constraints.txt" returned exit status 1.
2025-11-06 00:31:49.109714 | controller | Removing custom PyPI config: /root/.pydistutils.cfg
2025-11-06 00:31:49.109777 | controller | Removing custom PyPI config: /root/.pip/pip.conf
2025-11-06 00:31:49.109785 | controller | Removing custom PyPI hosts entries: /etc/hosts
2025-11-06 00:31:49.109815 | controller | Run command: docker exec be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 tar czf /root/output.tgz --exclude .tmp -C /root/ansible_collections/ansible/network/tests output
2025-11-06 00:31:49.190919 | controller | Run command: docker exec -i be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 dd if=/root/output.tgz bs=65536
2025-11-06 00:31:49.270221 | controller | Run command: tar oxzf /tmp/ansible-result-v643omo0.tgz -C /home/zuul/.ansible/collections/ansible_collections/ansible/network/tests
2025-11-06 00:31:49.284764 | controller | Run command: docker rm -f d14058a61be644980f9ee8ca82544b1c8fd56aa30f5134002a8097f496fcf0f9
2025-11-06 00:31:49.541307 | controller | Run command: docker rm -f be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50
2025-11-06 00:31:50.189767 | controller | ERROR: Command "docker exec be9e15f1215eba5c83e526a2cc83fe1424b18b657759ecd5a814888c0337cb50 /usr/bin/env ANSIBLE_TEST_CONTENT_ROOT=/root/ansible_collections/ansible/network LC_ALL=en_US.UTF-8 /usr/bin/python3.6 /root/ansible/bin/ansible-test sanity -v --metadata tests/output/.tmp/metadata-apathrrz.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/" returned exit status 1.
2025-11-06 00:31:50.815533 | controller | ERROR
2025-11-06 00:31:50.815800 | controller | {
2025-11-06 00:31:50.815829 | controller |   "delta": "0:03:19.015507",
2025-11-06 00:31:50.815847 | controller |   "end": "2025-11-06 00:31:50.267014",
2025-11-06 00:31:50.815865 | controller |   "msg": "non-zero return code",
2025-11-06 00:31:50.815881 | controller |   "rc": 1,
2025-11-06 00:31:50.815898 | controller |   "start": "2025-11-06 00:28:31.251507"
2025-11-06 00:31:50.815913 | controller | }
failure
2025-11-06 00:31:50.821122 | 
2025-11-06 00:31:50.821222 | PLAY RECAP
2025-11-06 00:31:50.821272 | controller | ok: 21 changed: 5 unreachable: 0 failed: 1 skipped: 20 rescued: 0 ignored: 1
2025-11-06 00:31:50.821297 | 
2025-11-06 00:31:50.990907 | RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-11-06 00:31:50.992377 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-06 00:31:51.614845 | 
2025-11-06 00:31:51.615026 | PLAY [all]
2025-11-06 00:31:51.639542 | 
2025-11-06 00:31:51.639725 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-06 00:31:54.609452 | controller | changed: non-zero return code
2025-11-06 00:31:54.624234 | 
2025-11-06 00:31:54.624498 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-06 00:31:54.642428 | controller | skipping: Conditional result was False
2025-11-06 00:31:54.655220 | 
2025-11-06 00:31:54.655382 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-06 00:31:54.687508 | 
2025-11-06 00:31:54.687704 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-06 00:31:54.723304 | 
2025-11-06 00:31:54.723657 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-06 00:31:54.751771 | controller | skipping: Conditional result was False
2025-11-06 00:31:54.767167 | 
2025-11-06 00:31:54.767391 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-06 00:31:54.809006 | 
2025-11-06 00:31:54.809465 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-06 00:31:54.827061 | controller | skipping: Conditional result was False
2025-11-06 00:31:54.844074 | 
2025-11-06 00:31:54.844277 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-06 00:31:54.860565 | controller | skipping: Conditional result was False
2025-11-06 00:31:54.870322 | 
2025-11-06 00:31:54.870456 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-06 00:31:54.885613 | controller | skipping: Conditional result was False
2025-11-06 00:31:54.929666 | 
2025-11-06 00:31:54.929801 | PLAY RECAP
2025-11-06 00:31:54.929847 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-06 00:31:54.929868 | 
2025-11-06 00:31:55.058475 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-06 00:31:55.059617 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-06 00:31:55.739023 | 
2025-11-06 00:31:55.739361 | PLAY [all:!appliance*]
2025-11-06 00:31:55.778019 | 
2025-11-06 00:31:55.778205 | TASK [unregister the node]
2025-11-06 00:31:56.136582 | controller | skipping: Conditional result was False
2025-11-06 00:31:56.143405 | 
2025-11-06 00:31:56.143550 | TASK [include_role : fetch-output]
2025-11-06 00:31:56.177967 | controller | ok
2025-11-06 00:31:56.205582 | 
2025-11-06 00:31:56.205776 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-06 00:31:56.272923 | controller | skipping: Conditional result was False
2025-11-06 00:31:56.281344 | 
2025-11-06 00:31:56.281528 | TASK [fetch-output : Set log path for single node]
2025-11-06 00:31:56.325924 | controller | ok
2025-11-06 00:31:56.331514 | 
2025-11-06 00:31:56.331597 | LOOP [fetch-output : Ensure local output dirs]
2025-11-06 00:31:56.815515 | controller -> localhost | ok: "/var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/logs"
2025-11-06 00:31:57.076812 | controller -> localhost | changed: "/var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/artifacts"
2025-11-06 00:31:57.351242 | controller -> localhost | changed: "/var/lib/zuul/builds/0fa85b9d7445435990f6f44f7e423d06/work/docs"
2025-11-06 00:31:57.372845 | 
2025-11-06 00:31:57.373118 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-06 00:31:59.691713 | controller | changed:
2025-11-06 00:31:59.692255 | controller | .d..t...... ./
2025-11-06 00:31:59.692320 | controller | cd+++++++++ controller/
2025-11-06 00:31:59.692397 | controller | changed: All items complete
2025-11-06 00:31:59.692442 | 
2025-11-06 00:32:01.748096 | controller | changed: .d..t...... ./
2025-11-06 00:32:03.755187 | controller | changed: .d..t...... ./
2025-11-06 00:32:03.779157 | 
2025-11-06 00:32:03.779378 | TASK [include_role : fetch-output-openshift]
2025-11-06 00:32:03.798117 | controller | skipping: Conditional result was False
2025-11-06 00:32:03.809426 | 
2025-11-06 00:32:03.809599 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-06 00:32:03.842458 | controller | skipping: Conditional result was False
2025-11-06 00:32:03.853424 | controller | skipping: Conditional result was False
2025-11-06 00:32:03.901544 | 
2025-11-06 00:32:03.901751 | PLAY [localhost]
2025-11-06 00:32:03.921774 | 
2025-11-06 00:32:03.921949 | TASK [Run Zuul manifest role]
2025-11-06 00:32:03.943586 | localhost | ok
2025-11-06 00:32:03.958956 | 
2025-11-06 00:32:03.959082 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-06 00:32:04.335500 | localhost | changed
2025-11-06 00:32:04.340744 | 
2025-11-06 00:32:04.340861 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-06 00:32:04.370627 | localhost | ok
2025-11-06 00:32:04.379598 | 
2025-11-06 00:32:04.379755 | TASK [Set zuul-log-path fact]
2025-11-06 00:32:04.401660 | localhost | ok
2025-11-06 00:32:04.459898 | 
2025-11-06 00:32:04.460082 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-06 00:32:04.489250 | localhost | ok
2025-11-06 00:32:04.497600 | 
2025-11-06 00:32:04.497679 | LOOP [Run upload-logs-swift role]
2025-11-06 00:32:04.522062 | localhost | Output suppressed because no_log was given
2025-11-06 00:32:04.548455 | 
2025-11-06 00:32:04.548602 | TASK [Set zuul-log-path fact]
2025-11-06 00:32:04.573640 | localhost | skipping: Conditional result was False
2025-11-06 00:32:04.583093 | 
2025-11-06 00:32:04.583268 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-06 00:32:05.009301 | localhost -> localhost | ok: Runtime: 0:00:00.006361
2025-11-06 00:32:05.022138 | 
2025-11-06 00:32:05.022312 | TASK [upload-logs-swift : Upload logs to swift]