2025-10-03 07:32:31.161536 | Job console starting...
2025-10-03 07:32:31.172050 | Updating repositories
2025-10-03 07:32:31.223457 | Preparing job workspace
2025-10-03 07:32:37.074128 | Running Ansible setup...
2025-10-03 07:32:43.122807 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 07:32:43.816196 | 
2025-10-03 07:32:43.816345 | PLAY [localhost]
2025-10-03 07:32:43.825765 | 
2025-10-03 07:32:43.825879 | TASK [Gathering Facts]
2025-10-03 07:32:44.762447 | localhost | ok
2025-10-03 07:32:44.795953 | 
2025-10-03 07:32:44.796146 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 07:32:45.231606 | localhost -> localhost | changed
2025-10-03 07:32:45.237360 | 
2025-10-03 07:32:45.237436 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 07:32:46.116575 | localhost -> localhost | changed
2025-10-03 07:32:46.129516 | 
2025-10-03 07:32:46.129604 | TASK [Setup log path fact]
2025-10-03 07:32:46.152634 | localhost | ok
2025-10-03 07:32:46.167946 | 
2025-10-03 07:32:46.168051 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 07:32:46.194988 | localhost | ok
2025-10-03 07:32:46.203212 | 
2025-10-03 07:32:46.203285 | TASK [emit-job-header : Print job information]
2025-10-03 07:32:46.230513 | # Job Information
2025-10-03 07:32:46.230669 | Ansible Version: 2.15.12
2025-10-03 07:32:46.230696 | Job: cifmw-molecule-ci_multus
2025-10-03 07:32:46.230715 | Pipeline: github-check
2025-10-03 07:32:46.230732 | Executor: ze01.softwarefactory-project.io
2025-10-03 07:32:46.230750 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-03 07:32:46.230769 | Log URL (when completed): https://logserver.rdoproject.org/0ab/rdoproject.org/0ab620811af94673946d3a0fddfdf906/
2025-10-03 07:32:46.230787 | Event ID: f958eab0-a02a-11f0-9ba1-0df9636946d8
2025-10-03 07:32:46.234532 | 
2025-10-03 07:32:46.234598 | LOOP [emit-job-header : Print node information]
2025-10-03 07:32:46.326873 | localhost | ok:
2025-10-03 07:32:46.327025 | localhost | # Node Information
2025-10-03 07:32:46.327114 | localhost | Inventory Hostname: controller
2025-10-03 07:32:46.327139 | localhost | Hostname: np0005468138
2025-10-03 07:32:46.327158 | localhost | Username: zuul
2025-10-03 07:32:46.327179 | localhost | Distro: CentOS 9
2025-10-03 07:32:46.327196 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-03 07:32:46.327213 | localhost | Region: RegionOne
2025-10-03 07:32:46.327230 | localhost | Label: centos-9-stream-crc-2-48-0-xxl
2025-10-03 07:32:46.327246 | localhost | Product Name: OpenStack Nova
2025-10-03 07:32:46.327261 | localhost | Interface IP: 38.102.83.163
2025-10-03 07:32:46.348365 | 
2025-10-03 07:32:46.348469 | PLAY [all]
2025-10-03 07:32:46.354919 | 
2025-10-03 07:32:46.354982 | TASK [Gather network facts]
2025-10-03 07:32:46.910347 | controller | ok
2025-10-03 07:32:46.925780 | 
2025-10-03 07:32:46.925842 | TASK [include_role : start-zuul-console]
2025-10-03 07:32:46.943750 | controller | ok
2025-10-03 07:32:46.955283 | 
2025-10-03 07:32:46.955345 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 07:32:47.474516 | controller | ok
2025-10-03 07:32:47.505003 | 
2025-10-03 07:32:47.505235 | TASK [include_role : add-build-sshkey]
2025-10-03 07:32:47.539311 | controller | ok
2025-10-03 07:32:47.557763 | 
2025-10-03 07:32:47.557879 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 07:32:47.799908 | controller -> localhost | ok
2025-10-03 07:32:47.812701 | 
2025-10-03 07:32:47.812926 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 07:32:47.852269 | controller | ok
2025-10-03 07:32:47.872148 | controller | included: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 07:32:47.879111 | 
2025-10-03 07:32:47.879220 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 07:32:48.592147 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 07:32:48.592364 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/0ab620811af94673946d3a0fddfdf906_id_rsa.
2025-10-03 07:32:48.592395 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/0ab620811af94673946d3a0fddfdf906_id_rsa.pub.
2025-10-03 07:32:48.592418 | controller -> localhost | The key fingerprint is:
2025-10-03 07:32:48.592438 | controller -> localhost | SHA256:gBw6wEIHnn5SHi88VIOmIDOFm2e8rNRxhrpjnk0Z/rM zuul-build-sshkey
2025-10-03 07:32:48.592457 | controller -> localhost | The key's randomart image is:
2025-10-03 07:32:48.592475 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 07:32:48.592493 | controller -> localhost | |+=o.oo           |
2025-10-03 07:32:48.592512 | controller -> localhost | |Ooo=.o.          |
2025-10-03 07:32:48.592530 | controller -> localhost | |+O=++ .          |
2025-10-03 07:32:48.592548 | controller -> localhost | |+.O+oo .         |
2025-10-03 07:32:48.592566 | controller -> localhost | | *oO+.  S        |
2025-10-03 07:32:48.592583 | controller -> localhost | | o*.=            |
2025-10-03 07:32:48.592600 | controller -> localhost | |...+             |
2025-10-03 07:32:48.592618 | controller -> localhost | |.++ ..           |
2025-10-03 07:32:48.592636 | controller -> localhost | |oo.. Eo          |
2025-10-03 07:32:48.592653 | controller -> localhost | +----[SHA256]-----+
2025-10-03 07:32:48.592701 | controller -> localhost | ok: Runtime: 0:00:00.181986
2025-10-03 07:32:48.598706 | 
2025-10-03 07:32:48.598766 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 07:32:48.641305 | controller | ok
2025-10-03 07:32:48.657556 | controller | included: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 07:32:48.666813 | 
2025-10-03 07:32:48.666896 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 07:32:48.691104 | controller | skipping: Conditional result was False
2025-10-03 07:32:48.697614 | 
2025-10-03 07:32:48.697680 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 07:32:49.402829 | controller | changed
2025-10-03 07:32:49.408976 | 
2025-10-03 07:32:49.409066 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 07:32:49.990820 | controller | ok
2025-10-03 07:32:49.996115 | 
2025-10-03 07:32:49.996178 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 07:32:51.808787 | controller | changed
2025-10-03 07:32:51.815613 | 
2025-10-03 07:32:51.815677 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 07:32:53.483814 | controller | changed
2025-10-03 07:32:53.489762 | 
2025-10-03 07:32:53.489848 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 07:32:53.514193 | controller | skipping: Conditional result was False
2025-10-03 07:32:53.519891 | 
2025-10-03 07:32:53.519958 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 07:32:53.984469 | controller -> localhost | changed
2025-10-03 07:32:53.995554 | 
2025-10-03 07:32:53.995667 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 07:32:54.285400 | controller -> localhost | Identity added: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/0ab620811af94673946d3a0fddfdf906_id_rsa (zuul-build-sshkey)
2025-10-03 07:32:54.285741 | controller -> localhost | ok: Runtime: 0:00:00.009562
2025-10-03 07:32:54.294698 | 
2025-10-03 07:32:54.294782 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 07:32:54.773254 | controller | ok
2025-10-03 07:32:54.778306 | 
2025-10-03 07:32:54.778397 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 07:32:54.802611 | controller | skipping: Conditional result was False
2025-10-03 07:32:54.813903 | 
2025-10-03 07:32:54.814093 | TASK [include_role : validate-host]
2025-10-03 07:32:54.864136 | controller | ok
2025-10-03 07:32:54.883819 | 
2025-10-03 07:32:54.883944 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 07:32:54.933206 | controller | ok
2025-10-03 07:32:54.938064 | 
2025-10-03 07:32:54.938152 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 07:32:55.198148 | controller -> localhost | ok
2025-10-03 07:32:55.206437 | 
2025-10-03 07:32:55.206560 | TASK [validate-host : Collect information about the host]
2025-10-03 07:32:56.137853 | controller | ok
2025-10-03 07:32:56.151633 | 
2025-10-03 07:32:56.151758 | TASK [validate-host : Sanitize hostname]
2025-10-03 07:32:56.215075 | controller | ok
2025-10-03 07:32:56.224856 | 
2025-10-03 07:32:56.224972 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 07:32:56.772161 | controller -> localhost | changed
2025-10-03 07:32:56.778841 | 
2025-10-03 07:32:56.778913 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 07:32:57.286008 | controller | ok
2025-10-03 07:32:57.297925 | 
2025-10-03 07:32:57.298177 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 07:32:57.824949 | controller -> localhost | changed
2025-10-03 07:32:57.846865 | 
2025-10-03 07:32:57.847061 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 07:32:57.862168 | controller | skipping: Conditional result was False
2025-10-03 07:32:57.870688 | 
2025-10-03 07:32:57.870831 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 07:32:57.896258 | controller | skipping: Conditional result was False
2025-10-03 07:32:57.901774 | 
2025-10-03 07:32:57.901845 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 07:32:58.293284 | controller | ok: "logs"
2025-10-03 07:32:58.294457 | controller | ok: All items complete
2025-10-03 07:32:58.294496 | 
2025-10-03 07:32:58.614309 | controller | ok: "artifacts"
2025-10-03 07:32:58.933530 | controller | ok: "docs"
2025-10-03 07:32:58.941421 | 
2025-10-03 07:32:58.941531 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 07:32:59.342461 | controller | changed: "logs"
2025-10-03 07:32:59.718872 | controller | changed: "artifacts"
2025-10-03 07:33:00.079597 | controller | changed: "docs"
2025-10-03 07:33:00.107809 | 
2025-10-03 07:33:00.107924 | PLAY RECAP
2025-10-03 07:33:00.107970 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 07:33:00.107995 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 07:33:00.108031 | 
2025-10-03 07:33:00.218334 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 07:33:00.219403 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-03 07:33:00.950398 | 
2025-10-03 07:33:00.950557 | PLAY [all]
2025-10-03 07:33:00.972208 | 
2025-10-03 07:33:00.972347 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-03 07:33:01.032271 | controller | ok
2025-10-03 07:33:01.037422 | 
2025-10-03 07:33:01.037526 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-03 07:33:01.672304 | controller | changed
2025-10-03 07:33:01.682468 | 
2025-10-03 07:33:01.682641 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-03 07:33:03.729488 | controller | changed
2025-10-03 07:33:03.748333 | 
2025-10-03 07:33:03.748463 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-03 07:33:04.351347 | controller | changed:
2025-10-03 07:33:04.352153 | controller | {
2025-10-03 07:33:04.352247 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-03 07:33:04.352330 | controller | }
2025-10-03 07:33:04.719292 | controller | changed:
2025-10-03 07:33:04.719642 | controller | {
2025-10-03 07:33:04.719723 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-03 07:33:04.719786 | controller | }
2025-10-03 07:33:05.134335 | controller | changed:
2025-10-03 07:33:05.134490 | controller | {
2025-10-03 07:33:05.134540 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-03 07:33:05.134580 | controller | }
2025-10-03 07:33:05.508757 | controller | changed:
2025-10-03 07:33:05.509140 | controller | {
2025-10-03 07:33:05.509214 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-03 07:33:05.509260 | controller | }
2025-10-03 07:33:05.895639 | controller | changed:
2025-10-03 07:33:05.895732 | controller | {
2025-10-03 07:33:05.895759 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-03 07:33:05.895786 | controller | }
2025-10-03 07:33:06.263681 | controller | changed:
2025-10-03 07:33:06.263771 | controller | {
2025-10-03 07:33:06.263796 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-03 07:33:06.263816 | controller | }
2025-10-03 07:33:06.670710 | controller | changed:
2025-10-03 07:33:06.670807 | controller | {
2025-10-03 07:33:06.670831 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-03 07:33:06.670851 | controller | }
2025-10-03 07:33:07.139948 | controller | changed:
2025-10-03 07:33:07.140091 | controller | {
2025-10-03 07:33:07.140127 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-03 07:33:07.140156 | controller | }
2025-10-03 07:33:07.512923 | controller | changed:
2025-10-03 07:33:07.515066 | controller | {
2025-10-03 07:33:07.515133 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-03 07:33:07.515165 | controller | }
2025-10-03 07:33:07.890264 | controller | changed:
2025-10-03 07:33:07.890519 | controller | {
2025-10-03 07:33:07.890581 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-03 07:33:07.890672 | controller | }
2025-10-03 07:33:08.260768 | controller | changed:
2025-10-03 07:33:08.260920 | controller | {
2025-10-03 07:33:08.260968 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-03 07:33:08.261009 | controller | }
2025-10-03 07:33:08.673538 | controller | changed:
2025-10-03 07:33:08.673645 | controller | {
2025-10-03 07:33:08.673669 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-03 07:33:08.673688 | controller | }
2025-10-03 07:33:09.073711 | controller | changed:
2025-10-03 07:33:09.073817 | controller | {
2025-10-03 07:33:09.073840 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-03 07:33:09.073858 | controller | }
2025-10-03 07:33:09.463149 | controller | changed:
2025-10-03 07:33:09.463269 | controller | {
2025-10-03 07:33:09.463304 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-03 07:33:09.463331 | controller | }
2025-10-03 07:33:09.836709 | controller | changed:
2025-10-03 07:33:09.836812 | controller | {
2025-10-03 07:33:09.836836 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-03 07:33:09.836856 | controller | }
2025-10-03 07:33:10.250650 | controller | changed:
2025-10-03 07:33:10.252646 | controller | {
2025-10-03 07:33:10.252710 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-03 07:33:10.252738 | controller | }
2025-10-03 07:33:10.636666 | controller | changed:
2025-10-03 07:33:10.636770 | controller | {
2025-10-03 07:33:10.636793 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-03 07:33:10.636812 | controller | }
2025-10-03 07:33:11.034154 | controller | changed:
2025-10-03 07:33:11.034512 | controller | {
2025-10-03 07:33:11.034562 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-03 07:33:11.034592 | controller | }
2025-10-03 07:33:11.424954 | controller | changed:
2025-10-03 07:33:11.425087 | controller | {
2025-10-03 07:33:11.425111 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-03 07:33:11.425130 | controller | }
2025-10-03 07:33:11.838716 | controller | changed:
2025-10-03 07:33:11.838825 | controller | {
2025-10-03 07:33:11.838849 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-03 07:33:11.838869 | controller | }
2025-10-03 07:33:12.252849 | controller | changed:
2025-10-03 07:33:12.253239 | controller | {
2025-10-03 07:33:12.253308 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-03 07:33:12.253352 | controller | }
2025-10-03 07:33:12.617615 | controller | changed:
2025-10-03 07:33:12.617749 | controller | {
2025-10-03 07:33:12.617799 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-03 07:33:12.617840 | controller | }
2025-10-03 07:33:13.045634 | controller | changed:
2025-10-03 07:33:13.045972 | controller | {
2025-10-03 07:33:13.046195 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-03 07:33:13.046254 | controller | }
2025-10-03 07:33:13.462800 | controller | changed:
2025-10-03 07:33:13.462922 | controller | {
2025-10-03 07:33:13.462946 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-03 07:33:13.462965 | controller | }
2025-10-03 07:33:13.940172 | controller | changed:
2025-10-03 07:33:13.940326 | controller | {
2025-10-03 07:33:13.940375 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-03 07:33:13.940415 | controller | }
2025-10-03 07:33:14.315481 | controller | changed:
2025-10-03 07:33:14.315589 | controller | {
2025-10-03 07:33:14.315614 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-03 07:33:14.315633 | controller | }
2025-10-03 07:33:14.341196 | 
2025-10-03 07:33:14.341418 | TASK [Set timezone to UTC]
2025-10-03 07:33:15.114487 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-03 07:33:15.127110 | 
2025-10-03 07:33:15.127258 | TASK [Create nodepool directory]
2025-10-03 07:33:15.489226 | controller | changed
2025-10-03 07:33:15.497097 | 
2025-10-03 07:33:15.497181 | TASK [Create nodepool sub_nodes file]
2025-10-03 07:33:17.158734 | controller | changed
2025-10-03 07:33:17.169515 | 
2025-10-03 07:33:17.169634 | TASK [Create nodepool sub_nodes_private file]
2025-10-03 07:33:18.748133 | controller | changed
2025-10-03 07:33:18.763409 | 
2025-10-03 07:33:18.763569 | LOOP [Populate nodepool sub_nodes file]
2025-10-03 07:33:18.829383 | 
2025-10-03 07:33:18.829602 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-03 07:33:18.863130 | 
2025-10-03 07:33:18.863450 | TASK [Create nodepool primary file]
2025-10-03 07:33:18.891718 | controller | skipping: Conditional result was False
2025-10-03 07:33:18.898910 | 
2025-10-03 07:33:18.898988 | TASK [Create nodepool node_private for this node]
2025-10-03 07:33:20.476407 | controller | changed
2025-10-03 07:33:20.489227 | 
2025-10-03 07:33:20.489358 | LOOP [Copy ssh keys to nodepool directory]
2025-10-03 07:33:21.106638 | controller | ok: Item: id_rsa Runtime: 0:00:00.011294
2025-10-03 07:33:21.106973 | 
2025-10-03 07:33:21.452522 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.011248
2025-10-03 07:33:21.474764 | 
2025-10-03 07:33:21.475165 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-03 07:33:23.045170 | controller | changed
2025-10-03 07:33:23.058157 | 
2025-10-03 07:33:23.058346 | TASK [Validate sudoers config after edits]
2025-10-03 07:33:23.485648 | controller | /etc/sudoers: parsed OK
2025-10-03 07:33:23.485931 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-03 07:33:23.485952 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-03 07:33:23.485961 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-03 07:33:23.608529 | controller | ok: Runtime: 0:00:00.010540
2025-10-03 07:33:23.664475 | 
2025-10-03 07:33:23.664603 | TASK [Show the environment passed in to job shell scripts]
2025-10-03 07:33:24.014763 | controller | SHELL=/bin/bash
2025-10-03 07:33:24.014826 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-03 07:33:24.014839 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-03 07:33:24.014868 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/62/3362/41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 07:33:24.014880 | controller | PWD=/home/zuul
2025-10-03 07:33:24.014889 | controller | ZUUL_PIPELINE=github-check
2025-10-03 07:33:24.014897 | controller | LOGNAME=zuul
2025-10-03 07:33:24.014904 | controller | XDG_SESSION_TYPE=tty
2025-10-03 07:33:24.014912 | controller | _=/usr/bin/env
2025-10-03 07:33:24.014919 | controller | MOTD_SHOWN=pam
2025-10-03 07:33:24.014926 | controller | HOME=/home/zuul
2025-10-03 07:33:24.014934 | controller | LANG=en_US.UTF-8
2025-10-03 07:33:24.014941 | controller | SSH_CONNECTION=38.102.83.114 53292 38.102.83.163 22
2025-10-03 07:33:24.014949 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-03 07:33:24.014961 | controller | ZUUL_CHANGE_IDS=3362,41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 07:33:24.014969 | controller | WORKSPACE=/home/zuul/workspace
2025-10-03 07:33:24.014977 | controller | XDG_SESSION_CLASS=user
2025-10-03 07:33:24.015054 | controller | SELINUX_ROLE_REQUESTED=
2025-10-03 07:33:24.015066 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-03 07:33:24.015074 | controller | USER=zuul
2025-10-03 07:33:24.015082 | controller | ZUUL_VOTING=True
2025-10-03 07:33:24.015090 | controller | BUILD_TIMEOUT=1800000
2025-10-03 07:33:24.015097 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-03 07:33:24.015105 | controller | SHLVL=1
2025-10-03 07:33:24.015113 | controller | ZUUL_PATCHSET=41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 07:33:24.015120 | controller | XDG_SESSION_ID=1
2025-10-03 07:33:24.015128 | controller | ZUUL_BRANCH=main
2025-10-03 07:33:24.015135 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-03 07:33:24.015143 | controller | SSH_CLIENT=38.102.83.114 53292 22
2025-10-03 07:33:24.015151 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-03 07:33:24.015159 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-03 07:33:24.015167 | controller | which_declare=declare -f
2025-10-03 07:33:24.015175 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-03 07:33:24.015183 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-03 07:33:24.015190 | controller | ZUUL_CHANGE=3362
2025-10-03 07:33:24.015198 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-03 07:33:24.015206 | controller | ZUUL_UUID=0ab620811af94673946d3a0fddfdf906
2025-10-03 07:33:24.015213 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-03 07:33:24.015221 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-03 07:33:24.015229 | controller | }
2025-10-03 07:33:24.199156 | controller | ok: Runtime: 0:00:00.010111
2025-10-03 07:33:24.211914 | 
2025-10-03 07:33:24.212346 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-03 07:33:24.239990 | controller | skipping: Conditional result was False
2025-10-03 07:33:24.255919 | 
2025-10-03 07:33:24.256146 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-03 07:33:24.810956 | controller | skipping: Conditional result was False
2025-10-03 07:33:24.817905 | 
2025-10-03 07:33:24.817990 | TASK [Ensure legacy workspace directory]
2025-10-03 07:33:25.185922 | controller | changed
2025-10-03 07:33:25.215481 | 
2025-10-03 07:33:25.215641 | PLAY RECAP
2025-10-03 07:33:25.215706 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 07:33:25.215736 | 
2025-10-03 07:33:25.363623 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-03 07:33:25.364472 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master]
2025-10-03 07:33:25.956673 | 
2025-10-03 07:33:25.956798 | PLAY [all,!compute]
2025-10-03 07:33:25.978417 | 
2025-10-03 07:33:25.978551 | TASK [Enable container-tools rhel-modules for c8/crc node]
2025-10-03 07:33:26.510168 | controller | skipping: Conditional result was False
2025-10-03 07:33:26.525689 | 
2025-10-03 07:33:26.525887 | TASK [Install podman]
2025-10-03 07:33:26.583119 | controller | skipping: Conditional result was False
2025-10-03 07:33:26.597191 | 
2025-10-03 07:33:26.597334 | TASK [Set var name for quay login zuul secret]
2025-10-03 07:33:26.654963 | controller | skipping: Conditional result was False
2025-10-03 07:33:26.662282 | 
2025-10-03 07:33:26.662394 | TASK [Print the username]
2025-10-03 07:33:27.201310 | controller | skipping: Conditional result was False
2025-10-03 07:33:27.210417 | 
2025-10-03 07:33:27.210522 | TASK [Fail when user or password is not set]
2025-10-03 07:33:27.287958 | controller | skipping: Conditional result was False
2025-10-03 07:33:27.295377 | 
2025-10-03 07:33:27.295466 | TASK [Set vars for quay login]
2025-10-03 07:33:27.359136 | 
2025-10-03 07:33:27.359315 | LOOP [Perform container registry login(s) with podman]
2025-10-03 07:33:27.420348 | 
2025-10-03 07:33:27.420651 | LOOP [Perform container registry login(s) with buildah]
2025-10-03 07:33:27.470891 | 
2025-10-03 07:33:27.471134 | TASK [Set Insecure registry for content provider]
2025-10-03 07:33:27.507631 | controller | skipping: Conditional result was False
2025-10-03 07:33:27.543859 | 
2025-10-03 07:33:27.543948 | PLAY RECAP
2025-10-03 07:33:27.544005 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 9 rescued: 0 ignored: 0
2025-10-03 07:33:27.544072 | 
2025-10-03 07:33:27.648701 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master]
2025-10-03 07:33:27.649491 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master]
2025-10-03 07:33:28.211735 | 
2025-10-03 07:33:28.211837 | PLAY [Prefer ipv4 over ipv6]
2025-10-03 07:33:28.235512 | 
2025-10-03 07:33:28.235604 | TASK [Configure /etc/gai.conf to prever ipv4 over ipv6]
2025-10-03 07:33:28.280255 | controller | skipping: Conditional result was False
2025-10-03 07:33:28.300978 | 
2025-10-03 07:33:28.301071 | PLAY [controller]
2025-10-03 07:33:28.315641 | 
2025-10-03 07:33:28.315724 | TASK [Fail when openshift_pull_sec not provided]
2025-10-03 07:33:28.339852 | controller | skipping: Conditional result was False
2025-10-03 07:33:28.345966 | 
2025-10-03 07:33:28.346044 | TASK [Clone repos in the job workspace]
2025-10-03 07:33:28.365927 | controller | ok
2025-10-03 07:33:28.382354 | 
2025-10-03 07:33:28.382425 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 07:33:28.888105 | controller | ok
2025-10-03 07:33:28.901436 | 
2025-10-03 07:33:28.901620 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 07:33:32.285164 | controller | Output suppressed because no_log was given
2025-10-03 07:33:32.310980 | 
2025-10-03 07:33:32.311171 | TASK [Create pull-secret.txt file]
2025-10-03 07:33:33.983897 | controller | Output suppressed because no_log was given
2025-10-03 07:33:33.988976 | 
2025-10-03 07:33:33.989086 | TASK [Apply CRC features and print image build date]
2025-10-03 07:33:34.021150 | controller | ok
2025-10-03 07:33:34.031163 | controller | included: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/trusted/project_0/review.rdoproject.org/config/playbooks/crc/features.yaml
2025-10-03 07:33:34.037704 | 
2025-10-03 07:33:34.037787 | TASK [Set additional parameters for crc - telemetry]
2025-10-03 07:33:34.566899 | controller | skipping: Conditional result was False
2025-10-03 07:33:34.620481 | 
2025-10-03 07:33:34.620625 | TASK [Set additional parameters for crc - monitoring]
2025-10-03 07:33:35.169943 | controller | skipping: Conditional result was False
2025-10-03 07:33:35.175721 | 
2025-10-03 07:33:35.175793 | TASK [Set minimum required memory to run the CRC when monitoring enabled]
2025-10-03 07:33:35.710203 | controller | skipping: Conditional result was False
2025-10-03 07:33:35.723148 | 
2025-10-03 07:33:35.723313 | TASK [Set additional parameters for crc - enable microshift preset]
2025-10-03 07:33:36.285153 | controller | skipping: Conditional result was False
2025-10-03 07:33:36.293899 | 
2025-10-03 07:33:36.294045 | TASK [Set additional parameters for crc - enable okd preset]
2025-10-03 07:33:36.840092 | controller | skipping: Conditional result was False
2025-10-03 07:33:36.845755 | 
2025-10-03 07:33:36.845816 | TASK [Delete the cluster if there's a non-default bundle URL]
2025-10-03 07:33:37.385307 | controller | skipping: Conditional result was False
2025-10-03 07:33:37.391419 | 
2025-10-03 07:33:37.391494 | TASK [Execute crc start command]
2025-10-03 07:45:48.365750 | controller | ok: Runtime: 0:12:10.130590
2025-10-03 07:45:48.379521 | 
2025-10-03 07:45:48.379706 | TASK [Verify that OpenShift is up and running]
2025-10-03 07:45:48.411333 | controller | ok
2025-10-03 07:45:48.431942 | controller | included: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/trusted/project_0/review.rdoproject.org/config/playbooks/crc/verify_openshift_start.yaml
2025-10-03 07:45:48.442706 | 
2025-10-03 07:45:48.442851 | TASK [Create script to login and verify services]
2025-10-03 07:45:49.796896 | controller | changed
2025-10-03 07:45:49.805206 | 
2025-10-03 07:45:49.805311 | TASK [Ensure that user is logged]
2025-10-03 07:45:50.204397 | controller | Checking login to the cluster 1...
2025-10-03 07:45:51.312620 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-03 07:45:51.631442 | controller |
2025-10-03 07:45:51.631525 | controller | Login successful.
2025-10-03 07:45:51.673881 | controller |
2025-10-03 07:45:51.673961 | controller | You have access to 65 projects, the list has been suppressed. You can list all projects with 'oc projects'
2025-10-03 07:45:51.673997 | controller |
2025-10-03 07:45:51.674009 | controller | Using project "default".
2025-10-03 07:45:51.859544 | controller | changed
2025-10-03 07:45:51.866534 | 
2025-10-03 07:45:51.866610 | TASK [Delete all openshift-marketplace pods]
2025-10-03 07:45:53.310983 | controller | pod "certified-operators-f8szs" deleted
2025-10-03 07:45:53.335961 | controller | pod "community-operators-5zsqg" deleted
2025-10-03 07:45:53.357955 | controller | pod "marketplace-operator-79b997595-d2lpl" deleted
2025-10-03 07:45:53.387964 | controller | pod "redhat-marketplace-ps6xk" deleted
2025-10-03 07:45:53.415937 | controller | pod "redhat-operators-tqxl9" deleted
2025-10-03 07:45:55.417498 | controller | ok
2025-10-03 07:45:55.429466 | 
2025-10-03 07:45:55.429615 | TASK [Copy script ensure_services_up.sh]
2025-10-03 07:45:55.496908 | controller | skipping: Conditional result was False
2025-10-03 07:45:55.510347 | 
2025-10-03 07:45:55.510495 | TASK [Ensure all pods are up and running]
2025-10-03 07:45:56.066764 | controller | skipping: Conditional result was False
2025-10-03 07:45:56.079222 | 
2025-10-03 07:45:56.079365 | TASK [Check if there is a image build date file]
2025-10-03 07:45:56.441590 | controller | ok
2025-10-03 07:45:56.449538 | 
2025-10-03 07:45:56.449692 | TASK [Print image date if available]
2025-10-03 07:45:56.854819 | controller | Tue Apr  1 06:17:46 PM EDT 2025
2025-10-03 07:45:56.992324 | controller | changed
2025-10-03 07:45:57.004096 | 
2025-10-03 07:45:57.004265 | TASK [Fix machineconfigpool]
2025-10-03 07:45:57.051771 | controller | skipping: Conditional result was False
2025-10-03 07:45:57.063727 | 
2025-10-03 07:45:57.063897 | TASK [Show available nodes]
2025-10-03 07:45:58.030054 | controller | NAME   STATUS   ROLES                         AGE    VERSION
2025-10-03 07:45:58.033198 | controller | crc    Ready    control-plane,master,worker   222d   v1.31.5
2025-10-03 07:45:58.116138 | controller | ok: Runtime: 0:00:00.586071
2025-10-03 07:45:58.123870 | 
2025-10-03 07:45:58.123959 | TASK [Configure insecure registry inside crc vm]
2025-10-03 07:45:58.159764 | controller | skipping: Conditional result was False
2025-10-03 07:45:58.167633 | 
2025-10-03 07:45:58.167724 | TASK [Catch CRC IP]
2025-10-03 07:45:58.784396 | controller | 192.168.130.11
2025-10-03 07:45:59.212508 | controller | changed
2025-10-03 07:45:59.221961 | 
2025-10-03 07:45:59.222079 | TASK [Check if id_ed25519 key exists]
2025-10-03 07:45:59.605444 | controller | ok
2025-10-03 07:45:59.618706 | 
2025-10-03 07:45:59.618904 | TASK [Set fact if new keypair exists]
2025-10-03 07:45:59.668082 | controller | ok
2025-10-03 07:45:59.680776 | 
2025-10-03 07:45:59.680945 | TASK [Run crc]
2025-10-03 07:46:01.204487 | controller |
2025-10-03 07:46:10.689793 | controller | PLAY [OpenShift secret copy and CRC securitization] ****************************
2025-10-03 07:46:10.689951 | controller |
2025-10-03 07:46:10.689967 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:46:10.689983 | controller | [WARNING]: Platform linux on host 192.168.130.11 is using the discovered Python
2025-10-03 07:46:10.741301 | controller | interpreter at /usr/bin/python3.9, but future installation of another Python
2025-10-03 07:46:10.741344 | controller | interpreter could change the meaning of that path. See
2025-10-03 07:46:10.741354 | controller | https://docs.ansible.com/ansible-
2025-10-03 07:46:10.741362 | controller | core/2.14/reference_appendices/interpreter_discovery.html for more information.
2025-10-03 07:46:10.741376 | controller | ok: [192.168.130.11]
2025-10-03 07:46:12.820928 | controller |
2025-10-03 07:46:12.820993 | controller | TASK [Copy pull-secret] ********************************************************
2025-10-03 07:46:12.821013 | controller | changed: [192.168.130.11]
2025-10-03 07:46:14.449971 | controller |
2025-10-03 07:46:14.450041 | controller | TASK [Add crio config] *********************************************************
2025-10-03 07:46:14.450057 | controller | changed: [192.168.130.11]
2025-10-03 07:46:18.289831 | controller |
2025-10-03 07:46:18.289930 | controller | TASK [Restart crio to pickup new configuration] ********************************
2025-10-03 07:46:18.289969 | controller | changed: [192.168.130.11]
2025-10-03 07:46:18.353243 | controller |
2025-10-03 07:46:18.353325 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:46:18.353334 | controller | 192.168.130.11             : ok=4    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:46:18.353341 | controller |
2025-10-03 07:46:18.846486 | controller | changed
2025-10-03 07:46:18.858806 | 
2025-10-03 07:46:18.858941 | TASK [Set slower etcd profile]
2025-10-03 07:46:18.941004 | controller | ok
2025-10-03 07:46:18.980226 | 
2025-10-03 07:46:18.980326 | TASK [prepare-crc-cloud : Set slower profile]
2025-10-03 07:46:19.525677 | controller | etcd.operator.openshift.io/cluster patched
2025-10-03 07:46:20.017914 | controller | ok
2025-10-03 07:46:20.030866 | 
2025-10-03 07:46:20.031060 | TASK [prepare-crc-cloud : Wait 30 seconds to apply]
2025-10-03 07:46:50.072752 | controller | ok
2025-10-03 07:46:50.080490 | 
2025-10-03 07:46:50.080601 | TASK [prepare-crc-cloud : Get pod phase status]
2025-10-03 07:52:20.526313 | controller | ok
2025-10-03 07:52:20.536247 | 
2025-10-03 07:52:20.536314 | TASK [Set limit for disk usage - IOPS and Read/Write]
2025-10-03 07:52:20.597907 | controller | ok
2025-10-03 07:52:20.604611 | controller | included: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/trusted/project_0/review.rdoproject.org/config/playbooks/crc/limit-disk-usage.yaml
2025-10-03 07:52:20.614279 | 
2025-10-03 07:52:20.614346 | TASK [Set facts for disk limitation]
2025-10-03 07:52:20.647723 | controller | ok
2025-10-03 07:52:20.654724 | 
2025-10-03 07:52:20.654806 | TASK [Print limits for the disk]
2025-10-03 07:52:20.685039 | controller | ok: Set limit to crc VM to the vda disk: iops 18000 read/write 262144000
2025-10-03 07:52:20.689682 | 
2025-10-03 07:52:20.689738 | TASK [Set limit to crc VM to the vda disk]
2025-10-03 07:52:21.323457 | controller |
2025-10-03 07:52:21.756463 | controller | changed
2025-10-03 07:52:21.763204 | 
2025-10-03 07:52:21.763378 | TASK [Pause machineconfigpool]
2025-10-03 07:52:21.826179 | controller | ok
2025-10-03 07:52:21.873749 | 
2025-10-03 07:52:21.873941 | LOOP [prepare-crc-cloud : Pause the machineconfig configuration if mcp is not needed]
2025-10-03 07:52:24.665848 | controller | ok
2025-10-03 07:52:29.688009 | controller | ok
2025-10-03 07:52:29.705637 | 
2025-10-03 07:52:29.706124 | TASK [prepare-crc-cloud : Print current machineconfigpool]
2025-10-03 07:52:31.669225 | controller | NAME     CONFIG                                             UPDATED   UPDATING   DEGRADED   MACHINECOUNT   READYMACHINECOUNT   UPDATEDMACHINECOUNT   DEGRADEDMACHINECOUNT   AGE
2025-10-03 07:52:31.677264 | controller | master   rendered-master-95020e6e79c40b4dd095817bccfc5060   True      False      False      1              1                   1                     0                      222d
2025-10-03 07:52:31.677334 | controller | worker   rendered-worker-594cc07c9feefb5e37f2530ac457d36c   True      False      False      0              0                   0                     0                      222d
2025-10-03 07:52:31.753997 | controller | ok
2025-10-03 07:52:31.786844 | 
2025-10-03 07:52:31.786972 | PLAY [Set IOPS and Read/Write disk limitation excluding controller]
2025-10-03 07:52:31.787104 | 
2025-10-03 07:52:31.787136 | PLAY RECAP
2025-10-03 07:52:31.787180 | controller | ok: 25 changed: 10 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 0
2025-10-03 07:52:31.787201 | 
2025-10-03 07:52:31.992521 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master]
2025-10-03 07:52:31.993670 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-03 07:52:32.628823 | 
2025-10-03 07:52:32.628958 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-03 07:52:32.651094 | 
2025-10-03 07:52:32.651202 | TASK [Create zuul-output directory]
2025-10-03 07:52:33.216744 | controller | changed
2025-10-03 07:52:33.229834 | 
2025-10-03 07:52:33.230166 | TASK [Slurp Zuul inventory test]
2025-10-03 07:52:33.644595 | controller -> localhost | ok
2025-10-03 07:52:33.659341 | 
2025-10-03 07:52:33.659513 | TASK [Save zuul inventory]
2025-10-03 07:52:35.512179 | controller | changed
2025-10-03 07:52:35.525376 | 
2025-10-03 07:52:35.525537 | TASK [Save zuul vars without the change_message]
2025-10-03 07:52:37.040990 | controller | changed
2025-10-03 07:52:37.079087 | 
2025-10-03 07:52:37.079213 | PLAY RECAP
2025-10-03 07:52:37.079268 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 07:52:37.079309 | 
2025-10-03 07:52:37.252669 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-03 07:52:37.253693 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-03 07:52:37.942867 | 
2025-10-03 07:52:37.943041 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-03 07:52:37.967520 | 
2025-10-03 07:52:37.967706 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-03 07:52:37.991050 | controller | ok
2025-10-03 07:52:38.012187 | 
2025-10-03 07:52:38.012447 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-03 07:52:38.059550 | controller | skipping: Conditional result was False
2025-10-03 07:52:38.067207 | 
2025-10-03 07:52:38.067406 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-03 07:52:38.731563 | controller | ok
2025-10-03 07:52:38.745724 | 
2025-10-03 07:52:38.745963 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-03 07:52:40.542933 | controller | ok
2025-10-03 07:52:40.567876 | 
2025-10-03 07:52:40.568173 | TASK [Prepare workspace]
2025-10-03 07:52:40.596498 | controller | ok
2025-10-03 07:52:40.624729 | 
2025-10-03 07:52:40.624950 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 07:52:41.138640 | controller | ok
2025-10-03 07:52:41.144776 | 
2025-10-03 07:52:41.144852 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 07:52:42.279592 | controller | Output suppressed because no_log was given
2025-10-03 07:52:42.338985 | 
2025-10-03 07:52:42.339163 | LOOP [Create zuul-output directory]
2025-10-03 07:52:42.778281 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-03 07:52:43.171253 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-03 07:52:43.182025 | 
2025-10-03 07:52:43.182203 | TASK [Install required packages]
2025-10-03 07:53:06.659052 | controller | ok: Nothing to do
2025-10-03 07:53:06.672444 | 
2025-10-03 07:53:06.672611 | TASK [Install venv]
2025-10-03 07:55:35.996876 | controller | changed
2025-10-03 07:55:36.060075 | 
2025-10-03 07:55:36.060211 | PLAY RECAP
2025-10-03 07:55:36.060272 | controller | ok: 7 changed: 2 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 07:55:36.060302 | 
2025-10-03 07:55:36.216827 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-03 07:55:36.218558 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-03 07:55:36.885270 | 
2025-10-03 07:55:36.885398 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-03 07:55:36.907550 | 
2025-10-03 07:55:36.907656 | TASK [Gather required facts]
2025-10-03 07:55:37.704430 | controller | ok
2025-10-03 07:55:37.720416 | 
2025-10-03 07:55:37.720693 | TASK [Load environment var if instructed to]
2025-10-03 07:55:37.749408 | controller | skipping: Conditional result was False
2025-10-03 07:55:37.758209 | 
2025-10-03 07:55:37.758373 | TASK [Run molecule]
2025-10-03 07:55:39.052456 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-03 07:55:39.379209 | controller | INFO     Running default > destroy
2025-10-03 07:55:39.379525 | controller | WARNING  Skipping, instances are delegated.
2025-10-03 07:55:39.392395 | controller | INFO     Running default > create
2025-10-03 07:55:39.393543 | controller | WARNING  Skipping, instances are delegated.
2025-10-03 07:55:39.402962 | controller | INFO     Running default > converge
2025-10-03 07:55:40.239365 | controller |
2025-10-03 07:55:40.239477 | controller | PLAY [Converge] ****************************************************************
2025-10-03 07:55:40.239528 | controller |
2025-10-03 07:55:40.239769 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:55:41.348000 | controller | Friday 03 October 2025  07:55:40 +0000 (0:00:00.011)       0:00:00.011 ********
2025-10-03 07:55:41.348039 | controller | ok: [instance]
2025-10-03 07:55:41.348085 | controller |
2025-10-03 07:55:41.348240 | controller | TASK [Add crc hostname with it's IP to /etc/hosts] *****************************
2025-10-03 07:55:41.348392 | controller | Friday 03 October 2025  07:55:41 +0000 (0:00:01.108)       0:00:01.120 ********
2025-10-03 07:55:42.414403 | controller | changed: [instance]
2025-10-03 07:55:42.414480 | controller |
2025-10-03 07:55:42.414571 | controller | TASK [Check if new ssh keypair exists] *****************************************
2025-10-03 07:55:42.414697 | controller | Friday 03 October 2025  07:55:42 +0000 (0:00:01.066)       0:00:02.187 ********
2025-10-03 07:55:42.441880 | controller |
2025-10-03 07:55:42.441949 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
2025-10-03 07:55:42.441978 | controller | Friday 03 October 2025  07:55:42 +0000 (0:00:00.027)       0:00:02.214 ********
2025-10-03 07:55:42.882412 | controller | ok: [instance]
2025-10-03 07:55:42.882595 | controller |
2025-10-03 07:55:42.882874 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
2025-10-03 07:55:42.883137 | controller | Friday 03 October 2025  07:55:42 +0000 (0:00:00.439)       0:00:02.654 ********
2025-10-03 07:55:42.915570 | controller | ok: [instance]
2025-10-03 07:55:42.915704 | controller |
2025-10-03 07:55:42.916037 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
2025-10-03 07:55:42.916204 | controller | Friday 03 October 2025  07:55:42 +0000 (0:00:00.032)       0:00:02.687 ********
2025-10-03 07:55:42.943482 | controller | skipping: [instance]
2025-10-03 07:55:42.943548 | controller |
2025-10-03 07:55:42.943683 | controller | TASK [Add the crc host dynamically] ********************************************
2025-10-03 07:55:42.943790 | controller | Friday 03 October 2025  07:55:42 +0000 (0:00:00.028)       0:00:02.716 ********
2025-10-03 07:55:42.966019 | controller | changed: [instance]
2025-10-03 07:55:42.966101 | controller |
2025-10-03 07:55:42.966251 | controller | TASK [Fetch crc network facts] *************************************************
2025-10-03 07:55:42.966386 | controller | Friday 03 October 2025  07:55:42 +0000 (0:00:00.022)       0:00:02.738 ********
2025-10-03 07:55:47.483679 | controller | ok: [instance -> crc]
2025-10-03 07:55:47.483747 | controller |
2025-10-03 07:55:47.483987 | controller | TASK [Load shared variables] ***************************************************
2025-10-03 07:55:47.546906 | controller | Friday 03 October 2025  07:55:47 +0000 (0:00:04.517)       0:00:07.256 ********
2025-10-03 07:55:47.546968 | controller | ok: [instance]
2025-10-03 07:55:47.601138 | controller |
2025-10-03 07:55:47.601212 | controller | TASK [Call ci_multus role] *****************************************************
2025-10-03 07:55:47.601228 | controller | Friday 03 October 2025  07:55:47 +0000 (0:00:00.062)       0:00:07.319 ********
2025-10-03 07:55:47.601247 | controller |
2025-10-03 07:55:47.601355 | controller | TASK [ci_multus : Create manifests directory] **********************************
2025-10-03 07:55:47.601373 | controller | Friday 03 October 2025  07:55:47 +0000 (0:00:00.054)       0:00:07.373 ********
2025-10-03 07:55:47.946490 | controller | changed: [instance]
2025-10-03 07:55:47.946563 | controller |
2025-10-03 07:55:47.946652 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-10-03 07:55:47.946768 | controller | Friday 03 October 2025  07:55:47 +0000 (0:00:00.345)       0:00:07.719 ********
2025-10-03 07:55:47.974086 | controller | skipping: [instance]
2025-10-03 07:55:47.974190 | controller |
2025-10-03 07:55:47.974353 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-10-03 07:55:47.974523 | controller | Friday 03 October 2025  07:55:47 +0000 (0:00:00.027)       0:00:07.746 ********
2025-10-03 07:55:48.003330 | controller | skipping: [instance]
2025-10-03 07:55:48.003410 | controller |
2025-10-03 07:55:48.003551 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-03 07:55:48.003928 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.029)       0:00:07.776 ********
2025-10-03 07:55:48.030564 | controller | skipping: [instance]
2025-10-03 07:55:48.030651 | controller |
2025-10-03 07:55:48.030776 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-10-03 07:55:48.030942 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.027)       0:00:07.803 ********
2025-10-03 07:55:48.062448 | controller | skipping: [instance]
2025-10-03 07:55:48.062517 | controller |
2025-10-03 07:55:48.062659 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] *****
2025-10-03 07:55:48.063110 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.031)       0:00:07.835 ********
2025-10-03 07:55:48.111268 | controller | ok: [instance]
2025-10-03 07:55:48.111339 | controller |
2025-10-03 07:55:48.111435 | controller | TASK [ci_multus : Merge any available multus net info patches] *****************
2025-10-03 07:55:48.111518 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.049)       0:00:07.884 ********
2025-10-03 07:55:48.310179 | controller | ok: [instance] => (item={'default': {'interface_name': 'eth0', 'network_name': 'default', 'gw_v4': '192.168.122.1', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'deny_network': {'gw_v4': '192.168.122.1', 'network_name': 'deny_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'not_allowed_network': {'gw_v4': '192.168.122.1', 'network_name': 'not_allowed_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'no_multus_network': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2'}})
2025-10-03 07:55:48.310228 | controller | ok: [instance] => (item={'patchnetwork': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'macvlan'}}}})
2025-10-03 07:55:48.310419 | controller | ok: [instance] => (item={'bridge-to-linux-bridge': {'gw_v4': '192.168.122.1', 'network_name': 'bridge-to-linux-bridge', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth1', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge', 'multus_attach': 'linux-bridge'}}}})
2025-10-03 07:55:48.310551 | controller |
2025-10-03 07:55:48.310695 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] *******
2025-10-03 07:55:48.310834 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.198)       0:00:08.083 ********
2025-10-03 07:55:48.399098 | controller | ok: [instance]
2025-10-03 07:55:48.399189 | controller |
2025-10-03 07:55:48.399201 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] ***
2025-10-03 07:55:48.399328 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.088)       0:00:08.172 ********
2025-10-03 07:55:48.482840 | controller | ok: [instance]
2025-10-03 07:55:48.482957 | controller |
2025-10-03 07:55:48.483142 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] ***
2025-10-03 07:55:48.483269 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.083)       0:00:08.255 ********
2025-10-03 07:55:48.560115 | controller | ok: [instance]
2025-10-03 07:55:48.560179 | controller |
2025-10-03 07:55:48.560348 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] ***************
2025-10-03 07:55:48.560468 | controller | Friday 03 October 2025  07:55:48 +0000 (0:00:00.077)       0:00:08.332 ********
2025-10-03 07:55:49.158086 | controller | changed: [instance]
2025-10-03 07:55:49.158159 | controller |
2025-10-03 07:55:49.158275 | controller | TASK [ci_multus : Create the multus namespace] *********************************
2025-10-03 07:55:49.158382 | controller | Friday 03 October 2025  07:55:49 +0000 (0:00:00.597)       0:00:08.930 ********
2025-10-03 07:55:50.341260 | controller | changed: [instance]
2025-10-03 07:55:50.341330 | controller |
2025-10-03 07:55:50.341481 | controller | TASK [ci_multus : Apply network attachment definition manifests] ***************
2025-10-03 07:55:50.341629 | controller | Friday 03 October 2025  07:55:50 +0000 (0:00:01.182)       0:00:10.113 ********
2025-10-03 07:55:51.282444 | controller | changed: [instance]
2025-10-03 07:55:51.282506 | controller |
2025-10-03 07:55:51.282515 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:55:51.282523 | controller | instance                   : ok=16   changed=6    unreachable=0    failed=0    skipped=5    rescued=0    ignored=0
2025-10-03 07:55:51.282529 | controller |
2025-10-03 07:55:51.282534 | controller | Friday 03 October 2025  07:55:51 +0000 (0:00:00.939)       0:00:11.053 ********
2025-10-03 07:55:51.282541 | controller | ===============================================================================
2025-10-03 07:55:51.282546 | controller | Fetch crc network facts ------------------------------------------------- 4.52s
2025-10-03 07:55:51.282552 | controller | ci_multus : Create the multus namespace --------------------------------- 1.18s
2025-10-03 07:55:51.282559 | controller | Gathering Facts --------------------------------------------------------- 1.11s
2025-10-03 07:55:51.282565 | controller | Add crc hostname with it's IP to /etc/hosts ----------------------------- 1.07s
2025-10-03 07:55:51.282571 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.94s
2025-10-03 07:55:51.282577 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.60s
2025-10-03 07:55:51.282583 | controller | recognize_ssh_keypair : Check if id_ed25519 key exists ------------------ 0.44s
2025-10-03 07:55:51.282588 | controller | ci_multus : Create manifests directory ---------------------------------- 0.35s
2025-10-03 07:55:51.282596 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.20s
2025-10-03 07:55:51.282621 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.09s
2025-10-03 07:55:51.283119 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.08s
2025-10-03 07:55:51.283305 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.08s
2025-10-03 07:55:51.283319 | controller | Load shared variables --------------------------------------------------- 0.06s
2025-10-03 07:55:51.283325 | controller | Call ci_multus role ----------------------------------------------------- 0.05s
2025-10-03 07:55:51.283331 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.05s
2025-10-03 07:55:51.283340 | controller | recognize_ssh_keypair : Set fact if new keypair exists ------------------ 0.03s
2025-10-03 07:55:51.283735 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.03s
2025-10-03 07:55:51.283799 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s
2025-10-03 07:55:51.372276 | controller | recognize_ssh_keypair : Set fact if new keypair does not exists --------- 0.03s
2025-10-03 07:55:51.372317 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s
2025-10-03 07:55:51.372335 | controller | INFO     Running default > verify
2025-10-03 07:55:51.372774 | controller | INFO     Running Ansible Verifier
2025-10-03 07:55:51.880676 | controller |
2025-10-03 07:55:52.970992 | controller | PLAY [Verify] ******************************************************************
2025-10-03 07:55:52.971035 | controller |
2025-10-03 07:55:52.971056 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:55:52.971063 | controller | Friday 03 October 2025  07:55:51 +0000 (0:00:00.018)       0:00:00.018 ********
2025-10-03 07:55:52.971074 | controller | ok: [instance]
2025-10-03 07:55:52.991973 | controller |
2025-10-03 07:55:52.992049 | controller | TASK [Load shared variables] ***************************************************
2025-10-03 07:55:52.992070 | controller | Friday 03 October 2025  07:55:52 +0000 (0:00:01.090)       0:00:01.109 ********
2025-10-03 07:55:52.992088 | controller | ok: [instance]
2025-10-03 07:55:52.992187 | controller |
2025-10-03 07:55:52.992208 | controller | TASK [Fetch files stat results] ************************************************
2025-10-03 07:55:53.424344 | controller | Friday 03 October 2025  07:55:52 +0000 (0:00:00.021)       0:00:01.130 ********
2025-10-03 07:55:53.424397 | controller | ok: [instance]
2025-10-03 07:55:53.424438 | controller |
2025-10-03 07:55:53.424449 | controller | TASK [Assert that expected file exist] *****************************************
2025-10-03 07:55:53.424613 | controller | Friday 03 October 2025  07:55:53 +0000 (0:00:00.431)       0:00:01.562 ********
2025-10-03 07:55:53.457522 | controller | ok: [instance] => changed=false
2025-10-03 07:55:53.457588 | controller |   msg: All assertions passed
2025-10-03 07:55:53.457693 | controller |
2025-10-03 07:55:53.457796 | controller | TASK [Fetch file content] ******************************************************
2025-10-03 07:55:53.457942 | controller | Friday 03 October 2025  07:55:53 +0000 (0:00:00.033)       0:00:01.596 ********
2025-10-03 07:55:53.806232 | controller | ok: [instance]
2025-10-03 07:55:53.806329 | controller |
2025-10-03 07:55:53.806438 | controller | TASK [Set _ci_multus_nad variable] *********************************************
2025-10-03 07:55:53.806465 | controller | Friday 03 October 2025  07:55:53 +0000 (0:00:00.348)       0:00:01.945 ********
2025-10-03 07:55:53.841920 | controller | ok: [instance]
2025-10-03 07:55:53.842016 | controller |
2025-10-03 07:55:53.842085 | controller | TASK [Assert expected number of Network Attachment Definitions are created] ****
2025-10-03 07:55:53.842216 | controller | Friday 03 October 2025  07:55:53 +0000 (0:00:00.035)       0:00:01.980 ********
2025-10-03 07:55:53.894172 | controller | ok: [instance]
2025-10-03 07:55:53.894257 | controller |
2025-10-03 07:55:53.894447 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:55:53.894622 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:55:53.894725 | controller |
2025-10-03 07:55:53.894901 | controller | Friday 03 October 2025  07:55:53 +0000 (0:00:00.052)       0:00:02.033 ********
2025-10-03 07:55:53.895021 | controller | ===============================================================================
2025-10-03 07:55:53.895169 | controller | Gathering Facts --------------------------------------------------------- 1.09s
2025-10-03 07:55:53.895299 | controller | Fetch files stat results ------------------------------------------------ 0.43s
2025-10-03 07:55:53.895430 | controller | Fetch file content ------------------------------------------------------ 0.35s
2025-10-03 07:55:53.895567 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.05s
2025-10-03 07:55:53.895715 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.04s
2025-10-03 07:55:53.895878 | controller | Assert that expected file exist ----------------------------------------- 0.03s
2025-10-03 07:55:53.896008 | controller | Load shared variables --------------------------------------------------- 0.02s
2025-10-03 07:55:53.959780 | controller | INFO     Verifier completed successfully.
2025-10-03 07:55:53.969296 | controller | INFO     Running default > verify
2025-10-03 07:55:53.969565 | controller | INFO     Running Ansible Verifier
2025-10-03 07:55:54.491293 | controller |
2025-10-03 07:55:54.491361 | controller | PLAY [Verify CRC] **************************************************************
2025-10-03 07:55:54.491426 | controller |
2025-10-03 07:55:54.491549 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:55:54.491667 | controller | Friday 03 October 2025  07:55:54 +0000 (0:00:00.017)       0:00:00.017 ********
2025-10-03 07:55:55.576373 | controller | ok: [instance]
2025-10-03 07:55:55.576458 | controller |
2025-10-03 07:55:55.576652 | controller | TASK [Include default vars] ****************************************************
2025-10-03 07:55:55.576947 | controller | Friday 03 October 2025  07:55:55 +0000 (0:00:01.084)       0:00:01.102 ********
2025-10-03 07:55:55.615175 | controller | ok: [instance]
2025-10-03 07:55:55.615260 | controller |
2025-10-03 07:55:55.615487 | controller | TASK [Check if NADs were created] **********************************************
2025-10-03 07:55:55.615699 | controller | Friday 03 October 2025  07:55:55 +0000 (0:00:00.038)       0:00:01.141 ********
2025-10-03 07:55:56.612646 | controller | ok: [instance]
2025-10-03 07:55:56.612720 | controller |
2025-10-03 07:55:56.612923 | controller | TASK [Store output spec] *******************************************************
2025-10-03 07:55:56.612946 | controller | Friday 03 October 2025  07:55:56 +0000 (0:00:00.997)       0:00:02.138 ********
2025-10-03 07:55:56.650277 | controller | ok: [instance]
2025-10-03 07:55:56.650382 | controller |
2025-10-03 07:55:56.650459 | controller | TASK [Ensure both lists have the same length] **********************************
2025-10-03 07:55:56.650596 | controller | Friday 03 October 2025  07:55:56 +0000 (0:00:00.037)       0:00:02.176 ********
2025-10-03 07:55:56.693770 | controller | ok: [instance] => changed=false
2025-10-03 07:55:56.693861 | controller |   msg: All assertions passed
2025-10-03 07:55:56.694063 | controller |
2025-10-03 07:55:56.694199 | controller | TASK [Compare each corresponding element in the lists] *************************
2025-10-03 07:55:56.694342 | controller | Friday 03 October 2025  07:55:56 +0000 (0:00:00.043)       0:00:02.220 ********
2025-10-03 07:55:56.753189 | controller | ok: [instance] => (item=['{\n  "cniVersion": "0.3.1",\n  "name": "bridge-to-linux-bridge",\n  "type": "bridge",\n  "bridge": "bridge-to-linux-bridge",\n  "ipam": {\n    "type": "whereabouts",\n    "range": "192.168.122.0/24",\n    "range_start": "192.168.122.30",\n    "range_end": "192.168.122.70"\n  }\n}', '{\n  "cniVersion": "0.3.1",\n  "name": "bridge-to-linux-bridge",\n  "type": "bridge",\n  "bridge": "bridge-to-linux-bridge",\n  "ipam": {\n    "type": "whereabouts",\n    "range": "192.168.122.0/24",\n    "range_start": "192.168.122.30",\n    "range_end": "192.168.122.70"\n  }\n}\n']) => changed=false
2025-10-03 07:55:56.753532 | controller |   ansible_loop_var: item
2025-10-03 07:55:56.754095 | controller |   item:
2025-10-03 07:55:56.754229 | controller |   - |-
2025-10-03 07:55:56.754743 | controller |     {
2025-10-03 07:55:56.755313 | controller |       "cniVersion": "0.3.1",
2025-10-03 07:55:56.755432 | controller |       "name": "bridge-to-linux-bridge",
2025-10-03 07:55:56.755539 | controller |       "type": "bridge",
2025-10-03 07:55:56.755749 | controller |       "bridge": "bridge-to-linux-bridge",
2025-10-03 07:55:56.755904 | controller |       "ipam": {
2025-10-03 07:55:56.756151 | controller |         "type": "whereabouts",
2025-10-03 07:55:56.756250 | controller |         "range": "192.168.122.0/24",
2025-10-03 07:55:56.756345 | controller |         "range_start": "192.168.122.30",
2025-10-03 07:55:56.756442 | controller |         "range_end": "192.168.122.70"
2025-10-03 07:55:56.756628 | controller |       }
2025-10-03 07:55:56.756725 | controller |     }
2025-10-03 07:55:56.756827 | controller |   - |-
2025-10-03 07:55:56.756948 | controller |     {
2025-10-03 07:55:56.757047 | controller |       "cniVersion": "0.3.1",
2025-10-03 07:55:56.757139 | controller |       "name": "bridge-to-linux-bridge",
2025-10-03 07:55:56.757261 | controller |       "type": "bridge",
2025-10-03 07:55:56.757357 | controller |       "bridge": "bridge-to-linux-bridge",
2025-10-03 07:55:56.757454 | controller |       "ipam": {
2025-10-03 07:55:56.757566 | controller |         "type": "whereabouts",
2025-10-03 07:55:56.757686 | controller |         "range": "192.168.122.0/24",
2025-10-03 07:55:56.757783 | controller |         "range_start": "192.168.122.30",
2025-10-03 07:55:56.757923 | controller |         "range_end": "192.168.122.70"
2025-10-03 07:55:56.758036 | controller |       }
2025-10-03 07:55:56.758143 | controller |     }
2025-10-03 07:55:56.763093 | controller |   msg: All assertions passed
2025-10-03 07:55:56.763239 | controller | ok: [instance] => (item=['{\n  "cniVersion": "0.3.1",\n  "name": "default",\n  "type": "bridge",\n  "bridge": "eth0",\n  "ipam": {\n    "type": "whereabouts",\n    "range": "192.168.122.0/24",\n    "range_start": "192.168.122.30",\n    "range_end": "192.168.122.70"\n  }\n}\n', '{\n  "cniVersion": "0.3.1",\n  "name": "default",\n  "type": "bridge",\n  "bridge": "eth0",\n  "ipam": {\n    "type": "whereabouts",\n    "range": "192.168.122.0/24",\n    "range_start": "192.168.122.30",\n    "range_end": "192.168.122.70"\n  }\n}\n']) => changed=false
2025-10-03 07:55:56.763337 | controller |   ansible_loop_var: item
2025-10-03 07:55:56.763433 | controller |   item:
2025-10-03 07:55:56.763546 | controller |   - |-
2025-10-03 07:55:56.763645 | controller |     {
2025-10-03 07:55:56.763745 | controller |       "cniVersion": "0.3.1",
2025-10-03 07:55:56.763839 | controller |       "name": "default",
2025-10-03 07:55:56.763959 | controller |       "type": "bridge",
2025-10-03 07:55:56.764067 | controller |       "bridge": "eth0",
2025-10-03 07:55:56.764180 | controller |       "ipam": {
2025-10-03 07:55:56.764286 | controller |         "type": "whereabouts",
2025-10-03 07:55:56.764381 | controller |         "range": "192.168.122.0/24",
2025-10-03 07:55:56.764481 | controller |         "range_start": "192.168.122.30",
2025-10-03 07:55:56.764579 | controller |         "range_end": "192.168.122.70"
2025-10-03 07:55:56.765197 | controller |       }
2025-10-03 07:55:56.765307 | controller |     }
2025-10-03 07:55:56.765411 | controller |   - |-
2025-10-03 07:55:56.765520 | controller |     {
2025-10-03 07:55:56.765624 | controller |       "cniVersion": "0.3.1",
2025-10-03 07:55:56.765725 | controller |       "name": "default",
2025-10-03 07:55:56.765909 | controller |       "type": "bridge",
2025-10-03 07:55:56.766014 | controller |       "bridge": "eth0",
2025-10-03 07:55:56.766109 | controller |       "ipam": {
2025-10-03 07:55:56.766230 | controller |         "type": "whereabouts",
2025-10-03 07:55:56.766358 | controller |         "range": "192.168.122.0/24",
2025-10-03 07:55:56.766476 | controller |         "range_start": "192.168.122.30",
2025-10-03 07:55:56.766568 | controller |         "range_end": "192.168.122.70"
2025-10-03 07:55:56.766666 | controller |       }
2025-10-03 07:55:56.766756 | controller |     }
2025-10-03 07:55:56.766870 | controller |   msg: All assertions passed
2025-10-03 07:55:56.767025 | controller | ok: [instance] => (item=['{\n  "cniVersion": "0.3.1",\n  "name": "patchnetwork",\n  "type": "macvlan",\n  "master": "eth2",\n  "ipam": {\n    "type": "whereabouts",\n    "range": "192.168.122.0/24",\n    "range_start": "192.168.122.30",\n    "range_end": "192.168.122.70"\n  }\n}\n', '{\n  "cniVersion": "0.3.1",\n  "name": "patchnetwork",\n  "type": "macvlan",\n  "master": "eth2",\n  "ipam": {\n    "type": "whereabouts",\n    "range": "192.168.122.0/24",\n    "range_start": "192.168.122.30",\n    "range_end": "192.168.122.70"\n  }\n}']) => changed=false
2025-10-03 07:55:56.767133 | controller |   ansible_loop_var: item
2025-10-03 07:55:56.767231 | controller |   item:
2025-10-03 07:55:56.767331 | controller |   - |-
2025-10-03 07:55:56.767423 | controller |     {
2025-10-03 07:55:56.767523 | controller |       "cniVersion": "0.3.1",
2025-10-03 07:55:56.767620 | controller |       "name": "patchnetwork",
2025-10-03 07:55:56.767713 | controller |       "type": "macvlan",
2025-10-03 07:55:56.767800 | controller |       "master": "eth2",
2025-10-03 07:55:56.767922 | controller |       "ipam": {
2025-10-03 07:55:56.768034 | controller |         "type": "whereabouts",
2025-10-03 07:55:56.768150 | controller |         "range": "192.168.122.0/24",
2025-10-03 07:55:56.768261 | controller |         "range_start": "192.168.122.30",
2025-10-03 07:55:56.768359 | controller |         "range_end": "192.168.122.70"
2025-10-03 07:55:56.768471 | controller |       }
2025-10-03 07:55:56.768578 | controller |     }
2025-10-03 07:55:56.768672 | controller |   - |-
2025-10-03 07:55:56.768766 | controller |     {
2025-10-03 07:55:56.768885 | controller |       "cniVersion": "0.3.1",
2025-10-03 07:55:56.768982 | controller |       "name": "patchnetwork",
2025-10-03 07:55:56.769093 | controller |       "type": "macvlan",
2025-10-03 07:55:56.769204 | controller |       "master": "eth2",
2025-10-03 07:55:56.769323 | controller |       "ipam": {
2025-10-03 07:55:56.769413 | controller |         "type": "whereabouts",
2025-10-03 07:55:56.769509 | controller |         "range": "192.168.122.0/24",
2025-10-03 07:55:56.769603 | controller |         "range_start": "192.168.122.30",
2025-10-03 07:55:56.769698 | controller |         "range_end": "192.168.122.70"
2025-10-03 07:55:56.769794 | controller |       }
2025-10-03 07:55:56.769914 | controller |     }
2025-10-03 07:55:56.770034 | controller |   msg: All assertions passed
2025-10-03 07:55:56.770119 | controller |
2025-10-03 07:55:56.770256 | controller | TASK [Create a test pod to attach a network] ***********************************
2025-10-03 07:55:56.770347 | controller | Friday 03 October 2025  07:55:56 +0000 (0:00:00.058)       0:00:02.279 ********
2025-10-03 07:56:07.800976 | controller | [WARNING]: unknown field "api_version"
2025-10-03 07:56:07.810673 | controller | changed: [instance]
2025-10-03 07:56:07.834872 | controller |
2025-10-03 07:56:07.834919 | controller | TASK [Assert that test pod has the additional network] *************************
2025-10-03 07:56:07.834930 | controller | Friday 03 October 2025  07:56:07 +0000 (0:00:11.057)       0:00:13.336 ********
2025-10-03 07:56:07.834945 | controller | ok: [instance] => changed=false
2025-10-03 07:56:08.747101 | controller |   msg: All assertions passed
2025-10-03 07:56:08.747155 | controller |
2025-10-03 07:56:08.747167 | controller | TASK [Delete test pod] *********************************************************
2025-10-03 07:56:08.747182 | controller | Friday 03 October 2025  07:56:07 +0000 (0:00:00.024)       0:00:13.361 ********
2025-10-03 07:56:08.747198 | controller | changed: [instance]
2025-10-03 07:56:08.828609 | controller |
2025-10-03 07:56:08.828646 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:08.828655 | controller | instance                   : ok=9    changed=2    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:08.828664 | controller |
2025-10-03 07:56:08.828672 | controller | Friday 03 October 2025  07:56:08 +0000 (0:00:00.910)       0:00:14.271 ********
2025-10-03 07:56:08.828681 | controller | ===============================================================================
2025-10-03 07:56:08.828688 | controller | Create a test pod to attach a network ---------------------------------- 11.06s
2025-10-03 07:56:08.828696 | controller | Gathering Facts --------------------------------------------------------- 1.08s
2025-10-03 07:56:08.828704 | controller | Check if NADs were created ---------------------------------------------- 1.00s
2025-10-03 07:56:08.828711 | controller | Delete test pod --------------------------------------------------------- 0.91s
2025-10-03 07:56:08.828719 | controller | Compare each corresponding element in the lists ------------------------- 0.06s
2025-10-03 07:56:08.828727 | controller | Ensure both lists have the same length ---------------------------------- 0.04s
2025-10-03 07:56:08.828735 | controller | Include default vars ---------------------------------------------------- 0.04s
2025-10-03 07:56:08.828742 | controller | Store output spec ------------------------------------------------------- 0.04s
2025-10-03 07:56:08.828749 | controller | Assert that test pod has the additional network ------------------------- 0.02s
2025-10-03 07:56:08.828764 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:08.839217 | controller | INFO     Running default > side_effect
2025-10-03 07:56:09.407274 | controller |
2025-10-03 07:56:10.421171 | controller | PLAY [Clean] *******************************************************************
2025-10-03 07:56:10.421229 | controller |
2025-10-03 07:56:10.421239 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:10.421247 | controller | Friday 03 October 2025  07:56:09 +0000 (0:00:00.017)       0:00:00.017 ********
2025-10-03 07:56:10.421263 | controller | ok: [instance]
2025-10-03 07:56:10.421303 | controller |
2025-10-03 07:56:10.421492 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] ****************
2025-10-03 07:56:10.421537 | controller | Friday 03 October 2025  07:56:10 +0000 (0:00:01.014)       0:00:01.032 ********
2025-10-03 07:56:10.821026 | controller | changed: [instance]
2025-10-03 07:56:10.821093 | controller |
2025-10-03 07:56:10.821377 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] ****************
2025-10-03 07:56:11.977168 | controller | Friday 03 October 2025  07:56:10 +0000 (0:00:00.399)       0:00:01.431 ********
2025-10-03 07:56:11.977231 | controller | ok: [instance]
2025-10-03 07:56:11.977320 | controller |
2025-10-03 07:56:11.977359 | controller | TASK [ci_multus : Cleanup - Delete NADs] ***************************************
2025-10-03 07:56:14.425984 | controller | Friday 03 October 2025  07:56:11 +0000 (0:00:01.156)       0:00:02.587 ********
2025-10-03 07:56:14.426080 | controller | changed: [instance] => (item=bridge-to-linux-bridge)
2025-10-03 07:56:14.821451 | controller | changed: [instance] => (item=default)
2025-10-03 07:56:14.821489 | controller | changed: [instance] => (item=patchnetwork)
2025-10-03 07:56:14.821497 | controller |
2025-10-03 07:56:14.821503 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] ***************
2025-10-03 07:56:14.821510 | controller | Friday 03 October 2025  07:56:14 +0000 (0:00:02.448)       0:00:05.036 ********
2025-10-03 07:56:14.821520 | controller | changed: [instance]
2025-10-03 07:56:14.898430 | controller |
2025-10-03 07:56:14.898469 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:14.898478 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:14.898484 | controller |
2025-10-03 07:56:14.898490 | controller | Friday 03 October 2025  07:56:14 +0000 (0:00:00.395)       0:00:05.431 ********
2025-10-03 07:56:14.898503 | controller | ===============================================================================
2025-10-03 07:56:14.898510 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 2.45s
2025-10-03 07:56:14.898515 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 1.16s
2025-10-03 07:56:14.898521 | controller | Gathering Facts --------------------------------------------------------- 1.01s
2025-10-03 07:56:14.898527 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.40s
2025-10-03 07:56:14.898533 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.40s
2025-10-03 07:56:14.898545 | controller | INFO     Running default > verify
2025-10-03 07:56:14.898917 | controller | INFO     Running Ansible Verifier
2025-10-03 07:56:15.428582 | controller |
2025-10-03 07:56:16.502108 | controller | PLAY [Verify Clean] ************************************************************
2025-10-03 07:56:16.502145 | controller |
2025-10-03 07:56:16.502152 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:16.502158 | controller | Friday 03 October 2025  07:56:15 +0000 (0:00:00.019)       0:00:00.019 ********
2025-10-03 07:56:16.502169 | controller | ok: [instance]
2025-10-03 07:56:16.502470 | controller |
2025-10-03 07:56:16.534563 | controller | TASK [Include default vars] ****************************************************
2025-10-03 07:56:16.534598 | controller | Friday 03 October 2025  07:56:16 +0000 (0:00:01.074)       0:00:01.093 ********
2025-10-03 07:56:16.534611 | controller | ok: [instance]
2025-10-03 07:56:16.905960 | controller |
2025-10-03 07:56:16.906002 | controller | TASK [Fetch file stat results] *************************************************
2025-10-03 07:56:16.906013 | controller | Friday 03 October 2025  07:56:16 +0000 (0:00:00.028)       0:00:01.122 ********
2025-10-03 07:56:16.906027 | controller | ok: [instance]
2025-10-03 07:56:16.906237 | controller |
2025-10-03 07:56:16.906253 | controller | TASK [Assert that created file are removed by cleanup] *************************
2025-10-03 07:56:16.906264 | controller | Friday 03 October 2025  07:56:16 +0000 (0:00:00.375)       0:00:01.497 ********
2025-10-03 07:56:16.961126 | controller | ok: [instance] => changed=false
2025-10-03 07:56:17.055913 | controller |   msg: All assertions passed
2025-10-03 07:56:17.055956 | controller |
2025-10-03 07:56:17.055964 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:17.055971 | controller | instance                   : ok=4    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:17.055978 | controller |
2025-10-03 07:56:17.055985 | controller | Friday 03 October 2025  07:56:16 +0000 (0:00:00.054)       0:00:01.551 ********
2025-10-03 07:56:17.055998 | controller | ===============================================================================
2025-10-03 07:56:17.056011 | controller | Gathering Facts --------------------------------------------------------- 1.07s
2025-10-03 07:56:17.056018 | controller | Fetch file stat results ------------------------------------------------- 0.38s
2025-10-03 07:56:17.056026 | controller | Assert that created file are removed by cleanup ------------------------- 0.05s
2025-10-03 07:56:17.056033 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-10-03 07:56:17.056048 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:17.063831 | controller | INFO     Running default > verify
2025-10-03 07:56:17.064197 | controller | INFO     Running Ansible Verifier
2025-10-03 07:56:17.731829 | controller |
2025-10-03 07:56:18.827178 | controller | PLAY [Verify Clean CRC] ********************************************************
2025-10-03 07:56:18.827237 | controller |
2025-10-03 07:56:18.827247 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:18.827256 | controller | Friday 03 October 2025  07:56:17 +0000 (0:00:00.024)       0:00:00.024 ********
2025-10-03 07:56:18.827291 | controller | ok: [instance]
2025-10-03 07:56:18.827427 | controller |
2025-10-03 07:56:18.827467 | controller | TASK [Include default vars] ****************************************************
2025-10-03 07:56:18.827482 | controller | Friday 03 October 2025  07:56:18 +0000 (0:00:01.096)       0:00:01.120 ********
2025-10-03 07:56:18.871725 | controller | ok: [instance]
2025-10-03 07:56:19.879959 | controller |
2025-10-03 07:56:19.880074 | controller | TASK [Check if NADs were deleted] **********************************************
2025-10-03 07:56:19.880087 | controller | Friday 03 October 2025  07:56:18 +0000 (0:00:00.044)       0:00:01.164 ********
2025-10-03 07:56:19.880101 | controller | ok: [instance]
2025-10-03 07:56:19.880292 | controller |
2025-10-03 07:56:19.880333 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:19.880347 | controller | instance                   : ok=3    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:19.880372 | controller |
2025-10-03 07:56:19.880381 | controller | Friday 03 October 2025  07:56:19 +0000 (0:00:01.009)       0:00:02.174 ********
2025-10-03 07:56:19.880529 | controller | ===============================================================================
2025-10-03 07:56:19.880554 | controller | Gathering Facts --------------------------------------------------------- 1.10s
2025-10-03 07:56:19.880663 | controller | Check if NADs were deleted ---------------------------------------------- 1.01s
2025-10-03 07:56:19.880773 | controller | Include default vars ---------------------------------------------------- 0.04s
2025-10-03 07:56:19.948897 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:19.949345 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-10-03 07:56:19.960759 | controller | INFO     Running local > destroy
2025-10-03 07:56:19.961014 | controller | WARNING  Skipping, instances are delegated.
2025-10-03 07:56:19.971722 | controller | INFO     Running local > create
2025-10-03 07:56:19.972661 | controller | WARNING  Skipping, instances are delegated.
2025-10-03 07:56:19.981410 | controller | INFO     Running local > converge
2025-10-03 07:56:20.545705 | controller |
2025-10-03 07:56:20.545801 | controller | PLAY [Converge] ****************************************************************
2025-10-03 07:56:20.545913 | controller |
2025-10-03 07:56:20.546093 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:20.546201 | controller | Friday 03 October 2025  07:56:20 +0000 (0:00:00.021)       0:00:00.021 ********
2025-10-03 07:56:21.638661 | controller | ok: [instance]
2025-10-03 07:56:21.638731 | controller |
2025-10-03 07:56:21.638895 | controller | TASK [Load shared variables] ***************************************************
2025-10-03 07:56:21.639062 | controller | Friday 03 October 2025  07:56:21 +0000 (0:00:01.093)       0:00:01.114 ********
2025-10-03 07:56:21.663038 | controller | ok: [instance]
2025-10-03 07:56:21.663139 | controller |
2025-10-03 07:56:21.663244 | controller | TASK [Call ci_multus role] *****************************************************
2025-10-03 07:56:21.663384 | controller | Friday 03 October 2025  07:56:21 +0000 (0:00:00.024)       0:00:01.139 ********
2025-10-03 07:56:21.709819 | controller |
2025-10-03 07:56:21.709919 | controller | TASK [ci_multus : Create manifests directory] **********************************
2025-10-03 07:56:21.710065 | controller | Friday 03 October 2025  07:56:21 +0000 (0:00:00.046)       0:00:01.186 ********
2025-10-03 07:56:22.078534 | controller | changed: [instance]
2025-10-03 07:56:22.078596 | controller |
2025-10-03 07:56:22.078757 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-10-03 07:56:22.078889 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.368)       0:00:01.554 ********
2025-10-03 07:56:22.109505 | controller | skipping: [instance]
2025-10-03 07:56:22.109585 | controller |
2025-10-03 07:56:22.109648 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-10-03 07:56:22.109663 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.030)       0:00:01.585 ********
2025-10-03 07:56:22.139690 | controller | skipping: [instance]
2025-10-03 07:56:22.139734 | controller |
2025-10-03 07:56:22.139822 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-03 07:56:22.139959 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.030)       0:00:01.615 ********
2025-10-03 07:56:22.168729 | controller | skipping: [instance]
2025-10-03 07:56:22.169033 | controller |
2025-10-03 07:56:22.169168 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-10-03 07:56:22.169185 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.029)       0:00:01.644 ********
2025-10-03 07:56:22.207281 | controller | skipping: [instance]
2025-10-03 07:56:22.207365 | controller |
2025-10-03 07:56:22.207376 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] *****
2025-10-03 07:56:22.207457 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.038)       0:00:01.683 ********
2025-10-03 07:56:22.246580 | controller | ok: [instance]
2025-10-03 07:56:22.246652 | controller |
2025-10-03 07:56:22.246744 | controller | TASK [ci_multus : Merge any available multus net info patches] *****************
2025-10-03 07:56:22.246879 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.039)       0:00:01.723 ********
2025-10-03 07:56:22.427348 | controller | ok: [instance] => (item={'default': {'interface_name': 'eth0', 'network_name': 'default', 'gw_v4': '192.168.122.1', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'deny_network': {'gw_v4': '192.168.122.1', 'network_name': 'deny_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'not_allowed_network': {'gw_v4': '192.168.122.1', 'network_name': 'not_allowed_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'no_multus_network': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2'}})
2025-10-03 07:56:22.427743 | controller | ok: [instance] => (item={'patchnetwork': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}]}}}})
2025-10-03 07:56:22.505433 | controller |
2025-10-03 07:56:22.505474 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] *******
2025-10-03 07:56:22.505483 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.180)       0:00:01.903 ********
2025-10-03 07:56:22.505495 | controller | ok: [instance]
2025-10-03 07:56:22.505585 | controller |
2025-10-03 07:56:22.505596 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] ***
2025-10-03 07:56:22.505694 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.078)       0:00:01.982 ********
2025-10-03 07:56:22.577253 | controller | ok: [instance]
2025-10-03 07:56:22.577328 | controller |
2025-10-03 07:56:22.577475 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] ***
2025-10-03 07:56:22.577577 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.071)       0:00:02.053 ********
2025-10-03 07:56:22.659048 | controller | ok: [instance]
2025-10-03 07:56:22.659121 | controller |
2025-10-03 07:56:22.659247 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] ***************
2025-10-03 07:56:22.659337 | controller | Friday 03 October 2025  07:56:22 +0000 (0:00:00.081)       0:00:02.135 ********
2025-10-03 07:56:23.365497 | controller | changed: [instance]
2025-10-03 07:56:23.365621 | controller |
2025-10-03 07:56:23.365757 | controller | TASK [ci_multus : Create the multus namespace] *********************************
2025-10-03 07:56:23.365945 | controller | Friday 03 October 2025  07:56:23 +0000 (0:00:00.706)       0:00:02.841 ********
2025-10-03 07:56:23.387951 | controller | skipping: [instance]
2025-10-03 07:56:23.387991 | controller |
2025-10-03 07:56:23.388132 | controller | TASK [ci_multus : Apply network attachment definition manifests] ***************
2025-10-03 07:56:23.388280 | controller | Friday 03 October 2025  07:56:23 +0000 (0:00:00.022)       0:00:02.864 ********
2025-10-03 07:56:23.429697 | controller | skipping: [instance]
2025-10-03 07:56:23.429738 | controller |
2025-10-03 07:56:23.429866 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:23.430045 | controller | instance                   : ok=9    changed=2    unreachable=0    failed=0    skipped=6    rescued=0    ignored=0
2025-10-03 07:56:23.430079 | controller |
2025-10-03 07:56:23.430205 | controller | Friday 03 October 2025  07:56:23 +0000 (0:00:00.042)       0:00:02.906 ********
2025-10-03 07:56:23.430359 | controller | ===============================================================================
2025-10-03 07:56:23.430424 | controller | Gathering Facts --------------------------------------------------------- 1.09s
2025-10-03 07:56:23.430542 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.71s
2025-10-03 07:56:23.430624 | controller | ci_multus : Create manifests directory ---------------------------------- 0.37s
2025-10-03 07:56:23.430763 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.18s
2025-10-03 07:56:23.430939 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.08s
2025-10-03 07:56:23.431046 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.08s
2025-10-03 07:56:23.431324 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.07s
2025-10-03 07:56:23.431379 | controller | Call ci_multus role ----------------------------------------------------- 0.05s
2025-10-03 07:56:23.431491 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.04s
2025-10-03 07:56:23.431595 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.04s
2025-10-03 07:56:23.431982 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.04s
2025-10-03 07:56:23.432060 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s
2025-10-03 07:56:23.432068 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s
2025-10-03 07:56:23.432077 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.03s
2025-10-03 07:56:23.432154 | controller | Load shared variables --------------------------------------------------- 0.02s
2025-10-03 07:56:23.432262 | controller | ci_multus : Create the multus namespace --------------------------------- 0.02s
2025-10-03 07:56:23.515875 | controller | INFO     Running local > verify
2025-10-03 07:56:23.516155 | controller | INFO     Running Ansible Verifier
2025-10-03 07:56:24.120314 | controller |
2025-10-03 07:56:24.120390 | controller | PLAY [Verify] ******************************************************************
2025-10-03 07:56:24.120598 | controller |
2025-10-03 07:56:24.120837 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:24.121106 | controller | Friday 03 October 2025  07:56:24 +0000 (0:00:00.018)       0:00:00.018 ********
2025-10-03 07:56:25.190502 | controller | ok: [instance]
2025-10-03 07:56:25.215016 | controller |
2025-10-03 07:56:25.215062 | controller | TASK [Load shared variables] ***************************************************
2025-10-03 07:56:25.215070 | controller | Friday 03 October 2025  07:56:25 +0000 (0:00:01.070)       0:00:01.089 ********
2025-10-03 07:56:25.215111 | controller | ok: [instance]
2025-10-03 07:56:25.215217 | controller |
2025-10-03 07:56:25.215331 | controller | TASK [Fetch files stat results] ************************************************
2025-10-03 07:56:25.215348 | controller | Friday 03 October 2025  07:56:25 +0000 (0:00:00.024)       0:00:01.113 ********
2025-10-03 07:56:25.611969 | controller | ok: [instance]
2025-10-03 07:56:25.612015 | controller |
2025-10-03 07:56:25.612278 | controller | TASK [Assert that expected file exist] *****************************************
2025-10-03 07:56:25.636803 | controller | Friday 03 October 2025  07:56:25 +0000 (0:00:00.396)       0:00:01.510 ********
2025-10-03 07:56:25.636842 | controller | ok: [instance] => changed=false
2025-10-03 07:56:25.636906 | controller |   msg: All assertions passed
2025-10-03 07:56:25.637025 | controller |
2025-10-03 07:56:25.637143 | controller | TASK [Fetch file content] ******************************************************
2025-10-03 07:56:25.637268 | controller | Friday 03 October 2025  07:56:25 +0000 (0:00:00.024)       0:00:01.535 ********
2025-10-03 07:56:25.973149 | controller | ok: [instance]
2025-10-03 07:56:25.973213 | controller |
2025-10-03 07:56:25.973304 | controller | TASK [Set _ci_multus_nad variable] *********************************************
2025-10-03 07:56:25.973419 | controller | Friday 03 October 2025  07:56:25 +0000 (0:00:00.331)       0:00:01.867 ********
2025-10-03 07:56:26.005963 | controller | ok: [instance]
2025-10-03 07:56:26.006037 | controller |
2025-10-03 07:56:26.006140 | controller | TASK [Assert expected number of Network Attachment Definitions are created] ****
2025-10-03 07:56:26.006247 | controller | Friday 03 October 2025  07:56:26 +0000 (0:00:00.037)       0:00:01.905 ********
2025-10-03 07:56:26.057666 | controller | ok: [instance]
2025-10-03 07:56:26.057735 | controller |
2025-10-03 07:56:26.057864 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:26.057981 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:26.058095 | controller |
2025-10-03 07:56:26.058234 | controller | Friday 03 October 2025  07:56:26 +0000 (0:00:00.052)       0:00:01.957 ********
2025-10-03 07:56:26.058357 | controller | ===============================================================================
2025-10-03 07:56:26.058490 | controller | Gathering Facts --------------------------------------------------------- 1.07s
2025-10-03 07:56:26.058623 | controller | Fetch files stat results ------------------------------------------------ 0.40s
2025-10-03 07:56:26.058754 | controller | Fetch file content ------------------------------------------------------ 0.33s
2025-10-03 07:56:26.058910 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.05s
2025-10-03 07:56:26.059032 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.04s
2025-10-03 07:56:26.059164 | controller | Assert that expected file exist ----------------------------------------- 0.02s
2025-10-03 07:56:26.059289 | controller | Load shared variables --------------------------------------------------- 0.02s
2025-10-03 07:56:26.140724 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:26.150913 | controller | INFO     Running local > side_effect
2025-10-03 07:56:26.707744 | controller |
2025-10-03 07:56:26.707808 | controller | PLAY [Clean] *******************************************************************
2025-10-03 07:56:26.707966 | controller |
2025-10-03 07:56:26.708109 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:26.708240 | controller | Friday 03 October 2025  07:56:26 +0000 (0:00:00.016)       0:00:00.016 ********
2025-10-03 07:56:27.723126 | controller | ok: [instance]
2025-10-03 07:56:27.723366 | controller |
2025-10-03 07:56:27.723386 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] ****************
2025-10-03 07:56:28.140010 | controller | Friday 03 October 2025  07:56:27 +0000 (0:00:01.015)       0:00:01.032 ********
2025-10-03 07:56:28.140062 | controller | changed: [instance]
2025-10-03 07:56:28.140102 | controller |
2025-10-03 07:56:28.140114 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] ****************
2025-10-03 07:56:28.140136 | controller | Friday 03 October 2025  07:56:28 +0000 (0:00:00.416)       0:00:01.449 ********
2025-10-03 07:56:28.166787 | controller | skipping: [instance]
2025-10-03 07:56:28.166871 | controller |
2025-10-03 07:56:28.166884 | controller | TASK [ci_multus : Cleanup - Delete NADs] ***************************************
2025-10-03 07:56:28.166895 | controller | Friday 03 October 2025  07:56:28 +0000 (0:00:00.026)       0:00:01.475 ********
2025-10-03 07:56:28.199244 | controller | skipping: [instance]
2025-10-03 07:56:28.199297 | controller |
2025-10-03 07:56:28.199307 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] ***************
2025-10-03 07:56:28.199395 | controller | Friday 03 October 2025  07:56:28 +0000 (0:00:00.032)       0:00:01.508 ********
2025-10-03 07:56:28.622280 | controller | changed: [instance]
2025-10-03 07:56:28.622326 | controller |
2025-10-03 07:56:28.622536 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:28.622712 | controller | instance                   : ok=3    changed=2    unreachable=0    failed=0    skipped=2    rescued=0    ignored=0
2025-10-03 07:56:28.622866 | controller |
2025-10-03 07:56:28.623017 | controller | Friday 03 October 2025  07:56:28 +0000 (0:00:00.422)       0:00:01.931 ********
2025-10-03 07:56:28.623141 | controller | ===============================================================================
2025-10-03 07:56:28.623278 | controller | Gathering Facts --------------------------------------------------------- 1.02s
2025-10-03 07:56:28.623418 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.42s
2025-10-03 07:56:28.623566 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.42s
2025-10-03 07:56:28.623701 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 0.03s
2025-10-03 07:56:28.623839 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.03s
2025-10-03 07:56:28.710865 | controller | INFO     Running local > verify
2025-10-03 07:56:28.711088 | controller | INFO     Running Ansible Verifier
2025-10-03 07:56:29.262171 | controller |
2025-10-03 07:56:29.262249 | controller | PLAY [Verify Clean] ************************************************************
2025-10-03 07:56:29.262373 | controller |
2025-10-03 07:56:29.262386 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:29.262483 | controller | Friday 03 October 2025  07:56:29 +0000 (0:00:00.021)       0:00:00.021 ********
2025-10-03 07:56:30.322101 | controller | ok: [instance]
2025-10-03 07:56:30.322337 | controller |
2025-10-03 07:56:30.349637 | controller | TASK [Include default vars] ****************************************************
2025-10-03 07:56:30.349673 | controller | Friday 03 October 2025  07:56:30 +0000 (0:00:01.060)       0:00:01.082 ********
2025-10-03 07:56:30.349685 | controller | ok: [instance]
2025-10-03 07:56:30.730949 | controller |
2025-10-03 07:56:30.730997 | controller | TASK [Fetch file stat results] *************************************************
2025-10-03 07:56:30.731009 | controller | Friday 03 October 2025  07:56:30 +0000 (0:00:00.027)       0:00:01.109 ********
2025-10-03 07:56:30.731024 | controller | ok: [instance]
2025-10-03 07:56:30.767323 | controller |
2025-10-03 07:56:30.767363 | controller | TASK [Assert that created file are removed by cleanup] *************************
2025-10-03 07:56:30.767372 | controller | Friday 03 October 2025  07:56:30 +0000 (0:00:00.380)       0:00:01.490 ********
2025-10-03 07:56:30.767384 | controller | ok: [instance] => changed=false
2025-10-03 07:56:30.767421 | controller |   msg: All assertions passed
2025-10-03 07:56:30.767430 | controller |
2025-10-03 07:56:30.767455 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:30.767929 | controller | instance                   : ok=4    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:30.767962 | controller |
2025-10-03 07:56:30.767971 | controller | Friday 03 October 2025  07:56:30 +0000 (0:00:00.038)       0:00:01.528 ********
2025-10-03 07:56:30.767977 | controller | ===============================================================================
2025-10-03 07:56:30.767986 | controller | Gathering Facts --------------------------------------------------------- 1.06s
2025-10-03 07:56:30.768300 | controller | Fetch file stat results ------------------------------------------------- 0.38s
2025-10-03 07:56:30.839302 | controller | Assert that created file are removed by cleanup ------------------------- 0.04s
2025-10-03 07:56:30.839385 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-10-03 07:56:30.839420 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:30.839917 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-10-03 07:56:30.855576 | controller | INFO     Running local_ipv6 > destroy
2025-10-03 07:56:30.856008 | controller | WARNING  Skipping, instances are delegated.
2025-10-03 07:56:30.869259 | controller | INFO     Running local_ipv6 > create
2025-10-03 07:56:30.870593 | controller | WARNING  Skipping, instances are delegated.
2025-10-03 07:56:30.883475 | controller | INFO     Running local_ipv6 > converge
2025-10-03 07:56:31.464080 | controller |
2025-10-03 07:56:32.545448 | controller | PLAY [Converge] ****************************************************************
2025-10-03 07:56:32.545523 | controller |
2025-10-03 07:56:32.545532 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:32.545545 | controller | Friday 03 October 2025  07:56:31 +0000 (0:00:00.017)       0:00:00.017 ********
2025-10-03 07:56:32.545556 | controller | ok: [instance]
2025-10-03 07:56:32.568735 | controller |
2025-10-03 07:56:32.568772 | controller | TASK [Load shared variables] ***************************************************
2025-10-03 07:56:32.568780 | controller | Friday 03 October 2025  07:56:32 +0000 (0:00:01.082)       0:00:01.099 ********
2025-10-03 07:56:32.568791 | controller | ok: [instance]
2025-10-03 07:56:32.617049 | controller |
2025-10-03 07:56:32.617097 | controller | TASK [Call ci_multus role] *****************************************************
2025-10-03 07:56:32.617105 | controller | Friday 03 October 2025  07:56:32 +0000 (0:00:00.023)       0:00:01.123 ********
2025-10-03 07:56:32.617118 | controller |
2025-10-03 07:56:33.040061 | controller | TASK [ci_multus : Create manifests directory] **********************************
2025-10-03 07:56:33.040130 | controller | Friday 03 October 2025  07:56:32 +0000 (0:00:00.048)       0:00:01.171 ********
2025-10-03 07:56:33.040146 | controller | changed: [instance]
2025-10-03 07:56:33.040184 | controller |
2025-10-03 07:56:33.040197 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-10-03 07:56:33.040401 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.423)       0:00:01.594 ********
2025-10-03 07:56:33.069816 | controller | skipping: [instance]
2025-10-03 07:56:33.099302 | controller |
2025-10-03 07:56:33.099346 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-10-03 07:56:33.099355 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.029)       0:00:01.623 ********
2025-10-03 07:56:33.099368 | controller | skipping: [instance]
2025-10-03 07:56:33.099390 | controller |
2025-10-03 07:56:33.099486 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-03 07:56:33.099629 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.029)       0:00:01.653 ********
2025-10-03 07:56:33.132464 | controller | skipping: [instance]
2025-10-03 07:56:33.132534 | controller |
2025-10-03 07:56:33.132612 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-10-03 07:56:33.132764 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.033)       0:00:01.686 ********
2025-10-03 07:56:33.173221 | controller | skipping: [instance]
2025-10-03 07:56:33.173283 | controller |
2025-10-03 07:56:33.173359 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] *****
2025-10-03 07:56:33.173518 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.040)       0:00:01.727 ********
2025-10-03 07:56:33.217711 | controller | ok: [instance]
2025-10-03 07:56:33.217798 | controller |
2025-10-03 07:56:33.217971 | controller | TASK [ci_multus : Merge any available multus net info patches] *****************
2025-10-03 07:56:33.218109 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.044)       0:00:01.772 ********
2025-10-03 07:56:33.353674 | controller | skipping: [instance] => (item={'default': {'interface_name': 'eth1', 'network_name': 'default', 'gw_v6': 'fdc0:8b54:108a:c949:0000:0000:0000:0001', 'network_v6': 'fdc0:8b54:108a:c949::/64', 'tools': {'multus': {'ipv6_ranges': [{'start': 'fdc0:8b54:108a:c949:0000:0000:0000:001e', 'end': 'fdc0:8b54:108a:c949:0000:0000:0000:0027'}]}}}})
2025-10-03 07:56:33.353757 | controller | skipping: [instance]
2025-10-03 07:56:33.353919 | controller |
2025-10-03 07:56:33.354062 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] *******
2025-10-03 07:56:33.354214 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.135)       0:00:01.908 ********
2025-10-03 07:56:33.440230 | controller | ok: [instance]
2025-10-03 07:56:33.440305 | controller |
2025-10-03 07:56:33.440434 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] ***
2025-10-03 07:56:33.440549 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.086)       0:00:01.994 ********
2025-10-03 07:56:33.531043 | controller | ok: [instance]
2025-10-03 07:56:33.531533 | controller |
2025-10-03 07:56:33.531647 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] ***
2025-10-03 07:56:33.531757 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.090)       0:00:02.085 ********
2025-10-03 07:56:33.618208 | controller | ok: [instance]
2025-10-03 07:56:33.618298 | controller |
2025-10-03 07:56:33.618310 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] ***************
2025-10-03 07:56:33.618404 | controller | Friday 03 October 2025  07:56:33 +0000 (0:00:00.087)       0:00:02.172 ********
2025-10-03 07:56:34.338022 | controller | changed: [instance]
2025-10-03 07:56:34.338093 | controller |
2025-10-03 07:56:34.338228 | controller | TASK [ci_multus : Create the multus namespace] *********************************
2025-10-03 07:56:34.338345 | controller | Friday 03 October 2025  07:56:34 +0000 (0:00:00.719)       0:00:02.892 ********
2025-10-03 07:56:34.362354 | controller | skipping: [instance]
2025-10-03 07:56:34.362392 | controller |
2025-10-03 07:56:34.362505 | controller | TASK [ci_multus : Apply network attachment definition manifests] ***************
2025-10-03 07:56:34.362601 | controller | Friday 03 October 2025  07:56:34 +0000 (0:00:00.024)       0:00:02.917 ********
2025-10-03 07:56:34.407161 | controller | skipping: [instance]
2025-10-03 07:56:34.407201 | controller |
2025-10-03 07:56:34.407269 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:34.407376 | controller | instance                   : ok=8    changed=2    unreachable=0    failed=0    skipped=7    rescued=0    ignored=0
2025-10-03 07:56:34.407563 | controller |
2025-10-03 07:56:34.407667 | controller | Friday 03 October 2025  07:56:34 +0000 (0:00:00.044)       0:00:02.962 ********
2025-10-03 07:56:34.407677 | controller | ===============================================================================
2025-10-03 07:56:34.407774 | controller | Gathering Facts --------------------------------------------------------- 1.08s
2025-10-03 07:56:34.407918 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.72s
2025-10-03 07:56:34.408015 | controller | ci_multus : Create manifests directory ---------------------------------- 0.42s
2025-10-03 07:56:34.408284 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.14s
2025-10-03 07:56:34.408358 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.09s
2025-10-03 07:56:34.408367 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.09s
2025-10-03 07:56:34.408451 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.09s
2025-10-03 07:56:34.408688 | controller | Call ci_multus role ----------------------------------------------------- 0.05s
2025-10-03 07:56:34.408834 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.04s
2025-10-03 07:56:34.408861 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.04s
2025-10-03 07:56:34.408973 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.04s
2025-10-03 07:56:34.408982 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.03s
2025-10-03 07:56:34.409174 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s
2025-10-03 07:56:34.409265 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s
2025-10-03 07:56:34.409274 | controller | ci_multus : Create the multus namespace --------------------------------- 0.02s
2025-10-03 07:56:34.409360 | controller | Load shared variables --------------------------------------------------- 0.02s
2025-10-03 07:56:34.494731 | controller | INFO     Running local_ipv6 > verify
2025-10-03 07:56:34.495130 | controller | INFO     Running Ansible Verifier
2025-10-03 07:56:35.016562 | controller |
2025-10-03 07:56:35.016632 | controller | PLAY [Verify] ******************************************************************
2025-10-03 07:56:35.018790 | controller |
2025-10-03 07:56:36.137705 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:36.137745 | controller | Friday 03 October 2025  07:56:35 +0000 (0:00:00.020)       0:00:00.020 ********
2025-10-03 07:56:36.137766 | controller | ok: [instance]
2025-10-03 07:56:36.137787 | controller |
2025-10-03 07:56:36.137944 | controller | TASK [Load shared variables] ***************************************************
2025-10-03 07:56:36.138060 | controller | Friday 03 October 2025  07:56:36 +0000 (0:00:01.121)       0:00:01.141 ********
2025-10-03 07:56:36.164814 | controller | ok: [instance]
2025-10-03 07:56:36.164929 | controller |
2025-10-03 07:56:36.165059 | controller | TASK [Fetch files stat results] ************************************************
2025-10-03 07:56:36.165203 | controller | Friday 03 October 2025  07:56:36 +0000 (0:00:00.026)       0:00:01.168 ********
2025-10-03 07:56:36.591059 | controller | ok: [instance]
2025-10-03 07:56:36.591124 | controller |
2025-10-03 07:56:36.591295 | controller | TASK [Assert that expected file exist] *****************************************
2025-10-03 07:56:36.591451 | controller | Friday 03 October 2025  07:56:36 +0000 (0:00:00.426)       0:00:01.594 ********
2025-10-03 07:56:36.617469 | controller | ok: [instance] => changed=false
2025-10-03 07:56:36.617545 | controller |   msg: All assertions passed
2025-10-03 07:56:36.617630 | controller |
2025-10-03 07:56:36.617726 | controller | TASK [Fetch file content] ******************************************************
2025-10-03 07:56:36.617982 | controller | Friday 03 October 2025  07:56:36 +0000 (0:00:00.026)       0:00:01.621 ********
2025-10-03 07:56:36.977618 | controller | ok: [instance]
2025-10-03 07:56:36.977699 | controller |
2025-10-03 07:56:36.977925 | controller | TASK [Set _ci_multus_nad variable] *********************************************
2025-10-03 07:56:36.978082 | controller | Friday 03 October 2025  07:56:36 +0000 (0:00:00.360)       0:00:01.981 ********
2025-10-03 07:56:37.017466 | controller | ok: [instance]
2025-10-03 07:56:37.017519 | controller |
2025-10-03 07:56:37.017664 | controller | TASK [Assert expected number of Network Attachment Definitions are created] ****
2025-10-03 07:56:37.017763 | controller | Friday 03 October 2025  07:56:37 +0000 (0:00:00.039)       0:00:02.021 ********
2025-10-03 07:56:37.080047 | controller | ok: [instance]
2025-10-03 07:56:37.080092 | controller |
2025-10-03 07:56:37.080207 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:37.081114 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:37.081146 | controller |
2025-10-03 07:56:37.081159 | controller | Friday 03 October 2025  07:56:37 +0000 (0:00:00.062)       0:00:02.084 ********
2025-10-03 07:56:37.081171 | controller | ===============================================================================
2025-10-03 07:56:37.081182 | controller | Gathering Facts --------------------------------------------------------- 1.12s
2025-10-03 07:56:37.081193 | controller | Fetch files stat results ------------------------------------------------ 0.43s
2025-10-03 07:56:37.081204 | controller | Fetch file content ------------------------------------------------------ 0.36s
2025-10-03 07:56:37.081218 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.06s
2025-10-03 07:56:37.081269 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.04s
2025-10-03 07:56:37.081392 | controller | Load shared variables --------------------------------------------------- 0.03s
2025-10-03 07:56:37.081507 | controller | Assert that expected file exist ----------------------------------------- 0.03s
2025-10-03 07:56:37.152996 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:37.168635 | controller | INFO     Running local_ipv6 > side_effect
2025-10-03 07:56:37.684311 | controller |
2025-10-03 07:56:37.684537 | controller | PLAY [Clean] *******************************************************************
2025-10-03 07:56:37.684658 | controller |
2025-10-03 07:56:37.684671 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:37.684782 | controller | Friday 03 October 2025  07:56:37 +0000 (0:00:00.017)       0:00:00.017 ********
2025-10-03 07:56:38.767200 | controller | ok: [instance]
2025-10-03 07:56:38.767494 | controller |
2025-10-03 07:56:39.225555 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] ****************
2025-10-03 07:56:39.225605 | controller | Friday 03 October 2025  07:56:38 +0000 (0:00:01.083)       0:00:01.100 ********
2025-10-03 07:56:39.225618 | controller | changed: [instance]
2025-10-03 07:56:39.225639 | controller |
2025-10-03 07:56:39.225827 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] ****************
2025-10-03 07:56:39.226045 | controller | Friday 03 October 2025  07:56:39 +0000 (0:00:00.458)       0:00:01.558 ********
2025-10-03 07:56:39.255450 | controller | skipping: [instance]
2025-10-03 07:56:39.294945 | controller |
2025-10-03 07:56:39.294983 | controller | TASK [ci_multus : Cleanup - Delete NADs] ***************************************
2025-10-03 07:56:39.294992 | controller | Friday 03 October 2025  07:56:39 +0000 (0:00:00.029)       0:00:01.588 ********
2025-10-03 07:56:39.295003 | controller | skipping: [instance]
2025-10-03 07:56:39.741224 | controller |
2025-10-03 07:56:39.741262 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] ***************
2025-10-03 07:56:39.741270 | controller | Friday 03 October 2025  07:56:39 +0000 (0:00:00.040)       0:00:01.628 ********
2025-10-03 07:56:39.741281 | controller | changed: [instance]
2025-10-03 07:56:39.741301 | controller |
2025-10-03 07:56:39.741425 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:39.741593 | controller | instance                   : ok=3    changed=2    unreachable=0    failed=0    skipped=2    rescued=0    ignored=0
2025-10-03 07:56:39.741708 | controller |
2025-10-03 07:56:39.741720 | controller | Friday 03 October 2025  07:56:39 +0000 (0:00:00.447)       0:00:02.075 ********
2025-10-03 07:56:39.741795 | controller | ===============================================================================
2025-10-03 07:56:39.741914 | controller | Gathering Facts --------------------------------------------------------- 1.08s
2025-10-03 07:56:39.742016 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.46s
2025-10-03 07:56:39.742109 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.45s
2025-10-03 07:56:39.742211 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 0.04s
2025-10-03 07:56:39.742360 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.03s
2025-10-03 07:56:39.821031 | controller | INFO     Running local_ipv6 > verify
2025-10-03 07:56:39.821393 | controller | INFO     Running Ansible Verifier
2025-10-03 07:56:40.358313 | controller |
2025-10-03 07:56:40.358427 | controller | PLAY [Verify Clean] ************************************************************
2025-10-03 07:56:40.358525 | controller |
2025-10-03 07:56:40.358630 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 07:56:40.358738 | controller | Friday 03 October 2025  07:56:40 +0000 (0:00:00.019)       0:00:00.019 ********
2025-10-03 07:56:41.422351 | controller | ok: [instance]
2025-10-03 07:56:41.422410 | controller |
2025-10-03 07:56:41.422422 | controller | TASK [Include default vars] ****************************************************
2025-10-03 07:56:41.422557 | controller | Friday 03 October 2025  07:56:41 +0000 (0:00:01.064)       0:00:01.084 ********
2025-10-03 07:56:41.448087 | controller | ok: [instance]
2025-10-03 07:56:41.793649 | controller |
2025-10-03 07:56:41.793680 | controller | TASK [Fetch file stat results] *************************************************
2025-10-03 07:56:41.793688 | controller | Friday 03 October 2025  07:56:41 +0000 (0:00:00.025)       0:00:01.110 ********
2025-10-03 07:56:41.793699 | controller | ok: [instance]
2025-10-03 07:56:41.793763 | controller |
2025-10-03 07:56:41.793960 | controller | TASK [Assert that created file are removed by cleanup] *************************
2025-10-03 07:56:41.794117 | controller | Friday 03 October 2025  07:56:41 +0000 (0:00:00.345)       0:00:01.455 ********
2025-10-03 07:56:41.831184 | controller | ok: [instance] => changed=false
2025-10-03 07:56:41.831358 | controller |   msg: All assertions passed
2025-10-03 07:56:41.831555 | controller |
2025-10-03 07:56:41.831755 | controller | PLAY RECAP *********************************************************************
2025-10-03 07:56:41.831964 | controller | instance                   : ok=4    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 07:56:41.832123 | controller |
2025-10-03 07:56:41.832327 | controller | Friday 03 October 2025  07:56:41 +0000 (0:00:00.037)       0:00:01.493 ********
2025-10-03 07:56:41.832518 | controller | ===============================================================================
2025-10-03 07:56:41.832722 | controller | Gathering Facts --------------------------------------------------------- 1.06s
2025-10-03 07:56:41.832957 | controller | Fetch file stat results ------------------------------------------------- 0.35s
2025-10-03 07:56:41.833164 | controller | Assert that created file are removed by cleanup ------------------------- 0.04s
2025-10-03 07:56:41.833362 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-10-03 07:56:41.899841 | controller | INFO     Verifier completed successfully.
2025-10-03 07:56:41.900271 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-10-03 07:56:41.902268 | controller | INFO     Writing /tmp/report.html report.
2025-10-03 07:56:42.404648 | controller | changed
2025-10-03 07:56:42.439378 | 
2025-10-03 07:56:42.439484 | PLAY RECAP
2025-10-03 07:56:42.439536 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 07:56:42.439565 | 
2025-10-03 07:56:42.552845 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-03 07:56:42.554429 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-03 07:56:43.143109 | 
2025-10-03 07:56:43.143283 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-03 07:56:43.165738 | 
2025-10-03 07:56:43.165906 | TASK [Filter out host if needed]
2025-10-03 07:56:43.176125 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-03 07:56:43.181259 | 
2025-10-03 07:56:43.181330 | TASK [Ensure file is present]
2025-10-03 07:56:43.658649 | controller | ok
2025-10-03 07:56:43.675283 | 
2025-10-03 07:56:43.675492 | TASK [Manage molecule report file]
2025-10-03 07:56:44.225250 | controller | changed
2025-10-03 07:56:44.237345 | 
2025-10-03 07:56:44.237490 | TASK [Check if we get ci-framework-data basedir]
2025-10-03 07:56:44.578752 | controller | ok
2025-10-03 07:56:44.586931 | 
2025-10-03 07:56:44.587134 | TASK [Create ci-framework-data log directory for zuul]
2025-10-03 07:56:45.111891 | controller | changed
2025-10-03 07:56:45.126597 | 
2025-10-03 07:56:45.126796 | TASK [Copy ci-framework interesting files]
2025-10-03 07:56:45.491458 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-03 07:56:45.678805 | controller | changed
2025-10-03 07:56:45.691191 | 
2025-10-03 07:56:45.691364 | TASK [Get SELinux listing]
2025-10-03 07:56:46.244837 | controller | changed
2025-10-03 07:56:46.258390 | 
2025-10-03 07:56:46.258577 | TASK [Generate log index]
2025-10-03 07:56:47.883527 | controller | changed
2025-10-03 07:56:47.895944 | 
2025-10-03 07:56:47.896246 | TASK [Get some env related data]
2025-10-03 07:56:48.725886 | controller | /home/zuul/.local/bin/ansible
2025-10-03 07:56:49.476273 | controller | changed
2025-10-03 07:56:49.523952 | 
2025-10-03 07:56:49.524112 | TASK [Generate list of logs to collect in home directory]
2025-10-03 07:56:50.069551 | controller | ok: All paths examined
2025-10-03 07:56:50.076670 | 
2025-10-03 07:56:50.076798 | LOOP [Copy logs from home directory]
2025-10-03 07:56:50.908106 | controller | changed:
2025-10-03 07:56:50.908444 | controller | {
2025-10-03 07:56:50.908484 | controller |   "atime": 1743544925.4788878,
2025-10-03 07:56:50.908511 | controller |   "ctime": 1743545329.1409318,
2025-10-03 07:56:50.908536 | controller |   "dev": 64513,
2025-10-03 07:56:50.908560 | controller |   "gid": 1000,
2025-10-03 07:56:50.908583 | controller |   "gr_name": "zuul",
2025-10-03 07:56:50.908607 | controller |   "inode": 4518807,
2025-10-03 07:56:50.908654 | controller |   "isblk": false,
2025-10-03 07:56:50.908679 | controller |   "ischr": false,
2025-10-03 07:56:50.908702 | controller |   "isdir": false,
2025-10-03 07:56:50.908724 | controller |   "isfifo": false,
2025-10-03 07:56:50.908762 | controller |   "isgid": false,
2025-10-03 07:56:50.908786 | controller |   "islnk": false,
2025-10-03 07:56:50.908808 | controller |   "isreg": true,
2025-10-03 07:56:50.908830 | controller |   "issock": false,
2025-10-03 07:56:50.908853 | controller |   "isuid": false,
2025-10-03 07:56:50.908874 | controller |   "mode": "0644",
2025-10-03 07:56:50.908896 | controller |   "mtime": 1743545329.1409318,
2025-10-03 07:56:50.908918 | controller |   "nlink": 1,
2025-10-03 07:56:50.908942 | controller |   "path": "/home/zuul/crc-setup.log",
2025-10-03 07:56:50.908965 | controller |   "pw_name": "zuul",
2025-10-03 07:56:50.908987 | controller |   "rgrp": true,
2025-10-03 07:56:50.909010 | controller |   "roth": true,
2025-10-03 07:56:50.909084 | controller |   "rusr": true,
2025-10-03 07:56:50.909110 | controller |   "size": 4108,
2025-10-03 07:56:50.909133 | controller |   "uid": 1000,
2025-10-03 07:56:50.909155 | controller |   "wgrp": false,
2025-10-03 07:56:50.909177 | controller |   "woth": false,
2025-10-03 07:56:50.909202 | controller |   "wusr": true,
2025-10-03 07:56:50.909226 | controller |   "xgrp": false,
2025-10-03 07:56:50.909249 | controller |   "xoth": false,
2025-10-03 07:56:50.909271 | controller |   "xusr": false
2025-10-03 07:56:50.909292 | controller | }
2025-10-03 07:56:51.762956 | controller | changed:
2025-10-03 07:56:51.763162 | controller | {
2025-10-03 07:56:51.763214 | controller |   "atime": 1759477550.1998165,
2025-10-03 07:56:51.763254 | controller |   "ctime": 1759477548.004758,
2025-10-03 07:56:51.763291 | controller |   "dev": 64513,
2025-10-03 07:56:51.763327 | controller |   "gid": 1000,
2025-10-03 07:56:51.763362 | controller |   "gr_name": "zuul",
2025-10-03 07:56:51.763396 | controller |   "inode": 4194437,
2025-10-03 07:56:51.763429 | controller |   "isblk": false,
2025-10-03 07:56:51.763463 | controller |   "ischr": false,
2025-10-03 07:56:51.763497 | controller |   "isdir": false,
2025-10-03 07:56:51.763529 | controller |   "isfifo": false,
2025-10-03 07:56:51.763562 | controller |   "isgid": false,
2025-10-03 07:56:51.763595 | controller |   "islnk": false,
2025-10-03 07:56:51.763628 | controller |   "isreg": true,
2025-10-03 07:56:51.763662 | controller |   "issock": false,
2025-10-03 07:56:51.763695 | controller |   "isuid": false,
2025-10-03 07:56:51.763729 | controller |   "mode": "0644",
2025-10-03 07:56:51.763763 | controller |   "mtime": 1759477548.004758,
2025-10-03 07:56:51.763797 | controller |   "nlink": 1,
2025-10-03 07:56:51.763830 | controller |   "path": "/home/zuul/crc-start.log",
2025-10-03 07:56:51.763864 | controller |   "pw_name": "zuul",
2025-10-03 07:56:51.763899 | controller |   "rgrp": true,
2025-10-03 07:56:51.763932 | controller |   "roth": true,
2025-10-03 07:56:51.763966 | controller |   "rusr": true,
2025-10-03 07:56:51.763998 | controller |   "size": 4400,
2025-10-03 07:56:51.764068 | controller |   "uid": 1000,
2025-10-03 07:56:51.764105 | controller |   "wgrp": false,
2025-10-03 07:56:51.764238 | controller |   "woth": false,
2025-10-03 07:56:51.764293 | controller |   "wusr": true,
2025-10-03 07:56:51.764334 | controller |   "xgrp": false,
2025-10-03 07:56:51.764375 | controller |   "xoth": false,
2025-10-03 07:56:51.764416 | controller |   "xusr": false
2025-10-03 07:56:51.764456 | controller | }
2025-10-03 07:56:52.614074 | controller | changed:
2025-10-03 07:56:52.614245 | controller | {
2025-10-03 07:56:52.614295 | controller |   "atime": 1759478114.036279,
2025-10-03 07:56:52.614335 | controller |   "ctime": 1759478135.4348204,
2025-10-03 07:56:52.614371 | controller |   "dev": 64513,
2025-10-03 07:56:52.614407 | controller |   "gid": 1000,
2025-10-03 07:56:52.614442 | controller |   "gr_name": "zuul",
2025-10-03 07:56:52.614477 | controller |   "inode": 4518824,
2025-10-03 07:56:52.614510 | controller |   "isblk": false,
2025-10-03 07:56:52.614543 | controller |   "ischr": false,
2025-10-03 07:56:52.614575 | controller |   "isdir": false,
2025-10-03 07:56:52.614607 | controller |   "isfifo": false,
2025-10-03 07:56:52.614653 | controller |   "isgid": false,
2025-10-03 07:56:52.614686 | controller |   "islnk": false,
2025-10-03 07:56:52.614718 | controller |   "isreg": true,
2025-10-03 07:56:52.614750 | controller |   "issock": false,
2025-10-03 07:56:52.614783 | controller |   "isuid": false,
2025-10-03 07:56:52.614815 | controller |   "mode": "0644",
2025-10-03 07:56:52.614846 | controller |   "mtime": 1759478135.4348204,
2025-10-03 07:56:52.614903 | controller |   "nlink": 1,
2025-10-03 07:56:52.614940 | controller |   "path": "/home/zuul/ansible.log",
2025-10-03 07:56:52.614974 | controller |   "pw_name": "zuul",
2025-10-03 07:56:52.615008 | controller |   "rgrp": true,
2025-10-03 07:56:52.615078 | controller |   "roth": true,
2025-10-03 07:56:52.615120 | controller |   "rusr": true,
2025-10-03 07:56:52.615156 | controller |   "size": 6701,
2025-10-03 07:56:52.615192 | controller |   "uid": 1000,
2025-10-03 07:56:52.615225 | controller |   "wgrp": false,
2025-10-03 07:56:52.615259 | controller |   "woth": false,
2025-10-03 07:56:52.615292 | controller |   "wusr": true,
2025-10-03 07:56:52.615324 | controller |   "xgrp": false,
2025-10-03 07:56:52.615356 | controller |   "xoth": false,
2025-10-03 07:56:52.615388 | controller |   "xusr": false
2025-10-03 07:56:52.615420 | controller | }
2025-10-03 07:56:52.624589 | 
2025-10-03 07:56:52.624712 | TASK [Copy crio stats log file]
2025-10-03 07:56:52.659338 | controller | skipping: Conditional result was False
2025-10-03 07:56:52.665143 | 
2025-10-03 07:56:52.665205 | TASK [Get SELinux related data]
2025-10-03 07:56:53.084747 | controller | <no matches>
2025-10-03 07:56:53.194805 | controller | ERROR
2025-10-03 07:56:53.195146 | controller | {
2025-10-03 07:56:53.195216 | controller |   "delta": "0:00:00.016649",
2025-10-03 07:56:53.195259 | controller |   "end": "2025-10-03 07:56:53.086591",
2025-10-03 07:56:53.195295 | controller |   "msg": "non-zero return code",
2025-10-03 07:56:53.195329 | controller |   "rc": 1,
2025-10-03 07:56:53.195363 | controller |   "start": "2025-10-03 07:56:53.069942"
2025-10-03 07:56:53.195396 | controller | }
2025-10-03 07:56:53.195441 | controller | ERROR: Ignoring Errors
2025-10-03 07:56:53.206612 | 
2025-10-03 07:56:53.206736 | TASK [Create system configuration directory]
2025-10-03 07:56:53.571374 | controller | changed
2025-10-03 07:56:53.582599 | 
2025-10-03 07:56:53.582765 | TASK [Get some of the system configurations]
2025-10-03 07:56:54.634623 | controller | changed
2025-10-03 07:56:54.642570 | 
2025-10-03 07:56:54.642703 | TASK [Copy generated documentation if available]
2025-10-03 07:56:54.670143 | controller | skipping: Conditional result was False
2025-10-03 07:56:54.678796 | 
2025-10-03 07:56:54.678930 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-03 07:56:54.707275 | controller | skipping: Conditional result was False
2025-10-03 07:56:54.716907 | 
2025-10-03 07:56:54.717097 | TASK [Compress logs bigger than 2MB]
2025-10-03 07:56:55.274622 | controller | changed
2025-10-03 07:56:55.286792 | 
2025-10-03 07:56:55.286996 | TASK [Copy files from workspace on node]
2025-10-03 07:56:55.316054 | controller | ok
2025-10-03 07:56:55.359553 | 
2025-10-03 07:56:55.359711 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 07:56:55.385346 | controller | skipping: Conditional result was False
2025-10-03 07:56:55.394655 | 
2025-10-03 07:56:55.394805 | TASK [fetch-output : Set log path for single node]
2025-10-03 07:56:55.441948 | controller | ok
2025-10-03 07:56:55.454010 | 
2025-10-03 07:56:55.454264 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 07:56:55.716373 | controller -> localhost | ok: "/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/logs"
2025-10-03 07:56:55.717272 | controller -> localhost | changed: All items complete
2025-10-03 07:56:55.717331 | 
2025-10-03 07:56:55.939370 | controller -> localhost | changed: "/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/artifacts"
2025-10-03 07:56:56.193976 | controller -> localhost | changed: "/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/docs"
2025-10-03 07:56:56.205979 | 
2025-10-03 07:56:56.206145 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 07:56:57.148075 | controller | changed:
2025-10-03 07:56:57.148567 | controller | .d..t...... ./
2025-10-03 07:56:57.148676 | controller | >f+++++++++ README.html
2025-10-03 07:56:57.148760 | controller | >f+++++++++ ansible-execution.log
2025-10-03 07:56:57.148843 | controller | >f+++++++++ ansible.log
2025-10-03 07:56:57.148920 | controller | >f+++++++++ crc-setup.log
2025-10-03 07:56:57.148988 | controller | >f+++++++++ crc-start.log
2025-10-03 07:56:57.149121 | controller | >f+++++++++ dmesg.log
2025-10-03 07:56:57.149205 | controller | >f+++++++++ installed-pkgs.log
2025-10-03 07:56:57.149278 | controller | >f+++++++++ python.log
2025-10-03 07:56:57.149349 | controller | >f+++++++++ registries.conf
2025-10-03 07:56:57.149570 | controller | >f+++++++++ report.html
2025-10-03 07:56:57.149623 | controller | >f+++++++++ selinux-denials.log
2025-10-03 07:56:57.149690 | controller | >f+++++++++ selinux-listing.log
2025-10-03 07:56:57.149754 | controller | cd+++++++++ ci-framework-data/
2025-10-03 07:56:57.149827 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-03 07:56:57.149895 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-03 07:56:57.149968 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/
2025-10-03 07:56:57.150245 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/
2025-10-03 07:56:57.150344 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ci_multus/
2025-10-03 07:56:57.150388 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ci_multus/ci_multus_nads.yml
2025-10-03 07:56:57.150425 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-03 07:56:57.150463 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-03 07:56:57.150499 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-03 07:56:57.150535 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-03 07:56:57.150571 | controller | cd+++++++++ registries.conf.d/
2025-10-03 07:56:57.150606 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-03 07:56:57.150641 | controller | cd+++++++++ system-config/
2025-10-03 07:56:57.150676 | controller | cd+++++++++ system-config/libvirt/
2025-10-03 07:56:57.150711 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-03 07:56:57.150747 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-03 07:56:57.150782 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-10-03 07:56:57.150816 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-10-03 07:56:57.150851 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-10-03 07:56:57.150885 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-10-03 07:56:57.150918 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-10-03 07:56:57.150952 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-10-03 07:56:57.150986 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-10-03 07:56:57.151084 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-10-03 07:56:57.151127 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-10-03 07:56:57.151162 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-10-03 07:56:57.151196 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-10-03 07:56:57.151230 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-10-03 07:56:57.151264 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-10-03 07:56:57.151298 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-10-03 07:56:57.828384 | controller | changed: .d..t...... ./
2025-10-03 07:56:58.443106 | controller | changed: .d..t...... ./
2025-10-03 07:56:58.481438 | 
2025-10-03 07:56:58.481653 | TASK [Return artifact to Zuul]
2025-10-03 07:56:58.542124 | controller | ok
2025-10-03 07:56:58.585160 | 
2025-10-03 07:56:58.585282 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-03 07:56:58.585445 | 
2025-10-03 07:56:58.585494 | PLAY RECAP
2025-10-03 07:56:58.585558 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-03 07:56:58.585598 | 
2025-10-03 07:56:58.803414 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-03 07:56:58.805373 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master]
2025-10-03 07:56:59.404844 | 
2025-10-03 07:56:59.404961 | PLAY [Report DLRN results after job run]
2025-10-03 07:56:59.426231 | 
2025-10-03 07:56:59.426336 | TASK [Report job status to DLRN]
2025-10-03 07:56:59.446592 | controller | ok
2025-10-03 07:56:59.472597 | 
2025-10-03 07:56:59.472711 | TASK [dlrn_report : Warning if DLRN is not running]
2025-10-03 07:56:59.537924 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.551930 | 
2025-10-03 07:56:59.552128 | TASK [dlrn_report : Install dlrnapi-client shyaml package]
2025-10-03 07:56:59.620772 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.636387 | 
2025-10-03 07:56:59.636561 | TASK [dlrn_report : Install kinit related package]
2025-10-03 07:56:59.695874 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.709580 | 
2025-10-03 07:56:59.709748 | TASK [dlrn_report : Install dlrn kerberos related packages]
2025-10-03 07:56:59.768712 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.783707 | 
2025-10-03 07:56:59.783857 | TASK [Set zuul-log-path fact]
2025-10-03 07:56:59.841501 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.854496 | 
2025-10-03 07:56:59.854658 | TASK [dlrn_report : Set the the value of cifmw_repo_setup_promotion when multiple dlrn tags are used]
2025-10-03 07:56:59.912644 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.925299 | 
2025-10-03 07:56:59.925492 | TASK [Get hash related data from repo_setup role]
2025-10-03 07:56:59.983466 | controller | skipping: Conditional result was False
2025-10-03 07:56:59.996626 | 
2025-10-03 07:56:59.996788 | TASK [dlrn_report : Perform kinit for DLRN kerberos authentication]
2025-10-03 07:57:00.541394 | controller | skipping: Conditional result was False
2025-10-03 07:57:00.553846 | 
2025-10-03 07:57:00.554081 | TASK [dlrn_report : Set empty value for dlrnapi password]
2025-10-03 07:57:00.642846 | controller | skipping: Conditional result was False
2025-10-03 07:57:00.650937 | 
2025-10-03 07:57:00.651120 | TASK [dlrn_report : Report results to dlrn for the tested hash]
2025-10-03 07:57:01.193379 | controller | skipping: Conditional result was False
2025-10-03 07:57:01.245698 | 
2025-10-03 07:57:01.245855 | PLAY RECAP
2025-10-03 07:57:01.245924 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 10 rescued: 0 ignored: 0
2025-10-03 07:57:01.245954 | 
2025-10-03 07:57:01.368909 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master]
2025-10-03 07:57:01.369758 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 07:57:02.050631 | 
2025-10-03 07:57:02.050780 | PLAY [all]
2025-10-03 07:57:02.071920 | 
2025-10-03 07:57:02.072118 | TASK [include_role : fetch-output]
2025-10-03 07:57:02.115994 | controller | ok
2025-10-03 07:57:02.141818 | 
2025-10-03 07:57:02.142004 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 07:57:02.199177 | controller | skipping: Conditional result was False
2025-10-03 07:57:02.208490 | 
2025-10-03 07:57:02.208638 | TASK [fetch-output : Set log path for single node]
2025-10-03 07:57:02.262871 | controller | ok
2025-10-03 07:57:02.270352 | 
2025-10-03 07:57:02.270467 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 07:57:02.735772 | controller -> localhost | ok: "/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/logs"
2025-10-03 07:57:03.063284 | controller -> localhost | ok: "/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/artifacts"
2025-10-03 07:57:03.347590 | controller -> localhost | ok: "/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/docs"
2025-10-03 07:57:03.365933 | 
2025-10-03 07:57:03.366149 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 07:57:04.235007 | controller | ok
2025-10-03 07:57:04.235517 | controller | ok: All items complete
2025-10-03 07:57:04.235581 | 
2025-10-03 07:57:04.860119 | controller | ok
2025-10-03 07:57:05.562369 | controller | ok
2025-10-03 07:57:05.594318 | 
2025-10-03 07:57:05.594499 | TASK [include_role : fetch-output-openshift]
2025-10-03 07:57:05.619954 | controller | skipping: Conditional result was False
2025-10-03 07:57:05.629338 | 
2025-10-03 07:57:05.629527 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 07:57:06.116896 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012963
2025-10-03 07:57:06.465193 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009446
2025-10-03 07:57:06.501090 | 
2025-10-03 07:57:06.501193 | PLAY [all]
2025-10-03 07:57:06.517129 | 
2025-10-03 07:57:06.517231 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 07:57:07.104187 | controller | changed
2025-10-03 07:57:07.150982 | 
2025-10-03 07:57:07.151127 | PLAY RECAP
2025-10-03 07:57:07.151184 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 07:57:07.151212 | 
2025-10-03 07:57:07.261205 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 07:57:07.262876 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 07:57:07.874755 | 
2025-10-03 07:57:07.874876 | PLAY [localhost]
2025-10-03 07:57:07.892728 | 
2025-10-03 07:57:07.892820 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 07:57:08.379461 | localhost | changed
2025-10-03 07:57:08.384487 | 
2025-10-03 07:57:08.384571 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 07:57:08.424957 | localhost | ok
2025-10-03 07:57:08.433294 | 
2025-10-03 07:57:08.433381 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 07:57:08.868467 | localhost | changed
2025-10-03 07:57:08.880457 | 
2025-10-03 07:57:08.880652 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 07:57:09.705255 | localhost | changed
2025-10-03 07:57:09.717042 | 
2025-10-03 07:57:09.717371 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 07:57:10.170270 | localhost | Identity added: /var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/tmp/ansible.e1jt2pxh (/var/lib/zuul/builds/0ab620811af94673946d3a0fddfdf906/work/tmp/ansible.e1jt2pxh)
2025-10-03 07:57:10.170460 | localhost | ok: Runtime: 0:00:00.014665
2025-10-03 07:57:10.175033 | 
2025-10-03 07:57:10.175103 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 07:57:10.491161 | localhost | ok: Runtime: 0:00:00.008890
2025-10-03 07:57:10.496404 | 
2025-10-03 07:57:10.496512 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 07:57:10.556578 | localhost | changed
2025-10-03 07:57:10.565624 | 
2025-10-03 07:57:10.565816 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 07:57:11.041763 | localhost | changed
2025-10-03 07:57:11.071618 | 
2025-10-03 07:57:11.071738 | PLAY [localhost]
2025-10-03 07:57:11.084803 | 
2025-10-03 07:57:11.084920 | TASK [Generate bulk log download script]
2025-10-03 07:57:11.105300 | localhost | ok
2025-10-03 07:57:11.117920 | 
2025-10-03 07:57:11.118071 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 07:57:11.167456 | localhost | ok: All assertions passed
2025-10-03 07:57:11.172234 | 
2025-10-03 07:57:11.172312 | TASK [local-log-download : Create download script]
2025-10-03 07:57:11.687167 | localhost -> localhost | changed
2025-10-03 07:57:11.697727 | 
2025-10-03 07:57:11.697847 | TASK [Register quick-download link]
2025-10-03 07:57:11.767999 | localhost | ok
2025-10-03 07:57:11.789263 | 
2025-10-03 07:57:11.789362 | PLAY [logserver.rdoproject.org]
2025-10-03 07:57:11.799318 | 
2025-10-03 07:57:11.799393 | TASK [Set zuul-log-path fact]
2025-10-03 07:57:11.826551 | logserver.rdoproject.org | ok
2025-10-03 07:57:11.835974 | 
2025-10-03 07:57:11.836100 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 07:57:11.873452 | logserver.rdoproject.org | ok
2025-10-03 07:57:11.878890 | 
2025-10-03 07:57:11.878956 | TASK [upload-logs : Create log directories]
2025-10-03 07:57:12.806565 | logserver.rdoproject.org | changed
2025-10-03 07:57:12.813942 | 
2025-10-03 07:57:12.814131 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 07:57:13.180099 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007233
2025-10-03 07:57:13.185138 | 
2025-10-03 07:57:13.185238 | TASK [upload-logs : Upload logs to log server]
2025-10-03 07:57:13.961433 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 07:57:13.968476 | 
2025-10-03 07:57:13.968684 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 07:57:14.029936 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 07:57:14.053233 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 07:57:14.064842 | 
2025-10-03 07:57:14.065204 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 07:57:14.132772 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 07:57:14.133270 | 
2025-10-03 07:57:14.137703 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 07:57:14.152254 | 
2025-10-03 07:57:14.152459 | LOOP [upload-logs : Upload console log and json output]