2025-12-18 00:07:32.918710 | Job console starting... 2025-12-18 00:07:32.929911 | Updating repositories 2025-12-18 00:07:33.114828 | Preparing job workspace 2025-12-18 00:07:38.425380 | Running Ansible setup... 2025-12-18 00:07:45.931250 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-18 00:07:46.570978 | 2025-12-18 00:07:46.571124 | PLAY [localhost] 2025-12-18 00:07:46.579738 | 2025-12-18 00:07:46.579819 | TASK [Gathering Facts] 2025-12-18 00:07:47.605918 | localhost | ok 2025-12-18 00:07:47.639600 | 2025-12-18 00:07:47.639750 | TASK [Setup log path fact] 2025-12-18 00:07:47.661759 | localhost | ok 2025-12-18 00:07:47.683082 | 2025-12-18 00:07:47.683240 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-18 00:07:47.714933 | localhost | ok 2025-12-18 00:07:47.728267 | 2025-12-18 00:07:47.728396 | TASK [emit-job-header : Print job information] 2025-12-18 00:07:47.776071 | # Job Information 2025-12-18 00:07:47.776274 | Ansible Version: 2.15.12 2025-12-18 00:07:47.776321 | Job: ansible-test-sanity-docker-stable-2.10 2025-12-18 00:07:47.776352 | Pipeline: periodic 2025-12-18 00:07:47.776379 | Executor: ze01.softwarefactory-project.io 2025-12-18 00:07:47.776406 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-18 00:07:47.776437 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/130/ansible/130fdbd5542f4ab580a79f9520a2ccac/ 2025-12-18 00:07:47.776465 | Event ID: 95f00f3203bf47de8d788a25b598cc45 2025-12-18 00:07:47.783366 | 2025-12-18 00:07:47.783492 | LOOP [emit-job-header : Print node information] 2025-12-18 00:07:47.910317 | localhost | ok: 2025-12-18 00:07:47.910719 | localhost | # Node Information 2025-12-18 00:07:47.910778 | localhost | Inventory Hostname: controller 2025-12-18 00:07:47.910823 | localhost | Hostname: np0005564919 2025-12-18 00:07:47.910865 | localhost | Username: zuul 2025-12-18 00:07:47.910919 | localhost | Distro: Fedora 37 2025-12-18 00:07:47.910961 | localhost | Provider: ansible-vexxhost-ams1 2025-12-18 00:07:47.911000 | localhost | Region: ams1 2025-12-18 00:07:47.911079 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-18 00:07:47.911120 | localhost | Product Name: OpenStack Nova 2025-12-18 00:07:47.911159 | localhost | Interface IP: 38.129.16.184 2025-12-18 00:07:47.935427 | 2025-12-18 00:07:47.935640 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-18 00:07:48.415840 | localhost -> localhost | changed 2025-12-18 00:07:48.427469 | 2025-12-18 00:07:48.427720 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-18 00:07:49.404117 | localhost -> localhost | changed 2025-12-18 00:07:49.424295 | 2025-12-18 00:07:49.424372 | PLAY [all:!appliance*] 2025-12-18 00:07:49.440994 | 2025-12-18 00:07:49.441143 | TASK [include_role : start-zuul-console] 2025-12-18 00:07:49.461529 | controller | ok 2025-12-18 00:07:49.476471 | 2025-12-18 00:07:49.476646 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-18 00:07:50.671191 | controller | ok 2025-12-18 00:07:50.688550 | 2025-12-18 00:07:50.688695 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-18 00:07:52.888955 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-18 00:07:52.895777 | 2025-12-18 00:07:52.895867 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-18 00:07:53.249495 | controller | skipping: Conditional result was False 2025-12-18 00:07:53.267267 | 2025-12-18 00:07:53.267479 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-18 00:07:53.304891 | controller | skipping: Conditional result was False 2025-12-18 00:07:53.318952 | 2025-12-18 00:07:53.319214 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-18 00:07:53.357531 | controller | skipping: Conditional result was False 2025-12-18 00:07:53.371851 | 2025-12-18 00:07:53.372073 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-18 00:07:53.409488 | controller | skipping: Conditional result was False 2025-12-18 00:07:53.425430 | 2025-12-18 00:07:53.425640 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-18 00:07:53.463559 | controller | skipping: Conditional result was False 2025-12-18 00:07:53.479303 | 2025-12-18 00:07:53.479512 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-18 00:07:53.517720 | controller | skipping: Conditional result was False 2025-12-18 00:07:53.536125 | 2025-12-18 00:07:53.536293 | TASK [Disable Fedora Modular] 2025-12-18 00:07:54.812590 | controller | changed 2025-12-18 00:07:54.825776 | 2025-12-18 00:07:54.826217 | TASK [Enable EPEL] 2025-12-18 00:07:54.853295 | controller | skipping: Conditional result was False 2025-12-18 00:07:54.867491 | 2025-12-18 00:07:54.867667 | TASK [Register the RHEL node] 2025-12-18 00:07:55.289817 | 2025-12-18 00:07:55.290005 | TASK [Show the subscription-manager status] 2025-12-18 00:07:55.664522 | controller | skipping: Conditional result was False 2025-12-18 00:07:55.673920 | 2025-12-18 00:07:55.674204 | TASK [Enable EPEL on RHEL] 2025-12-18 00:07:56.046623 | controller | skipping: Conditional result was False 2025-12-18 00:07:56.054574 | 2025-12-18 00:07:56.054685 | TASK [Install git and tox] 2025-12-18 00:10:36.657519 | controller | changed 2025-12-18 00:10:36.664895 | 2025-12-18 00:10:36.665008 | TASK [include_role : prepare-workspace] 2025-12-18 00:10:36.685506 | controller | ok 2025-12-18 00:10:36.709868 | 2025-12-18 00:10:36.710018 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-18 00:10:37.546609 | controller | ok 2025-12-18 00:10:37.555721 | 2025-12-18 00:10:37.555834 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-18 00:10:53.470091 | controller | Output suppressed because no_log was given 2025-12-18 00:10:53.526353 | 2025-12-18 00:10:53.526475 | TASK [include_role : prepare-workspace-openshift] 2025-12-18 00:10:53.552963 | controller | skipping: Conditional result was False 2025-12-18 00:10:53.580005 | 2025-12-18 00:10:53.580111 | PLAY [all:!appliance] 2025-12-18 00:10:53.599085 | 2025-12-18 00:10:53.599198 | TASK [Run add-build-sshkey role (RSA)] 2025-12-18 00:10:53.621369 | controller | ok 2025-12-18 00:10:53.638312 | 2025-12-18 00:10:53.638434 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-18 00:10:53.888190 | controller -> localhost | ok 2025-12-18 00:10:53.895853 | 2025-12-18 00:10:53.895941 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-18 00:10:53.926883 | controller | ok 2025-12-18 00:10:53.945652 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-18 00:10:53.952120 | 2025-12-18 00:10:53.952191 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-18 00:10:54.456892 | controller -> localhost | Generating public/private rsa key pair. 2025-12-18 00:10:54.457134 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/130fdbd5542f4ab580a79f9520a2ccac_id_rsa. 2025-12-18 00:10:54.457171 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/130fdbd5542f4ab580a79f9520a2ccac_id_rsa.pub. 2025-12-18 00:10:54.457196 | controller -> localhost | The key fingerprint is: 2025-12-18 00:10:54.457226 | controller -> localhost | SHA256:MjdKQ2X16U3QczLqzU+vCGpqPjtUX+qmadh1PjnUwXI zuul-build-sshkey 2025-12-18 00:10:54.457248 | controller -> localhost | The key's randomart image is: 2025-12-18 00:10:54.457267 | controller -> localhost | +---[RSA 2048]----+ 2025-12-18 00:10:54.457286 | controller -> localhost | | o.. .. | 2025-12-18 00:10:54.457305 | controller -> localhost | | o . o= .| 2025-12-18 00:10:54.457323 | controller -> localhost | | . oo.= | 2025-12-18 00:10:54.457341 | controller -> localhost | | . . .+oE | 2025-12-18 00:10:54.457359 | controller -> localhost | | =.S. +.*.. | 2025-12-18 00:10:54.457383 | controller -> localhost | | ..* .+ + + .| 2025-12-18 00:10:54.457411 | controller -> localhost | | ..o o.+ . o.| 2025-12-18 00:10:54.457432 | controller -> localhost | | = +oo.=. o| 2025-12-18 00:10:54.457451 | controller -> localhost | | o+B+o .o.. | 2025-12-18 00:10:54.457472 | controller -> localhost | +----[SHA256]-----+ 2025-12-18 00:10:54.457516 | controller -> localhost | ok: Runtime: 0:00:00.084258 2025-12-18 00:10:54.467648 | 2025-12-18 00:10:54.467767 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-18 00:10:54.494941 | controller | ok 2025-12-18 00:10:54.505453 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-18 00:10:54.515879 | 2025-12-18 00:10:54.515973 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-18 00:10:54.530052 | controller | skipping: Conditional result was False 2025-12-18 00:10:54.538880 | 2025-12-18 00:10:54.538998 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-18 00:10:55.675389 | controller | changed 2025-12-18 00:10:55.683837 | 2025-12-18 00:10:55.683921 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-18 00:10:56.441718 | controller | ok 2025-12-18 00:10:56.448896 | 2025-12-18 00:10:56.448986 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-18 00:10:59.579705 | controller | changed 2025-12-18 00:10:59.596172 | 2025-12-18 00:10:59.596309 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-18 00:11:02.872188 | controller | changed 2025-12-18 00:11:02.881838 | 2025-12-18 00:11:02.881953 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-18 00:11:02.908216 | controller | skipping: Conditional result was False 2025-12-18 00:11:02.920759 | 2025-12-18 00:11:02.920902 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-18 00:11:03.386134 | controller -> localhost | changed 2025-12-18 00:11:03.399220 | 2025-12-18 00:11:03.399362 | TASK [add-build-sshkey : Add back temp key] 2025-12-18 00:11:03.811334 | controller -> localhost | Identity added: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/130fdbd5542f4ab580a79f9520a2ccac_id_rsa (zuul-build-sshkey) 2025-12-18 00:11:03.811518 | controller -> localhost | ok: Runtime: 0:00:00.007624 2025-12-18 00:11:03.818241 | 2025-12-18 00:11:03.818305 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-18 00:11:04.866919 | controller | ok 2025-12-18 00:11:04.873452 | 2025-12-18 00:11:04.873535 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-18 00:11:04.903590 | controller | skipping: Conditional result was False 2025-12-18 00:11:04.917521 | 2025-12-18 00:11:04.917634 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-18 00:11:04.950529 | controller | ok 2025-12-18 00:11:04.971980 | 2025-12-18 00:11:04.972140 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-18 00:11:05.304030 | controller -> localhost | ok 2025-12-18 00:11:05.312625 | 2025-12-18 00:11:05.312735 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-18 00:11:05.346328 | controller | ok 2025-12-18 00:11:05.360916 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-18 00:11:05.370047 | 2025-12-18 00:11:05.370159 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-18 00:11:05.681699 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-18 00:11:05.681880 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/130fdbd5542f4ab580a79f9520a2ccac_id_ecdsa. 2025-12-18 00:11:05.681910 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/130fdbd5542f4ab580a79f9520a2ccac_id_ecdsa.pub. 2025-12-18 00:11:05.681943 | controller -> localhost | The key fingerprint is: 2025-12-18 00:11:05.681965 | controller -> localhost | SHA256:D9Rz6CqiyUPRBU4Ny6P6Nq1yetslCgsVjuAceCUyruQ zuul-build-sshkey 2025-12-18 00:11:05.681985 | controller -> localhost | The key's randomart image is: 2025-12-18 00:11:05.682004 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-18 00:11:05.682044 | controller -> localhost | |o . =+ | 2025-12-18 00:11:05.682069 | controller -> localhost | |oo * .o . . | 2025-12-18 00:11:05.682089 | controller -> localhost | |o+o.=. . + . | 2025-12-18 00:11:05.682108 | controller -> localhost | |B+oo.. . . o | 2025-12-18 00:11:05.682126 | controller -> localhost | |oE+. S . | 2025-12-18 00:11:05.682144 | controller -> localhost | | o. + | 2025-12-18 00:11:05.682162 | controller -> localhost | |+. .o o . . | 2025-12-18 00:11:05.682181 | controller -> localhost | |o=*=.+ . | 2025-12-18 00:11:05.682199 | controller -> localhost | |o*O=. | 2025-12-18 00:11:05.682217 | controller -> localhost | +----[SHA256]-----+ 2025-12-18 00:11:05.682282 | controller -> localhost | ok: Runtime: 0:00:00.009055 2025-12-18 00:11:05.691094 | 2025-12-18 00:11:05.691207 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-18 00:11:05.732009 | controller | ok 2025-12-18 00:11:05.744570 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-18 00:11:05.773513 | 2025-12-18 00:11:05.773643 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-18 00:11:05.818314 | controller | skipping: Conditional result was False 2025-12-18 00:11:05.826120 | 2025-12-18 00:11:05.826205 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-18 00:11:06.965332 | controller | changed 2025-12-18 00:11:06.975768 | 2025-12-18 00:11:06.975903 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-18 00:11:07.807657 | controller | ok 2025-12-18 00:11:07.815433 | 2025-12-18 00:11:07.815559 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-18 00:11:11.012984 | controller | changed 2025-12-18 00:11:11.021540 | 2025-12-18 00:11:11.021664 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-18 00:11:14.158290 | controller | changed 2025-12-18 00:11:14.194220 | 2025-12-18 00:11:14.194402 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-18 00:11:14.222008 | controller | skipping: Conditional result was False 2025-12-18 00:11:14.230329 | 2025-12-18 00:11:14.230442 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-18 00:11:14.521515 | controller -> localhost | changed 2025-12-18 00:11:14.537177 | 2025-12-18 00:11:14.537305 | TASK [add-build-sshkey : Add back temp key] 2025-12-18 00:11:14.839394 | controller -> localhost | Identity added: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/130fdbd5542f4ab580a79f9520a2ccac_id_ecdsa (zuul-build-sshkey) 2025-12-18 00:11:14.839650 | controller -> localhost | ok: Runtime: 0:00:00.007747 2025-12-18 00:11:14.846717 | 2025-12-18 00:11:14.846798 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-18 00:11:15.584040 | controller | ok 2025-12-18 00:11:15.590201 | 2025-12-18 00:11:15.590275 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-18 00:11:15.614211 | controller | skipping: Conditional result was False 2025-12-18 00:11:15.630307 | 2025-12-18 00:11:15.630436 | TASK [include_role : remove-zuul-sshkey] 2025-12-18 00:11:15.654756 | controller | skipping: Conditional result was False 2025-12-18 00:11:15.663088 | 2025-12-18 00:11:15.663202 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-18 00:11:16.401254 | controller | ok: "logs" 2025-12-18 00:11:16.401537 | controller | ok: All items complete 2025-12-18 00:11:16.401578 | 2025-12-18 00:11:17.107601 | controller | ok: "artifacts" 2025-12-18 00:11:17.788129 | controller | ok: "docs" 2025-12-18 00:11:17.806326 | 2025-12-18 00:11:17.806453 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-18 00:11:18.596490 | controller | changed: "logs" 2025-12-18 00:11:19.284161 | controller | changed: "artifacts" 2025-12-18 00:11:19.995391 | controller | changed: "docs" 2025-12-18 00:11:20.038494 | 2025-12-18 00:11:20.038595 | PLAY RECAP 2025-12-18 00:11:20.038638 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-18 00:11:20.038666 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-18 00:11:20.038684 | 2025-12-18 00:11:20.193531 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-18 00:11:20.194470 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-18 00:11:20.858500 | 2025-12-18 00:11:20.858658 | PLAY [all] 2025-12-18 00:11:20.892113 | 2025-12-18 00:11:20.892298 | TASK [Install binary dependencies] 2025-12-18 00:11:20.956625 | controller | ok 2025-12-18 00:11:20.984397 | 2025-12-18 00:11:20.984591 | TASK [bindep : Include find tasks] 2025-12-18 00:11:21.027597 | controller | ok 2025-12-18 00:11:21.038827 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-18 00:11:21.048293 | 2025-12-18 00:11:21.048427 | TASK [bindep : Look for bindep.txt] 2025-12-18 00:11:22.050755 | controller | ok 2025-12-18 00:11:22.059951 | 2025-12-18 00:11:22.060214 | TASK [bindep : Define bindep_file fact] 2025-12-18 00:11:22.076495 | controller | skipping: Conditional result was False 2025-12-18 00:11:22.085109 | 2025-12-18 00:11:22.085234 | TASK [bindep : Look for other-requirements.txt] 2025-12-18 00:11:22.788749 | controller | ok 2025-12-18 00:11:22.801727 | 2025-12-18 00:11:22.801901 | TASK [bindep : Define bindep_file fact] 2025-12-18 00:11:22.828501 | controller | skipping: Conditional result was False 2025-12-18 00:11:22.838735 | 2025-12-18 00:11:22.838907 | TASK [bindep : Look for bindep fallback file] 2025-12-18 00:11:22.873578 | controller | skipping: Conditional result was False 2025-12-18 00:11:22.883443 | 2025-12-18 00:11:22.883592 | TASK [bindep : Define bindep_file fact] 2025-12-18 00:11:22.910217 | controller | skipping: Conditional result was False 2025-12-18 00:11:22.921702 | 2025-12-18 00:11:22.921895 | TASK [bindep : Include bindep tasks] 2025-12-18 00:11:22.947926 | controller | skipping: Conditional result was False 2025-12-18 00:11:22.957927 | 2025-12-18 00:11:22.958099 | TASK [bindep : Include install tasks] 2025-12-18 00:11:22.985091 | controller | skipping: Conditional result was False 2025-12-18 00:11:22.995264 | 2025-12-18 00:11:22.995405 | LOOP [bindep : Include package tasks] 2025-12-18 00:11:23.063523 | 2025-12-18 00:11:23.063727 | TASK [Run test-setup role] 2025-12-18 00:11:23.089711 | controller | ok 2025-12-18 00:11:23.126243 | 2025-12-18 00:11:23.126398 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-18 00:11:23.913636 | controller | ok 2025-12-18 00:11:23.925493 | 2025-12-18 00:11:23.925650 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-18 00:11:24.290988 | controller | skipping: Conditional result was False 2025-12-18 00:11:24.320406 | 2025-12-18 00:11:24.320496 | PLAY RECAP 2025-12-18 00:11:24.320534 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-18 00:11:24.320555 | 2025-12-18 00:11:24.444269 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-18 00:11:24.445500 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-18 00:11:25.157592 | 2025-12-18 00:11:25.157712 | PLAY [controller] 2025-12-18 00:11:25.178341 | 2025-12-18 00:11:25.178439 | TASK [Create the /root directory] 2025-12-18 00:11:26.329568 | controller | ok 2025-12-18 00:11:26.335543 | 2025-12-18 00:11:26.335613 | TASK [Install glibc-langpack-en] 2025-12-18 00:11:36.092358 | controller | ok: Nothing to do 2025-12-18 00:11:36.099951 | 2025-12-18 00:11:36.100109 | TASK [Ensure controller directory exists] 2025-12-18 00:11:36.971388 | controller | changed 2025-12-18 00:11:36.978620 | 2025-12-18 00:11:36.978730 | TASK [Install container runtime] 2025-12-18 00:11:37.043567 | controller | ok 2025-12-18 00:11:37.096782 | 2025-12-18 00:11:37.096895 | LOOP [ensure-docker : Gather variables for each operating system] 2025-12-18 00:11:37.132322 | controller | ok: "/var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml" 2025-12-18 00:11:37.150061 | 2025-12-18 00:11:37.150179 | TASK [ensure-docker : Sanity check for distro selection] 2025-12-18 00:11:37.164515 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.172230 | 2025-12-18 00:11:37.172340 | TASK [ensure-docker : Sanity check for distro install] 2025-12-18 00:11:37.196553 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.204548 | 2025-12-18 00:11:37.204687 | TASK [ensure-docker : Sanity check for upstream install] 2025-12-18 00:11:37.229209 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.236778 | 2025-12-18 00:11:37.236917 | TASK [ensure-docker : Sanity check for upstream install mirrors] 2025-12-18 00:11:37.277299 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.286807 | 2025-12-18 00:11:37.286939 | TASK [ensure-docker : Include tasks for docker install] 2025-12-18 00:11:37.308992 | controller | ok 2025-12-18 00:11:37.322181 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml 2025-12-18 00:11:37.340352 | 2025-12-18 00:11:37.340492 | TASK [ensure-docker : Not Implemented] 2025-12-18 00:11:37.382089 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.389729 | 2025-12-18 00:11:37.389826 | TASK [Set up docker mirrors] 2025-12-18 00:11:37.413069 | controller | ok 2025-12-18 00:11:37.485853 | 2025-12-18 00:11:37.485989 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info] 2025-12-18 00:11:37.523043 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.533450 | 2025-12-18 00:11:37.533583 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info] 2025-12-18 00:11:37.568415 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.578071 | 2025-12-18 00:11:37.578199 | TASK [use-docker-mirror : Set docker_mirror fact] 2025-12-18 00:11:37.623165 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.635412 | 2025-12-18 00:11:37.635565 | TASK [use-docker-mirror : Set up docker mirrors] 2025-12-18 00:11:37.673227 | controller | skipping: Conditional result was False 2025-12-18 00:11:37.693461 | 2025-12-18 00:11:37.693608 | TASK [Add all repositories] 2025-12-18 00:11:37.718330 | controller | ok 2025-12-18 00:11:37.757457 | 2025-12-18 00:11:37.757602 | LOOP [ensure-package-repositories : Install repositories] 2025-12-18 00:11:37.790519 | controller | ok: "/var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml" 2025-12-18 00:11:37.790708 | controller | ok: All items complete 2025-12-18 00:11:37.790747 | 2025-12-18 00:11:37.806886 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml 2025-12-18 00:11:37.818606 | 2025-12-18 00:11:37.818708 | TASK [ensure-package-repositories : Create GPG key temp directory] 2025-12-18 00:11:38.781980 | controller | changed 2025-12-18 00:11:38.791276 | 2025-12-18 00:11:38.791395 | LOOP [ensure-package-repositories : Upload GPG keys] 2025-12-18 00:11:42.161559 | controller | changed: 2025-12-18 00:11:42.161853 | controller | { 2025-12-18 00:11:42.161914 | 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-12-18 00:11:42.161967 | controller | } 2025-12-18 00:11:42.170707 | 2025-12-18 00:11:42.170780 | LOOP [ensure-package-repositories : Import GPG keys] 2025-12-18 00:11:43.460293 | controller | changed: 2025-12-18 00:11:43.460652 | controller | { 2025-12-18 00:11:43.460717 | 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-12-18 00:11:43.460763 | controller | } 2025-12-18 00:11:43.460823 | controller | changed: All items complete 2025-12-18 00:11:43.460866 | 2025-12-18 00:11:43.476359 | 2025-12-18 00:11:43.476500 | TASK [ensure-package-repositories : Remove GPG temp directory] 2025-12-18 00:11:44.229528 | controller | changed 2025-12-18 00:11:44.238511 | 2025-12-18 00:11:44.238630 | LOOP [ensure-package-repositories : Add repositories] 2025-12-18 00:11:45.103497 | controller | changed: 2025-12-18 00:11:45.103671 | controller | { 2025-12-18 00:11:45.103697 | controller | "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable", 2025-12-18 00:11:45.103716 | controller | "description": "Docker CE Stable - $basearch", 2025-12-18 00:11:45.103733 | controller | "gpgcheck": true, 2025-12-18 00:11:45.103749 | controller | "name": "docker-ce-stable" 2025-12-18 00:11:45.103765 | controller | } 2025-12-18 00:11:45.117797 | 2025-12-18 00:11:45.117916 | TASK [ensure-docker : Install pre-reqs] 2025-12-18 00:11:51.323434 | controller | ok: Nothing to do 2025-12-18 00:11:51.329641 | 2025-12-18 00:11:51.329719 | TASK [ensure-docker : Remove packages] 2025-12-18 00:11:54.697079 | controller | ok: Nothing to do 2025-12-18 00:11:54.704550 | 2025-12-18 00:11:54.704647 | TASK [ensure-docker : Install upstream docker using package] 2025-12-18 00:13:30.139302 | controller | changed 2025-12-18 00:13:30.175797 | 2025-12-18 00:13:30.176001 | TASK [ensure-docker : Setup docker] 2025-12-18 00:13:30.206582 | controller | ok 2025-12-18 00:13:30.221398 | controller | included: /var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml 2025-12-18 00:13:30.236271 | 2025-12-18 00:13:30.236401 | TASK [ensure-docker : Ensure "docker" group exists] 2025-12-18 00:13:31.251488 | controller | ok 2025-12-18 00:13:31.259364 | 2025-12-18 00:13:31.259513 | TASK [ensure-docker : Add user to docker group] 2025-12-18 00:13:32.503816 | controller | changed 2025-12-18 00:13:32.522467 | 2025-12-18 00:13:32.523133 | TASK [Update docker daemon proxy configuration] 2025-12-18 00:13:32.564054 | controller | skipping: Conditional result was False 2025-12-18 00:13:32.577930 | 2025-12-18 00:13:32.578116 | TASK [Lower default MTU] 2025-12-18 00:13:32.609670 | controller | skipping: Conditional result was False 2025-12-18 00:13:32.627699 | 2025-12-18 00:13:32.627927 | TASK [ensure-docker : Get the status of the docket.socket unit] 2025-12-18 00:13:33.696023 | controller | inactive 2025-12-18 00:13:34.031225 | controller | ok: Runtime: 0:00:00.023515 2025-12-18 00:13:34.039360 | 2025-12-18 00:13:34.039471 | TASK [ensure-docker : Get the status of the docket unit] 2025-12-18 00:13:34.894625 | controller | inactive 2025-12-18 00:13:35.409067 | controller | ok: Runtime: 0:00:00.026145 2025-12-18 00:13:35.416805 | 2025-12-18 00:13:35.416914 | TASK [ensure-docker : Restart docker] 2025-12-18 00:13:35.501808 | Trigger a Docker restart 2025-12-18 00:13:35.521228 | 2025-12-18 00:13:35.521362 | TASK [ensure-docker : Reset ssh connection to pick up docker group] 2025-12-18 00:13:35.602941 | 2025-12-18 00:13:35.603122 | TASK [ensure-docker : Install docker-compose] 2025-12-18 00:13:35.653548 | controller | skipping: Conditional result was False 2025-12-18 00:13:35.664654 | 2025-12-18 00:13:35.664811 | TASK [ensure-docker : Flush handlers before role exit] 2025-12-18 00:13:35.696323 | 2025-12-18 00:13:35.696466 | TASK [ensure-docker : Stop docker.socket to avoid any conflict] 2025-12-18 00:13:39.477937 | controller | changed 2025-12-18 00:13:39.498264 | 2025-12-18 00:13:39.498393 | TASK [ensure-docker : Assure docker service is running] 2025-12-18 00:13:43.632712 | controller | changed 2025-12-18 00:13:43.644796 | 2025-12-18 00:13:43.644952 | TASK [ensure-docker : Assure docker.socket service is running] 2025-12-18 00:13:45.003907 | controller | ok 2025-12-18 00:13:45.014346 | 2025-12-18 00:13:45.014465 | TASK [ensure-docker : Correct group ownership on docker sock] 2025-12-18 00:13:45.779532 | controller | ok 2025-12-18 00:13:45.790373 | 2025-12-18 00:13:45.790712 | TASK [ensure-docker : Validate ability to talk with docker] 2025-12-18 00:13:46.425110 | controller | CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 2025-12-18 00:13:46.660196 | controller | ok: Runtime: 0:00:00.039332 2025-12-18 00:13:46.667363 | 2025-12-18 00:13:46.667493 | TASK [ensure-docker : Get version details] 2025-12-18 00:13:47.454307 | controller | Client: Docker Engine - Community 2025-12-18 00:13:47.454384 | controller | Version: 24.0.7 2025-12-18 00:13:47.454443 | controller | API version: 1.43 2025-12-18 00:13:47.454457 | controller | Go version: go1.20.10 2025-12-18 00:13:47.454491 | controller | Git commit: afdd53b 2025-12-18 00:13:47.454500 | controller | Built: Thu Oct 26 09:09:39 2023 2025-12-18 00:13:47.454508 | controller | OS/Arch: linux/amd64 2025-12-18 00:13:47.454517 | controller | Context: default 2025-12-18 00:13:47.454526 | controller | 2025-12-18 00:13:47.454533 | controller | Server: Docker Engine - Community 2025-12-18 00:13:47.454539 | controller | Engine: 2025-12-18 00:13:47.454549 | controller | Version: 24.0.7 2025-12-18 00:13:47.454555 | controller | API version: 1.43 (minimum version 1.12) 2025-12-18 00:13:47.454562 | controller | Go version: go1.20.10 2025-12-18 00:13:47.454568 | controller | Git commit: 311b9ff 2025-12-18 00:13:47.454574 | controller | Built: Thu Oct 26 09:08:11 2023 2025-12-18 00:13:47.454580 | controller | OS/Arch: linux/amd64 2025-12-18 00:13:47.454586 | controller | Experimental: false 2025-12-18 00:13:47.454601 | controller | containerd: 2025-12-18 00:13:47.454607 | controller | Version: 1.6.25 2025-12-18 00:13:47.454613 | controller | GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f 2025-12-18 00:13:47.454619 | controller | runc: 2025-12-18 00:13:47.454624 | controller | Version: 1.1.10 2025-12-18 00:13:47.454633 | controller | GitCommit: v1.1.10-0-g18a0cb0 2025-12-18 00:13:47.456335 | controller | docker-init: 2025-12-18 00:13:47.456351 | controller | Version: 0.19.0 2025-12-18 00:13:47.456358 | controller | GitCommit: de40ad0 2025-12-18 00:13:48.051137 | controller | ok: Runtime: 0:00:00.055289 2025-12-18 00:13:48.059631 | 2025-12-18 00:13:48.059744 | TASK [ensure-docker : Dump installed docker details] 2025-12-18 00:13:48.092495 | {'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-12-18 00:13:47.401541', 'end': '2025-12-18 00:13:47.456830', 'delta': '0:00:00.055289', 'msg': '', 'zuul_log_id': 'fa163ec2-ffbe-6b2d-a208-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-12-18 00:13:48.102104 | 2025-12-18 00:13:48.102214 | TASK [Use buildset registry] 2025-12-18 00:13:48.117165 | controller | skipping: Conditional result was False 2025-12-18 00:13:48.134251 | 2025-12-18 00:13:48.134389 | TASK [Ensure python3.8 is present] 2025-12-18 00:13:48.150109 | controller | skipping: Conditional result was False 2025-12-18 00:13:48.160053 | 2025-12-18 00:13:48.160194 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-18 00:13:48.182576 | controller | ok 2025-12-18 00:13:48.213114 | 2025-12-18 00:13:48.213273 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-18 00:13:54.696905 | controller | ok: Nothing to do 2025-12-18 00:13:54.704566 | 2025-12-18 00:13:54.704668 | TASK [our-ensure-python : Also install python3-devel] 2025-12-18 00:14:12.960521 | controller | changed 2025-12-18 00:14:12.977503 | 2025-12-18 00:14:12.977628 | TASK [Run ensure-virtualenv role] 2025-12-18 00:14:13.007805 | controller | ok 2025-12-18 00:14:13.039249 | 2025-12-18 00:14:13.039399 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-18 00:14:13.842685 | controller | /usr/bin/virtualenv 2025-12-18 00:14:14.400851 | controller | ok: Runtime: 0:00:00.007074 2025-12-18 00:14:14.412426 | 2025-12-18 00:14:14.412588 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-18 00:14:14.436470 | controller | skipping: Conditional result was False 2025-12-18 00:14:14.436755 | controller | changed: All items complete 2025-12-18 00:14:14.436797 | 2025-12-18 00:14:14.464640 | 2025-12-18 00:14:14.464789 | TASK [Find the full path of the Python interpreter] 2025-12-18 00:14:15.270407 | controller | /usr/bin/python3.8 2025-12-18 00:14:15.852171 | controller | ok 2025-12-18 00:14:15.861891 | 2025-12-18 00:14:15.862248 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-18 00:14:18.028659 | controller | created virtual environment CPython3.8.18.final.0-64 in 1089ms 2025-12-18 00:14:18.082886 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-18 00:14:18.082944 | 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-12-18 00:14:18.082960 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-18 00:14:18.082980 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-18 00:14:18.235528 | controller | changed 2025-12-18 00:14:18.241848 | 2025-12-18 00:14:18.241967 | TASK [Set selinux package] 2025-12-18 00:14:18.262343 | controller | ok 2025-12-18 00:14:18.268406 | 2025-12-18 00:14:18.268533 | TASK [Set selinux package (Fedora)] 2025-12-18 00:14:18.301824 | controller | ok 2025-12-18 00:14:18.310439 | 2025-12-18 00:14:18.310739 | TASK [Install selinux into virtualenv] 2025-12-18 00:14:24.420502 | controller | Collecting selinux-please-lie-to-me 2025-12-18 00:14:24.566541 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-18 00:14:25.778834 | controller | Collecting setuptools<50.0.0 2025-12-18 00:14:25.791917 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-18 00:14:25.910887 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 7.1 MB/s eta 0:00:00 2025-12-18 00:14:26.068121 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-18 00:14:26.068467 | controller | Attempting uninstall: setuptools 2025-12-18 00:14:26.069629 | controller | Found existing installation: setuptools 62.6.0 2025-12-18 00:14:26.214146 | controller | Uninstalling setuptools-62.6.0: 2025-12-18 00:14:26.232774 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-18 00:14:27.169576 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-18 00:14:27.410417 | controller | 2025-12-18 00:14:27.700743 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1 2025-12-18 00:14:27.700790 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2025-12-18 00:14:28.201593 | controller | ok: Runtime: 0:00:08.264795 2025-12-18 00:14:28.217831 | 2025-12-18 00:14:28.218254 | TASK [Install pytest-forked into virtualenv] 2025-12-18 00:14:30.048853 | controller | Collecting pytest-forked 2025-12-18 00:14:30.118311 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-18 00:14:30.384766 | controller | Collecting pytest>=3.10 2025-12-18 00:14:30.397262 | controller | Downloading pytest-8.3.5-py3-none-any.whl (343 kB) 2025-12-18 00:14:30.462684 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 6.0 MB/s eta 0:00:00 2025-12-18 00:14:30.552886 | controller | Collecting py 2025-12-18 00:14:30.565416 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-18 00:14:30.592337 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.0 MB/s eta 0:00:00 2025-12-18 00:14:30.715573 | controller | Collecting exceptiongroup>=1.0.0rc8 2025-12-18 00:14:30.725675 | controller | Downloading exceptiongroup-1.3.1-py3-none-any.whl (16 kB) 2025-12-18 00:14:30.819076 | controller | Collecting pluggy<2,>=1.5 2025-12-18 00:14:30.825554 | controller | Downloading pluggy-1.5.0-py3-none-any.whl (20 kB) 2025-12-18 00:14:30.930956 | controller | Collecting packaging 2025-12-18 00:14:30.938970 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-18 00:14:30.972319 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 2.1 MB/s eta 0:00:00 2025-12-18 00:14:31.013420 | controller | Collecting iniconfig 2025-12-18 00:14:31.021569 | controller | Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB) 2025-12-18 00:14:31.113708 | controller | Collecting tomli>=1 2025-12-18 00:14:31.121972 | controller | Downloading tomli-2.3.0-py3-none-any.whl (14 kB) 2025-12-18 00:14:31.225144 | controller | Collecting typing-extensions>=4.6.0 2025-12-18 00:14:31.232644 | controller | Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB) 2025-12-18 00:14:31.245533 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 4.7 MB/s eta 0:00:00 2025-12-18 00:14:31.353227 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked 2025-12-18 00:14:32.563264 | controller | Successfully installed exceptiongroup-1.3.1 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-12-18 00:14:32.570301 | controller | 2025-12-18 00:14:32.812550 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1 2025-12-18 00:14:32.812600 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2025-12-18 00:14:33.088639 | controller | ok: Runtime: 0:00:03.688702 2025-12-18 00:14:33.094962 | 2025-12-18 00:14:33.095291 | TASK [Update pip] 2025-12-18 00:14:35.297341 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2) 2025-12-18 00:14:35.678691 | controller | Collecting pip 2025-12-18 00:14:35.774333 | controller | Downloading pip-25.0.1-py3-none-any.whl (1.8 MB) 2025-12-18 00:14:35.884307 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 18.0 MB/s eta 0:00:00 2025-12-18 00:14:36.067204 | controller | Installing collected packages: pip 2025-12-18 00:14:36.590246 | controller | Attempting uninstall: pip 2025-12-18 00:14:36.590302 | controller | Found existing installation: pip 22.2.2 2025-12-18 00:14:36.590328 | controller | Uninstalling pip-22.2.2: 2025-12-18 00:14:36.635961 | controller | Successfully uninstalled pip-22.2.2 2025-12-18 00:14:39.159198 | controller | Successfully installed pip-25.0.1 2025-12-18 00:14:39.986774 | controller | ok: Runtime: 0:00:05.274312 2025-12-18 00:14:39.997811 | 2025-12-18 00:14:39.997926 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-18 00:14:41.127257 | controller | changed 2025-12-18 00:14:41.139382 | 2025-12-18 00:14:41.139517 | TASK [Install ansible into virtualenv] 2025-12-18 00:14:43.161337 | controller | Processing ./src/github.com/ansible/ansible 2025-12-18 00:14:43.164031 | controller | Preparing metadata (setup.py): started 2025-12-18 00:14:44.065907 | controller | Preparing metadata (setup.py): finished with status 'done' 2025-12-18 00:14:44.132170 | controller | Collecting jinja2 (from ansible-base==2.10.17.post0) 2025-12-18 00:14:44.146987 | controller | Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB) 2025-12-18 00:14:44.240167 | controller | Collecting PyYAML (from ansible-base==2.10.17.post0) 2025-12-18 00:14:44.247889 | 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-12-18 00:14:44.702898 | controller | Collecting cryptography (from ansible-base==2.10.17.post0) 2025-12-18 00:14:44.709287 | controller | Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB) 2025-12-18 00:14:44.731179 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.8/site-packages (from ansible-base==2.10.17.post0) (25.0) 2025-12-18 00:14:44.991255 | controller | Collecting cffi>=1.14 (from cryptography->ansible-base==2.10.17.post0) 2025-12-18 00:14:44.997656 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB) 2025-12-18 00:14:45.007028 | 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-12-18 00:14:45.116545 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible-base==2.10.17.post0) 2025-12-18 00:14:45.125027 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB) 2025-12-18 00:14:45.155905 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible-base==2.10.17.post0) 2025-12-18 00:14:45.162785 | controller | Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes) 2025-12-18 00:14:45.183321 | controller | Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl (4.5 MB) 2025-12-18 00:14:45.236050 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.5/4.5 MB 106.6 MB/s eta 0:00:00 2025-12-18 00:14:45.241173 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB) 2025-12-18 00:14:45.256703 | 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-12-18 00:14:45.285335 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 806.0/806.0 kB 27.4 MB/s eta 0:00:00 2025-12-18 00:14:45.295561 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB) 2025-12-18 00:14:45.325276 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB) 2025-12-18 00:14:45.340434 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB) 2025-12-18 00:14:45.376055 | controller | Building wheels for collected packages: ansible-base 2025-12-18 00:14:45.377266 | controller | Building wheel for ansible-base (setup.py): started 2025-12-18 00:14:48.110286 | controller | Building wheel for ansible-base (setup.py): finished with status 'done' 2025-12-18 00:14:48.113800 | controller | Created wheel for ansible-base: filename=ansible_base-2.10.17.post0-py3-none-any.whl size=1881569 sha256=3aa274d2060939a5113ad8ab1299a4842537882f50e609c3c0473f1d1765020f 2025-12-18 00:14:48.114104 | controller | Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-p34yggc_/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7 2025-12-18 00:14:48.134531 | controller | Successfully built ansible-base 2025-12-18 00:14:48.199312 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible-base 2025-12-18 00:14:51.862548 | 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-12-18 00:14:52.575590 | controller | ok: Runtime: 0:00:10.073404 2025-12-18 00:14:52.584654 | 2025-12-18 00:14:52.584825 | TASK [Setup download-artifact-fork role] 2025-12-18 00:14:52.606788 | controller | ok 2025-12-18 00:14:52.629515 | 2025-12-18 00:14:52.629645 | TASK [download-artifact-fork : Parse inventory response] 2025-12-18 00:14:52.671033 | controller | ok 2025-12-18 00:14:52.680800 | 2025-12-18 00:14:52.680924 | TASK [download-artifact-fork : Fetch info from Zuul API] 2025-12-18 00:14:52.706374 | controller | skipping: Conditional result was False 2025-12-18 00:14:52.713555 | 2025-12-18 00:14:52.713714 | TASK [download-artifact-fork : Parse build response] 2025-12-18 00:14:52.749100 | controller | skipping: Conditional result was False 2025-12-18 00:14:52.757136 | 2025-12-18 00:14:52.757259 | TASK [download-artifact-fork : Ensure artifacts directory exists] 2025-12-18 00:14:53.777175 | controller | changed 2025-12-18 00:14:53.786792 | 2025-12-18 00:14:53.786950 | LOOP [download-artifact-fork : Download archive by type] 2025-12-18 00:14:53.823182 | controller | skipping: Conditional result was False 2025-12-18 00:14:53.823516 | 2025-12-18 00:14:56.092356 | controller | changed: OK (20199 bytes) 2025-12-18 00:14:56.114043 | 2025-12-18 00:14:56.114163 | TASK [deploy-artifacts : define __collections] 2025-12-18 00:14:56.149425 | controller | ok 2025-12-18 00:14:56.159524 | 2025-12-18 00:14:56.159658 | LOOP [deploy-artifacts : Create list of collections] 2025-12-18 00:14:56.188182 | controller | skipping: Conditional result was False 2025-12-18 00:14:56.201313 | controller | ok: 2025-12-18 00:14:56.201429 | controller | { 2025-12-18 00:14:56.201453 | controller | "branch": "main", 2025-12-18 00:14:56.201472 | controller | "job": "build-ansible-collection", 2025-12-18 00:14:56.201489 | controller | "metadata": { 2025-12-18 00:14:56.201507 | controller | "type": "ansible_collection", 2025-12-18 00:14:56.201523 | controller | "version": "5.0.0" 2025-12-18 00:14:56.201541 | controller | }, 2025-12-18 00:14:56.201565 | controller | "name": "ansible.network", 2025-12-18 00:14:56.201583 | controller | "project": "ansible-collections/ansible.network", 2025-12-18 00:14:56.201599 | controller | "url": "https://7bfdff24fd69c05d87b3-1058dc3e51dc205c011a13c69f0de41f.ssl.cf2.rackcdn.com/ansible/6dd4976c9a9f4c06b5de144213bc0a17/artifacts/ansible-network-5.0.0.tar.gz" 2025-12-18 00:14:56.201626 | controller | } 2025-12-18 00:14:56.218344 | 2025-12-18 00:14:56.218469 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy] 2025-12-18 00:14:57.832178 | controller | Starting galaxy collection install process 2025-12-18 00:14:57.832657 | controller | Process install dependency map 2025-12-18 00:15:11.783166 | controller | Starting collection install process 2025-12-18 00:15:11.796579 | controller | Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network' 2025-12-18 00:15:11.796641 | controller | ansible.network (5.0.0) was installed successfully 2025-12-18 00:15:11.796752 | controller | Installing 'ansible.netcommon:8.2.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon' 2025-12-18 00:15:11.796770 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-netcommon-8.2.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:13.520496 | controller | ansible.netcommon (8.2.0) was installed successfully 2025-12-18 00:15:13.520664 | controller | Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils' 2025-12-18 00:15:13.520918 | 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-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:15.429071 | controller | ansible.utils (6.0.0) was installed successfully 2025-12-18 00:15:15.429237 | controller | Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos' 2025-12-18 00:15:15.429641 | 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-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:18.469683 | controller | arista.eos (12.0.0) was installed successfully 2025-12-18 00:15:18.470126 | controller | Installing 'cisco.ios:11.2.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios' 2025-12-18 00:15:18.470146 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-ios-11.2.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:22.032044 | controller | cisco.ios (11.2.0) was installed successfully 2025-12-18 00:15:22.032303 | controller | Installing 'cisco.iosxr:12.1.1' to '/home/zuul/.ansible/collections/ansible_collections/cisco/iosxr' 2025-12-18 00:15:22.032317 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-iosxr-12.1.1.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:25.137252 | controller | cisco.iosxr (12.1.1) was installed successfully 2025-12-18 00:15:25.137387 | controller | Installing 'cisco.nxos:11.1.1' to '/home/zuul/.ansible/collections/ansible_collections/cisco/nxos' 2025-12-18 00:15:25.137674 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-nxos-11.1.1.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:30.660581 | controller | cisco.nxos (11.1.1) was installed successfully 2025-12-18 00:15:30.660843 | controller | Installing 'junipernetworks.junos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/junipernetworks/junos' 2025-12-18 00:15:30.660885 | 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-4149o66yflis/tmpjpxtvuwh 2025-12-18 00:15:33.652983 | controller | junipernetworks.junos (11.0.0) was installed successfully 2025-12-18 00:15:34.121557 | controller | ok: Runtime: 0:00:36.785035 2025-12-18 00:15:34.157188 | 2025-12-18 00:15:34.157391 | TASK [podman may need iptables kernel modules] 2025-12-18 00:15:35.535183 | controller | ok: Runtime: 0:00:00.006678 2025-12-18 00:15:35.575548 | 2025-12-18 00:15:35.575701 | PLAY RECAP 2025-12-18 00:15:35.575763 | controller | ok: 46 changed: 26 unreachable: 0 failed: 0 skipped: 17 rescued: 0 ignored: 0 2025-12-18 00:15:35.575794 | 2025-12-18 00:15:35.752334 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-18 00:15:35.753563 | RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master] 2025-12-18 00:15:36.488862 | 2025-12-18 00:15:36.488985 | PLAY [controller] 2025-12-18 00:15:36.514297 | 2025-12-18 00:15:36.514445 | TASK [Copy the galaxy.yml on the controller] 2025-12-18 00:15:40.407751 | controller | changed 2025-12-18 00:15:40.413680 | 2025-12-18 00:15:40.413755 | TASK [Load information from galaxy.yml] 2025-12-18 00:15:40.444889 | controller | ok 2025-12-18 00:15:40.451625 | 2025-12-18 00:15:40.451708 | LOOP [Enable FIPS mode] 2025-12-18 00:15:40.472871 | 2025-12-18 00:15:40.473057 | LOOP [ansible-test : Include branch specific variables.] 2025-12-18 00:15:40.499895 | controller | ok: "/var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/untrusted/project_2/github.com/ansible/ansible-zuul-jobs/roles/ansible-test/vars/default.yaml" 2025-12-18 00:15:40.500076 | 2025-12-18 00:15:40.515711 | 2025-12-18 00:15:40.515843 | TASK [ansible-test : Setup --skip-tags for test_options] 2025-12-18 00:15:40.556991 | controller | ok 2025-12-18 00:15:40.563005 | 2025-12-18 00:15:40.563121 | TASK [ansible-test : Enable --inventory for network-integration] 2025-12-18 00:15:40.578486 | controller | skipping: Conditional result was False 2025-12-18 00:15:40.586413 | 2025-12-18 00:15:40.586524 | TASK [ansible-test : Enable --retry-on-error] 2025-12-18 00:15:40.600870 | controller | skipping: Conditional result was False 2025-12-18 00:15:40.608486 | 2025-12-18 00:15:40.608590 | TASK [ansible-test : Enable --continue-on-error] 2025-12-18 00:15:40.639078 | controller | ok 2025-12-18 00:15:40.647979 | 2025-12-18 00:15:40.648155 | TASK [ansible-test : Enable --requirements] 2025-12-18 00:15:40.664176 | controller | skipping: Conditional result was False 2025-12-18 00:15:40.671750 | 2025-12-18 00:15:40.671855 | TASK [ansible-test : Adjust options for unit tests] 2025-12-18 00:15:40.687417 | controller | skipping: Conditional result was False 2025-12-18 00:15:40.697453 | 2025-12-18 00:15:40.697612 | TASK [ansible-test : Install requirements with unit tests] 2025-12-18 00:15:40.758981 | controller | ok 2025-12-18 00:15:40.765085 | 2025-12-18 00:15:40.765164 | TASK [ansible-test : Set --skip-test] 2025-12-18 00:15:40.810471 | controller | skipping: Conditional result was False 2025-12-18 00:15:40.820799 | 2025-12-18 00:15:40.820971 | TASK [ansible-test : Reduce verbosity] 2025-12-18 00:15:40.855330 | controller | ok 2025-12-18 00:15:40.863202 | 2025-12-18 00:15:40.863325 | TASK [ansible-test : Setup --python option] 2025-12-18 00:15:40.889311 | controller | skipping: Conditional result was False 2025-12-18 00:15:40.896940 | 2025-12-18 00:15:40.897046 | TASK [ansible-test : Setup --docker option] 2025-12-18 00:15:40.931938 | controller | ok 2025-12-18 00:15:40.941690 | 2025-12-18 00:15:40.941817 | TASK [ansible-test : check if MANIFEST.json exists] 2025-12-18 00:15:42.198902 | controller | ok 2025-12-18 00:15:42.209088 | 2025-12-18 00:15:42.209244 | TASK [ansible-test : Copy the MANIFEST.json on the controller] 2025-12-18 00:15:42.235843 | controller | skipping: Conditional result was False 2025-12-18 00:15:42.245543 | 2025-12-18 00:15:42.245654 | TASK [ansible-test : Load information from MANIFEST.json] 2025-12-18 00:15:42.271250 | controller | skipping: Conditional result was False 2025-12-18 00:15:42.279998 | 2025-12-18 00:15:42.280132 | TASK [ansible-test : Setup location of project for integration tests] 2025-12-18 00:15:42.304488 | controller | skipping: Conditional result was False 2025-12-18 00:15:42.315006 | 2025-12-18 00:15:42.315173 | TASK [ansible-test : Copy the galaxy.yml on the controller] 2025-12-18 00:15:43.591122 | controller | ok 2025-12-18 00:15:43.599183 | 2025-12-18 00:15:43.599272 | TASK [ansible-test : Load information from galaxy.yml] 2025-12-18 00:15:43.633386 | controller | ok 2025-12-18 00:15:43.641244 | 2025-12-18 00:15:43.641389 | TASK [ansible-test : Setup location of project for integration tests] 2025-12-18 00:15:43.672406 | controller | ok 2025-12-18 00:15:43.679913 | 2025-12-18 00:15:43.680058 | TASK [ansible-test : Setup minimum test requirements] 2025-12-18 00:15:43.713884 | controller | ok 2025-12-18 00:15:43.725213 | 2025-12-18 00:15:43.725380 | TASK [ansible-test : Ensure pip temp directory exists in /var/tmp] 2025-12-18 00:15:44.677884 | controller | ok 2025-12-18 00:15:44.685312 | 2025-12-18 00:15:44.685425 | TASK [ansible-test : Install python requirements] 2025-12-18 00:15:46.362663 | controller | Collecting yamllint (from -r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1)) 2025-12-18 00:15:46.385199 | controller | Downloading yamllint-1.35.1-py3-none-any.whl.metadata (4.2 kB) 2025-12-18 00:15:46.434465 | controller | Collecting pathspec>=0.5.3 (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1)) 2025-12-18 00:15:46.441187 | controller | Downloading pathspec-0.12.1-py3-none-any.whl.metadata (21 kB) 2025-12-18 00:15:46.465592 | 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-12-18 00:15:46.480233 | controller | Downloading yamllint-1.35.1-py3-none-any.whl (66 kB) 2025-12-18 00:15:46.501640 | controller | Downloading pathspec-0.12.1-py3-none-any.whl (31 kB) 2025-12-18 00:15:46.576198 | controller | Installing collected packages: pathspec, yamllint 2025-12-18 00:15:46.707894 | controller | Successfully installed pathspec-0.12.1 yamllint-1.35.1 2025-12-18 00:15:47.048974 | controller | ok: Runtime: 0:00:01.308289 2025-12-18 00:15:47.059163 | 2025-12-18 00:15:47.060325 | TASK [ansible-test : Copy the integration_config.yml file from the controller] 2025-12-18 00:15:47.891952 | controller | cp: cannot stat '/tmp/integration_config.yml': No such file or directory 2025-12-18 00:15:48.430748 | controller | ERROR 2025-12-18 00:15:48.430982 | controller | { 2025-12-18 00:15:48.431038 | controller | "delta": "0:00:00.009401", 2025-12-18 00:15:48.431065 | controller | "end": "2025-12-18 00:15:47.892195", 2025-12-18 00:15:48.431089 | controller | "msg": "non-zero return code", 2025-12-18 00:15:48.431110 | controller | "rc": 1, 2025-12-18 00:15:48.431129 | controller | "start": "2025-12-18 00:15:47.882794" 2025-12-18 00:15:48.431148 | controller | } 2025-12-18 00:15:48.431227 | controller | ERROR: Ignoring Errors 2025-12-18 00:15:48.441175 | 2025-12-18 00:15:48.441317 | TASK [ansible-test : Copy potential cloud provider configuration for ansible-test in the collection] 2025-12-18 00:15:48.815696 | controller | skipping: Conditional result was False 2025-12-18 00:15:48.825281 | 2025-12-18 00:15:48.825400 | TASK [ansible-test : Enable persistent connection logging] 2025-12-18 00:15:50.396496 | controller | changed: section and option added 2025-12-18 00:15:50.405106 | 2025-12-18 00:15:50.405213 | TASK [ansible-test : Set persistent ssh_type value] 2025-12-18 00:15:51.429334 | controller | changed: option added 2025-12-18 00:15:51.441256 | 2025-12-18 00:15:51.441433 | TASK [ansible-test : Set ansible log path] 2025-12-18 00:15:52.793746 | controller | changed: section and option added 2025-12-18 00:15:52.803203 | 2025-12-18 00:15:52.803311 | TASK [ansible-test : Identify the changed targets] 2025-12-18 00:15:53.171978 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.190841 | 2025-12-18 00:15:53.191091 | TASK [ansible-test : set_fact] 2025-12-18 00:15:53.270833 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.291288 | 2025-12-18 00:15:53.291480 | TASK [ansible-test : Set the targets] 2025-12-18 00:15:53.381972 | controller | ok 2025-12-18 00:15:53.390212 | 2025-12-18 00:15:53.390308 | TASK [ansible-test : set_fact] 2025-12-18 00:15:53.416266 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.424095 | 2025-12-18 00:15:53.424234 | TASK [ansible-test : List the targets] 2025-12-18 00:15:53.789770 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.797423 | 2025-12-18 00:15:53.797552 | TASK [ansible-test : set_fact] 2025-12-18 00:15:53.811692 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.821656 | 2025-12-18 00:15:53.821780 | TASK [ansible-test : set_fact] 2025-12-18 00:15:53.847840 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.857685 | 2025-12-18 00:15:53.857820 | LOOP [ansible-test : set_fact] 2025-12-18 00:15:53.915339 | 2025-12-18 00:15:53.915595 | TASK [ansible-test : set_fact] 2025-12-18 00:15:53.931975 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.941449 | 2025-12-18 00:15:53.941692 | TASK [ansible-test : debug] 2025-12-18 00:15:53.956611 | controller | skipping: Conditional result was False 2025-12-18 00:15:53.966239 | 2025-12-18 00:15:53.966365 | TASK [ansible-test : debug] 2025-12-18 00:15:53.998021 | About to run: ansible-test sanity --requirements --docker -v 2025-12-18 00:15:54.005074 | 2025-12-18 00:15:54.005183 | TASK [ansible-test : Run the test suite] 2025-12-18 00:15:55.864691 | controller | Run command: docker images quay.io/ansible/default-test-container:2.9.0 --format '{{json .}}' 2025-12-18 00:15:55.980620 | controller | Run command: docker pull quay.io/ansible/default-test-container:2.9.0 2025-12-18 00:15:57.554432 | controller | 2.9.0: Pulling from ansible/default-test-container 2025-12-18 00:15:57.554646 | controller | 171857c49d0f: Pulling fs layer 2025-12-18 00:15:57.554673 | controller | 419640447d26: Pulling fs layer 2025-12-18 00:15:57.554681 | controller | 61e52f862619: Pulling fs layer 2025-12-18 00:15:57.554700 | controller | 851de0426e26: Pulling fs layer 2025-12-18 00:15:57.554710 | controller | 37425716ea5b: Pulling fs layer 2025-12-18 00:15:57.554719 | controller | cd9b0c439616: Pulling fs layer 2025-12-18 00:15:57.554725 | controller | d4612dbd8855: Pulling fs layer 2025-12-18 00:15:57.554731 | controller | 554699364730: Pulling fs layer 2025-12-18 00:15:57.554741 | controller | 1ff15d4bdb3e: Pulling fs layer 2025-12-18 00:15:57.554747 | controller | 5f2e4724adea: Pulling fs layer 2025-12-18 00:15:57.554754 | controller | a02d9a95ccb8: Pulling fs layer 2025-12-18 00:15:57.554760 | controller | 989f4ce370cb: Pulling fs layer 2025-12-18 00:15:57.554766 | controller | 0d7f52cdf9df: Pulling fs layer 2025-12-18 00:15:57.554772 | controller | c423742351d5: Pulling fs layer 2025-12-18 00:15:57.554778 | controller | 851de0426e26: Waiting 2025-12-18 00:15:57.554785 | controller | 37425716ea5b: Waiting 2025-12-18 00:15:57.554791 | controller | cd9b0c439616: Waiting 2025-12-18 00:15:57.554796 | controller | d4612dbd8855: Waiting 2025-12-18 00:15:57.554802 | controller | 554699364730: Waiting 2025-12-18 00:15:57.554808 | controller | 1ff15d4bdb3e: Waiting 2025-12-18 00:15:57.554831 | controller | 5f2e4724adea: Waiting 2025-12-18 00:15:57.554841 | controller | a02d9a95ccb8: Waiting 2025-12-18 00:15:57.554847 | controller | 989f4ce370cb: Waiting 2025-12-18 00:15:57.554853 | controller | 0d7f52cdf9df: Waiting 2025-12-18 00:15:57.554859 | controller | 109236341d21: Pulling fs layer 2025-12-18 00:15:57.554866 | controller | 07a2f61c96b8: Pulling fs layer 2025-12-18 00:15:57.554871 | controller | c423742351d5: Waiting 2025-12-18 00:15:57.554878 | controller | 109236341d21: Waiting 2025-12-18 00:15:57.554884 | controller | 041f122f27ae: Pulling fs layer 2025-12-18 00:15:57.554893 | controller | ca6f5098b12e: Pulling fs layer 2025-12-18 00:15:57.554900 | controller | 1eb3e7b2afd9: Pulling fs layer 2025-12-18 00:15:57.554906 | controller | 18a0b750727a: Pulling fs layer 2025-12-18 00:15:57.554912 | controller | 17f2f596716c: Pulling fs layer 2025-12-18 00:15:57.554917 | controller | 07a2f61c96b8: Waiting 2025-12-18 00:15:57.554923 | controller | 041f122f27ae: Waiting 2025-12-18 00:15:57.554933 | controller | ca6f5098b12e: Waiting 2025-12-18 00:15:57.931520 | controller | 1eb3e7b2afd9: Waiting 2025-12-18 00:15:57.931570 | controller | 18a0b750727a: Waiting 2025-12-18 00:15:57.931577 | controller | f35a9998a9bd: Pulling fs layer 2025-12-18 00:15:57.931584 | controller | fdfc10566405: Pulling fs layer 2025-12-18 00:15:57.931590 | controller | 1ff1c442c5fe: Pulling fs layer 2025-12-18 00:15:57.931596 | controller | a3443c4a17ed: Pulling fs layer 2025-12-18 00:15:57.931601 | controller | 0edcf9fb2b15: Pulling fs layer 2025-12-18 00:15:57.931607 | controller | 5af43b69e845: Pulling fs layer 2025-12-18 00:15:57.931613 | controller | 1651773effb2: Pulling fs layer 2025-12-18 00:15:57.931619 | controller | 79e23c5c0fe4: Pulling fs layer 2025-12-18 00:15:57.931625 | controller | e5058b1faaa6: Pulling fs layer 2025-12-18 00:15:57.931631 | controller | 846775490569: Pulling fs layer 2025-12-18 00:15:57.931637 | controller | 17f2f596716c: Waiting 2025-12-18 00:15:57.931645 | controller | f35a9998a9bd: Waiting 2025-12-18 00:15:57.931651 | controller | fdfc10566405: Waiting 2025-12-18 00:15:57.931657 | controller | 1ff1c442c5fe: Waiting 2025-12-18 00:15:57.931663 | controller | a3443c4a17ed: Waiting 2025-12-18 00:15:57.931669 | controller | 0edcf9fb2b15: Waiting 2025-12-18 00:15:57.931675 | controller | 5af43b69e845: Waiting 2025-12-18 00:15:57.931681 | controller | 1651773effb2: Waiting 2025-12-18 00:15:57.931687 | controller | 79e23c5c0fe4: Waiting 2025-12-18 00:15:57.931692 | controller | e5058b1faaa6: Waiting 2025-12-18 00:15:57.931699 | controller | 846775490569: Waiting 2025-12-18 00:15:57.931714 | controller | 419640447d26: Verifying Checksum 2025-12-18 00:15:57.985541 | controller | 419640447d26: Download complete 2025-12-18 00:15:57.985616 | controller | 61e52f862619: Verifying Checksum 2025-12-18 00:15:58.379944 | controller | 61e52f862619: Download complete 2025-12-18 00:15:58.380033 | controller | 171857c49d0f: Verifying Checksum 2025-12-18 00:15:58.837120 | controller | 171857c49d0f: Download complete 2025-12-18 00:15:58.837173 | controller | 851de0426e26: Verifying Checksum 2025-12-18 00:15:58.840404 | controller | 851de0426e26: Download complete 2025-12-18 00:15:59.188003 | controller | cd9b0c439616: Verifying Checksum 2025-12-18 00:15:59.624983 | controller | cd9b0c439616: Download complete 2025-12-18 00:15:59.625038 | controller | d4612dbd8855: Verifying Checksum 2025-12-18 00:16:00.561971 | controller | d4612dbd8855: Download complete 2025-12-18 00:16:00.562025 | controller | 1ff15d4bdb3e: Verifying Checksum 2025-12-18 00:16:01.527621 | controller | 1ff15d4bdb3e: Download complete 2025-12-18 00:16:01.527674 | controller | 5f2e4724adea: Verifying Checksum 2025-12-18 00:16:03.071771 | controller | 5f2e4724adea: Download complete 2025-12-18 00:16:03.071847 | controller | a02d9a95ccb8: Verifying Checksum 2025-12-18 00:16:03.823811 | controller | a02d9a95ccb8: Download complete 2025-12-18 00:16:03.823901 | controller | 171857c49d0f: Pull complete 2025-12-18 00:16:03.887690 | controller | 419640447d26: Pull complete 2025-12-18 00:16:03.923103 | controller | 61e52f862619: Pull complete 2025-12-18 00:16:03.941680 | controller | 989f4ce370cb: Verifying Checksum 2025-12-18 00:16:03.941896 | controller | 989f4ce370cb: Download complete 2025-12-18 00:16:03.964423 | controller | 851de0426e26: Pull complete 2025-12-18 00:16:04.790800 | controller | 0d7f52cdf9df: Download complete 2025-12-18 00:16:05.661377 | controller | c423742351d5: Verifying Checksum 2025-12-18 00:16:05.661508 | controller | c423742351d5: Download complete 2025-12-18 00:16:08.366182 | controller | 554699364730: Verifying Checksum 2025-12-18 00:16:08.366399 | controller | 554699364730: Download complete 2025-12-18 00:16:09.279483 | controller | 07a2f61c96b8: Verifying Checksum 2025-12-18 00:16:09.279610 | controller | 07a2f61c96b8: Download complete 2025-12-18 00:16:10.101409 | controller | 041f122f27ae: Verifying Checksum 2025-12-18 00:16:10.101531 | controller | 041f122f27ae: Download complete 2025-12-18 00:16:11.804770 | controller | ca6f5098b12e: Verifying Checksum 2025-12-18 00:16:11.804959 | controller | ca6f5098b12e: Download complete 2025-12-18 00:16:13.120023 | controller | 1eb3e7b2afd9: Verifying Checksum 2025-12-18 00:16:13.120250 | controller | 1eb3e7b2afd9: Download complete 2025-12-18 00:16:14.766992 | controller | 18a0b750727a: Verifying Checksum 2025-12-18 00:16:14.767247 | controller | 18a0b750727a: Download complete 2025-12-18 00:16:15.306371 | controller | 109236341d21: Verifying Checksum 2025-12-18 00:16:15.306480 | controller | 109236341d21: Download complete 2025-12-18 00:16:15.649953 | controller | 17f2f596716c: Verifying Checksum 2025-12-18 00:16:15.650128 | controller | 17f2f596716c: Download complete 2025-12-18 00:16:16.128145 | controller | f35a9998a9bd: Verifying Checksum 2025-12-18 00:16:16.128364 | controller | f35a9998a9bd: Download complete 2025-12-18 00:16:16.560919 | controller | fdfc10566405: Verifying Checksum 2025-12-18 00:16:16.561388 | controller | fdfc10566405: Download complete 2025-12-18 00:16:17.137741 | controller | 1ff1c442c5fe: Verifying Checksum 2025-12-18 00:16:17.137884 | controller | 1ff1c442c5fe: Download complete 2025-12-18 00:16:19.976684 | controller | 0edcf9fb2b15: Verifying Checksum 2025-12-18 00:16:19.976809 | controller | 0edcf9fb2b15: Download complete 2025-12-18 00:16:22.791627 | controller | a3443c4a17ed: Verifying Checksum 2025-12-18 00:16:22.793980 | controller | a3443c4a17ed: Download complete 2025-12-18 00:16:23.672997 | controller | 37425716ea5b: Verifying Checksum 2025-12-18 00:16:26.174968 | controller | 37425716ea5b: Download complete 2025-12-18 00:16:26.175028 | controller | 1651773effb2: Verifying Checksum 2025-12-18 00:16:26.807794 | controller | 1651773effb2: Download complete 2025-12-18 00:16:26.807907 | controller | 5af43b69e845: Verifying Checksum 2025-12-18 00:16:26.851957 | controller | 5af43b69e845: Download complete 2025-12-18 00:16:26.852056 | controller | 79e23c5c0fe4: Verifying Checksum 2025-12-18 00:16:30.353894 | controller | 79e23c5c0fe4: Download complete 2025-12-18 00:16:30.354958 | controller | e5058b1faaa6: Verifying Checksum 2025-12-18 00:16:33.264749 | controller | e5058b1faaa6: Download complete 2025-12-18 00:16:33.264875 | controller | 846775490569: Verifying Checksum 2025-12-18 00:16:33.265045 | controller | 846775490569: Download complete 2025-12-18 00:16:46.756374 | controller | 37425716ea5b: Pull complete 2025-12-18 00:16:46.782762 | controller | cd9b0c439616: Pull complete 2025-12-18 00:16:46.843134 | controller | d4612dbd8855: Pull complete 2025-12-18 00:16:52.623458 | controller | 554699364730: Pull complete 2025-12-18 00:16:52.666462 | controller | 1ff15d4bdb3e: Pull complete 2025-12-18 00:16:52.699089 | controller | 5f2e4724adea: Pull complete 2025-12-18 00:16:52.759756 | controller | a02d9a95ccb8: Pull complete 2025-12-18 00:16:52.813522 | controller | 989f4ce370cb: Pull complete 2025-12-18 00:16:52.844867 | controller | 0d7f52cdf9df: Pull complete 2025-12-18 00:16:52.880102 | controller | c423742351d5: Pull complete 2025-12-18 00:16:55.671652 | controller | 109236341d21: Pull complete 2025-12-18 00:16:55.708611 | controller | 07a2f61c96b8: Pull complete 2025-12-18 00:16:55.737036 | controller | 041f122f27ae: Pull complete 2025-12-18 00:16:55.945952 | controller | ca6f5098b12e: Pull complete 2025-12-18 00:16:56.028459 | controller | 1eb3e7b2afd9: Pull complete 2025-12-18 00:16:56.103969 | controller | 18a0b750727a: Pull complete 2025-12-18 00:16:56.135921 | controller | 17f2f596716c: Pull complete 2025-12-18 00:16:56.190243 | controller | f35a9998a9bd: Pull complete 2025-12-18 00:16:56.236593 | controller | fdfc10566405: Pull complete 2025-12-18 00:16:56.274262 | controller | 1ff1c442c5fe: Pull complete 2025-12-18 00:16:58.433732 | controller | a3443c4a17ed: Pull complete 2025-12-18 00:17:02.374223 | controller | 0edcf9fb2b15: Pull complete 2025-12-18 00:17:05.495574 | controller | 5af43b69e845: Pull complete 2025-12-18 00:17:08.567387 | controller | 1651773effb2: Pull complete 2025-12-18 00:17:11.444303 | controller | 79e23c5c0fe4: Pull complete 2025-12-18 00:17:13.605497 | controller | e5058b1faaa6: Pull complete 2025-12-18 00:17:16.417978 | controller | 846775490569: Pull complete 2025-12-18 00:17:16.445561 | controller | Digest: sha256:923f4b465456ae05243474faf9061abbefa2c2c5b88f24455fa2d5ce3d8d2ab4 2025-12-18 00:17:16.452442 | controller | Status: Downloaded newer image for quay.io/ansible/default-test-container:2.9.0 2025-12-18 00:17:16.460252 | controller | quay.io/ansible/default-test-container:2.9.0 2025-12-18 00:17:16.464805 | controller | Run command: docker images quay.io/ansible/pypi-test-container:1.0.0 --format '{{json .}}' 2025-12-18 00:17:16.490906 | controller | Run command: docker pull quay.io/ansible/pypi-test-container:1.0.0 2025-12-18 00:17:18.109856 | controller | 1.0.0: Pulling from ansible/pypi-test-container 2025-12-18 00:17:18.110069 | controller | 04a5f4cda3ee: Pulling fs layer 2025-12-18 00:17:18.110142 | controller | ff496a88c8ed: Pulling fs layer 2025-12-18 00:17:18.110211 | controller | 0ce83f459fe7: Pulling fs layer 2025-12-18 00:17:18.110282 | controller | 2e5170e1f099: Pulling fs layer 2025-12-18 00:17:18.110934 | controller | 7641eb41b08c: Pulling fs layer 2025-12-18 00:17:18.111933 | controller | ad15fa9da398: Pulling fs layer 2025-12-18 00:17:18.111952 | controller | 087d91352424: Pulling fs layer 2025-12-18 00:17:18.111959 | controller | 8b92efd6a100: Pulling fs layer 2025-12-18 00:17:18.111970 | controller | 2e5170e1f099: Waiting 2025-12-18 00:17:18.112094 | controller | 7641eb41b08c: Waiting 2025-12-18 00:17:18.112222 | controller | ad15fa9da398: Waiting 2025-12-18 00:17:18.113580 | controller | 087d91352424: Waiting 2025-12-18 00:17:18.458267 | controller | 8b92efd6a100: Waiting 2025-12-18 00:17:18.458324 | controller | ff496a88c8ed: Verifying Checksum 2025-12-18 00:17:18.458426 | controller | ff496a88c8ed: Download complete 2025-12-18 00:17:18.498402 | controller | 0ce83f459fe7: Verifying Checksum 2025-12-18 00:17:18.498511 | controller | 0ce83f459fe7: Download complete 2025-12-18 00:17:18.736721 | controller | 04a5f4cda3ee: Verifying Checksum 2025-12-18 00:17:18.736914 | controller | 04a5f4cda3ee: Download complete 2025-12-18 00:17:18.904782 | controller | 7641eb41b08c: Verifying Checksum 2025-12-18 00:17:18.904981 | controller | 7641eb41b08c: Download complete 2025-12-18 00:17:19.053043 | controller | 2e5170e1f099: Verifying Checksum 2025-12-18 00:17:19.060834 | controller | 2e5170e1f099: Download complete 2025-12-18 00:17:19.077099 | controller | ad15fa9da398: Verifying Checksum 2025-12-18 00:17:19.077452 | controller | ad15fa9da398: Download complete 2025-12-18 00:17:19.326915 | controller | 087d91352424: Verifying Checksum 2025-12-18 00:17:19.327128 | controller | 087d91352424: Download complete 2025-12-18 00:17:19.457600 | controller | 8b92efd6a100: Verifying Checksum 2025-12-18 00:17:19.458000 | controller | 8b92efd6a100: Download complete 2025-12-18 00:17:21.391236 | controller | 04a5f4cda3ee: Pull complete 2025-12-18 00:17:21.421863 | controller | ff496a88c8ed: Pull complete 2025-12-18 00:17:21.455270 | controller | 0ce83f459fe7: Pull complete 2025-12-18 00:17:23.066526 | controller | 2e5170e1f099: Pull complete 2025-12-18 00:17:23.106493 | controller | 7641eb41b08c: Pull complete 2025-12-18 00:17:23.156003 | controller | ad15fa9da398: Pull complete 2025-12-18 00:17:25.451495 | controller | 087d91352424: Pull complete 2025-12-18 00:17:25.528926 | controller | 8b92efd6a100: Pull complete 2025-12-18 00:17:25.585016 | controller | Digest: sha256:71042ab0a14971b5608fe75706de54f367fc31db573e3b3955182037f73cadb6 2025-12-18 00:17:25.598597 | controller | Status: Downloaded newer image for quay.io/ansible/pypi-test-container:1.0.0 2025-12-18 00:17:25.617783 | controller | quay.io/ansible/pypi-test-container:1.0.0 2025-12-18 00:17:25.624896 | controller | Run command: docker run --detach quay.io/ansible/pypi-test-container:1.0.0 2025-12-18 00:17:33.562249 | controller | Run command: docker inspect e5076b55a0d66cb614980dfb84b58e592c91eda40d2c0706a51f506e986226ed 2025-12-18 00:17:33.625379 | controller | Scanning collection root: /home/zuul/.ansible/collections/ansible_collections 2025-12-18 00:17:33.640255 | controller | Including collection: ansible.netcommon (292 files) 2025-12-18 00:17:33.657684 | controller | Including collection: ansible.network (23 files) 2025-12-18 00:17:33.657744 | controller | Including collection: ansible.utils (442 files) 2025-12-18 00:17:33.705155 | controller | Including collection: arista.eos (1022 files) 2025-12-18 00:17:33.757945 | controller | Including collection: cisco.ios (1174 files) 2025-12-18 00:17:33.817449 | controller | Including collection: cisco.iosxr (1044 files) 2025-12-18 00:17:33.909837 | controller | Including collection: cisco.nxos (1682 files) 2025-12-18 00:17:33.961375 | controller | Including collection: junipernetworks.junos (963 files) 2025-12-18 00:17:34.011283 | controller | Creating a payload archive containing 7368 files... 2025-12-18 00:17:36.540461 | controller | Created a 5992105 byte payload archive containing 7368 files in 2 seconds. 2025-12-18 00:17:36.547084 | controller | Assuming Docker is available on localhost. 2025-12-18 00:17:36.547418 | 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-12-18 00:17:37.192253 | controller | Run command: docker exec -i 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 dd of=/root/docker.sh bs=65536 2025-12-18 00:17:37.279929 | controller | Run command: docker exec 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 /bin/bash /root/docker.sh 2025-12-18 00:17:37.361870 | controller | Run command: docker exec -i 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 dd of=/root/test.tgz bs=65536 2025-12-18 00:17:37.477170 | controller | Run command: docker exec 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 tar oxzf /root/test.tgz -C /root 2025-12-18 00:17:38.584895 | controller | Run command: docker exec 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 /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-m4_kop87.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/ 2025-12-18 00:17:39.058542 | controller | Injecting custom PyPI hosts entries: /etc/hosts 2025-12-18 00:17:39.059087 | controller | Injecting custom PyPI config: /root/.pip/pip.conf 2025-12-18 00:17:39.060385 | controller | Injecting custom PyPI config: /root/.pydistutils.cfg 2025-12-18 00:17:39.062297 | controller | Running sanity test 'action-plugin-docs' with Python 3.6 2025-12-18 00:17:39.063297 | controller | Read 0 sanity test ignore line(s) for Ansible 2.10 from: tests/sanity/ignore-2.10.txt 2025-12-18 00:17:39.073285 | controller | No tests applicable. 2025-12-18 00:17:40.191188 | controller | Running sanity test 'ansible-doc' with Python 3.6 2025-12-18 00:17:40.192233 | controller | No tests applicable. 2025-12-18 00:17:40.192244 | controller | Running sanity test 'changelog' with Python 3.6 2025-12-18 00:17:40.192252 | 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-12-18 00:17:40.192276 | 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-12-18 00:17:40.931040 | controller | Collecting antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2)) 2025-12-18 00:17:55.955146 | 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-12-18 00:18:11.458004 | 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-12-18 00:18:27.484556 | 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-12-18 00:18:44.483061 | 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-12-18 00:19:03.505287 | 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-12-18 00:19:18.524985 | 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-12-18 00:19:18.526703 | 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-12-18 00:19:18.669043 | controller | Removing custom PyPI config: /root/.pydistutils.cfg 2025-12-18 00:19:18.669152 | 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-12-18 00:19:18.669285 | controller | Removing custom PyPI config: /root/.pip/pip.conf 2025-12-18 00:19:18.672242 | controller | Removing custom PyPI hosts entries: /etc/hosts 2025-12-18 00:19:18.731715 | controller | Run command: docker exec 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 tar czf /root/output.tgz --exclude .tmp -C /root/ansible_collections/ansible/network/tests output 2025-12-18 00:19:18.822909 | controller | Run command: docker exec -i 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 dd if=/root/output.tgz bs=65536 2025-12-18 00:19:18.916286 | controller | Run command: tar oxzf /tmp/ansible-result-l14sfyg9.tgz -C /home/zuul/.ansible/collections/ansible_collections/ansible/network/tests 2025-12-18 00:19:18.935314 | controller | Run command: docker rm -f e5076b55a0d66cb614980dfb84b58e592c91eda40d2c0706a51f506e986226ed 2025-12-18 00:19:19.311156 | controller | Run command: docker rm -f 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 2025-12-18 00:19:20.069192 | controller | ERROR: Command "docker exec 4bd849b3de25e2b32c9c1a8cd2503a6315515dd9e62823a4f280827d8cd2d505 /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-m4_kop87.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/" returned exit status 1. 2025-12-18 00:19:20.596470 | controller | ERROR 2025-12-18 00:19:20.596684 | controller | { 2025-12-18 00:19:20.596714 | controller | "delta": "0:03:24.785607", 2025-12-18 00:19:20.596733 | controller | "end": "2025-12-18 00:19:20.138986", 2025-12-18 00:19:20.596751 | controller | "msg": "non-zero return code", 2025-12-18 00:19:20.596767 | controller | "rc": 1, 2025-12-18 00:19:20.596785 | controller | "start": "2025-12-18 00:15:55.353379" 2025-12-18 00:19:20.596809 | controller | } failure 2025-12-18 00:19:20.601726 | 2025-12-18 00:19:20.601879 | PLAY RECAP 2025-12-18 00:19:20.601939 | controller | ok: 21 changed: 6 unreachable: 0 failed: 1 skipped: 20 rescued: 0 ignored: 1 2025-12-18 00:19:20.601961 | 2025-12-18 00:19:20.752221 | RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master] 2025-12-18 00:19:20.753381 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-18 00:19:21.397493 | 2025-12-18 00:19:21.397623 | PLAY [all] 2025-12-18 00:19:21.420668 | 2025-12-18 00:19:21.420820 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-18 00:19:24.438608 | controller | changed: non-zero return code 2025-12-18 00:19:24.445534 | 2025-12-18 00:19:24.445697 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-18 00:19:24.460938 | controller | skipping: Conditional result was False 2025-12-18 00:19:24.469356 | 2025-12-18 00:19:24.469503 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-18 00:19:24.503185 | 2025-12-18 00:19:24.503370 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-18 00:19:24.524874 | 2025-12-18 00:19:24.525191 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-18 00:19:24.538476 | controller | skipping: Conditional result was False 2025-12-18 00:19:24.545055 | 2025-12-18 00:19:24.545139 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-18 00:19:24.565366 | 2025-12-18 00:19:24.565528 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-18 00:19:24.579192 | controller | skipping: Conditional result was False 2025-12-18 00:19:24.587949 | 2025-12-18 00:19:24.588118 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-18 00:19:24.602187 | controller | skipping: Conditional result was False 2025-12-18 00:19:24.609895 | 2025-12-18 00:19:24.610038 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-18 00:19:24.624416 | controller | skipping: Conditional result was False 2025-12-18 00:19:24.654731 | 2025-12-18 00:19:24.654828 | PLAY RECAP 2025-12-18 00:19:24.654866 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-18 00:19:24.654888 | 2025-12-18 00:19:24.773140 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-18 00:19:24.774158 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-18 00:19:25.399257 | 2025-12-18 00:19:25.399396 | PLAY [all:!appliance*] 2025-12-18 00:19:25.423282 | 2025-12-18 00:19:25.423426 | TASK [unregister the node] 2025-12-18 00:19:25.779677 | controller | skipping: Conditional result was False 2025-12-18 00:19:25.786220 | 2025-12-18 00:19:25.786328 | TASK [include_role : fetch-output] 2025-12-18 00:19:25.827976 | controller | ok 2025-12-18 00:19:25.875054 | 2025-12-18 00:19:25.875223 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-18 00:19:25.936197 | controller | skipping: Conditional result was False 2025-12-18 00:19:25.943428 | 2025-12-18 00:19:25.943574 | TASK [fetch-output : Set log path for single node] 2025-12-18 00:19:25.984874 | controller | ok 2025-12-18 00:19:25.990867 | 2025-12-18 00:19:25.990978 | LOOP [fetch-output : Ensure local output dirs] 2025-12-18 00:19:26.445726 | controller -> localhost | ok: "/var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/logs" 2025-12-18 00:19:26.704371 | controller -> localhost | changed: "/var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/artifacts" 2025-12-18 00:19:26.985577 | controller -> localhost | changed: "/var/lib/zuul/builds/130fdbd5542f4ab580a79f9520a2ccac/work/docs" 2025-12-18 00:19:26.996050 | 2025-12-18 00:19:26.996175 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-18 00:19:29.236455 | controller | changed: 2025-12-18 00:19:29.236659 | controller | .d..t...... ./ 2025-12-18 00:19:29.236687 | controller | cd+++++++++ controller/ 2025-12-18 00:19:29.236719 | controller | changed: All items complete 2025-12-18 00:19:29.236739 | 2025-12-18 00:19:31.321497 | controller | changed: .d..t...... ./ 2025-12-18 00:19:33.349726 | controller | changed: .d..t...... ./ 2025-12-18 00:19:33.369230 | 2025-12-18 00:19:33.369368 | TASK [include_role : fetch-output-openshift] 2025-12-18 00:19:33.384364 | controller | skipping: Conditional result was False 2025-12-18 00:19:33.393864 | 2025-12-18 00:19:33.393988 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-18 00:19:33.422446 | controller | skipping: Conditional result was False 2025-12-18 00:19:33.431300 | controller | skipping: Conditional result was False 2025-12-18 00:19:33.471614 | 2025-12-18 00:19:33.471717 | PLAY [localhost] 2025-12-18 00:19:33.486527 | 2025-12-18 00:19:33.486640 | TASK [Run Zuul manifest role] 2025-12-18 00:19:33.505688 | localhost | ok 2025-12-18 00:19:33.523661 | 2025-12-18 00:19:33.523810 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-18 00:19:33.913517 | localhost | changed 2025-12-18 00:19:33.918582 | 2025-12-18 00:19:33.918670 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-18 00:19:33.958455 | localhost | ok 2025-12-18 00:19:33.968849 | 2025-12-18 00:19:33.969537 | TASK [Set zuul-log-path fact] 2025-12-18 00:19:33.990646 | localhost | ok 2025-12-18 00:19:34.044723 | 2025-12-18 00:19:34.044849 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-18 00:19:34.075120 | localhost | ok 2025-12-18 00:19:34.085117 | 2025-12-18 00:19:34.085224 | LOOP [Run upload-logs-swift role] 2025-12-18 00:19:34.109398 | localhost | Output suppressed because no_log was given 2025-12-18 00:19:34.155211 | 2025-12-18 00:19:34.155350 | TASK [Set zuul-log-path fact] 2025-12-18 00:19:34.189974 | localhost | skipping: Conditional result was False 2025-12-18 00:19:34.197353 | 2025-12-18 00:19:34.197470 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-18 00:19:34.665049 | localhost -> localhost | ok: Runtime: 0:00:00.006071 2025-12-18 00:19:34.672063 | 2025-12-18 00:19:34.672184 | TASK [upload-logs-swift : Upload logs to swift]