2025-10-11 00:06:33.559000 | Job console starting...
2025-10-11 00:06:33.567948 | Updating repositories
2025-10-11 00:06:33.773618 | Preparing job workspace
2025-10-11 00:06:37.449539 | Running Ansible setup...
2025-10-11 00:06:47.038812 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-11 00:06:47.610866 | 
2025-10-11 00:06:47.611034 | PLAY [localhost]
2025-10-11 00:06:47.619068 | 
2025-10-11 00:06:47.619137 | TASK [Gathering Facts]
2025-10-11 00:06:48.602987 | localhost | ok
2025-10-11 00:06:48.617645 | 
2025-10-11 00:06:48.617757 | TASK [Setup log path fact]
2025-10-11 00:06:48.646311 | localhost | ok
2025-10-11 00:06:48.658664 | 
2025-10-11 00:06:48.658752 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-11 00:06:48.686606 | localhost | ok
2025-10-11 00:06:48.695750 | 
2025-10-11 00:06:48.695834 | TASK [emit-job-header : Print job information]
2025-10-11 00:06:48.724252 | # Job Information
2025-10-11 00:06:48.724449 | Ansible Version: 2.15.12
2025-10-11 00:06:48.724484 | Job: ansible-test-sanity-docker-devel
2025-10-11 00:06:48.724506 | Pipeline: periodic
2025-10-11 00:06:48.724525 | Executor: ze04.softwarefactory-project.io
2025-10-11 00:06:48.724543 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-11 00:06:48.724564 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/c3b/ansible/c3bd83602d7e4180a52dae67d274c9cb/
2025-10-11 00:06:48.724582 | Event ID: d6ccd92d500144d2bcd347dd8f427b4a
2025-10-11 00:06:48.728568 | 
2025-10-11 00:06:48.728637 | LOOP [emit-job-header : Print node information]
2025-10-11 00:06:48.823693 | localhost | ok:
2025-10-11 00:06:48.823890 | localhost | # Node Information
2025-10-11 00:06:48.823918 | localhost | Inventory Hostname: controller
2025-10-11 00:06:48.823939 | localhost | Hostname: ip-172-16-202-50
2025-10-11 00:06:48.823957 | localhost | Username: zuul-worker
2025-10-11 00:06:48.823977 | localhost | Distro: Fedora 37
2025-10-11 00:06:48.823996 | localhost | Provider: ansible-us-east-2
2025-10-11 00:06:48.824014 | localhost | Region: us-east-2
2025-10-11 00:06:48.824032 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-11 00:06:48.824049 | localhost | Product Name: t3.small
2025-10-11 00:06:48.824066 | localhost | Interface IP: 3.15.156.201
2025-10-11 00:06:48.842713 | 
2025-10-11 00:06:48.842832 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-11 00:06:49.257538 | localhost -> localhost | changed
2025-10-11 00:06:49.262997 | 
2025-10-11 00:06:49.263062 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-11 00:06:50.198893 | localhost -> localhost | changed
2025-10-11 00:06:50.219708 | 
2025-10-11 00:06:50.219784 | PLAY [all:!appliance*]
2025-10-11 00:06:50.247609 | 
2025-10-11 00:06:50.247692 | TASK [include_role : start-zuul-console]
2025-10-11 00:06:50.276612 | controller | ok
2025-10-11 00:06:50.298335 | 
2025-10-11 00:06:50.298397 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-11 00:06:50.959424 | controller | ok
2025-10-11 00:06:50.972112 | 
2025-10-11 00:06:50.972180 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-11 00:06:52.529282 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-11 00:06:52.535412 | 
2025-10-11 00:06:52.535471 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-11 00:06:52.680813 | controller | skipping: Conditional result was False
2025-10-11 00:06:52.689834 | 
2025-10-11 00:06:52.689903 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-11 00:06:52.732221 | controller | skipping: Conditional result was False
2025-10-11 00:06:52.738966 | 
2025-10-11 00:06:52.739059 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-11 00:06:52.774511 | controller | skipping: Conditional result was False
2025-10-11 00:06:52.781505 | 
2025-10-11 00:06:52.781582 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-11 00:06:52.796674 | controller | skipping: Conditional result was False
2025-10-11 00:06:52.803599 | 
2025-10-11 00:06:52.803674 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-11 00:06:52.819540 | controller | skipping: Conditional result was False
2025-10-11 00:06:52.826839 | 
2025-10-11 00:06:52.826930 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-11 00:06:52.842630 | controller | skipping: Conditional result was False
2025-10-11 00:06:52.858856 | 
2025-10-11 00:06:52.858948 | TASK [Disable Fedora Modular]
2025-10-11 00:06:53.630174 | controller | changed
2025-10-11 00:06:53.635751 | 
2025-10-11 00:06:53.635811 | TASK [Enable EPEL]
2025-10-11 00:06:53.649137 | controller | skipping: Conditional result was False
2025-10-11 00:06:53.656577 | 
2025-10-11 00:06:53.656652 | TASK [Register the RHEL node]
2025-10-11 00:06:53.812606 | 
2025-10-11 00:06:53.812819 | TASK [Show the subscription-manager status]
2025-10-11 00:06:53.965788 | controller | skipping: Conditional result was False
2025-10-11 00:06:54.039150 | 
2025-10-11 00:06:54.039329 | TASK [Enable EPEL on RHEL]
2025-10-11 00:06:54.217697 | controller | skipping: Conditional result was False
2025-10-11 00:06:54.223482 | 
2025-10-11 00:06:54.223548 | TASK [Install git and tox]
2025-10-11 00:08:22.369304 | controller | changed
2025-10-11 00:08:22.385104 | 
2025-10-11 00:08:22.385275 | TASK [include_role : prepare-workspace]
2025-10-11 00:08:22.415988 | controller | ok
2025-10-11 00:08:22.449494 | 
2025-10-11 00:08:22.449630 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-11 00:08:22.933003 | controller | ok
2025-10-11 00:08:22.952314 | 
2025-10-11 00:08:22.952485 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-11 00:08:37.048041 | controller | Output suppressed because no_log was given
2025-10-11 00:08:37.062753 | 
2025-10-11 00:08:37.062832 | TASK [include_role : prepare-workspace-openshift]
2025-10-11 00:08:37.086851 | controller | skipping: Conditional result was False
2025-10-11 00:08:37.108459 | 
2025-10-11 00:08:37.108535 | PLAY [all:!appliance]
2025-10-11 00:08:37.130043 | 
2025-10-11 00:08:37.130193 | TASK [Run add-build-sshkey role (RSA)]
2025-10-11 00:08:37.163104 | controller | ok
2025-10-11 00:08:37.183219 | 
2025-10-11 00:08:37.183367 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-11 00:08:37.423460 | controller -> localhost | ok
2025-10-11 00:08:37.438907 | 
2025-10-11 00:08:37.439091 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-11 00:08:37.533030 | controller | ok
2025-10-11 00:08:37.549843 | controller | included: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-11 00:08:37.555960 | 
2025-10-11 00:08:37.556055 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-11 00:08:38.038333 | controller -> localhost | Generating public/private rsa key pair.
2025-10-11 00:08:38.038639 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/c3bd83602d7e4180a52dae67d274c9cb_id_rsa.
2025-10-11 00:08:38.038716 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/c3bd83602d7e4180a52dae67d274c9cb_id_rsa.pub.
2025-10-11 00:08:38.038757 | controller -> localhost | The key fingerprint is:
2025-10-11 00:08:38.038793 | controller -> localhost | SHA256:a/c9RzHH4XIVbzC5Yyus/RgrSJfGfdLxbjgGhWdm3qg zuul-build-sshkey
2025-10-11 00:08:38.038827 | controller -> localhost | The key's randomart image is:
2025-10-11 00:08:38.038860 | controller -> localhost | +---[RSA 2048]----+
2025-10-11 00:08:38.038893 | controller -> localhost | |              oo.|
2025-10-11 00:08:38.038927 | controller -> localhost | |              .+o|
2025-10-11 00:08:38.038960 | controller -> localhost | |             ..o=|
2025-10-11 00:08:38.038993 | controller -> localhost | |            ..@*o|
2025-10-11 00:08:38.039025 | controller -> localhost | |        S. + XoB+|
2025-10-11 00:08:38.039068 | controller -> localhost | |        ..= * * +|
2025-10-11 00:08:38.039111 | controller -> localhost | |       .o+.o.* + |
2025-10-11 00:08:38.039145 | controller -> localhost | |       ...o.E== +|
2025-10-11 00:08:38.039179 | controller -> localhost | |           .+oo= |
2025-10-11 00:08:38.039213 | controller -> localhost | +----[SHA256]-----+
2025-10-11 00:08:38.039286 | controller -> localhost | ok: Runtime: 0:00:00.170203
2025-10-11 00:08:38.060399 | 
2025-10-11 00:08:38.060560 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-11 00:08:38.088526 | controller | ok
2025-10-11 00:08:38.105043 | controller | included: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-11 00:08:38.114967 | 
2025-10-11 00:08:38.115068 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-11 00:08:38.129038 | controller | skipping: Conditional result was False
2025-10-11 00:08:38.136187 | 
2025-10-11 00:08:38.136262 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-11 00:08:38.728649 | controller | changed
2025-10-11 00:08:38.737520 | 
2025-10-11 00:08:38.737600 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-11 00:08:39.099083 | controller | ok
2025-10-11 00:08:39.111380 | 
2025-10-11 00:08:39.111510 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-11 00:08:40.408425 | controller | changed
2025-10-11 00:08:40.421016 | 
2025-10-11 00:08:40.421145 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-11 00:08:41.708508 | controller | changed
2025-10-11 00:08:41.718023 | 
2025-10-11 00:08:41.718152 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-11 00:08:41.744303 | controller | skipping: Conditional result was False
2025-10-11 00:08:41.754856 | 
2025-10-11 00:08:41.754968 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-11 00:08:42.120736 | controller -> localhost | changed
2025-10-11 00:08:42.138071 | 
2025-10-11 00:08:42.138195 | TASK [add-build-sshkey : Add back temp key]
2025-10-11 00:08:42.440385 | controller -> localhost | Identity added: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/c3bd83602d7e4180a52dae67d274c9cb_id_rsa (zuul-build-sshkey)
2025-10-11 00:08:42.440775 | controller -> localhost | ok: Runtime: 0:00:00.012631
2025-10-11 00:08:42.454462 | 
2025-10-11 00:08:42.454626 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-11 00:08:42.884988 | controller | ok
2025-10-11 00:08:42.890468 | 
2025-10-11 00:08:42.890531 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-11 00:08:42.914108 | controller | skipping: Conditional result was False
2025-10-11 00:08:42.924976 | 
2025-10-11 00:08:42.925040 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-11 00:08:42.943838 | controller | ok
2025-10-11 00:08:42.961728 | 
2025-10-11 00:08:42.961835 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-11 00:08:43.262597 | controller -> localhost | ok
2025-10-11 00:08:43.274022 | 
2025-10-11 00:08:43.274113 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-11 00:08:43.315167 | controller | ok
2025-10-11 00:08:43.326451 | controller | included: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-11 00:08:43.333341 | 
2025-10-11 00:08:43.333405 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-11 00:08:43.643645 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-11 00:08:43.644059 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/c3bd83602d7e4180a52dae67d274c9cb_id_ecdsa.
2025-10-11 00:08:43.644120 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/c3bd83602d7e4180a52dae67d274c9cb_id_ecdsa.pub.
2025-10-11 00:08:43.644179 | controller -> localhost | The key fingerprint is:
2025-10-11 00:08:43.644224 | controller -> localhost | SHA256:qpovjoSIwTBfFxpDJScQ7dYcbPdew7EYS+KXwijtl3A zuul-build-sshkey
2025-10-11 00:08:43.644268 | controller -> localhost | The key's randomart image is:
2025-10-11 00:08:43.644310 | controller -> localhost | +---[ECDSA 521]---+
2025-10-11 00:08:43.644351 | controller -> localhost | |  o=*o+          |
2025-10-11 00:08:43.644391 | controller -> localhost | |    .B+.o o .    |
2025-10-11 00:08:43.644432 | controller -> localhost | |o  .o=.* + * o   |
2025-10-11 00:08:43.644472 | controller -> localhost | |oo .+.* E * =    |
2025-10-11 00:08:43.644511 | controller -> localhost | |.... o oS= . .   |
2025-10-11 00:08:43.644550 | controller -> localhost | |+.    ..o .      |
2025-10-11 00:08:43.644589 | controller -> localhost | |+.    ..         |
2025-10-11 00:08:43.644629 | controller -> localhost | |.... .           |
2025-10-11 00:08:43.644669 | controller -> localhost | |..++o            |
2025-10-11 00:08:43.644766 | controller -> localhost | +----[SHA256]-----+
2025-10-11 00:08:43.644867 | controller -> localhost | ok: Runtime: 0:00:00.018030
2025-10-11 00:08:43.658572 | 
2025-10-11 00:08:43.658755 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-11 00:08:43.699019 | controller | ok
2025-10-11 00:08:43.713903 | controller | included: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-11 00:08:43.726941 | 
2025-10-11 00:08:43.727087 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-11 00:08:43.752831 | controller | skipping: Conditional result was False
2025-10-11 00:08:43.761281 | 
2025-10-11 00:08:43.761369 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-11 00:08:44.223103 | controller | changed
2025-10-11 00:08:44.231130 | 
2025-10-11 00:08:44.231221 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-11 00:08:44.577883 | controller | ok
2025-10-11 00:08:44.583833 | 
2025-10-11 00:08:44.583897 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-11 00:08:46.409143 | controller | changed
2025-10-11 00:08:46.424007 | 
2025-10-11 00:08:46.424171 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-11 00:08:47.984527 | controller | changed
2025-10-11 00:08:47.999370 | 
2025-10-11 00:08:47.999525 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-11 00:08:48.031082 | controller | skipping: Conditional result was False
2025-10-11 00:08:48.048333 | 
2025-10-11 00:08:48.048602 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-11 00:08:48.346067 | controller -> localhost | changed
2025-10-11 00:08:48.378315 | 
2025-10-11 00:08:48.378462 | TASK [add-build-sshkey : Add back temp key]
2025-10-11 00:08:48.690813 | controller -> localhost | Identity added: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/c3bd83602d7e4180a52dae67d274c9cb_id_ecdsa (zuul-build-sshkey)
2025-10-11 00:08:48.691027 | controller -> localhost | ok: Runtime: 0:00:00.013389
2025-10-11 00:08:48.700301 | 
2025-10-11 00:08:48.700431 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-11 00:08:49.068351 | controller | ok
2025-10-11 00:08:49.083285 | 
2025-10-11 00:08:49.083455 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-11 00:08:49.120474 | controller | skipping: Conditional result was False
2025-10-11 00:08:49.135640 | 
2025-10-11 00:08:49.135920 | TASK [include_role : remove-zuul-sshkey]
2025-10-11 00:08:49.160785 | controller | skipping: Conditional result was False
2025-10-11 00:08:49.171389 | 
2025-10-11 00:08:49.171515 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-11 00:08:49.507339 | controller | ok: "logs"
2025-10-11 00:08:49.507584 | controller | ok: All items complete
2025-10-11 00:08:49.507636 | 
2025-10-11 00:08:49.801992 | controller | ok: "artifacts"
2025-10-11 00:08:50.130023 | controller | ok: "docs"
2025-10-11 00:08:50.146391 | 
2025-10-11 00:08:50.146496 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-11 00:08:50.547403 | controller | changed: "logs"
2025-10-11 00:08:50.847259 | controller | changed: "artifacts"
2025-10-11 00:08:51.158259 | controller | changed: "docs"
2025-10-11 00:08:51.209506 | 
2025-10-11 00:08:51.209635 | PLAY RECAP
2025-10-11 00:08:51.209719 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-11 00:08:51.209764 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-11 00:08:51.209792 | 
2025-10-11 00:08:51.320112 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-11 00:08:51.320990 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-11 00:08:51.962411 | 
2025-10-11 00:08:51.962578 | PLAY [all]
2025-10-11 00:08:51.988873 | 
2025-10-11 00:08:51.989047 | TASK [Install binary dependencies]
2025-10-11 00:08:52.062880 | controller | ok
2025-10-11 00:08:52.088236 | 
2025-10-11 00:08:52.088411 | TASK [bindep : Include find tasks]
2025-10-11 00:08:52.120950 | controller | ok
2025-10-11 00:08:52.130435 | controller | included: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-11 00:08:52.138535 | 
2025-10-11 00:08:52.138641 | TASK [bindep : Look for bindep.txt]
2025-10-11 00:08:52.919493 | controller | ok
2025-10-11 00:08:52.934252 | 
2025-10-11 00:08:52.934404 | TASK [bindep : Define bindep_file fact]
2025-10-11 00:08:52.962343 | controller | skipping: Conditional result was False
2025-10-11 00:08:52.975111 | 
2025-10-11 00:08:52.975231 | TASK [bindep : Look for other-requirements.txt]
2025-10-11 00:08:53.330468 | controller | ok
2025-10-11 00:08:53.343762 | 
2025-10-11 00:08:53.343983 | TASK [bindep : Define bindep_file fact]
2025-10-11 00:08:53.382050 | controller | skipping: Conditional result was False
2025-10-11 00:08:53.401859 | 
2025-10-11 00:08:53.402110 | TASK [bindep : Look for bindep fallback file]
2025-10-11 00:08:53.441849 | controller | skipping: Conditional result was False
2025-10-11 00:08:53.450489 | 
2025-10-11 00:08:53.450595 | TASK [bindep : Define bindep_file fact]
2025-10-11 00:08:53.475921 | controller | skipping: Conditional result was False
2025-10-11 00:08:53.491847 | 
2025-10-11 00:08:53.492037 | TASK [bindep : Include bindep tasks]
2025-10-11 00:08:53.527549 | controller | skipping: Conditional result was False
2025-10-11 00:08:53.544753 | 
2025-10-11 00:08:53.544958 | TASK [bindep : Include install tasks]
2025-10-11 00:08:53.584779 | controller | skipping: Conditional result was False
2025-10-11 00:08:53.598958 | 
2025-10-11 00:08:53.599138 | LOOP [bindep : Include package tasks]
2025-10-11 00:08:53.672645 | 
2025-10-11 00:08:53.672899 | TASK [Run test-setup role]
2025-10-11 00:08:53.696255 | controller | ok
2025-10-11 00:08:53.723620 | 
2025-10-11 00:08:53.723794 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-11 00:08:54.130126 | controller | ok
2025-10-11 00:08:54.142928 | 
2025-10-11 00:08:54.143070 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-11 00:08:54.305041 | controller | skipping: Conditional result was False
2025-10-11 00:08:54.348664 | 
2025-10-11 00:08:54.348835 | PLAY RECAP
2025-10-11 00:08:54.348894 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-11 00:08:54.348921 | 
2025-10-11 00:08:54.465468 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-11 00:08:54.466532 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-11 00:08:55.190167 | 
2025-10-11 00:08:55.190417 | PLAY [controller]
2025-10-11 00:08:55.214544 | 
2025-10-11 00:08:55.214781 | TASK [Create the /root directory]
2025-10-11 00:08:56.012560 | controller | ok
2025-10-11 00:08:56.025023 | 
2025-10-11 00:08:56.025176 | TASK [Install glibc-langpack-en]
2025-10-11 00:09:04.162021 | controller | ok: Nothing to do
2025-10-11 00:09:04.170526 | 
2025-10-11 00:09:04.170635 | TASK [Ensure controller directory exists]
2025-10-11 00:09:04.606824 | controller | changed
2025-10-11 00:09:04.618404 | 
2025-10-11 00:09:04.618548 | TASK [Install container runtime]
2025-10-11 00:09:04.688486 | controller | ok
2025-10-11 00:09:04.750363 | 
2025-10-11 00:09:04.750518 | LOOP [ensure-podman : Find distribution installation]
2025-10-11 00:09:04.798654 | controller | ok: "/var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-11 00:09:04.809480 | controller | included: /var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-11 00:09:04.818792 | 
2025-10-11 00:09:04.818890 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-11 00:10:22.008235 | controller | changed
2025-10-11 00:10:22.017314 | 
2025-10-11 00:10:22.017402 | TASK [ensure-podman : Fetch podman version]
2025-10-11 00:10:22.759440 | controller | Client:       Podman Engine
2025-10-11 00:10:22.759521 | controller | Version:      4.6.2
2025-10-11 00:10:22.759552 | controller | API Version:  4.6.2
2025-10-11 00:10:22.759579 | controller | Go Version:   go1.19.12
2025-10-11 00:10:22.759622 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-11 00:10:22.759650 | controller | OS/Arch:      linux/amd64
2025-10-11 00:10:23.171223 | controller | ok: Runtime: 0:00:00.227633
2025-10-11 00:10:23.178392 | 
2025-10-11 00:10:23.178511 | TASK [ensure-podman : Print podman version installed]
2025-10-11 00:10:23.220945 | Podman version: Client:       Podman Engine
2025-10-11 00:10:23.221146 | Version:      4.6.2
2025-10-11 00:10:23.221205 | API Version:  4.6.2
2025-10-11 00:10:23.221235 | Go Version:   go1.19.12
2025-10-11 00:10:23.221265 | Built:        Mon Aug 28 19:38:31 2023
2025-10-11 00:10:23.221294 | OS/Arch:      linux/amd64
2025-10-11 00:10:23.228126 | 
2025-10-11 00:10:23.228214 | TASK [ensure-podman : Validate podman engine]
2025-10-11 00:10:23.357627 | controller | skipping: Conditional result was False
2025-10-11 00:10:23.364006 | 
2025-10-11 00:10:23.364085 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-11 00:10:23.378559 | controller | skipping: Conditional result was False
2025-10-11 00:10:23.390332 | 
2025-10-11 00:10:23.390410 | TASK [Ensure python3.8 is present]
2025-10-11 00:10:23.404661 | controller | skipping: Conditional result was False
2025-10-11 00:10:23.410453 | 
2025-10-11 00:10:23.410512 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-11 00:10:23.429671 | controller | ok
2025-10-11 00:10:23.448893 | 
2025-10-11 00:10:23.448982 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-11 00:10:27.297986 | controller | ok: Nothing to do
2025-10-11 00:10:27.314351 | 
2025-10-11 00:10:27.314483 | TASK [our-ensure-python : Also install python3-devel]
2025-10-11 00:10:40.723736 | controller | changed
2025-10-11 00:10:40.734992 | 
2025-10-11 00:10:40.735105 | TASK [Run ensure-virtualenv role]
2025-10-11 00:10:40.754656 | controller | ok
2025-10-11 00:10:40.774465 | 
2025-10-11 00:10:40.774580 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-11 00:10:41.159972 | controller | /usr/bin/virtualenv
2025-10-11 00:10:41.436563 | controller | ok: Runtime: 0:00:00.004863
2025-10-11 00:10:41.448939 | 
2025-10-11 00:10:41.449113 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-11 00:10:41.471917 | controller | skipping: Conditional result was False
2025-10-11 00:10:41.472296 | controller | ok: All items complete
2025-10-11 00:10:41.472325 | 
2025-10-11 00:10:41.500120 | 
2025-10-11 00:10:41.500359 | TASK [Find the full path of the Python interpreter]
2025-10-11 00:10:41.937209 | controller | /usr/bin/python3
2025-10-11 00:10:42.148072 | controller | ok
2025-10-11 00:10:42.163092 | 
2025-10-11 00:10:42.163242 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-11 00:10:43.585794 | controller | created virtual environment CPython3.11.0.final.0-64 in 765ms
2025-10-11 00:10:43.628323 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-11 00:10:43.628383 | 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-worker/.local/share/virtualenv)
2025-10-11 00:10:43.628401 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-11 00:10:43.628424 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-11 00:10:43.822780 | controller | changed
2025-10-11 00:10:43.836164 | 
2025-10-11 00:10:43.836302 | TASK [Set selinux package]
2025-10-11 00:10:43.875928 | controller | ok
2025-10-11 00:10:43.888069 | 
2025-10-11 00:10:43.888213 | TASK [Set selinux package (Fedora)]
2025-10-11 00:10:43.940567 | controller | ok
2025-10-11 00:10:43.951629 | 
2025-10-11 00:10:43.951924 | TASK [Install selinux into virtualenv]
2025-10-11 00:10:46.560526 | controller | Collecting selinux-please-lie-to-me
2025-10-11 00:10:46.655901 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-11 00:10:47.185169 | controller | Collecting setuptools<50.0.0
2025-10-11 00:10:47.201931 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-11 00:10:47.324417 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 6.9 MB/s eta 0:00:00
2025-10-11 00:10:47.477684 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-11 00:10:47.478135 | controller |   Attempting uninstall: setuptools
2025-10-11 00:10:47.483151 | controller |     Found existing installation: setuptools 62.6.0
2025-10-11 00:10:47.593990 | controller |     Uninstalling setuptools-62.6.0:
2025-10-11 00:10:47.609220 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-11 00:10:48.331210 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-11 00:10:48.540874 | controller |
2025-10-11 00:10:48.743751 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-11 00:10:48.743797 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-11 00:10:49.115345 | controller | ok: Runtime: 0:00:04.308798
2025-10-11 00:10:49.122020 | 
2025-10-11 00:10:49.122103 | TASK [Install pytest-forked into virtualenv]
2025-10-11 00:10:50.334448 | controller | Collecting pytest-forked
2025-10-11 00:10:50.423839 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-11 00:10:50.482093 | controller | Collecting py
2025-10-11 00:10:50.497365 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-11 00:10:50.534459 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.9 MB/s eta 0:00:00
2025-10-11 00:10:50.708237 | controller | Collecting pytest>=3.10
2025-10-11 00:10:50.720661 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-11 00:10:50.779479 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 6.5 MB/s eta 0:00:00
2025-10-11 00:10:50.834112 | controller | Collecting iniconfig>=1
2025-10-11 00:10:50.870463 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-11 00:10:50.937571 | controller | Collecting packaging>=20
2025-10-11 00:10:50.951189 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-11 00:10:50.962888 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.9 MB/s eta 0:00:00
2025-10-11 00:10:51.009694 | controller | Collecting pluggy<2,>=1.5
2025-10-11 00:10:51.021954 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-11 00:10:51.097864 | controller | Collecting pygments>=2.7.2
2025-10-11 00:10:51.110532 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-11 00:10:51.227958 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 10.7 MB/s eta 0:00:00
2025-10-11 00:10:51.358687 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-11 00:10:53.597012 | controller | Successfully installed iniconfig-2.1.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-10-11 00:10:53.612751 | controller |
2025-10-11 00:10:53.797778 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-11 00:10:53.797821 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-11 00:10:54.277149 | controller | ok: Runtime: 0:00:04.208096
2025-10-11 00:10:54.286745 | 
2025-10-11 00:10:54.286872 | TASK [Update pip]
2025-10-11 00:10:55.414391 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-11 00:10:55.647032 | controller | Collecting pip
2025-10-11 00:10:55.768957 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-11 00:10:55.926062 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 11.5 MB/s eta 0:00:00
2025-10-11 00:10:56.092161 | controller | Installing collected packages: pip
2025-10-11 00:10:56.093651 | controller |   Attempting uninstall: pip
2025-10-11 00:10:56.098654 | controller |     Found existing installation: pip 22.2.2
2025-10-11 00:10:56.418365 | controller |     Uninstalling pip-22.2.2:
2025-10-11 00:10:56.447961 | controller |       Successfully uninstalled pip-22.2.2
2025-10-11 00:10:58.210490 | controller | Successfully installed pip-25.2
2025-10-11 00:10:58.944014 | controller | ok: Runtime: 0:00:03.588001
2025-10-11 00:10:58.966309 | 
2025-10-11 00:10:58.966525 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-11 00:10:59.519939 | controller | changed
2025-10-11 00:10:59.537737 | 
2025-10-11 00:10:59.537893 | TASK [Install ansible into virtualenv]
2025-10-11 00:11:00.623088 | controller | Processing ./src/github.com/ansible/ansible
2025-10-11 00:11:00.629575 | controller |   Installing build dependencies: started
2025-10-11 00:11:02.619789 | controller |   Installing build dependencies: finished with status 'done'
2025-10-11 00:11:02.621003 | controller |   Getting requirements to build wheel: started
2025-10-11 00:11:04.204791 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-11 00:11:04.206357 | controller |   Preparing metadata (pyproject.toml): started
2025-10-11 00:11:05.131789 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-11 00:11:05.136954 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while.
2025-10-11 00:11:05.141804 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-11 00:11:06.192654 | controller | ERROR
2025-10-11 00:11:06.192869 | controller | {
2025-10-11 00:11:06.192901 | controller |   "delta": "0:00:05.300989",
2025-10-11 00:11:06.192921 | controller |   "end": "2025-10-11 00:11:05.293324",
2025-10-11 00:11:06.192939 | controller |   "msg": "non-zero return code",
2025-10-11 00:11:06.192966 | controller |   "rc": 1,
2025-10-11 00:11:06.192983 | controller |   "start": "2025-10-11 00:10:59.992335"
2025-10-11 00:11:06.192998 | controller | }
failure
2025-10-11 00:11:06.194623 | 
2025-10-11 00:11:06.194694 | PLAY RECAP
2025-10-11 00:11:06.194745 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-11 00:11:06.194767 | 
2025-10-11 00:11:06.342936 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-11 00:11:06.345877 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-11 00:11:07.023074 | 
2025-10-11 00:11:07.023256 | PLAY [all]
2025-10-11 00:11:07.050846 | 
2025-10-11 00:11:07.051025 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-11 00:11:07.866811 | controller | changed: non-zero return code
2025-10-11 00:11:07.872600 | 
2025-10-11 00:11:07.872707 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-11 00:11:07.898916 | controller | skipping: Conditional result was False
2025-10-11 00:11:07.906254 | 
2025-10-11 00:11:07.906356 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-11 00:11:07.945997 | 
2025-10-11 00:11:07.946202 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-11 00:11:07.984355 | 
2025-10-11 00:11:07.984591 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-11 00:11:08.000120 | controller | skipping: Conditional result was False
2025-10-11 00:11:08.007706 | 
2025-10-11 00:11:08.007810 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-11 00:11:08.044742 | 
2025-10-11 00:11:08.045045 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-11 00:11:08.093609 | controller | skipping: Conditional result was False
2025-10-11 00:11:08.101096 | 
2025-10-11 00:11:08.101203 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-11 00:11:08.136557 | controller | skipping: Conditional result was False
2025-10-11 00:11:08.148623 | 
2025-10-11 00:11:08.148854 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-11 00:11:08.178354 | controller | skipping: Conditional result was False
2025-10-11 00:11:08.216295 | 
2025-10-11 00:11:08.216423 | PLAY RECAP
2025-10-11 00:11:08.216479 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-11 00:11:08.216504 | 
2025-10-11 00:11:08.354190 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-11 00:11:08.355084 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-11 00:11:08.996709 | 
2025-10-11 00:11:08.996818 | PLAY [all:!appliance*]
2025-10-11 00:11:09.031140 | 
2025-10-11 00:11:09.031387 | TASK [unregister the node]
2025-10-11 00:11:09.161329 | controller | skipping: Conditional result was False
2025-10-11 00:11:09.168025 | 
2025-10-11 00:11:09.168124 | TASK [include_role : fetch-output]
2025-10-11 00:11:09.211739 | controller | ok
2025-10-11 00:11:09.272733 | 
2025-10-11 00:11:09.272862 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-11 00:11:09.318435 | controller | skipping: Conditional result was False
2025-10-11 00:11:09.325193 | 
2025-10-11 00:11:09.325280 | TASK [fetch-output : Set log path for single node]
2025-10-11 00:11:09.358963 | controller | ok
2025-10-11 00:11:09.368044 | 
2025-10-11 00:11:09.368170 | LOOP [fetch-output : Ensure local output dirs]
2025-10-11 00:11:09.773950 | controller -> localhost | ok: "/var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/logs"
2025-10-11 00:11:10.031829 | controller -> localhost | changed: "/var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/artifacts"
2025-10-11 00:11:10.291527 | controller -> localhost | changed: "/var/lib/zuul/builds/c3bd83602d7e4180a52dae67d274c9cb/work/docs"
2025-10-11 00:11:10.307954 | 
2025-10-11 00:11:10.308142 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-11 00:11:11.588874 | controller | changed:
2025-10-11 00:11:11.589078 | controller | .d..t...... ./
2025-10-11 00:11:11.589106 | controller | cd+++++++++ controller/
2025-10-11 00:11:11.589141 | controller | changed: All items complete
2025-10-11 00:11:11.589162 | 
2025-10-11 00:11:12.684763 | controller | changed: .d..t...... ./
2025-10-11 00:11:13.809622 | controller | changed: .d..t...... ./
2025-10-11 00:11:13.824711 | 
2025-10-11 00:11:13.824840 | TASK [include_role : fetch-output-openshift]
2025-10-11 00:11:13.850175 | controller | skipping: Conditional result was False
2025-10-11 00:11:13.856865 | 
2025-10-11 00:11:13.856946 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-11 00:11:13.882561 | controller | skipping: Conditional result was False
2025-10-11 00:11:13.891140 | controller | skipping: Conditional result was False
2025-10-11 00:11:13.923192 | 
2025-10-11 00:11:13.923304 | PLAY [localhost]
2025-10-11 00:11:13.936575 | 
2025-10-11 00:11:13.936637 | TASK [Run Zuul manifest role]
2025-10-11 00:11:13.954967 | localhost | ok
2025-10-11 00:11:13.976302 | 
2025-10-11 00:11:13.976456 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-11 00:11:14.349793 | localhost | changed
2025-10-11 00:11:14.356174 | 
2025-10-11 00:11:14.356292 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-11 00:11:14.384606 | localhost | ok
2025-10-11 00:11:14.393032 | 
2025-10-11 00:11:14.393091 | TASK [Set zuul-log-path fact]
2025-10-11 00:11:14.411380 | localhost | ok
2025-10-11 00:11:14.426926 | 
2025-10-11 00:11:14.426989 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-11 00:11:14.475154 | localhost | ok
2025-10-11 00:11:14.484944 | 
2025-10-11 00:11:14.485013 | LOOP [Run upload-logs-swift role]
2025-10-11 00:11:14.519378 | localhost | Output suppressed because no_log was given
2025-10-11 00:11:14.548101 | 
2025-10-11 00:11:14.548265 | TASK [Set zuul-log-path fact]
2025-10-11 00:11:14.575188 | localhost | skipping: Conditional result was False
2025-10-11 00:11:14.581246 | 
2025-10-11 00:11:14.581370 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-11 00:11:15.068833 | localhost -> localhost | ok: Runtime: 0:00:00.006302
2025-10-11 00:11:15.074651 | 
2025-10-11 00:11:15.074766 | TASK [upload-logs-swift : Upload logs to swift]