2025-11-24 08:34:18.587920 | Job console starting...
2025-11-24 08:34:18.599529 | Updating repositories
2025-11-24 08:34:18.641692 | Preparing job workspace
2025-11-24 08:34:26.902095 | Running Ansible setup...
2025-11-24 08:34:33.252019 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:34:33.841071 | 
2025-11-24 08:34:33.841210 | PLAY [localhost]
2025-11-24 08:34:33.868065 | 
2025-11-24 08:34:33.868177 | TASK [Gathering Facts]
2025-11-24 08:34:34.802431 | localhost | ok
2025-11-24 08:34:34.824791 | 
2025-11-24 08:34:34.824940 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-24 08:34:35.292375 | localhost -> localhost | changed
2025-11-24 08:34:35.300114 | 
2025-11-24 08:34:35.300219 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-24 08:34:36.234002 | localhost -> localhost | changed
2025-11-24 08:34:36.248501 | 
2025-11-24 08:34:36.248659 | TASK [Setup log path fact]
2025-11-24 08:34:36.268582 | localhost | ok
2025-11-24 08:34:36.280754 | 
2025-11-24 08:34:36.280828 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:34:36.309852 | localhost | ok
2025-11-24 08:34:36.318519 | 
2025-11-24 08:34:36.318590 | TASK [emit-job-header : Print job information]
2025-11-24 08:34:36.356536 | # Job Information
2025-11-24 08:34:36.356754 | Ansible Version: 2.15.12
2025-11-24 08:34:36.356780 | Job: cifmw-molecule-ci_multus
2025-11-24 08:34:36.356800 | Pipeline: github-check
2025-11-24 08:34:36.356818 | Executor: ze04.softwarefactory-project.io
2025-11-24 08:34:36.356839 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2025-11-24 08:34:36.356859 | Log URL (when completed): https://logserver.rdoproject.org/734/rdoproject.org/73460b62a45f402b9c79057064b21881/
2025-11-24 08:34:36.356877 | Event ID: 2dae9040-c910-11f0-818a-433f9d14d6bc
2025-11-24 08:34:36.362214 | 
2025-11-24 08:34:36.362286 | LOOP [emit-job-header : Print node information]
2025-11-24 08:34:36.484987 | localhost | ok:
2025-11-24 08:34:36.485166 | localhost | # Node Information
2025-11-24 08:34:36.485192 | localhost | Inventory Hostname: controller
2025-11-24 08:34:36.485215 | localhost | Hostname: np0005533171
2025-11-24 08:34:36.485235 | localhost | Username: zuul
2025-11-24 08:34:36.485255 | localhost | Distro: CentOS 9
2025-11-24 08:34:36.485273 | localhost | Provider: vexxhost-nodepool-tripleo
2025-11-24 08:34:36.485290 | localhost | Region: RegionOne
2025-11-24 08:34:36.485307 | localhost | Label: centos-9-stream-crc-2-48-0-xxl
2025-11-24 08:34:36.485323 | localhost | Product Name: OpenStack Nova
2025-11-24 08:34:36.485339 | localhost | Interface IP: 38.129.56.190
2025-11-24 08:34:36.517193 | 
2025-11-24 08:34:36.517382 | PLAY [all]
2025-11-24 08:34:36.526696 | 
2025-11-24 08:34:36.526801 | TASK [Gather network facts]
2025-11-24 08:34:37.179555 | controller | ok
2025-11-24 08:34:37.206645 | 
2025-11-24 08:34:37.206770 | TASK [include_role : start-zuul-console]
2025-11-24 08:34:37.225550 | controller | ok
2025-11-24 08:34:37.237802 | 
2025-11-24 08:34:37.237884 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-24 08:34:37.848540 | controller | ok
2025-11-24 08:34:37.870390 | 
2025-11-24 08:34:37.870513 | TASK [include_role : add-build-sshkey]
2025-11-24 08:34:37.974927 | controller | ok
2025-11-24 08:34:38.032282 | 
2025-11-24 08:34:38.032522 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-24 08:34:38.475605 | controller -> localhost | ok
2025-11-24 08:34:38.482101 | 
2025-11-24 08:34:38.482175 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-24 08:34:38.546427 | controller | ok
2025-11-24 08:34:38.563555 | controller | included: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-24 08:34:38.569953 | 
2025-11-24 08:34:38.570024 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-24 08:34:39.836468 | controller -> localhost | Generating public/private rsa key pair.
2025-11-24 08:34:39.836731 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/73460b62a45f402b9c79057064b21881_id_rsa.
2025-11-24 08:34:39.836769 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/73460b62a45f402b9c79057064b21881_id_rsa.pub.
2025-11-24 08:34:39.836792 | controller -> localhost | The key fingerprint is:
2025-11-24 08:34:39.836812 | controller -> localhost | SHA256:i+ByTitPnX17I+6mYU3LOiqOaUFs+A9+3/BFHDK7Fp4 zuul-build-sshkey
2025-11-24 08:34:39.836832 | controller -> localhost | The key's randomart image is:
2025-11-24 08:34:39.836850 | controller -> localhost | +---[RSA 3072]----+
2025-11-24 08:34:39.836867 | controller -> localhost | |                 |
2025-11-24 08:34:39.836885 | controller -> localhost | |                 |
2025-11-24 08:34:39.836903 | controller -> localhost | | o      o .      |
2025-11-24 08:34:39.836921 | controller -> localhost | |. +      = .     |
2025-11-24 08:34:39.836938 | controller -> localhost | | +  .   S +      |
2025-11-24 08:34:39.836955 | controller -> localhost | |  +. o = X .     |
2025-11-24 08:34:39.836972 | controller -> localhost | | ..+= = E *      |
2025-11-24 08:34:39.836989 | controller -> localhost | |  +O+. *.=o.o    |
2025-11-24 08:34:39.837007 | controller -> localhost | | .o==oo.=*+o .   |
2025-11-24 08:34:39.837026 | controller -> localhost | +----[SHA256]-----+
2025-11-24 08:34:39.837072 | controller -> localhost | ok: Runtime: 0:00:00.457655
2025-11-24 08:34:39.845708 | 
2025-11-24 08:34:39.845804 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-24 08:34:39.877798 | controller | ok
2025-11-24 08:34:39.889498 | controller | included: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-24 08:34:39.898359 | 
2025-11-24 08:34:39.898423 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-24 08:34:39.923514 | controller | skipping: Conditional result was False
2025-11-24 08:34:39.929445 | 
2025-11-24 08:34:39.929511 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-24 08:34:40.582348 | controller | changed
2025-11-24 08:34:40.588638 | 
2025-11-24 08:34:40.588732 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-24 08:34:40.999992 | controller | ok
2025-11-24 08:34:41.006283 | 
2025-11-24 08:34:41.006349 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-24 08:34:42.667451 | controller | changed
2025-11-24 08:34:42.672583 | 
2025-11-24 08:34:42.672646 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-24 08:34:44.374473 | controller | changed
2025-11-24 08:34:44.383890 | 
2025-11-24 08:34:44.384046 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-24 08:34:44.409194 | controller | skipping: Conditional result was False
2025-11-24 08:34:44.415030 | 
2025-11-24 08:34:44.415099 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-24 08:34:44.806101 | controller -> localhost | changed
2025-11-24 08:34:44.816353 | 
2025-11-24 08:34:44.816424 | TASK [add-build-sshkey : Add back temp key]
2025-11-24 08:34:45.107391 | controller -> localhost | Identity added: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/73460b62a45f402b9c79057064b21881_id_rsa (zuul-build-sshkey)
2025-11-24 08:34:45.107568 | controller -> localhost | ok: Runtime: 0:00:00.019910
2025-11-24 08:34:45.113732 | 
2025-11-24 08:34:45.113796 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-24 08:34:45.576359 | controller | ok
2025-11-24 08:34:45.590445 | 
2025-11-24 08:34:45.590592 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-24 08:34:45.627725 | controller | skipping: Conditional result was False
2025-11-24 08:34:45.672175 | 
2025-11-24 08:34:45.672279 | TASK [include_role : validate-host]
2025-11-24 08:34:45.701561 | controller | ok
2025-11-24 08:34:45.721238 | 
2025-11-24 08:34:45.721329 | TASK [validate-host : Define zuul_info_dir fact]
2025-11-24 08:34:45.764260 | controller | ok
2025-11-24 08:34:45.769218 | 
2025-11-24 08:34:45.769282 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-11-24 08:34:46.012192 | controller -> localhost | ok
2025-11-24 08:34:46.021311 | 
2025-11-24 08:34:46.021399 | TASK [validate-host : Collect information about the host]
2025-11-24 08:34:46.936632 | controller | ok
2025-11-24 08:34:46.945363 | 
2025-11-24 08:34:46.945428 | TASK [validate-host : Sanitize hostname]
2025-11-24 08:34:46.994823 | controller | ok
2025-11-24 08:34:46.999859 | 
2025-11-24 08:34:46.999922 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-11-24 08:34:47.430976 | controller -> localhost | changed
2025-11-24 08:34:47.437159 | 
2025-11-24 08:34:47.437250 | TASK [validate-host : Collect information about zuul worker]
2025-11-24 08:34:47.946205 | controller | ok
2025-11-24 08:34:47.953542 | 
2025-11-24 08:34:47.953632 | TASK [validate-host : Write out all zuul information for each host]
2025-11-24 08:34:48.392413 | controller -> localhost | changed
2025-11-24 08:34:48.405489 | 
2025-11-24 08:34:48.405600 | TASK [include_role : prepare-workspace-openshift]
2025-11-24 08:34:48.429862 | controller | skipping: Conditional result was False
2025-11-24 08:34:48.434962 | 
2025-11-24 08:34:48.435024 | TASK [include_role : remove-zuul-sshkey]
2025-11-24 08:34:48.459181 | controller | skipping: Conditional result was False
2025-11-24 08:34:48.464534 | 
2025-11-24 08:34:48.464604 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 08:34:48.866773 | controller | ok: "logs"
2025-11-24 08:34:48.867734 | controller | ok: All items complete
2025-11-24 08:34:48.867807 | 
2025-11-24 08:34:49.194212 | controller | ok: "artifacts"
2025-11-24 08:34:49.534816 | controller | ok: "docs"
2025-11-24 08:34:49.549293 | 
2025-11-24 08:34:49.549412 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 08:34:49.883367 | controller | changed: "logs"
2025-11-24 08:34:51.255060 | controller | changed: "artifacts"
2025-11-24 08:34:51.633591 | controller | changed: "docs"
2025-11-24 08:34:51.687001 | 
2025-11-24 08:34:51.687141 | PLAY RECAP
2025-11-24 08:34:51.687202 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:34:51.687237 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:34:51.687261 | 
2025-11-24 08:34:51.837536 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:34:51.838488 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-11-24 08:34:52.561929 | 
2025-11-24 08:34:52.562128 | PLAY [all]
2025-11-24 08:34:52.583865 | 
2025-11-24 08:34:52.583970 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-11-24 08:34:52.682521 | controller | ok
2025-11-24 08:34:52.694110 | 
2025-11-24 08:34:52.694269 | TASK [mirror-info-fork : Create /etc/ci]
2025-11-24 08:34:53.354493 | controller | changed
2025-11-24 08:34:53.369793 | 
2025-11-24 08:34:53.369946 | TASK [mirror-info-fork : Install ci_mirror script]
2025-11-24 08:34:55.314612 | controller | changed
2025-11-24 08:34:55.344788 | 
2025-11-24 08:34:55.344956 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-11-24 08:34:56.038669 | controller | changed:
2025-11-24 08:34:56.038905 | controller | {
2025-11-24 08:34:56.038947 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-11-24 08:34:56.038987 | controller | }
2025-11-24 08:34:56.478486 | controller | changed:
2025-11-24 08:34:56.478640 | controller | {
2025-11-24 08:34:56.478773 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-11-24 08:34:56.478822 | controller | }
2025-11-24 08:34:56.910163 | controller | changed:
2025-11-24 08:34:56.910274 | controller | {
2025-11-24 08:34:56.910310 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-11-24 08:34:56.910340 | controller | }
2025-11-24 08:34:57.288521 | controller | changed:
2025-11-24 08:34:57.288668 | controller | {
2025-11-24 08:34:57.288731 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-11-24 08:34:57.288809 | controller | }
2025-11-24 08:34:57.686111 | controller | changed:
2025-11-24 08:34:57.686336 | controller | {
2025-11-24 08:34:57.686414 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-11-24 08:34:57.686476 | controller | }
2025-11-24 08:34:58.072524 | controller | changed:
2025-11-24 08:34:58.072717 | controller | {
2025-11-24 08:34:58.072746 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-11-24 08:34:58.072766 | controller | }
2025-11-24 08:34:58.463243 | controller | changed:
2025-11-24 08:34:58.463451 | controller | {
2025-11-24 08:34:58.463504 | 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-11-24 08:34:58.463548 | controller | }
2025-11-24 08:34:58.850105 | controller | changed:
2025-11-24 08:34:58.850265 | controller | {
2025-11-24 08:34:58.850291 | 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-11-24 08:34:58.850312 | controller | }
2025-11-24 08:34:59.225420 | controller | changed:
2025-11-24 08:34:59.225605 | controller | {
2025-11-24 08:34:59.225629 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-11-24 08:34:59.225647 | controller | }
2025-11-24 08:34:59.631092 | controller | changed:
2025-11-24 08:34:59.631337 | controller | {
2025-11-24 08:34:59.631369 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-11-24 08:34:59.631390 | controller | }
2025-11-24 08:35:00.067035 | controller | changed:
2025-11-24 08:35:00.067183 | controller | {
2025-11-24 08:35:00.067227 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-11-24 08:35:00.067257 | controller | }
2025-11-24 08:35:00.517189 | controller | changed:
2025-11-24 08:35:00.517434 | controller | {
2025-11-24 08:35:00.517496 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-11-24 08:35:00.517551 | controller | }
2025-11-24 08:35:00.950897 | controller | changed:
2025-11-24 08:35:00.951023 | controller | {
2025-11-24 08:35:00.951058 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-11-24 08:35:00.951085 | controller | }
2025-11-24 08:35:01.335994 | controller | changed:
2025-11-24 08:35:01.336319 | controller | {
2025-11-24 08:35:01.336353 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-11-24 08:35:01.336374 | controller | }
2025-11-24 08:35:01.700513 | controller | changed:
2025-11-24 08:35:01.700633 | controller | {
2025-11-24 08:35:01.700658 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-11-24 08:35:01.700692 | controller | }
2025-11-24 08:35:02.131491 | controller | changed:
2025-11-24 08:35:02.131590 | controller | {
2025-11-24 08:35:02.131614 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-11-24 08:35:02.131632 | controller | }
2025-11-24 08:35:02.537114 | controller | changed:
2025-11-24 08:35:02.537248 | controller | {
2025-11-24 08:35:02.537297 | 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-11-24 08:35:02.537332 | controller | }
2025-11-24 08:35:02.919887 | controller | changed:
2025-11-24 08:35:02.920039 | controller | {
2025-11-24 08:35:02.920094 | 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-11-24 08:35:02.920137 | controller | }
2025-11-24 08:35:03.281458 | controller | changed:
2025-11-24 08:35:03.281560 | controller | {
2025-11-24 08:35:03.281583 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-11-24 08:35:03.281601 | controller | }
2025-11-24 08:35:03.688339 | controller | changed:
2025-11-24 08:35:03.688461 | controller | {
2025-11-24 08:35:03.688489 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-11-24 08:35:03.688508 | controller | }
2025-11-24 08:35:04.101295 | controller | changed:
2025-11-24 08:35:04.101402 | controller | {
2025-11-24 08:35:04.101426 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-11-24 08:35:04.101444 | controller | }
2025-11-24 08:35:04.554240 | controller | changed:
2025-11-24 08:35:04.554353 | controller | {
2025-11-24 08:35:04.554377 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-11-24 08:35:04.554396 | controller | }
2025-11-24 08:35:04.961713 | controller | changed:
2025-11-24 08:35:04.961805 | controller | {
2025-11-24 08:35:04.961829 | 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-11-24 08:35:04.961849 | controller | }
2025-11-24 08:35:05.394369 | controller | changed:
2025-11-24 08:35:05.394473 | controller | {
2025-11-24 08:35:05.394498 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-11-24 08:35:05.394517 | controller | }
2025-11-24 08:35:05.781727 | controller | changed:
2025-11-24 08:35:05.781830 | controller | {
2025-11-24 08:35:05.781853 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-11-24 08:35:05.781871 | controller | }
2025-11-24 08:35:06.194212 | controller | changed:
2025-11-24 08:35:06.195216 | controller | {
2025-11-24 08:35:06.195272 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-11-24 08:35:06.195302 | controller | }
2025-11-24 08:35:06.221962 | 
2025-11-24 08:35:06.222066 | TASK [Set timezone to UTC]
2025-11-24 08:35:06.906333 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-11-24 08:35:06.915479 | 
2025-11-24 08:35:06.915560 | TASK [Create nodepool directory]
2025-11-24 08:35:07.372544 | controller | changed
2025-11-24 08:35:07.385223 | 
2025-11-24 08:35:07.385308 | TASK [Create nodepool sub_nodes file]
2025-11-24 08:35:08.697652 | controller | changed
2025-11-24 08:35:08.703160 | 
2025-11-24 08:35:08.703225 | TASK [Create nodepool sub_nodes_private file]
2025-11-24 08:35:10.130801 | controller | changed
2025-11-24 08:35:10.137175 | 
2025-11-24 08:35:10.137256 | LOOP [Populate nodepool sub_nodes file]
2025-11-24 08:35:10.181162 | 
2025-11-24 08:35:10.181438 | LOOP [Populate nodepool sub_nodes_private file]
2025-11-24 08:35:10.236496 | 
2025-11-24 08:35:10.236784 | TASK [Create nodepool primary file]
2025-11-24 08:35:10.262999 | controller | skipping: Conditional result was False
2025-11-24 08:35:10.273091 | 
2025-11-24 08:35:10.273282 | TASK [Create nodepool node_private for this node]
2025-11-24 08:35:11.855953 | controller | changed
2025-11-24 08:35:11.872122 | 
2025-11-24 08:35:11.872361 | LOOP [Copy ssh keys to nodepool directory]
2025-11-24 08:35:12.439369 | controller | ok: Item: id_rsa Runtime: 0:00:00.012096
2025-11-24 08:35:12.439742 | 
2025-11-24 08:35:12.751556 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.008775
2025-11-24 08:35:12.783195 | 
2025-11-24 08:35:12.783360 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-11-24 08:35:14.361517 | controller | changed
2025-11-24 08:35:14.371768 | 
2025-11-24 08:35:14.371873 | TASK [Validate sudoers config after edits]
2025-11-24 08:35:14.799040 | controller | /etc/sudoers: parsed OK
2025-11-24 08:35:14.799158 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-11-24 08:35:14.799169 | controller | /etc/sudoers.d/zuul: parsed OK
2025-11-24 08:35:14.799176 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-11-24 08:35:14.920618 | controller | ok: Runtime: 0:00:00.008466
2025-11-24 08:35:14.927239 | 
2025-11-24 08:35:14.927324 | TASK [Show the environment passed in to job shell scripts]
2025-11-24 08:35:15.316380 | controller | SHELL=/bin/bash
2025-11-24 08:35:15.316445 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-11-24 08:35:15.316457 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-11-24 08:35:15.316465 | controller | ZUUL_CHANGES=rdo-jobs:master:refs/changes/88/58488/1^openstack-k8s-operators/ci-framework:main:refs/changes/51/3451/9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:35:15.316474 | controller | PWD=/home/zuul
2025-11-24 08:35:15.316482 | controller | ZUUL_PIPELINE=github-check
2025-11-24 08:35:15.316490 | controller | LOGNAME=zuul
2025-11-24 08:35:15.316497 | controller | XDG_SESSION_TYPE=tty
2025-11-24 08:35:15.316505 | controller | _=/usr/bin/env
2025-11-24 08:35:15.316513 | controller | MOTD_SHOWN=pam
2025-11-24 08:35:15.316520 | controller | HOME=/home/zuul
2025-11-24 08:35:15.316528 | controller | LANG=en_US.UTF-8
2025-11-24 08:35:15.316535 | controller | SSH_CONNECTION=38.102.83.114 36862 38.129.56.190 22
2025-11-24 08:35:15.316588 | 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-11-24 08:35:15.316606 | controller | ZUUL_CHANGE_IDS=58488,1 3451,9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:35:15.316614 | controller | WORKSPACE=/home/zuul/workspace
2025-11-24 08:35:15.316623 | controller | XDG_SESSION_CLASS=user
2025-11-24 08:35:15.316630 | controller | SELINUX_ROLE_REQUESTED=
2025-11-24 08:35:15.316638 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-11-24 08:35:15.316646 | controller | USER=zuul
2025-11-24 08:35:15.316654 | controller | ZUUL_VOTING=True
2025-11-24 08:35:15.316661 | controller | BUILD_TIMEOUT=1800000
2025-11-24 08:35:15.316668 | controller | SELINUX_USE_CURRENT_RANGE=
2025-11-24 08:35:15.316676 | controller | SHLVL=1
2025-11-24 08:35:15.316683 | controller | ZUUL_PATCHSET=9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:35:15.316691 | controller | XDG_SESSION_ID=1
2025-11-24 08:35:15.316698 | controller | ZUUL_BRANCH=main
2025-11-24 08:35:15.316732 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-11-24 08:35:15.316741 | controller | SSH_CLIENT=38.102.83.114 36862 22
2025-11-24 08:35:15.316748 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-11-24 08:35:15.316756 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-11-24 08:35:15.316764 | controller | which_declare=declare -f
2025-11-24 08:35:15.316772 | 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-11-24 08:35:15.316780 | controller | SELINUX_LEVEL_REQUESTED=
2025-11-24 08:35:15.316787 | controller | ZUUL_CHANGE=3451
2025-11-24 08:35:15.316795 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-11-24 08:35:15.316803 | controller | ZUUL_UUID=73460b62a45f402b9c79057064b21881
2025-11-24 08:35:15.316810 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-11-24 08:35:15.316820 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-11-24 08:35:15.316828 | controller | }
2025-11-24 08:35:15.501820 | controller | ok: Runtime: 0:00:00.008005
2025-11-24 08:35:15.516258 | 
2025-11-24 08:35:15.516404 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-11-24 08:35:15.546006 | controller | skipping: Conditional result was False
2025-11-24 08:35:15.561583 | 
2025-11-24 08:35:15.561782 | TASK [Symlink /home/zuul-worker/workspace]
2025-11-24 08:35:16.117575 | controller | skipping: Conditional result was False
2025-11-24 08:35:16.132522 | 
2025-11-24 08:35:16.132706 | TASK [Ensure legacy workspace directory]
2025-11-24 08:35:16.503528 | controller | changed
2025-11-24 08:35:16.540332 | 
2025-11-24 08:35:16.540510 | PLAY RECAP
2025-11-24 08:35:16.540582 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:35:16.540613 | 
2025-11-24 08:35:16.666624 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-11-24 08:35:16.667649 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master]
2025-11-24 08:35:17.253826 | 
2025-11-24 08:35:17.253993 | PLAY [all,!compute]
2025-11-24 08:35:17.275451 | 
2025-11-24 08:35:17.275546 | TASK [Enable container-tools rhel-modules for c8/crc node]
2025-11-24 08:35:17.811505 | controller | skipping: Conditional result was False
2025-11-24 08:35:17.826104 | 
2025-11-24 08:35:17.826352 | TASK [Install podman]
2025-11-24 08:35:17.897115 | controller | skipping: Conditional result was False
2025-11-24 08:35:17.907942 | 
2025-11-24 08:35:17.908134 | TASK [Set var name for quay login zuul secret]
2025-11-24 08:35:17.954745 | controller | skipping: Conditional result was False
2025-11-24 08:35:17.961993 | 
2025-11-24 08:35:17.962068 | TASK [Print the username]
2025-11-24 08:35:18.496544 | controller | skipping: Conditional result was False
2025-11-24 08:35:18.504241 | 
2025-11-24 08:35:18.504325 | TASK [Fail when user or password is not set]
2025-11-24 08:35:18.571083 | controller | skipping: Conditional result was False
2025-11-24 08:35:18.585936 | 
2025-11-24 08:35:18.586093 | TASK [Set vars for quay login]
2025-11-24 08:35:18.658121 | 
2025-11-24 08:35:18.658421 | LOOP [Perform container registry login(s) with podman]
2025-11-24 08:35:18.738260 | 
2025-11-24 08:35:18.738486 | LOOP [Perform container registry login(s) with buildah]
2025-11-24 08:35:18.852152 | 
2025-11-24 08:35:18.852382 | TASK [Set Insecure registry for content provider]
2025-11-24 08:35:18.908947 | controller | skipping: Conditional result was False
2025-11-24 08:35:18.938821 | 
2025-11-24 08:35:18.938931 | PLAY RECAP
2025-11-24 08:35:18.938977 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 9 rescued: 0 ignored: 0
2025-11-24 08:35:18.938997 | 
2025-11-24 08:35:19.060784 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master]
2025-11-24 08:35:19.061854 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master]
2025-11-24 08:35:19.676616 | 
2025-11-24 08:35:19.676827 | PLAY [Prefer ipv4 over ipv6]
2025-11-24 08:35:19.707332 | 
2025-11-24 08:35:19.707459 | TASK [Configure /etc/gai.conf to prever ipv4 over ipv6]
2025-11-24 08:35:19.754076 | controller | skipping: Conditional result was False
2025-11-24 08:35:19.776236 | 
2025-11-24 08:35:19.776318 | PLAY [controller]
2025-11-24 08:35:19.791031 | 
2025-11-24 08:35:19.791125 | TASK [Fail when openshift_pull_sec not provided]
2025-11-24 08:35:19.815498 | controller | skipping: Conditional result was False
2025-11-24 08:35:19.823345 | 
2025-11-24 08:35:19.823421 | TASK [Clone repos in the job workspace]
2025-11-24 08:35:19.850480 | controller | ok
2025-11-24 08:35:19.867911 | 
2025-11-24 08:35:19.868028 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-24 08:35:20.594845 | controller | ok
2025-11-24 08:35:20.621171 | 
2025-11-24 08:35:20.621401 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-24 08:35:25.261273 | controller | Output suppressed because no_log was given
2025-11-24 08:35:25.273834 | 
2025-11-24 08:35:25.273904 | TASK [Create pull-secret.txt file]
2025-11-24 08:35:27.266092 | controller | Output suppressed because no_log was given
2025-11-24 08:35:27.276079 | 
2025-11-24 08:35:27.276320 | TASK [Apply CRC features and print image build date]
2025-11-24 08:35:27.325009 | controller | ok
2025-11-24 08:35:27.334829 | controller | included: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/trusted/project_0/review.rdoproject.org/config/playbooks/crc/features.yaml
2025-11-24 08:35:27.344655 | 
2025-11-24 08:35:27.344874 | TASK [Set additional parameters for crc - telemetry]
2025-11-24 08:35:27.903563 | controller | skipping: Conditional result was False
2025-11-24 08:35:27.922408 | 
2025-11-24 08:35:27.923006 | TASK [Set additional parameters for crc - monitoring]
2025-11-24 08:35:28.482556 | controller | skipping: Conditional result was False
2025-11-24 08:35:28.495531 | 
2025-11-24 08:35:28.495677 | TASK [Set minimum required memory to run the CRC when monitoring enabled]
2025-11-24 08:35:29.058274 | controller | skipping: Conditional result was False
2025-11-24 08:35:29.075389 | 
2025-11-24 08:35:29.075623 | TASK [Set additional parameters for crc - enable microshift preset]
2025-11-24 08:35:29.638470 | controller | skipping: Conditional result was False
2025-11-24 08:35:29.653942 | 
2025-11-24 08:35:29.654198 | TASK [Set additional parameters for crc - enable okd preset]
2025-11-24 08:35:30.212745 | controller | skipping: Conditional result was False
2025-11-24 08:35:30.219951 | 
2025-11-24 08:35:30.220024 | TASK [Delete the cluster if there's a non-default bundle URL]
2025-11-24 08:35:30.765215 | controller | skipping: Conditional result was False
2025-11-24 08:35:30.780030 | 
2025-11-24 08:35:30.780224 | TASK [Execute crc start command]
2025-11-24 08:47:18.203350 | controller | ok: Runtime: 0:11:46.636522
2025-11-24 08:47:18.215788 | 
2025-11-24 08:47:18.215979 | TASK [Verify that OpenShift is up and running]
2025-11-24 08:47:18.241515 | controller | ok
2025-11-24 08:47:18.250870 | controller | included: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/trusted/project_0/review.rdoproject.org/config/playbooks/crc/verify_openshift_start.yaml
2025-11-24 08:47:18.258262 | 
2025-11-24 08:47:18.258334 | TASK [Create script to login and verify services]
2025-11-24 08:47:19.710889 | controller | changed
2025-11-24 08:47:19.720548 | 
2025-11-24 08:47:19.720653 | TASK [Ensure that user is logged]
2025-11-24 08:47:20.128365 | controller | Checking login to the cluster 1...
2025-11-24 08:47:21.063121 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-11-24 08:47:21.361872 | controller |
2025-11-24 08:47:21.361966 | controller | Login successful.
2025-11-24 08:47:21.391132 | controller |
2025-11-24 08:47:21.391232 | controller | You have access to 65 projects, the list has been suppressed. You can list all projects with 'oc projects'
2025-11-24 08:47:21.444036 | controller |
2025-11-24 08:47:21.444186 | controller | Using project "default".
2025-11-24 08:47:21.763126 | controller | changed
2025-11-24 08:47:21.770790 | 
2025-11-24 08:47:21.770898 | TASK [Delete all openshift-marketplace pods]
2025-11-24 08:47:23.110554 | controller | pod "certified-operators-f8szs" deleted
2025-11-24 08:47:23.151799 | controller | pod "community-operators-5zsqg" deleted
2025-11-24 08:47:23.187780 | controller | pod "marketplace-operator-79b997595-d2lpl" deleted
2025-11-24 08:47:23.212778 | controller | pod "redhat-marketplace-ps6xk" deleted
2025-11-24 08:47:23.253720 | controller | pod "redhat-operators-tqxl9" deleted
2025-11-24 08:47:25.309476 | controller | ok
2025-11-24 08:47:25.316261 | 
2025-11-24 08:47:25.316389 | TASK [Copy script ensure_services_up.sh]
2025-11-24 08:47:25.351621 | controller | skipping: Conditional result was False
2025-11-24 08:47:25.358305 | 
2025-11-24 08:47:25.358396 | TASK [Ensure all pods are up and running]
2025-11-24 08:47:25.888859 | controller | skipping: Conditional result was False
2025-11-24 08:47:25.902262 | 
2025-11-24 08:47:25.902453 | TASK [Check if there is a image build date file]
2025-11-24 08:47:26.425018 | controller | ok
2025-11-24 08:47:26.437479 | 
2025-11-24 08:47:26.437611 | TASK [Print image date if available]
2025-11-24 08:47:26.828776 | controller | Tue Apr  1 06:17:46 PM EDT 2025
2025-11-24 08:47:26.987904 | controller | changed
2025-11-24 08:47:26.993896 | 
2025-11-24 08:47:26.993999 | TASK [Fix machineconfigpool]
2025-11-24 08:47:27.059436 | controller | skipping: Conditional result was False
2025-11-24 08:47:27.065540 | 
2025-11-24 08:47:27.065606 | TASK [Show available nodes]
2025-11-24 08:47:28.083833 | controller | NAME   STATUS   ROLES                         AGE    VERSION
2025-11-24 08:47:28.087168 | controller | crc    Ready    control-plane,master,worker   274d   v1.31.5
2025-11-24 08:47:28.128491 | controller | ok: Runtime: 0:00:00.625796
2025-11-24 08:47:28.135714 | 
2025-11-24 08:47:28.135794 | TASK [Configure insecure registry inside crc vm]
2025-11-24 08:47:28.173070 | controller | skipping: Conditional result was False
2025-11-24 08:47:28.182552 | 
2025-11-24 08:47:28.182658 | TASK [Catch CRC IP]
2025-11-24 08:47:28.674126 | controller | 192.168.130.11
2025-11-24 08:47:28.728422 | controller | changed
2025-11-24 08:47:28.736985 | 
2025-11-24 08:47:28.737081 | TASK [Check if id_ed25519 key exists]
2025-11-24 08:47:29.290246 | controller | ok
2025-11-24 08:47:29.301655 | 
2025-11-24 08:47:29.301781 | TASK [Set fact if new keypair exists]
2025-11-24 08:47:29.344781 | controller | ok
2025-11-24 08:47:29.351905 | 
2025-11-24 08:47:29.351999 | TASK [Run crc]
2025-11-24 08:47:31.050195 | controller |
2025-11-24 08:47:39.623649 | controller | PLAY [OpenShift secret copy and CRC securitization] ****************************
2025-11-24 08:47:39.623930 | controller |
2025-11-24 08:47:39.623944 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:47:39.623959 | controller | [WARNING]: Platform linux on host 192.168.130.11 is using the discovered Python
2025-11-24 08:47:39.679590 | controller | interpreter at /usr/bin/python3.9, but future installation of another Python
2025-11-24 08:47:39.679644 | controller | interpreter could change the meaning of that path. See
2025-11-24 08:47:39.679653 | controller | https://docs.ansible.com/ansible-
2025-11-24 08:47:39.679660 | controller | core/2.14/reference_appendices/interpreter_discovery.html for more information.
2025-11-24 08:47:39.679674 | controller | ok: [192.168.130.11]
2025-11-24 08:47:41.541785 | controller |
2025-11-24 08:47:41.541851 | controller | TASK [Copy pull-secret] ********************************************************
2025-11-24 08:47:41.541867 | controller | changed: [192.168.130.11]
2025-11-24 08:47:43.094695 | controller |
2025-11-24 08:47:43.094800 | controller | TASK [Add crio config] *********************************************************
2025-11-24 08:47:43.094822 | controller | changed: [192.168.130.11]
2025-11-24 08:47:46.923688 | controller |
2025-11-24 08:47:46.923785 | controller | TASK [Restart crio to pickup new configuration] ********************************
2025-11-24 08:47:46.923820 | controller | changed: [192.168.130.11]
2025-11-24 08:47:46.993061 | controller |
2025-11-24 08:47:46.993136 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:47:46.993146 | controller | 192.168.130.11             : ok=4    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:47:46.993290 | controller |
2025-11-24 08:47:47.434958 | controller | changed
2025-11-24 08:47:47.447733 | 
2025-11-24 08:47:47.447893 | TASK [Set slower etcd profile]
2025-11-24 08:47:47.534255 | controller | ok
2025-11-24 08:47:47.584106 | 
2025-11-24 08:47:47.584481 | TASK [prepare-crc-cloud : Set slower profile]
2025-11-24 08:47:48.187252 | controller | etcd.operator.openshift.io/cluster patched
2025-11-24 08:47:48.622942 | controller | ok
2025-11-24 08:47:48.630262 | 
2025-11-24 08:47:48.630340 | TASK [prepare-crc-cloud : Wait 30 seconds to apply]
2025-11-24 08:48:18.679154 | controller | ok
2025-11-24 08:48:18.693027 | 
2025-11-24 08:48:18.693126 | TASK [prepare-crc-cloud : Get pod phase status]
2025-11-24 08:53:34.374572 | controller | ok
2025-11-24 08:53:34.399261 | 
2025-11-24 08:53:34.399444 | TASK [Set limit for disk usage - IOPS and Read/Write]
2025-11-24 08:53:34.484181 | controller | ok
2025-11-24 08:53:34.502138 | controller | included: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/trusted/project_0/review.rdoproject.org/config/playbooks/crc/limit-disk-usage.yaml
2025-11-24 08:53:34.526313 | 
2025-11-24 08:53:34.526544 | TASK [Set facts for disk limitation]
2025-11-24 08:53:34.565585 | controller | ok
2025-11-24 08:53:34.577622 | 
2025-11-24 08:53:34.577796 | TASK [Print limits for the disk]
2025-11-24 08:53:34.617343 | controller | ok: Set limit to crc VM to the vda disk: iops 18000 read/write 262144000
2025-11-24 08:53:34.630268 | 
2025-11-24 08:53:34.630429 | TASK [Set limit to crc VM to the vda disk]
2025-11-24 08:53:35.037754 | controller |
2025-11-24 08:53:35.170875 | controller | changed
2025-11-24 08:53:35.184747 | 
2025-11-24 08:53:35.184922 | TASK [Pause machineconfigpool]
2025-11-24 08:53:35.266307 | controller | ok
2025-11-24 08:53:35.311897 | 
2025-11-24 08:53:35.312050 | LOOP [prepare-crc-cloud : Pause the machineconfig configuration if mcp is not needed]
2025-11-24 08:53:35.872497 | controller | ok
2025-11-24 08:53:36.404605 | controller | ok
2025-11-24 08:53:36.422047 | 
2025-11-24 08:53:36.422260 | TASK [prepare-crc-cloud : Print current machineconfigpool]
2025-11-24 08:53:37.058145 | controller | NAME     CONFIG                                             UPDATED   UPDATING   DEGRADED   MACHINECOUNT   READYMACHINECOUNT   UPDATEDMACHINECOUNT   DEGRADEDMACHINECOUNT   AGE
2025-11-24 08:53:37.058522 | controller | master   rendered-master-95020e6e79c40b4dd095817bccfc5060   True      False      False      1              1                   1                     0                      274d
2025-11-24 08:53:37.058824 | controller | worker   rendered-worker-594cc07c9feefb5e37f2530ac457d36c   True      False      False      0              0                   0                     0                      274d
2025-11-24 08:53:37.483773 | controller | ok
2025-11-24 08:53:37.541008 | 
2025-11-24 08:53:37.541135 | PLAY [Set IOPS and Read/Write disk limitation excluding controller]
2025-11-24 08:53:37.541286 | 
2025-11-24 08:53:37.541329 | PLAY RECAP
2025-11-24 08:53:37.541383 | controller | ok: 25 changed: 10 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 0
2025-11-24 08:53:37.541413 | 
2025-11-24 08:53:37.675043 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master]
2025-11-24 08:53:37.676804 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-11-24 08:53:38.299142 | 
2025-11-24 08:53:38.299294 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-11-24 08:53:38.323038 | 
2025-11-24 08:53:38.323202 | TASK [Create zuul-output directory]
2025-11-24 08:53:38.862653 | controller | changed
2025-11-24 08:53:38.876106 | 
2025-11-24 08:53:38.876305 | TASK [Slurp Zuul inventory test]
2025-11-24 08:53:39.346024 | controller -> localhost | ok
2025-11-24 08:53:39.352619 | 
2025-11-24 08:53:39.352688 | TASK [Save zuul inventory]
2025-11-24 08:53:41.015752 | controller | changed
2025-11-24 08:53:41.027591 | 
2025-11-24 08:53:41.027807 | TASK [Save zuul vars without the change_message]
2025-11-24 08:53:42.517418 | controller | changed
2025-11-24 08:53:42.562071 | 
2025-11-24 08:53:42.562255 | PLAY RECAP
2025-11-24 08:53:42.562321 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:53:42.562372 | 
2025-11-24 08:53:42.686953 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-11-24 08:53:42.688813 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-11-24 08:53:43.351923 | 
2025-11-24 08:53:43.352046 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-11-24 08:53:43.375287 | 
2025-11-24 08:53:43.375420 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-11-24 08:53:43.396394 | controller | ok
2025-11-24 08:53:43.414254 | 
2025-11-24 08:53:43.414356 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-11-24 08:53:43.459344 | controller | skipping: Conditional result was False
2025-11-24 08:53:43.466181 | 
2025-11-24 08:53:43.466266 | TASK [mirror-info-fork : Create /etc/ci]
2025-11-24 08:53:44.034919 | controller | ok
2025-11-24 08:53:44.047989 | 
2025-11-24 08:53:44.048160 | TASK [mirror-info-fork : Install ci_mirror script]
2025-11-24 08:53:45.263788 | controller | ok
2025-11-24 08:53:45.287996 | 
2025-11-24 08:53:45.288189 | TASK [Prepare workspace]
2025-11-24 08:53:45.318178 | controller | ok
2025-11-24 08:53:45.353799 | 
2025-11-24 08:53:45.353962 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-24 08:53:45.893821 | controller | ok
2025-11-24 08:53:45.902834 | 
2025-11-24 08:53:45.902946 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-24 08:53:47.194556 | controller | Output suppressed because no_log was given
2025-11-24 08:53:47.206583 | 
2025-11-24 08:53:47.206720 | LOOP [Create zuul-output directory]
2025-11-24 08:53:47.605242 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-11-24 08:53:47.819834 | controller | ok: "/home/zuul/zuul-output/logs"
2025-11-24 08:53:47.836585 | 
2025-11-24 08:53:47.836949 | TASK [Install required packages]
2025-11-24 08:54:48.084320 | controller | ok: Nothing to do
2025-11-24 08:54:48.101583 | 
2025-11-24 08:54:48.101756 | TASK [Install venv]
2025-11-24 08:56:32.745003 | controller | changed
2025-11-24 08:56:32.789927 | 
2025-11-24 08:56:32.790090 | PLAY RECAP
2025-11-24 08:56:32.790153 | controller | ok: 7 changed: 2 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:56:32.790183 | 
2025-11-24 08:56:32.925450 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-11-24 08:56:32.927613 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-11-24 08:56:33.542929 | 
2025-11-24 08:56:33.543059 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-11-24 08:56:33.564759 | 
2025-11-24 08:56:33.564844 | TASK [Gather required facts]
2025-11-24 08:56:34.208907 | controller | ok
2025-11-24 08:56:34.222076 | 
2025-11-24 08:56:34.222277 | TASK [Load environment var if instructed to]
2025-11-24 08:56:34.260550 | controller | skipping: Conditional result was False
2025-11-24 08:56:34.274098 | 
2025-11-24 08:56:34.274296 | TASK [Ensure group_vars dir exists]
2025-11-24 08:56:34.835419 | controller | ok
2025-11-24 08:56:34.847634 | 
2025-11-24 08:56:34.847825 | TASK [Print related variables]
2025-11-24 08:56:34.898855 | controller | ok:
2025-11-24 08:56:34.899163 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-11-24 08:56:34.899226 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_multus
2025-11-24 08:56:34.911014 | 
2025-11-24 08:56:34.911151 | TASK [Run molecule]
2025-11-24 08:56:36.248794 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-11-24 08:56:36.508604 | controller | INFO     Running default > destroy
2025-11-24 08:56:36.508850 | controller | WARNING  Skipping, instances are delegated.
2025-11-24 08:56:36.539175 | controller | INFO     Running default > create
2025-11-24 08:56:36.540126 | controller | WARNING  Skipping, instances are delegated.
2025-11-24 08:56:36.549638 | controller | INFO     Running default > converge
2025-11-24 08:56:37.371685 | controller |
2025-11-24 08:56:37.371865 | controller | PLAY [Converge] ****************************************************************
2025-11-24 08:56:37.372054 | controller |
2025-11-24 08:56:37.372436 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:56:37.372720 | controller | Monday 24 November 2025  08:56:37 +0000 (0:00:00.013)       0:00:00.013 *******
2025-11-24 08:56:38.531126 | controller | ok: [instance]
2025-11-24 08:56:38.531175 | controller |
2025-11-24 08:56:38.531286 | controller | TASK [Add crc hostname with it's IP to /etc/hosts] *****************************
2025-11-24 08:56:38.531382 | controller | Monday 24 November 2025  08:56:38 +0000 (0:00:01.161)       0:00:01.174 *******
2025-11-24 08:56:38.894029 | controller | changed: [instance]
2025-11-24 08:56:38.894201 | controller |
2025-11-24 08:56:38.894439 | controller | TASK [Check if new ssh keypair exists] *****************************************
2025-11-24 08:56:38.894678 | controller | Monday 24 November 2025  08:56:38 +0000 (0:00:00.362)       0:00:01.536 *******
2025-11-24 08:56:38.925641 | controller |
2025-11-24 08:56:38.925715 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
2025-11-24 08:56:38.925766 | controller | Monday 24 November 2025  08:56:38 +0000 (0:00:00.031)       0:00:01.568 *******
2025-11-24 08:56:39.270905 | controller | ok: [instance]
2025-11-24 08:56:39.270975 | controller |
2025-11-24 08:56:39.271142 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
2025-11-24 08:56:39.271285 | controller | Monday 24 November 2025  08:56:39 +0000 (0:00:00.344)       0:00:01.913 *******
2025-11-24 08:56:39.294356 | controller | ok: [instance]
2025-11-24 08:56:39.294419 | controller |
2025-11-24 08:56:39.294596 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
2025-11-24 08:56:39.294759 | controller | Monday 24 November 2025  08:56:39 +0000 (0:00:00.023)       0:00:01.937 *******
2025-11-24 08:56:39.321402 | controller | skipping: [instance]
2025-11-24 08:56:39.321459 | controller |
2025-11-24 08:56:39.321623 | controller | TASK [Add the crc host dynamically] ********************************************
2025-11-24 08:56:39.321795 | controller | Monday 24 November 2025  08:56:39 +0000 (0:00:00.027)       0:00:01.964 *******
2025-11-24 08:56:39.345865 | controller | changed: [instance]
2025-11-24 08:56:39.345933 | controller |
2025-11-24 08:56:39.346086 | controller | TASK [Fetch crc network facts] *************************************************
2025-11-24 08:56:39.346265 | controller | Monday 24 November 2025  08:56:39 +0000 (0:00:00.024)       0:00:01.988 *******
2025-11-24 08:56:44.025083 | controller | ok: [instance -> crc]
2025-11-24 08:56:44.025374 | controller |
2025-11-24 08:56:44.025775 | controller | TASK [Load shared variables] ***************************************************
2025-11-24 08:56:44.026147 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:04.678)       0:00:06.667 *******
2025-11-24 08:56:44.054358 | controller | ok: [instance]
2025-11-24 08:56:44.104743 | controller |
2025-11-24 08:56:44.104800 | controller | TASK [Call ci_multus role] *****************************************************
2025-11-24 08:56:44.104819 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.028)       0:00:06.695 *******
2025-11-24 08:56:44.104835 | controller |
2025-11-24 08:56:44.104864 | controller | TASK [ci_multus : Create manifests directory] **********************************
2025-11-24 08:56:44.104941 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.051)       0:00:06.747 *******
2025-11-24 08:56:44.458331 | controller | changed: [instance]
2025-11-24 08:56:44.458386 | controller |
2025-11-24 08:56:44.458481 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-11-24 08:56:44.458592 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.353)       0:00:07.101 *******
2025-11-24 08:56:44.487123 | controller | skipping: [instance]
2025-11-24 08:56:44.487229 | controller |
2025-11-24 08:56:44.487389 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-11-24 08:56:44.487537 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.028)       0:00:07.129 *******
2025-11-24 08:56:44.522317 | controller | skipping: [instance]
2025-11-24 08:56:44.522480 | controller |
2025-11-24 08:56:44.522817 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-11-24 08:56:44.523042 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.035)       0:00:07.165 *******
2025-11-24 08:56:44.556227 | controller | skipping: [instance]
2025-11-24 08:56:44.556332 | controller |
2025-11-24 08:56:44.556491 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-11-24 08:56:44.556649 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.034)       0:00:07.199 *******
2025-11-24 08:56:44.591943 | controller | skipping: [instance]
2025-11-24 08:56:44.592059 | controller |
2025-11-24 08:56:44.592222 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] *****
2025-11-24 08:56:44.592371 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.035)       0:00:07.234 *******
2025-11-24 08:56:44.646198 | controller | ok: [instance]
2025-11-24 08:56:44.646292 | controller |
2025-11-24 08:56:44.646453 | controller | TASK [ci_multus : Merge any available multus net info patches] *****************
2025-11-24 08:56:44.646635 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.054)       0:00:07.289 *******
2025-11-24 08:56:44.867651 | 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-11-24 08:56:44.867792 | 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-11-24 08:56:44.868219 | 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-11-24 08:56:44.868404 | controller |
2025-11-24 08:56:44.868413 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] *******
2025-11-24 08:56:44.868423 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.221)       0:00:07.510 *******
2025-11-24 08:56:44.969318 | controller | ok: [instance]
2025-11-24 08:56:44.969364 | controller |
2025-11-24 08:56:44.969470 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] ***
2025-11-24 08:56:44.969568 | controller | Monday 24 November 2025  08:56:44 +0000 (0:00:00.101)       0:00:07.612 *******
2025-11-24 08:56:45.052074 | controller | ok: [instance]
2025-11-24 08:56:45.052157 | controller |
2025-11-24 08:56:45.052316 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] ***
2025-11-24 08:56:45.052400 | controller | Monday 24 November 2025  08:56:45 +0000 (0:00:00.082)       0:00:07.695 *******
2025-11-24 08:56:45.130379 | controller | ok: [instance]
2025-11-24 08:56:45.130449 | controller |
2025-11-24 08:56:45.130584 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] ***************
2025-11-24 08:56:45.130681 | controller | Monday 24 November 2025  08:56:45 +0000 (0:00:00.078)       0:00:07.773 *******
2025-11-24 08:56:45.740999 | controller | changed: [instance]
2025-11-24 08:56:45.741102 | controller |
2025-11-24 08:56:45.741266 | controller | TASK [ci_multus : Create the multus namespace] *********************************
2025-11-24 08:56:45.741425 | controller | Monday 24 November 2025  08:56:45 +0000 (0:00:00.610)       0:00:08.383 *******
2025-11-24 08:56:46.816636 | controller | changed: [instance]
2025-11-24 08:56:46.816694 | controller |
2025-11-24 08:56:46.816830 | controller | TASK [ci_multus : Apply network attachment definition manifests] ***************
2025-11-24 08:56:46.816964 | controller | Monday 24 November 2025  08:56:46 +0000 (0:00:01.076)       0:00:09.459 *******
2025-11-24 08:56:47.676901 | controller | changed: [instance]
2025-11-24 08:56:47.676971 | controller |
2025-11-24 08:56:47.677080 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:56:47.677210 | controller | instance                   : ok=16   changed=6    unreachable=0    failed=0    skipped=5    rescued=0    ignored=0
2025-11-24 08:56:47.677304 | controller |
2025-11-24 08:56:47.677415 | controller | Monday 24 November 2025  08:56:47 +0000 (0:00:00.860)       0:00:10.320 *******
2025-11-24 08:56:47.677511 | controller | ===============================================================================
2025-11-24 08:56:47.677604 | controller | Fetch crc network facts ------------------------------------------------- 4.68s
2025-11-24 08:56:47.677750 | controller | Gathering Facts --------------------------------------------------------- 1.16s
2025-11-24 08:56:47.677842 | controller | ci_multus : Create the multus namespace --------------------------------- 1.08s
2025-11-24 08:56:47.677964 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.86s
2025-11-24 08:56:47.678039 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.61s
2025-11-24 08:56:47.678140 | controller | Add crc hostname with it's IP to /etc/hosts ----------------------------- 0.36s
2025-11-24 08:56:47.678231 | controller | ci_multus : Create manifests directory ---------------------------------- 0.35s
2025-11-24 08:56:47.678341 | controller | recognize_ssh_keypair : Check if id_ed25519 key exists ------------------ 0.34s
2025-11-24 08:56:47.678424 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.22s
2025-11-24 08:56:47.678519 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.10s
2025-11-24 08:56:47.678611 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.08s
2025-11-24 08:56:47.678731 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.08s
2025-11-24 08:56:47.678841 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.05s
2025-11-24 08:56:47.678942 | controller | Call ci_multus role ----------------------------------------------------- 0.05s
2025-11-24 08:56:47.679069 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.04s
2025-11-24 08:56:47.679218 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.04s
2025-11-24 08:56:47.679352 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.03s
2025-11-24 08:56:47.679484 | controller | Check if new ssh keypair exists ----------------------------------------- 0.03s
2025-11-24 08:56:47.679621 | controller | Load shared variables --------------------------------------------------- 0.03s
2025-11-24 08:56:47.679901 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s
2025-11-24 08:56:47.764813 | controller | INFO     Running default > verify
2025-11-24 08:56:47.765054 | controller | INFO     Running Ansible Verifier
2025-11-24 08:56:48.300550 | controller |
2025-11-24 08:56:48.300668 | controller | PLAY [Verify] ******************************************************************
2025-11-24 08:56:48.300822 | controller |
2025-11-24 08:56:48.300989 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:56:48.301109 | controller | Monday 24 November 2025  08:56:48 +0000 (0:00:00.026)       0:00:00.026 *******
2025-11-24 08:56:49.334006 | controller | ok: [instance]
2025-11-24 08:56:49.334079 | controller |
2025-11-24 08:56:49.334200 | controller | TASK [Load shared variables] ***************************************************
2025-11-24 08:56:49.334234 | controller | Monday 24 November 2025  08:56:49 +0000 (0:00:01.034)       0:00:01.061 *******
2025-11-24 08:56:49.361497 | controller | ok: [instance]
2025-11-24 08:56:49.361553 | controller |
2025-11-24 08:56:49.361587 | controller | TASK [Fetch files stat results] ************************************************
2025-11-24 08:56:49.361725 | controller | Monday 24 November 2025  08:56:49 +0000 (0:00:00.024)       0:00:01.085 *******
2025-11-24 08:56:49.724414 | controller | ok: [instance]
2025-11-24 08:56:49.750628 | controller |
2025-11-24 08:56:49.750674 | controller | TASK [Assert that expected file exist] *****************************************
2025-11-24 08:56:49.750683 | controller | Monday 24 November 2025  08:56:49 +0000 (0:00:00.365)       0:00:01.450 *******
2025-11-24 08:56:49.750696 | controller | ok: [instance] => changed=false
2025-11-24 08:56:49.750741 | controller |   msg: All assertions passed
2025-11-24 08:56:49.750749 | controller |
2025-11-24 08:56:49.750758 | controller | TASK [Fetch file content] ******************************************************
2025-11-24 08:56:49.750920 | controller | Monday 24 November 2025  08:56:49 +0000 (0:00:00.026)       0:00:01.477 *******
2025-11-24 08:56:50.135939 | controller | ok: [instance]
2025-11-24 08:56:50.174853 | controller |
2025-11-24 08:56:50.174891 | controller | TASK [Set _ci_multus_nad variable] *********************************************
2025-11-24 08:56:50.174899 | controller | Monday 24 November 2025  08:56:50 +0000 (0:00:00.385)       0:00:01.862 *******
2025-11-24 08:56:50.174910 | controller | ok: [instance]
2025-11-24 08:56:50.234871 | controller |
2025-11-24 08:56:50.234926 | controller | TASK [Assert expected number of Network Attachment Definitions are created] ****
2025-11-24 08:56:50.234937 | controller | Monday 24 November 2025  08:56:50 +0000 (0:00:00.038)       0:00:01.901 *******
2025-11-24 08:56:50.234952 | controller | ok: [instance]
2025-11-24 08:56:50.234977 | controller |
2025-11-24 08:56:50.234988 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:56:50.235006 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:56:50.235015 | controller |
2025-11-24 08:56:50.235029 | controller | Monday 24 November 2025  08:56:50 +0000 (0:00:00.060)       0:00:01.961 *******
2025-11-24 08:56:50.235037 | controller | ===============================================================================
2025-11-24 08:56:50.235045 | controller | Gathering Facts --------------------------------------------------------- 1.03s
2025-11-24 08:56:50.235052 | controller | Fetch file content ------------------------------------------------------ 0.39s
2025-11-24 08:56:50.235059 | controller | Fetch files stat results ------------------------------------------------ 0.37s
2025-11-24 08:56:50.235070 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.06s
2025-11-24 08:56:50.235096 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.04s
2025-11-24 08:56:50.235262 | controller | Assert that expected file exist ----------------------------------------- 0.03s
2025-11-24 08:56:50.300080 | controller | Load shared variables --------------------------------------------------- 0.02s
2025-11-24 08:56:50.300154 | controller | INFO     Verifier completed successfully.
2025-11-24 08:56:50.312452 | controller | INFO     Running default > verify
2025-11-24 08:56:50.312791 | controller | INFO     Running Ansible Verifier
2025-11-24 08:56:50.847037 | controller |
2025-11-24 08:56:51.914314 | controller | PLAY [Verify CRC] **************************************************************
2025-11-24 08:56:51.914360 | controller |
2025-11-24 08:56:51.914370 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:56:51.914378 | controller | Monday 24 November 2025  08:56:50 +0000 (0:00:00.018)       0:00:00.018 *******
2025-11-24 08:56:51.914392 | controller | ok: [instance]
2025-11-24 08:56:51.914617 | controller |
2025-11-24 08:56:51.914638 | controller | TASK [Include default vars] ****************************************************
2025-11-24 08:56:51.944488 | controller | Monday 24 November 2025  08:56:51 +0000 (0:00:01.067)       0:00:01.086 *******
2025-11-24 08:56:51.944572 | controller | ok: [instance]
2025-11-24 08:56:51.944618 | controller |
2025-11-24 08:56:51.944627 | controller | TASK [Check if NADs were created] **********************************************
2025-11-24 08:56:51.944844 | controller | Monday 24 November 2025  08:56:51 +0000 (0:00:00.030)       0:00:01.116 *******
2025-11-24 08:56:52.834249 | controller | ok: [instance]
2025-11-24 08:56:52.834302 | controller |
2025-11-24 08:56:52.834310 | controller | TASK [Store output spec] *******************************************************
2025-11-24 08:56:52.834319 | controller | Monday 24 November 2025  08:56:52 +0000 (0:00:00.889)       0:00:02.005 *******
2025-11-24 08:56:52.878249 | controller | ok: [instance]
2025-11-24 08:56:52.922562 | controller |
2025-11-24 08:56:52.922599 | controller | TASK [Ensure both lists have the same length] **********************************
2025-11-24 08:56:52.922608 | controller | Monday 24 November 2025  08:56:52 +0000 (0:00:00.044)       0:00:02.049 *******
2025-11-24 08:56:52.922620 | controller | ok: [instance] => changed=false
2025-11-24 08:56:52.987010 | controller |   msg: All assertions passed
2025-11-24 08:56:52.987055 | controller |
2025-11-24 08:56:52.987067 | controller | TASK [Compare each corresponding element in the lists] *************************
2025-11-24 08:56:52.987079 | controller | Monday 24 November 2025  08:56:52 +0000 (0:00:00.044)       0:00:02.094 *******
2025-11-24 08:56:52.987117 | 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-11-24 08:56:52.987344 | controller |   ansible_loop_var: item
2025-11-24 08:56:52.987363 | controller |   item:
2025-11-24 08:56:52.987377 | controller |   - |-
2025-11-24 08:56:52.987458 | controller |     {
2025-11-24 08:56:52.987481 | controller |       "cniVersion": "0.3.1",
2025-11-24 08:56:52.987628 | controller |       "name": "bridge-to-linux-bridge",
2025-11-24 08:56:52.987855 | controller |       "type": "bridge",
2025-11-24 08:56:52.987999 | controller |       "bridge": "bridge-to-linux-bridge",
2025-11-24 08:56:52.988133 | controller |       "ipam": {
2025-11-24 08:56:52.988272 | controller |         "type": "whereabouts",
2025-11-24 08:56:52.988424 | controller |         "range": "192.168.122.0/24",
2025-11-24 08:56:52.988558 | controller |         "range_start": "192.168.122.30",
2025-11-24 08:56:52.988694 | controller |         "range_end": "192.168.122.70"
2025-11-24 08:56:52.988865 | controller |       }
2025-11-24 08:56:52.989007 | controller |     }
2025-11-24 08:56:52.989134 | controller |   - |-
2025-11-24 08:56:52.989260 | controller |     {
2025-11-24 08:56:52.989407 | controller |       "cniVersion": "0.3.1",
2025-11-24 08:56:52.989543 | controller |       "name": "bridge-to-linux-bridge",
2025-11-24 08:56:52.989677 | controller |       "type": "bridge",
2025-11-24 08:56:52.989834 | controller |       "bridge": "bridge-to-linux-bridge",
2025-11-24 08:56:52.989961 | controller |       "ipam": {
2025-11-24 08:56:52.990102 | controller |         "type": "whereabouts",
2025-11-24 08:56:52.990249 | controller |         "range": "192.168.122.0/24",
2025-11-24 08:56:52.990399 | controller |         "range_start": "192.168.122.30",
2025-11-24 08:56:52.990547 | controller |         "range_end": "192.168.122.70"
2025-11-24 08:56:52.990719 | controller |       }
2025-11-24 08:56:52.990850 | controller |     }
2025-11-24 08:56:52.991020 | controller |   msg: All assertions passed
2025-11-24 08:56:52.991206 | 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-11-24 08:56:52.991348 | controller |   ansible_loop_var: item
2025-11-24 08:56:52.991485 | controller |   item:
2025-11-24 08:56:52.991617 | controller |   - |-
2025-11-24 08:56:52.991769 | controller |     {
2025-11-24 08:56:52.991923 | controller |       "cniVersion": "0.3.1",
2025-11-24 08:56:52.992054 | controller |       "name": "default",
2025-11-24 08:56:52.992201 | controller |       "type": "bridge",
2025-11-24 08:56:52.992338 | controller |       "bridge": "eth0",
2025-11-24 08:56:52.992475 | controller |       "ipam": {
2025-11-24 08:56:52.992614 | controller |         "type": "whereabouts",
2025-11-24 08:56:52.992769 | controller |         "range": "192.168.122.0/24",
2025-11-24 08:56:52.992922 | controller |         "range_start": "192.168.122.30",
2025-11-24 08:56:52.993067 | controller |         "range_end": "192.168.122.70"
2025-11-24 08:56:52.993667 | controller |       }
2025-11-24 08:56:52.993855 | controller |     }
2025-11-24 08:56:52.993991 | controller |   - |-
2025-11-24 08:56:52.994127 | controller |     {
2025-11-24 08:56:52.994277 | controller |       "cniVersion": "0.3.1",
2025-11-24 08:56:52.994413 | controller |       "name": "default",
2025-11-24 08:56:52.994574 | controller |       "type": "bridge",
2025-11-24 08:56:52.994741 | controller |       "bridge": "eth0",
2025-11-24 08:56:52.994884 | controller |       "ipam": {
2025-11-24 08:56:52.995035 | controller |         "type": "whereabouts",
2025-11-24 08:56:52.995180 | controller |         "range": "192.168.122.0/24",
2025-11-24 08:56:52.995339 | controller |         "range_start": "192.168.122.30",
2025-11-24 08:56:52.995472 | controller |         "range_end": "192.168.122.70"
2025-11-24 08:56:52.995617 | controller |       }
2025-11-24 08:56:52.995780 | controller |     }
2025-11-24 08:56:52.995957 | controller |   msg: All assertions passed
2025-11-24 08:56:52.996162 | 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-11-24 08:56:52.996317 | controller |   ansible_loop_var: item
2025-11-24 08:56:52.996450 | controller |   item:
2025-11-24 08:56:52.996599 | controller |   - |-
2025-11-24 08:56:52.996763 | controller |     {
2025-11-24 08:56:52.996901 | controller |       "cniVersion": "0.3.1",
2025-11-24 08:56:52.997043 | controller |       "name": "patchnetwork",
2025-11-24 08:56:52.997195 | controller |       "type": "macvlan",
2025-11-24 08:56:52.997337 | controller |       "master": "eth2",
2025-11-24 08:56:52.997462 | controller |       "ipam": {
2025-11-24 08:56:52.997597 | controller |         "type": "whereabouts",
2025-11-24 08:56:52.997851 | controller |         "range": "192.168.122.0/24",
2025-11-24 08:56:52.997995 | controller |         "range_start": "192.168.122.30",
2025-11-24 08:56:52.998125 | controller |         "range_end": "192.168.122.70"
2025-11-24 08:56:52.998255 | controller |       }
2025-11-24 08:56:52.998390 | controller |     }
2025-11-24 08:56:52.998523 | controller |   - |-
2025-11-24 08:56:52.998653 | controller |     {
2025-11-24 08:56:52.998840 | controller |       "cniVersion": "0.3.1",
2025-11-24 08:56:52.998968 | controller |       "name": "patchnetwork",
2025-11-24 08:56:52.999103 | controller |       "type": "macvlan",
2025-11-24 08:56:52.999234 | controller |       "master": "eth2",
2025-11-24 08:56:52.999384 | controller |       "ipam": {
2025-11-24 08:56:52.999512 | controller |         "type": "whereabouts",
2025-11-24 08:56:52.999663 | controller |         "range": "192.168.122.0/24",
2025-11-24 08:56:52.999852 | controller |         "range_start": "192.168.122.30",
2025-11-24 08:56:53.000008 | controller |         "range_end": "192.168.122.70"
2025-11-24 08:56:53.000137 | controller |       }
2025-11-24 08:56:53.000264 | controller |     }
2025-11-24 08:56:53.000410 | controller |   msg: All assertions passed
2025-11-24 08:56:53.000554 | controller |
2025-11-24 08:56:53.000695 | controller | TASK [Create a test pod to attach a network] ***********************************
2025-11-24 08:56:53.000855 | controller | Monday 24 November 2025  08:56:52 +0000 (0:00:00.064)       0:00:02.158 *******
2025-11-24 08:57:04.107867 | controller | [WARNING]: unknown field "api_version"
2025-11-24 08:57:04.117736 | controller | changed: [instance]
2025-11-24 08:57:04.117805 | controller |
2025-11-24 08:57:04.117931 | controller | TASK [Assert that test pod has the additional network] *************************
2025-11-24 08:57:04.118055 | controller | Monday 24 November 2025  08:57:04 +0000 (0:00:11.130)       0:00:13.289 *******
2025-11-24 08:57:04.144179 | controller | ok: [instance] => changed=false
2025-11-24 08:57:04.144231 | controller |   msg: All assertions passed
2025-11-24 08:57:04.144349 | controller |
2025-11-24 08:57:04.144471 | controller | TASK [Delete test pod] *********************************************************
2025-11-24 08:57:04.144597 | controller | Monday 24 November 2025  08:57:04 +0000 (0:00:00.026)       0:00:13.316 *******
2025-11-24 08:57:04.995056 | controller | changed: [instance]
2025-11-24 08:57:04.995162 | controller |
2025-11-24 08:57:04.995364 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:04.995622 | controller | instance                   : ok=9    changed=2    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:04.995843 | controller |
2025-11-24 08:57:04.996029 | controller | Monday 24 November 2025  08:57:04 +0000 (0:00:00.850)       0:00:14.166 *******
2025-11-24 08:57:04.996214 | controller | ===============================================================================
2025-11-24 08:57:04.996388 | controller | Create a test pod to attach a network ---------------------------------- 11.13s
2025-11-24 08:57:04.996571 | controller | Gathering Facts --------------------------------------------------------- 1.07s
2025-11-24 08:57:04.996776 | controller | Check if NADs were created ---------------------------------------------- 0.89s
2025-11-24 08:57:04.996962 | controller | Delete test pod --------------------------------------------------------- 0.85s
2025-11-24 08:57:04.997134 | controller | Compare each corresponding element in the lists ------------------------- 0.06s
2025-11-24 08:57:04.997360 | controller | Ensure both lists have the same length ---------------------------------- 0.04s
2025-11-24 08:57:04.997538 | controller | Store output spec ------------------------------------------------------- 0.04s
2025-11-24 08:57:04.997719 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-11-24 08:57:04.997914 | controller | Assert that test pod has the additional network ------------------------- 0.03s
2025-11-24 08:57:05.070174 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:05.092778 | controller | INFO     Running default > side_effect
2025-11-24 08:57:05.671118 | controller |
2025-11-24 08:57:05.671172 | controller | PLAY [Clean] *******************************************************************
2025-11-24 08:57:05.671291 | controller |
2025-11-24 08:57:05.671447 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:05.671581 | controller | Monday 24 November 2025  08:57:05 +0000 (0:00:00.023)       0:00:00.023 *******
2025-11-24 08:57:06.707372 | controller | ok: [instance]
2025-11-24 08:57:06.707481 | controller |
2025-11-24 08:57:06.707645 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] ****************
2025-11-24 08:57:06.707725 | controller | Monday 24 November 2025  08:57:06 +0000 (0:00:01.036)       0:00:01.059 *******
2025-11-24 08:57:07.080129 | controller | changed: [instance]
2025-11-24 08:57:07.080427 | controller |
2025-11-24 08:57:07.080614 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] ****************
2025-11-24 08:57:07.080660 | controller | Monday 24 November 2025  08:57:07 +0000 (0:00:00.372)       0:00:01.432 *******
2025-11-24 08:57:08.052748 | controller | ok: [instance]
2025-11-24 08:57:08.053169 | controller |
2025-11-24 08:57:10.545519 | controller | TASK [ci_multus : Cleanup - Delete NADs] ***************************************
2025-11-24 08:57:10.545574 | controller | Monday 24 November 2025  08:57:08 +0000 (0:00:00.972)       0:00:02.405 *******
2025-11-24 08:57:10.545589 | controller | changed: [instance] => (item=bridge-to-linux-bridge)
2025-11-24 08:57:10.545724 | controller | changed: [instance] => (item=default)
2025-11-24 08:57:10.545782 | controller | changed: [instance] => (item=patchnetwork)
2025-11-24 08:57:10.545790 | controller |
2025-11-24 08:57:10.545801 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] ***************
2025-11-24 08:57:10.926572 | controller | Monday 24 November 2025  08:57:10 +0000 (0:00:02.492)       0:00:04.897 *******
2025-11-24 08:57:10.926623 | controller | changed: [instance]
2025-11-24 08:57:10.926714 | controller |
2025-11-24 08:57:10.926736 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:10.926746 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:10.926758 | controller |
2025-11-24 08:57:10.926842 | controller | Monday 24 November 2025  08:57:10 +0000 (0:00:00.381)       0:00:05.279 *******
2025-11-24 08:57:10.927493 | controller | ===============================================================================
2025-11-24 08:57:10.929511 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 2.49s
2025-11-24 08:57:10.929550 | controller | Gathering Facts --------------------------------------------------------- 1.04s
2025-11-24 08:57:10.929560 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.97s
2025-11-24 08:57:10.929567 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.38s
2025-11-24 08:57:10.929579 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.37s
2025-11-24 08:57:11.007432 | controller | INFO     Running default > verify
2025-11-24 08:57:11.007757 | controller | INFO     Running Ansible Verifier
2025-11-24 08:57:11.556154 | controller |
2025-11-24 08:57:11.556215 | controller | PLAY [Verify Clean] ************************************************************
2025-11-24 08:57:11.556297 | controller |
2025-11-24 08:57:11.556445 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:11.556593 | controller | Monday 24 November 2025  08:57:11 +0000 (0:00:00.023)       0:00:00.023 *******
2025-11-24 08:57:12.613341 | controller | ok: [instance]
2025-11-24 08:57:12.613559 | controller |
2025-11-24 08:57:12.613915 | controller | TASK [Include default vars] ****************************************************
2025-11-24 08:57:12.614142 | controller | Monday 24 November 2025  08:57:12 +0000 (0:00:01.057)       0:00:01.080 *******
2025-11-24 08:57:12.644848 | controller | ok: [instance]
2025-11-24 08:57:12.644918 | controller |
2025-11-24 08:57:12.645011 | controller | TASK [Fetch file stat results] *************************************************
2025-11-24 08:57:12.645121 | controller | Monday 24 November 2025  08:57:12 +0000 (0:00:00.031)       0:00:01.112 *******
2025-11-24 08:57:12.982498 | controller | ok: [instance]
2025-11-24 08:57:12.982550 | controller |
2025-11-24 08:57:12.982650 | controller | TASK [Assert that created file are removed by cleanup] *************************
2025-11-24 08:57:12.982795 | controller | Monday 24 November 2025  08:57:12 +0000 (0:00:00.338)       0:00:01.450 *******
2025-11-24 08:57:13.036687 | controller | ok: [instance] => changed=false
2025-11-24 08:57:13.037418 | controller |   msg: All assertions passed
2025-11-24 08:57:13.037489 | controller |
2025-11-24 08:57:13.037502 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:13.037512 | controller | instance                   : ok=4    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:13.037521 | controller |
2025-11-24 08:57:13.037530 | controller | Monday 24 November 2025  08:57:13 +0000 (0:00:00.054)       0:00:01.504 *******
2025-11-24 08:57:13.037539 | controller | ===============================================================================
2025-11-24 08:57:13.037551 | controller | Gathering Facts --------------------------------------------------------- 1.06s
2025-11-24 08:57:13.037616 | controller | Fetch file stat results ------------------------------------------------- 0.34s
2025-11-24 08:57:13.037746 | controller | Assert that created file are removed by cleanup ------------------------- 0.05s
2025-11-24 08:57:13.037878 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-11-24 08:57:13.106313 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:13.116544 | controller | INFO     Running default > verify
2025-11-24 08:57:13.116850 | controller | INFO     Running Ansible Verifier
2025-11-24 08:57:13.651245 | controller |
2025-11-24 08:57:13.651377 | controller | PLAY [Verify Clean CRC] ********************************************************
2025-11-24 08:57:13.651550 | controller |
2025-11-24 08:57:13.651637 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:13.651779 | controller | Monday 24 November 2025  08:57:13 +0000 (0:00:00.018)       0:00:00.018 *******
2025-11-24 08:57:14.709532 | controller | ok: [instance]
2025-11-24 08:57:14.709670 | controller |
2025-11-24 08:57:14.709694 | controller | TASK [Include default vars] ****************************************************
2025-11-24 08:57:14.709749 | controller | Monday 24 November 2025  08:57:14 +0000 (0:00:01.057)       0:00:01.076 *******
2025-11-24 08:57:14.737578 | controller | ok: [instance]
2025-11-24 08:57:15.711763 | controller |
2025-11-24 08:57:15.711815 | controller | TASK [Check if NADs were deleted] **********************************************
2025-11-24 08:57:15.711823 | controller | Monday 24 November 2025  08:57:14 +0000 (0:00:00.028)       0:00:01.104 *******
2025-11-24 08:57:15.711834 | controller | ok: [instance]
2025-11-24 08:57:15.711869 | controller |
2025-11-24 08:57:15.711877 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:15.711886 | controller | instance                   : ok=3    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:15.711917 | controller |
2025-11-24 08:57:15.712136 | controller | Monday 24 November 2025  08:57:15 +0000 (0:00:00.974)       0:00:02.079 *******
2025-11-24 08:57:15.712484 | controller | ===============================================================================
2025-11-24 08:57:15.712521 | controller | Gathering Facts --------------------------------------------------------- 1.06s
2025-11-24 08:57:15.775999 | controller | Check if NADs were deleted ---------------------------------------------- 0.97s
2025-11-24 08:57:15.776065 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-11-24 08:57:15.776082 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:15.776361 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-11-24 08:57:15.789336 | controller | INFO     Running local > destroy
2025-11-24 08:57:15.789581 | controller | WARNING  Skipping, instances are delegated.
2025-11-24 08:57:15.800025 | controller | INFO     Running local > create
2025-11-24 08:57:15.800956 | controller | WARNING  Skipping, instances are delegated.
2025-11-24 08:57:15.809658 | controller | INFO     Running local > converge
2025-11-24 08:57:16.321900 | controller |
2025-11-24 08:57:16.322088 | controller | PLAY [Converge] ****************************************************************
2025-11-24 08:57:16.322207 | controller |
2025-11-24 08:57:16.322384 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:16.322509 | controller | Monday 24 November 2025  08:57:16 +0000 (0:00:00.020)       0:00:00.020 *******
2025-11-24 08:57:17.405999 | controller | ok: [instance]
2025-11-24 08:57:17.406068 | controller |
2025-11-24 08:57:17.406096 | controller | TASK [Load shared variables] ***************************************************
2025-11-24 08:57:17.406257 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:01.084)       0:00:01.104 *******
2025-11-24 08:57:17.439697 | controller | ok: [instance]
2025-11-24 08:57:17.440241 | controller |
2025-11-24 08:57:17.486263 | controller | TASK [Call ci_multus role] *****************************************************
2025-11-24 08:57:17.486473 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:00.033)       0:00:01.137 *******
2025-11-24 08:57:17.486498 | controller |
2025-11-24 08:57:17.887884 | controller | TASK [ci_multus : Create manifests directory] **********************************
2025-11-24 08:57:17.887927 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:00.046)       0:00:01.184 *******
2025-11-24 08:57:17.887944 | controller | changed: [instance]
2025-11-24 08:57:17.887983 | controller |
2025-11-24 08:57:17.887999 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-11-24 08:57:17.888087 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:00.400)       0:00:01.585 *******
2025-11-24 08:57:17.913903 | controller | skipping: [instance]
2025-11-24 08:57:17.913973 | controller |
2025-11-24 08:57:17.914171 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-11-24 08:57:17.939995 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:00.026)       0:00:01.612 *******
2025-11-24 08:57:17.940041 | controller | skipping: [instance]
2025-11-24 08:57:17.940065 | controller |
2025-11-24 08:57:17.940727 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-11-24 08:57:17.967677 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:00.026)       0:00:01.638 *******
2025-11-24 08:57:17.967763 | controller | skipping: [instance]
2025-11-24 08:57:17.967802 | controller |
2025-11-24 08:57:17.967978 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-11-24 08:57:17.968149 | controller | Monday 24 November 2025  08:57:17 +0000 (0:00:00.027)       0:00:01.666 *******
2025-11-24 08:57:18.003764 | controller | skipping: [instance]
2025-11-24 08:57:18.003860 | controller |
2025-11-24 08:57:18.004006 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] *****
2025-11-24 08:57:18.004167 | controller | Monday 24 November 2025  08:57:18 +0000 (0:00:00.036)       0:00:01.702 *******
2025-11-24 08:57:18.047439 | controller | ok: [instance]
2025-11-24 08:57:18.047517 | controller |
2025-11-24 08:57:18.047679 | controller | TASK [ci_multus : Merge any available multus net info patches] *****************
2025-11-24 08:57:18.047800 | controller | Monday 24 November 2025  08:57:18 +0000 (0:00:00.043)       0:00:01.745 *******
2025-11-24 08:57:18.210649 | 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-11-24 08:57:18.210729 | 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-11-24 08:57:18.210864 | controller |
2025-11-24 08:57:18.210962 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] *******
2025-11-24 08:57:18.211063 | controller | Monday 24 November 2025  08:57:18 +0000 (0:00:00.163)       0:00:01.909 *******
2025-11-24 08:57:18.294497 | controller | ok: [instance]
2025-11-24 08:57:18.294574 | controller |
2025-11-24 08:57:18.294729 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] ***
2025-11-24 08:57:18.294894 | controller | Monday 24 November 2025  08:57:18 +0000 (0:00:00.083)       0:00:01.993 *******
2025-11-24 08:57:18.373368 | controller | ok: [instance]
2025-11-24 08:57:18.373443 | controller |
2025-11-24 08:57:18.373588 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] ***
2025-11-24 08:57:18.373738 | controller | Monday 24 November 2025  08:57:18 +0000 (0:00:00.079)       0:00:02.072 *******
2025-11-24 08:57:18.443819 | controller | ok: [instance]
2025-11-24 08:57:18.443926 | controller |
2025-11-24 08:57:18.444057 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] ***************
2025-11-24 08:57:18.444290 | controller | Monday 24 November 2025  08:57:18 +0000 (0:00:00.070)       0:00:02.142 *******
2025-11-24 08:57:19.139848 | controller | changed: [instance]
2025-11-24 08:57:19.139961 | controller |
2025-11-24 08:57:19.140104 | controller | TASK [ci_multus : Create the multus namespace] *********************************
2025-11-24 08:57:19.140245 | controller | Monday 24 November 2025  08:57:19 +0000 (0:00:00.695)       0:00:02.838 *******
2025-11-24 08:57:19.160871 | controller | skipping: [instance]
2025-11-24 08:57:19.160938 | controller |
2025-11-24 08:57:19.161055 | controller | TASK [ci_multus : Apply network attachment definition manifests] ***************
2025-11-24 08:57:19.161301 | controller | Monday 24 November 2025  08:57:19 +0000 (0:00:00.021)       0:00:02.859 *******
2025-11-24 08:57:19.201924 | controller | skipping: [instance]
2025-11-24 08:57:19.202001 | controller |
2025-11-24 08:57:19.202125 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:19.202290 | controller | instance                   : ok=9    changed=2    unreachable=0    failed=0    skipped=6    rescued=0    ignored=0
2025-11-24 08:57:19.202421 | controller |
2025-11-24 08:57:19.202564 | controller | Monday 24 November 2025  08:57:19 +0000 (0:00:00.041)       0:00:02.900 *******
2025-11-24 08:57:19.202723 | controller | ===============================================================================
2025-11-24 08:57:19.202869 | controller | Gathering Facts --------------------------------------------------------- 1.08s
2025-11-24 08:57:19.202988 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.70s
2025-11-24 08:57:19.203120 | controller | ci_multus : Create manifests directory ---------------------------------- 0.40s
2025-11-24 08:57:19.203287 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.16s
2025-11-24 08:57:19.203398 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.08s
2025-11-24 08:57:19.203566 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.08s
2025-11-24 08:57:19.203660 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.07s
2025-11-24 08:57:19.203821 | controller | Call ci_multus role ----------------------------------------------------- 0.05s
2025-11-24 08:57:19.203969 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.04s
2025-11-24 08:57:19.204140 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.04s
2025-11-24 08:57:19.204269 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.04s
2025-11-24 08:57:19.204390 | controller | Load shared variables --------------------------------------------------- 0.03s
2025-11-24 08:57:19.204555 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.03s
2025-11-24 08:57:19.204659 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s
2025-11-24 08:57:19.204810 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s
2025-11-24 08:57:19.204967 | controller | ci_multus : Create the multus namespace --------------------------------- 0.02s
2025-11-24 08:57:19.279860 | controller | INFO     Running local > verify
2025-11-24 08:57:19.280134 | controller | INFO     Running Ansible Verifier
2025-11-24 08:57:19.810914 | controller |
2025-11-24 08:57:19.811055 | controller | PLAY [Verify] ******************************************************************
2025-11-24 08:57:19.811205 | controller |
2025-11-24 08:57:19.811352 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:19.811506 | controller | Monday 24 November 2025  08:57:19 +0000 (0:00:00.021)       0:00:00.021 *******
2025-11-24 08:57:20.820763 | controller | ok: [instance]
2025-11-24 08:57:20.820821 | controller |
2025-11-24 08:57:20.821075 | controller | TASK [Load shared variables] ***************************************************
2025-11-24 08:57:20.844918 | controller | Monday 24 November 2025  08:57:20 +0000 (0:00:01.010)       0:00:01.031 *******
2025-11-24 08:57:20.844998 | controller | ok: [instance]
2025-11-24 08:57:20.845143 | controller |
2025-11-24 08:57:20.845189 | controller | TASK [Fetch files stat results] ************************************************
2025-11-24 08:57:21.208883 | controller | Monday 24 November 2025  08:57:20 +0000 (0:00:00.023)       0:00:01.055 *******
2025-11-24 08:57:21.209015 | controller | ok: [instance]
2025-11-24 08:57:21.209052 | controller |
2025-11-24 08:57:21.209204 | controller | TASK [Assert that expected file exist] *****************************************
2025-11-24 08:57:21.209244 | controller | Monday 24 November 2025  08:57:21 +0000 (0:00:00.363)       0:00:01.419 *******
2025-11-24 08:57:21.233784 | controller | ok: [instance] => changed=false
2025-11-24 08:57:21.567100 | controller |   msg: All assertions passed
2025-11-24 08:57:21.567160 | controller |
2025-11-24 08:57:21.567169 | controller | TASK [Fetch file content] ******************************************************
2025-11-24 08:57:21.567176 | controller | Monday 24 November 2025  08:57:21 +0000 (0:00:00.024)       0:00:01.443 *******
2025-11-24 08:57:21.567189 | controller | ok: [instance]
2025-11-24 08:57:21.567393 | controller |
2025-11-24 08:57:21.567435 | controller | TASK [Set _ci_multus_nad variable] *********************************************
2025-11-24 08:57:21.604487 | controller | Monday 24 November 2025  08:57:21 +0000 (0:00:00.333)       0:00:01.777 *******
2025-11-24 08:57:21.604532 | controller | ok: [instance]
2025-11-24 08:57:21.664968 | controller |
2025-11-24 08:57:21.665021 | controller | TASK [Assert expected number of Network Attachment Definitions are created] ****
2025-11-24 08:57:21.665031 | controller | Monday 24 November 2025  08:57:21 +0000 (0:00:00.037)       0:00:01.814 *******
2025-11-24 08:57:21.665048 | controller | ok: [instance]
2025-11-24 08:57:21.665183 | controller |
2025-11-24 08:57:21.665198 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:21.665206 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:21.665214 | controller |
2025-11-24 08:57:21.665221 | controller | Monday 24 November 2025  08:57:21 +0000 (0:00:00.060)       0:00:01.875 *******
2025-11-24 08:57:21.665228 | controller | ===============================================================================
2025-11-24 08:57:21.665236 | controller | Gathering Facts --------------------------------------------------------- 1.01s
2025-11-24 08:57:21.665246 | controller | Fetch files stat results ------------------------------------------------ 0.36s
2025-11-24 08:57:21.665284 | controller | Fetch file content ------------------------------------------------------ 0.33s
2025-11-24 08:57:21.665434 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.06s
2025-11-24 08:57:21.665522 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.04s
2025-11-24 08:57:21.665632 | controller | Assert that expected file exist ----------------------------------------- 0.02s
2025-11-24 08:57:21.665720 | controller | Load shared variables --------------------------------------------------- 0.02s
2025-11-24 08:57:21.732135 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:21.744649 | controller | INFO     Running local > side_effect
2025-11-24 08:57:22.296769 | controller |
2025-11-24 08:57:22.296879 | controller | PLAY [Clean] *******************************************************************
2025-11-24 08:57:22.297066 | controller |
2025-11-24 08:57:22.297155 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:22.297384 | controller | Monday 24 November 2025  08:57:22 +0000 (0:00:00.019)       0:00:00.019 *******
2025-11-24 08:57:23.374994 | controller | ok: [instance]
2025-11-24 08:57:23.375116 | controller |
2025-11-24 08:57:23.375138 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] ****************
2025-11-24 08:57:23.375268 | controller | Monday 24 November 2025  08:57:23 +0000 (0:00:01.078)       0:00:01.098 *******
2025-11-24 08:57:23.859047 | controller | changed: [instance]
2025-11-24 08:57:23.859127 | controller |
2025-11-24 08:57:23.859237 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] ****************
2025-11-24 08:57:23.859425 | controller | Monday 24 November 2025  08:57:23 +0000 (0:00:00.483)       0:00:01.581 *******
2025-11-24 08:57:23.891643 | controller | skipping: [instance]
2025-11-24 08:57:23.891737 | controller |
2025-11-24 08:57:23.891754 | controller | TASK [ci_multus : Cleanup - Delete NADs] ***************************************
2025-11-24 08:57:23.891886 | controller | Monday 24 November 2025  08:57:23 +0000 (0:00:00.032)       0:00:01.614 *******
2025-11-24 08:57:23.928986 | controller | skipping: [instance]
2025-11-24 08:57:23.929073 | controller |
2025-11-24 08:57:23.929216 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] ***************
2025-11-24 08:57:23.929366 | controller | Monday 24 November 2025  08:57:23 +0000 (0:00:00.037)       0:00:01.651 *******
2025-11-24 08:57:24.335323 | controller | changed: [instance]
2025-11-24 08:57:24.335407 | controller |
2025-11-24 08:57:24.335522 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:24.335632 | controller | instance                   : ok=3    changed=2    unreachable=0    failed=0    skipped=2    rescued=0    ignored=0
2025-11-24 08:57:24.335875 | controller |
2025-11-24 08:57:24.335986 | controller | Monday 24 November 2025  08:57:24 +0000 (0:00:00.406)       0:00:02.058 *******
2025-11-24 08:57:24.336140 | controller | ===============================================================================
2025-11-24 08:57:24.336160 | controller | Gathering Facts --------------------------------------------------------- 1.08s
2025-11-24 08:57:24.336775 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.48s
2025-11-24 08:57:24.336856 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.41s
2025-11-24 08:57:24.417993 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 0.04s
2025-11-24 08:57:24.418090 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.03s
2025-11-24 08:57:24.418139 | controller | INFO     Running local > verify
2025-11-24 08:57:24.418230 | controller | INFO     Running Ansible Verifier
2025-11-24 08:57:25.029325 | controller |
2025-11-24 08:57:25.029385 | controller | PLAY [Verify Clean] ************************************************************
2025-11-24 08:57:25.029399 | controller |
2025-11-24 08:57:25.029504 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:25.029607 | controller | Monday 24 November 2025  08:57:25 +0000 (0:00:00.025)       0:00:00.025 *******
2025-11-24 08:57:26.109282 | controller | ok: [instance]
2025-11-24 08:57:26.109370 | controller |
2025-11-24 08:57:26.109392 | controller | TASK [Include default vars] ****************************************************
2025-11-24 08:57:26.109416 | controller | Monday 24 November 2025  08:57:26 +0000 (0:00:01.080)       0:00:01.105 *******
2025-11-24 08:57:26.150903 | controller | ok: [instance]
2025-11-24 08:57:26.150962 | controller |
2025-11-24 08:57:26.151117 | controller | TASK [Fetch file stat results] *************************************************
2025-11-24 08:57:26.151251 | controller | Monday 24 November 2025  08:57:26 +0000 (0:00:00.041)       0:00:01.147 *******
2025-11-24 08:57:26.510187 | controller | ok: [instance]
2025-11-24 08:57:26.511018 | controller |
2025-11-24 08:57:26.552442 | controller | TASK [Assert that created file are removed by cleanup] *************************
2025-11-24 08:57:26.552503 | controller | Monday 24 November 2025  08:57:26 +0000 (0:00:00.359)       0:00:01.506 *******
2025-11-24 08:57:26.552518 | controller | ok: [instance] => changed=false
2025-11-24 08:57:26.552527 | controller |   msg: All assertions passed
2025-11-24 08:57:26.552664 | controller |
2025-11-24 08:57:26.552827 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:26.553004 | controller | instance                   : ok=4    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:26.553257 | controller |
2025-11-24 08:57:26.553397 | controller | Monday 24 November 2025  08:57:26 +0000 (0:00:00.042)       0:00:01.549 *******
2025-11-24 08:57:26.553411 | controller | ===============================================================================
2025-11-24 08:57:26.553538 | controller | Gathering Facts --------------------------------------------------------- 1.08s
2025-11-24 08:57:26.553656 | controller | Fetch file stat results ------------------------------------------------- 0.36s
2025-11-24 08:57:26.553801 | controller | Assert that created file are removed by cleanup ------------------------- 0.04s
2025-11-24 08:57:26.553923 | controller | Include default vars ---------------------------------------------------- 0.04s
2025-11-24 08:57:26.633135 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:26.633616 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-11-24 08:57:26.648029 | controller | INFO     Running local_ipv6 > destroy
2025-11-24 08:57:26.648365 | controller | WARNING  Skipping, instances are delegated.
2025-11-24 08:57:26.660671 | controller | INFO     Running local_ipv6 > create
2025-11-24 08:57:26.661824 | controller | WARNING  Skipping, instances are delegated.
2025-11-24 08:57:26.673484 | controller | INFO     Running local_ipv6 > converge
2025-11-24 08:57:27.200182 | controller |
2025-11-24 08:57:27.200305 | controller | PLAY [Converge] ****************************************************************
2025-11-24 08:57:27.200417 | controller |
2025-11-24 08:57:27.200554 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:27.200720 | controller | Monday 24 November 2025  08:57:27 +0000 (0:00:00.017)       0:00:00.017 *******
2025-11-24 08:57:28.249386 | controller | ok: [instance]
2025-11-24 08:57:28.249840 | controller |
2025-11-24 08:57:28.249919 | controller | TASK [Load shared variables] ***************************************************
2025-11-24 08:57:28.249938 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:01.049)       0:00:01.066 *******
2025-11-24 08:57:28.274870 | controller | ok: [instance]
2025-11-24 08:57:28.274909 | controller |
2025-11-24 08:57:28.274919 | controller | TASK [Call ci_multus role] *****************************************************
2025-11-24 08:57:28.274930 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.025)       0:00:01.092 *******
2025-11-24 08:57:28.328473 | controller |
2025-11-24 08:57:28.734001 | controller | TASK [ci_multus : Create manifests directory] **********************************
2025-11-24 08:57:28.734095 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.053)       0:00:01.146 *******
2025-11-24 08:57:28.734125 | controller | changed: [instance]
2025-11-24 08:57:28.762907 | controller |
2025-11-24 08:57:28.762963 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-11-24 08:57:28.762974 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.405)       0:00:01.551 *******
2025-11-24 08:57:28.762992 | controller | skipping: [instance]
2025-11-24 08:57:28.763061 | controller |
2025-11-24 08:57:28.763076 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-11-24 08:57:28.792106 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.028)       0:00:01.580 *******
2025-11-24 08:57:28.792152 | controller | skipping: [instance]
2025-11-24 08:57:28.792176 | controller |
2025-11-24 08:57:28.792614 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-11-24 08:57:28.821016 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.029)       0:00:01.609 *******
2025-11-24 08:57:28.821072 | controller | skipping: [instance]
2025-11-24 08:57:28.821098 | controller |
2025-11-24 08:57:28.821128 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-11-24 08:57:28.821247 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.028)       0:00:01.638 *******
2025-11-24 08:57:28.853732 | controller | skipping: [instance]
2025-11-24 08:57:28.853801 | controller |
2025-11-24 08:57:28.853863 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] *****
2025-11-24 08:57:28.853984 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.032)       0:00:01.671 *******
2025-11-24 08:57:28.893286 | controller | ok: [instance]
2025-11-24 08:57:28.893371 | controller |
2025-11-24 08:57:28.893525 | controller | TASK [ci_multus : Merge any available multus net info patches] *****************
2025-11-24 08:57:28.893675 | controller | Monday 24 November 2025  08:57:28 +0000 (0:00:00.039)       0:00:01.711 *******
2025-11-24 08:57:29.008803 | 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-11-24 08:57:29.008844 | controller | skipping: [instance]
2025-11-24 08:57:29.008997 | controller |
2025-11-24 08:57:29.009156 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] *******
2025-11-24 08:57:29.009339 | controller | Monday 24 November 2025  08:57:29 +0000 (0:00:00.115)       0:00:01.826 *******
2025-11-24 08:57:29.090843 | controller | ok: [instance]
2025-11-24 08:57:29.090924 | controller |
2025-11-24 08:57:29.091006 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] ***
2025-11-24 08:57:29.091113 | controller | Monday 24 November 2025  08:57:29 +0000 (0:00:00.082)       0:00:01.908 *******
2025-11-24 08:57:29.174781 | controller | ok: [instance]
2025-11-24 08:57:29.175220 | controller |
2025-11-24 08:57:29.175367 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] ***
2025-11-24 08:57:29.175492 | controller | Monday 24 November 2025  08:57:29 +0000 (0:00:00.083)       0:00:01.992 *******
2025-11-24 08:57:29.251924 | controller | ok: [instance]
2025-11-24 08:57:29.251982 | controller |
2025-11-24 08:57:29.252098 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] ***************
2025-11-24 08:57:29.252230 | controller | Monday 24 November 2025  08:57:29 +0000 (0:00:00.077)       0:00:02.069 *******
2025-11-24 08:57:30.014474 | controller | changed: [instance]
2025-11-24 08:57:30.014515 | controller |
2025-11-24 08:57:30.014622 | controller | TASK [ci_multus : Create the multus namespace] *********************************
2025-11-24 08:57:30.014762 | controller | Monday 24 November 2025  08:57:30 +0000 (0:00:00.762)       0:00:02.832 *******
2025-11-24 08:57:30.034993 | controller | skipping: [instance]
2025-11-24 08:57:30.108069 | controller |
2025-11-24 08:57:30.108162 | controller | TASK [ci_multus : Apply network attachment definition manifests] ***************
2025-11-24 08:57:30.108174 | controller | Monday 24 November 2025  08:57:30 +0000 (0:00:00.020)       0:00:02.852 *******
2025-11-24 08:57:30.108222 | controller | skipping: [instance]
2025-11-24 08:57:30.108435 | controller |
2025-11-24 08:57:30.108471 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:30.109022 | controller | instance                   : ok=8    changed=2    unreachable=0    failed=0    skipped=7    rescued=0    ignored=0
2025-11-24 08:57:30.109067 | controller |
2025-11-24 08:57:30.109080 | controller | Monday 24 November 2025  08:57:30 +0000 (0:00:00.073)       0:00:02.926 *******
2025-11-24 08:57:30.109186 | controller | ===============================================================================
2025-11-24 08:57:30.109201 | controller | Gathering Facts --------------------------------------------------------- 1.05s
2025-11-24 08:57:30.109210 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.76s
2025-11-24 08:57:30.109217 | controller | ci_multus : Create manifests directory ---------------------------------- 0.41s
2025-11-24 08:57:30.109229 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.12s
2025-11-24 08:57:30.109337 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.08s
2025-11-24 08:57:30.109459 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.08s
2025-11-24 08:57:30.109546 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.08s
2025-11-24 08:57:30.109651 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.07s
2025-11-24 08:57:30.109785 | controller | Call ci_multus role ----------------------------------------------------- 0.05s
2025-11-24 08:57:30.109882 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.04s
2025-11-24 08:57:30.110021 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.03s
2025-11-24 08:57:30.110098 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s
2025-11-24 08:57:30.110191 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s
2025-11-24 08:57:30.110311 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.03s
2025-11-24 08:57:30.110394 | controller | Load shared variables --------------------------------------------------- 0.03s
2025-11-24 08:57:30.110496 | controller | ci_multus : Create the multus namespace --------------------------------- 0.02s
2025-11-24 08:57:30.211335 | controller | INFO     Running local_ipv6 > verify
2025-11-24 08:57:30.211575 | controller | INFO     Running Ansible Verifier
2025-11-24 08:57:30.757248 | controller |
2025-11-24 08:57:30.757322 | controller | PLAY [Verify] ******************************************************************
2025-11-24 08:57:30.757469 | controller |
2025-11-24 08:57:30.757606 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:30.757744 | controller | Monday 24 November 2025  08:57:30 +0000 (0:00:00.018)       0:00:00.018 *******
2025-11-24 08:57:31.775117 | controller | ok: [instance]
2025-11-24 08:57:31.775260 | controller |
2025-11-24 08:57:31.775468 | controller | TASK [Load shared variables] ***************************************************
2025-11-24 08:57:31.775733 | controller | Monday 24 November 2025  08:57:31 +0000 (0:00:01.017)       0:00:01.036 *******
2025-11-24 08:57:31.802598 | controller | ok: [instance]
2025-11-24 08:57:31.802748 | controller |
2025-11-24 08:57:31.802990 | controller | TASK [Fetch files stat results] ************************************************
2025-11-24 08:57:31.803181 | controller | Monday 24 November 2025  08:57:31 +0000 (0:00:00.027)       0:00:01.063 *******
2025-11-24 08:57:32.173217 | controller | ok: [instance]
2025-11-24 08:57:32.173291 | controller |
2025-11-24 08:57:32.173452 | controller | TASK [Assert that expected file exist] *****************************************
2025-11-24 08:57:32.173599 | controller | Monday 24 November 2025  08:57:32 +0000 (0:00:00.371)       0:00:01.435 *******
2025-11-24 08:57:32.197531 | controller | ok: [instance] => changed=false
2025-11-24 08:57:32.197626 | controller |   msg: All assertions passed
2025-11-24 08:57:32.197766 | controller |
2025-11-24 08:57:32.197918 | controller | TASK [Fetch file content] ******************************************************
2025-11-24 08:57:32.198057 | controller | Monday 24 November 2025  08:57:32 +0000 (0:00:00.023)       0:00:01.459 *******
2025-11-24 08:57:32.526513 | controller | ok: [instance]
2025-11-24 08:57:32.526623 | controller |
2025-11-24 08:57:32.526870 | controller | TASK [Set _ci_multus_nad variable] *********************************************
2025-11-24 08:57:32.527044 | controller | Monday 24 November 2025  08:57:32 +0000 (0:00:00.329)       0:00:01.788 *******
2025-11-24 08:57:32.561327 | controller | ok: [instance]
2025-11-24 08:57:32.561435 | controller |
2025-11-24 08:57:32.561604 | controller | TASK [Assert expected number of Network Attachment Definitions are created] ****
2025-11-24 08:57:32.561840 | controller | Monday 24 November 2025  08:57:32 +0000 (0:00:00.034)       0:00:01.822 *******
2025-11-24 08:57:32.629401 | controller | ok: [instance]
2025-11-24 08:57:32.629468 | controller |
2025-11-24 08:57:32.629547 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:32.629662 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:32.629860 | controller |
2025-11-24 08:57:32.629885 | controller | Monday 24 November 2025  08:57:32 +0000 (0:00:00.069)       0:00:01.891 *******
2025-11-24 08:57:32.630025 | controller | ===============================================================================
2025-11-24 08:57:32.630115 | controller | Gathering Facts --------------------------------------------------------- 1.02s
2025-11-24 08:57:32.630207 | controller | Fetch files stat results ------------------------------------------------ 0.37s
2025-11-24 08:57:32.630301 | controller | Fetch file content ------------------------------------------------------ 0.33s
2025-11-24 08:57:32.630400 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.07s
2025-11-24 08:57:32.630530 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.03s
2025-11-24 08:57:32.630637 | controller | Load shared variables --------------------------------------------------- 0.03s
2025-11-24 08:57:32.630787 | controller | Assert that expected file exist ----------------------------------------- 0.02s
2025-11-24 08:57:32.699634 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:32.709954 | controller | INFO     Running local_ipv6 > side_effect
2025-11-24 08:57:33.233120 | controller |
2025-11-24 08:57:33.233220 | controller | PLAY [Clean] *******************************************************************
2025-11-24 08:57:33.233333 | controller |
2025-11-24 08:57:33.233357 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:33.233463 | controller | Monday 24 November 2025  08:57:33 +0000 (0:00:00.016)       0:00:00.016 *******
2025-11-24 08:57:34.279560 | controller | ok: [instance]
2025-11-24 08:57:34.279693 | controller |
2025-11-24 08:57:34.279771 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] ****************
2025-11-24 08:57:34.279958 | controller | Monday 24 November 2025  08:57:34 +0000 (0:00:01.046)       0:00:01.063 *******
2025-11-24 08:57:34.670501 | controller | changed: [instance]
2025-11-24 08:57:34.670564 | controller |
2025-11-24 08:57:34.670581 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] ****************
2025-11-24 08:57:34.670599 | controller | Monday 24 November 2025  08:57:34 +0000 (0:00:00.390)       0:00:01.454 *******
2025-11-24 08:57:34.701370 | controller | skipping: [instance]
2025-11-24 08:57:34.733228 | controller |
2025-11-24 08:57:34.733264 | controller | TASK [ci_multus : Cleanup - Delete NADs] ***************************************
2025-11-24 08:57:34.733275 | controller | Monday 24 November 2025  08:57:34 +0000 (0:00:00.029)       0:00:01.483 *******
2025-11-24 08:57:34.733288 | controller | skipping: [instance]
2025-11-24 08:57:35.118227 | controller |
2025-11-24 08:57:35.118278 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] ***************
2025-11-24 08:57:35.118287 | controller | Monday 24 November 2025  08:57:34 +0000 (0:00:00.033)       0:00:01.516 *******
2025-11-24 08:57:35.118297 | controller | changed: [instance]
2025-11-24 08:57:35.118319 | controller |
2025-11-24 08:57:35.118592 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:35.118934 | controller | instance                   : ok=3    changed=2    unreachable=0    failed=0    skipped=2    rescued=0    ignored=0
2025-11-24 08:57:35.119169 | controller |
2025-11-24 08:57:35.119413 | controller | Monday 24 November 2025  08:57:35 +0000 (0:00:00.385)       0:00:01.902 *******
2025-11-24 08:57:35.119711 | controller | ===============================================================================
2025-11-24 08:57:35.120077 | controller | Gathering Facts --------------------------------------------------------- 1.05s
2025-11-24 08:57:35.120419 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.39s
2025-11-24 08:57:35.120657 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.39s
2025-11-24 08:57:35.120966 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 0.03s
2025-11-24 08:57:35.121427 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.03s
2025-11-24 08:57:35.192373 | controller | INFO     Running local_ipv6 > verify
2025-11-24 08:57:35.192641 | controller | INFO     Running Ansible Verifier
2025-11-24 08:57:35.724869 | controller |
2025-11-24 08:57:35.725045 | controller | PLAY [Verify Clean] ************************************************************
2025-11-24 08:57:35.725290 | controller |
2025-11-24 08:57:35.725624 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:57:35.725914 | controller | Monday 24 November 2025  08:57:35 +0000 (0:00:00.017)       0:00:00.017 *******
2025-11-24 08:57:36.795926 | controller | ok: [instance]
2025-11-24 08:57:36.796011 | controller |
2025-11-24 08:57:36.796108 | controller | TASK [Include default vars] ****************************************************
2025-11-24 08:57:36.796142 | controller | Monday 24 November 2025  08:57:36 +0000 (0:00:01.071)       0:00:01.088 *******
2025-11-24 08:57:36.821864 | controller | ok: [instance]
2025-11-24 08:57:36.821967 | controller |
2025-11-24 08:57:36.821999 | controller | TASK [Fetch file stat results] *************************************************
2025-11-24 08:57:36.822011 | controller | Monday 24 November 2025  08:57:36 +0000 (0:00:00.025)       0:00:01.114 *******
2025-11-24 08:57:37.227297 | controller | ok: [instance]
2025-11-24 08:57:37.227813 | controller |
2025-11-24 08:57:37.227835 | controller | TASK [Assert that created file are removed by cleanup] *************************
2025-11-24 08:57:37.227974 | controller | Monday 24 November 2025  08:57:37 +0000 (0:00:00.404)       0:00:01.519 *******
2025-11-24 08:57:37.281900 | controller | ok: [instance] => changed=false
2025-11-24 08:57:37.281946 | controller |   msg: All assertions passed
2025-11-24 08:57:37.281957 | controller |
2025-11-24 08:57:37.281972 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:57:37.281981 | controller | instance                   : ok=4    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:57:37.281989 | controller |
2025-11-24 08:57:37.281997 | controller | Monday 24 November 2025  08:57:37 +0000 (0:00:00.054)       0:00:01.574 *******
2025-11-24 08:57:37.282006 | controller | ===============================================================================
2025-11-24 08:57:37.282014 | controller | Gathering Facts --------------------------------------------------------- 1.07s
2025-11-24 08:57:37.282021 | controller | Fetch file stat results ------------------------------------------------- 0.40s
2025-11-24 08:57:37.282029 | controller | Assert that created file are removed by cleanup ------------------------- 0.05s
2025-11-24 08:57:37.282041 | controller | Include default vars ---------------------------------------------------- 0.03s
2025-11-24 08:57:37.347832 | controller | INFO     Verifier completed successfully.
2025-11-24 08:57:37.348688 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-11-24 08:57:37.352568 | controller | INFO     Writing /tmp/report.html report.
2025-11-24 08:57:37.533412 | controller | changed
2025-11-24 08:57:37.588717 | 
2025-11-24 08:57:37.588856 | PLAY RECAP
2025-11-24 08:57:37.588907 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:57:37.588935 | 
2025-11-24 08:57:37.704702 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-11-24 08:57:37.705746 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-11-24 08:57:38.330931 | 
2025-11-24 08:57:38.331157 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-11-24 08:57:38.354094 | 
2025-11-24 08:57:38.354195 | TASK [Filter out host if needed]
2025-11-24 08:57:38.363801 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-11-24 08:57:38.368742 | 
2025-11-24 08:57:38.368808 | TASK [Ensure file is present]
2025-11-24 08:57:38.898437 | controller | ok
2025-11-24 08:57:38.917639 | 
2025-11-24 08:57:38.918168 | TASK [Manage molecule report file]
2025-11-24 08:57:39.976613 | controller | changed
2025-11-24 08:57:39.988843 | 
2025-11-24 08:57:39.989002 | TASK [Check if we get ci-framework-data basedir]
2025-11-24 08:57:40.376871 | controller | ok
2025-11-24 08:57:40.391018 | 
2025-11-24 08:57:40.391326 | TASK [Create ci-framework-data log directory for zuul]
2025-11-24 08:57:40.945973 | controller | changed
2025-11-24 08:57:40.959857 | 
2025-11-24 08:57:40.959974 | TASK [Copy ci-framework interesting files]
2025-11-24 08:57:41.354332 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-11-24 08:57:41.498016 | controller | changed
2025-11-24 08:57:41.509058 | 
2025-11-24 08:57:41.509292 | TASK [Get SELinux listing]
2025-11-24 08:57:42.074054 | controller | changed
2025-11-24 08:57:42.088196 | 
2025-11-24 08:57:42.088373 | TASK [Generate log index]
2025-11-24 08:57:43.693288 | controller | changed
2025-11-24 08:57:43.701261 | 
2025-11-24 08:57:43.701366 | TASK [Get some env related data]
2025-11-24 08:57:44.471344 | controller | /home/zuul/.local/bin/ansible
2025-11-24 08:57:45.238195 | controller | changed
2025-11-24 08:57:45.303663 | 
2025-11-24 08:57:45.303901 | TASK [Generate list of logs to collect in home directory]
2025-11-24 08:57:45.760502 | controller | ok: All paths examined
2025-11-24 08:57:45.776545 | 
2025-11-24 08:57:45.776745 | LOOP [Copy logs from home directory]
2025-11-24 08:57:46.534501 | controller | changed:
2025-11-24 08:57:46.534771 | controller | {
2025-11-24 08:57:46.534812 | controller |   "atime": 1743544925.4788878,
2025-11-24 08:57:46.534831 | controller |   "ctime": 1743545329.1409318,
2025-11-24 08:57:46.534848 | controller |   "dev": 64513,
2025-11-24 08:57:46.534864 | controller |   "gid": 1000,
2025-11-24 08:57:46.534880 | controller |   "gr_name": "zuul",
2025-11-24 08:57:46.534896 | controller |   "inode": 4518807,
2025-11-24 08:57:46.534912 | controller |   "isblk": false,
2025-11-24 08:57:46.534926 | controller |   "ischr": false,
2025-11-24 08:57:46.534941 | controller |   "isdir": false,
2025-11-24 08:57:46.534956 | controller |   "isfifo": false,
2025-11-24 08:57:46.534971 | controller |   "isgid": false,
2025-11-24 08:57:46.534986 | controller |   "islnk": false,
2025-11-24 08:57:46.535000 | controller |   "isreg": true,
2025-11-24 08:57:46.535015 | controller |   "issock": false,
2025-11-24 08:57:46.535030 | controller |   "isuid": false,
2025-11-24 08:57:46.535044 | controller |   "mode": "0644",
2025-11-24 08:57:46.535058 | controller |   "mtime": 1743545329.1409318,
2025-11-24 08:57:46.535073 | controller |   "nlink": 1,
2025-11-24 08:57:46.535088 | controller |   "path": "/home/zuul/crc-setup.log",
2025-11-24 08:57:46.535104 | controller |   "pw_name": "zuul",
2025-11-24 08:57:46.535120 | controller |   "rgrp": true,
2025-11-24 08:57:46.535135 | controller |   "roth": true,
2025-11-24 08:57:46.535151 | controller |   "rusr": true,
2025-11-24 08:57:46.535167 | controller |   "size": 4108,
2025-11-24 08:57:46.535187 | controller |   "uid": 1000,
2025-11-24 08:57:46.535207 | controller |   "wgrp": false,
2025-11-24 08:57:46.535226 | controller |   "woth": false,
2025-11-24 08:57:46.535244 | controller |   "wusr": true,
2025-11-24 08:57:46.535260 | controller |   "xgrp": false,
2025-11-24 08:57:46.535276 | controller |   "xoth": false,
2025-11-24 08:57:46.535290 | controller |   "xusr": false
2025-11-24 08:57:46.535305 | controller | }
2025-11-24 08:57:47.402729 | controller | changed:
2025-11-24 08:57:47.403111 | controller | {
2025-11-24 08:57:47.403354 | controller |   "atime": 1763974040.1219635,
2025-11-24 08:57:47.403401 | controller |   "ctime": 1763974038.031913,
2025-11-24 08:57:47.403469 | controller |   "dev": 64513,
2025-11-24 08:57:47.403513 | controller |   "gid": 1000,
2025-11-24 08:57:47.403551 | controller |   "gr_name": "zuul",
2025-11-24 08:57:47.403589 | controller |   "inode": 4194437,
2025-11-24 08:57:47.403625 | controller |   "isblk": false,
2025-11-24 08:57:47.403660 | controller |   "ischr": false,
2025-11-24 08:57:47.403739 | controller |   "isdir": false,
2025-11-24 08:57:47.403781 | controller |   "isfifo": false,
2025-11-24 08:57:47.403818 | controller |   "isgid": false,
2025-11-24 08:57:47.403853 | controller |   "islnk": false,
2025-11-24 08:57:47.403889 | controller |   "isreg": true,
2025-11-24 08:57:47.403939 | controller |   "issock": false,
2025-11-24 08:57:47.403995 | controller |   "isuid": false,
2025-11-24 08:57:47.404052 | controller |   "mode": "0644",
2025-11-24 08:57:47.404093 | controller |   "mtime": 1763974038.031913,
2025-11-24 08:57:47.404130 | controller |   "nlink": 1,
2025-11-24 08:57:47.404167 | controller |   "path": "/home/zuul/crc-start.log",
2025-11-24 08:57:47.404204 | controller |   "pw_name": "zuul",
2025-11-24 08:57:47.404241 | controller |   "rgrp": true,
2025-11-24 08:57:47.404278 | controller |   "roth": true,
2025-11-24 08:57:47.404315 | controller |   "rusr": true,
2025-11-24 08:57:47.404352 | controller |   "size": 4395,
2025-11-24 08:57:47.404389 | controller |   "uid": 1000,
2025-11-24 08:57:47.404426 | controller |   "wgrp": false,
2025-11-24 08:57:47.404463 | controller |   "woth": false,
2025-11-24 08:57:47.404500 | controller |   "wusr": true,
2025-11-24 08:57:47.404537 | controller |   "xgrp": false,
2025-11-24 08:57:47.404573 | controller |   "xoth": false,
2025-11-24 08:57:47.404611 | controller |   "xusr": false
2025-11-24 08:57:47.404647 | controller | }
2025-11-24 08:57:48.167788 | controller | changed:
2025-11-24 08:57:48.167990 | controller | {
2025-11-24 08:57:48.168069 | controller |   "atime": 1763974549.1581514,
2025-11-24 08:57:48.168118 | controller |   "ctime": 1763974592.1231363,
2025-11-24 08:57:48.168156 | controller |   "dev": 64513,
2025-11-24 08:57:48.168191 | controller |   "gid": 1000,
2025-11-24 08:57:48.168226 | controller |   "gr_name": "zuul",
2025-11-24 08:57:48.168260 | controller |   "inode": 4685819,
2025-11-24 08:57:48.168293 | controller |   "isblk": false,
2025-11-24 08:57:48.168326 | controller |   "ischr": false,
2025-11-24 08:57:48.168359 | controller |   "isdir": false,
2025-11-24 08:57:48.168392 | controller |   "isfifo": false,
2025-11-24 08:57:48.168426 | controller |   "isgid": false,
2025-11-24 08:57:48.168459 | controller |   "islnk": false,
2025-11-24 08:57:48.168494 | controller |   "isreg": true,
2025-11-24 08:57:48.168530 | controller |   "issock": false,
2025-11-24 08:57:48.168565 | controller |   "isuid": false,
2025-11-24 08:57:48.168599 | controller |   "mode": "0644",
2025-11-24 08:57:48.168634 | controller |   "mtime": 1763974592.1231363,
2025-11-24 08:57:48.168669 | controller |   "nlink": 1,
2025-11-24 08:57:48.168748 | controller |   "path": "/home/zuul/ansible.log",
2025-11-24 08:57:48.168786 | controller |   "pw_name": "zuul",
2025-11-24 08:57:48.168823 | controller |   "rgrp": true,
2025-11-24 08:57:48.168858 | controller |   "roth": true,
2025-11-24 08:57:48.168899 | controller |   "rusr": true,
2025-11-24 08:57:48.168968 | controller |   "size": 6701,
2025-11-24 08:57:48.169009 | controller |   "uid": 1000,
2025-11-24 08:57:48.169060 | controller |   "wgrp": false,
2025-11-24 08:57:48.169104 | controller |   "woth": false,
2025-11-24 08:57:48.169139 | controller |   "wusr": true,
2025-11-24 08:57:48.169173 | controller |   "xgrp": false,
2025-11-24 08:57:48.169207 | controller |   "xoth": false,
2025-11-24 08:57:48.169240 | controller |   "xusr": false
2025-11-24 08:57:48.169273 | controller | }
2025-11-24 08:57:48.195275 | 
2025-11-24 08:57:48.195506 | TASK [Copy crio stats log file]
2025-11-24 08:57:48.234846 | controller | skipping: Conditional result was False
2025-11-24 08:57:48.248845 | 
2025-11-24 08:57:48.248994 | TASK [Get SELinux related data]
2025-11-24 08:57:48.636689 | controller | <no matches>
2025-11-24 08:57:48.792945 | controller | ERROR
2025-11-24 08:57:48.793177 | controller | {
2025-11-24 08:57:48.793241 | controller |   "delta": "0:00:00.014468",
2025-11-24 08:57:48.793286 | controller |   "end": "2025-11-24 08:57:48.638218",
2025-11-24 08:57:48.793329 | controller |   "msg": "non-zero return code",
2025-11-24 08:57:48.793368 | controller |   "rc": 1,
2025-11-24 08:57:48.793408 | controller |   "start": "2025-11-24 08:57:48.623750"
2025-11-24 08:57:48.793445 | controller | }
2025-11-24 08:57:48.793494 | controller | ERROR: Ignoring Errors
2025-11-24 08:57:48.805771 | 
2025-11-24 08:57:48.805906 | TASK [Create system configuration directory]
2025-11-24 08:57:49.220025 | controller | changed
2025-11-24 08:57:49.227524 | 
2025-11-24 08:57:49.227615 | TASK [Get some of the system configurations]
2025-11-24 08:57:49.768163 | controller | changed
2025-11-24 08:57:49.780994 | 
2025-11-24 08:57:49.781126 | TASK [Copy generated documentation if available]
2025-11-24 08:57:49.809438 | controller | skipping: Conditional result was False
2025-11-24 08:57:49.823764 | 
2025-11-24 08:57:49.823951 | TASK [Copy generated AsciiDoc documentation if available]
2025-11-24 08:57:49.853282 | controller | skipping: Conditional result was False
2025-11-24 08:57:49.867257 | 
2025-11-24 08:57:49.867399 | TASK [Compress logs bigger than 2MB]
2025-11-24 08:57:50.418263 | controller | changed
2025-11-24 08:57:50.432905 | 
2025-11-24 08:57:50.433177 | TASK [Copy files from workspace on node]
2025-11-24 08:57:50.466198 | controller | ok
2025-11-24 08:57:50.511631 | 
2025-11-24 08:57:50.511833 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:57:50.548773 | controller | skipping: Conditional result was False
2025-11-24 08:57:50.563273 | 
2025-11-24 08:57:50.563428 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:57:50.615259 | controller | ok
2025-11-24 08:57:50.627609 | 
2025-11-24 08:57:50.627805 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:57:50.903009 | controller -> localhost | ok: "/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/logs"
2025-11-24 08:57:50.903526 | controller -> localhost | changed: All items complete
2025-11-24 08:57:50.903585 | 
2025-11-24 08:57:51.180549 | controller -> localhost | changed: "/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/artifacts"
2025-11-24 08:57:51.418028 | controller -> localhost | changed: "/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/docs"
2025-11-24 08:57:51.441099 | 
2025-11-24 08:57:51.441247 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:57:52.315176 | controller | changed:
2025-11-24 08:57:52.315530 | controller | .d..t...... ./
2025-11-24 08:57:52.315588 | controller | >f+++++++++ README.html
2025-11-24 08:57:52.315631 | controller | >f+++++++++ ansible-execution.log
2025-11-24 08:57:52.315672 | controller | >f+++++++++ ansible.log
2025-11-24 08:57:52.315830 | controller | >f+++++++++ crc-setup.log
2025-11-24 08:57:52.315910 | controller | >f+++++++++ crc-start.log
2025-11-24 08:57:52.316046 | controller | >f+++++++++ dmesg.log
2025-11-24 08:57:52.316129 | controller | >f+++++++++ installed-pkgs.log
2025-11-24 08:57:52.316178 | controller | >f+++++++++ python.log
2025-11-24 08:57:52.316217 | controller | >f+++++++++ registries.conf
2025-11-24 08:57:52.316255 | controller | >f+++++++++ report.html
2025-11-24 08:57:52.316291 | controller | >f+++++++++ selinux-denials.log
2025-11-24 08:57:52.316326 | controller | >f+++++++++ selinux-listing.log
2025-11-24 08:57:52.316362 | controller | cd+++++++++ ci-framework-data/
2025-11-24 08:57:52.316398 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-11-24 08:57:52.316433 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-11-24 08:57:52.316469 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/
2025-11-24 08:57:52.316505 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/
2025-11-24 08:57:52.316541 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ci_multus/
2025-11-24 08:57:52.316577 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ci_multus/ci_multus_nads.yml
2025-11-24 08:57:52.316613 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-11-24 08:57:52.316650 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-11-24 08:57:52.316798 | controller | cd+++++++++ ci-framework-data/logs/
2025-11-24 08:57:52.316845 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-11-24 08:57:52.316882 | controller | cd+++++++++ registries.conf.d/
2025-11-24 08:57:52.316919 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-11-24 08:57:52.316955 | controller | cd+++++++++ system-config/
2025-11-24 08:57:52.316990 | controller | cd+++++++++ system-config/libvirt/
2025-11-24 08:57:52.317025 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-11-24 08:57:52.317061 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-11-24 08:57:52.317096 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-11-24 08:57:52.317131 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-11-24 08:57:52.317166 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-11-24 08:57:52.317201 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-11-24 08:57:52.317235 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-11-24 08:57:52.317269 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-11-24 08:57:52.317303 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-11-24 08:57:52.317337 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-11-24 08:57:52.317372 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-11-24 08:57:52.317418 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-11-24 08:57:52.317454 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-11-24 08:57:52.317489 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-11-24 08:57:52.317524 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-11-24 08:57:52.317559 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-11-24 08:57:52.993523 | controller | changed: .d..t...... ./
2025-11-24 08:57:53.583554 | controller | changed: .d..t...... ./
2025-11-24 08:57:53.606737 | 
2025-11-24 08:57:53.606907 | TASK [Return artifact to Zuul]
2025-11-24 08:57:53.662723 | controller | ok
2025-11-24 08:57:53.690888 | 
2025-11-24 08:57:53.690976 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-11-24 08:57:53.691129 | 
2025-11-24 08:57:53.691175 | PLAY RECAP
2025-11-24 08:57:53.691238 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-11-24 08:57:53.691274 | 
2025-11-24 08:57:53.853211 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-11-24 08:57:53.854185 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master]
2025-11-24 08:57:54.459055 | 
2025-11-24 08:57:54.459311 | PLAY [Report DLRN results after job run]
2025-11-24 08:57:54.480929 | 
2025-11-24 08:57:54.481066 | TASK [Report job status to DLRN]
2025-11-24 08:57:54.512125 | controller | ok
2025-11-24 08:57:54.539602 | 
2025-11-24 08:57:54.539771 | TASK [dlrn_report : Warning if DLRN is not running]
2025-11-24 08:57:54.584738 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.591167 | 
2025-11-24 08:57:54.591246 | TASK [dlrn_report : Install dlrnapi-client shyaml package]
2025-11-24 08:57:54.636055 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.649899 | 
2025-11-24 08:57:54.650057 | TASK [dlrn_report : Install kinit related package]
2025-11-24 08:57:54.695758 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.702630 | 
2025-11-24 08:57:54.702729 | TASK [dlrn_report : Install dlrn kerberos related packages]
2025-11-24 08:57:54.747064 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.754130 | 
2025-11-24 08:57:54.754236 | TASK [Set zuul-log-path fact]
2025-11-24 08:57:54.801115 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.807913 | 
2025-11-24 08:57:54.808002 | TASK [dlrn_report : Set the the value of cifmw_repo_setup_promotion when multiple dlrn tags are used]
2025-11-24 08:57:54.852991 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.859784 | 
2025-11-24 08:57:54.859874 | TASK [Get hash related data from repo_setup role]
2025-11-24 08:57:54.904259 | controller | skipping: Conditional result was False
2025-11-24 08:57:54.918552 | 
2025-11-24 08:57:54.918757 | TASK [dlrn_report : Perform kinit for DLRN kerberos authentication]
2025-11-24 08:57:55.469054 | controller | skipping: Conditional result was False
2025-11-24 08:57:55.483258 | 
2025-11-24 08:57:55.483456 | TASK [dlrn_report : Set empty value for dlrnapi password]
2025-11-24 08:57:55.541660 | controller | skipping: Conditional result was False
2025-11-24 08:57:55.551020 | 
2025-11-24 08:57:55.551137 | TASK [dlrn_report : Report results to dlrn for the tested hash]
2025-11-24 08:57:56.094476 | controller | skipping: Conditional result was False
2025-11-24 08:57:56.149441 | 
2025-11-24 08:57:56.149605 | PLAY RECAP
2025-11-24 08:57:56.149673 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 10 rescued: 0 ignored: 0
2025-11-24 08:57:56.149730 | 
2025-11-24 08:57:56.275610 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master]
2025-11-24 08:57:56.276503 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:57:56.924435 | 
2025-11-24 08:57:56.924571 | PLAY [all]
2025-11-24 08:57:56.944049 | 
2025-11-24 08:57:56.944224 | TASK [include_role : fetch-output]
2025-11-24 08:57:56.975264 | controller | ok
2025-11-24 08:57:56.993631 | 
2025-11-24 08:57:56.993731 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:57:57.059517 | controller | skipping: Conditional result was False
2025-11-24 08:57:57.065926 | 
2025-11-24 08:57:57.066003 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:57:57.105438 | controller | ok
2025-11-24 08:57:57.110603 | 
2025-11-24 08:57:57.110667 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:57:57.545311 | controller -> localhost | ok: "/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/logs"
2025-11-24 08:57:57.756514 | controller -> localhost | ok: "/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/artifacts"
2025-11-24 08:57:57.964563 | controller -> localhost | ok: "/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/docs"
2025-11-24 08:57:57.977905 | 
2025-11-24 08:57:57.978033 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:57:58.786368 | controller | ok
2025-11-24 08:57:58.786938 | controller | ok: All items complete
2025-11-24 08:57:58.787011 | 
2025-11-24 08:57:59.412046 | controller | ok
2025-11-24 08:58:00.026548 | controller | ok
2025-11-24 08:58:00.060398 | 
2025-11-24 08:58:00.060586 | TASK [include_role : fetch-output-openshift]
2025-11-24 08:58:00.088944 | controller | skipping: Conditional result was False
2025-11-24 08:58:00.103334 | 
2025-11-24 08:58:00.103482 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-24 08:58:00.600393 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013680
2025-11-24 08:58:00.895443 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014108
2025-11-24 08:58:00.923795 | 
2025-11-24 08:58:00.923877 | PLAY [all]
2025-11-24 08:58:00.945883 | 
2025-11-24 08:58:00.946064 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-11-24 08:58:01.585217 | controller | changed
2025-11-24 08:58:01.631951 | 
2025-11-24 08:58:01.632061 | PLAY RECAP
2025-11-24 08:58:01.632116 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 08:58:01.632144 | 
2025-11-24 08:58:01.753893 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:58:01.754800 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-11-24 08:58:02.420908 | 
2025-11-24 08:58:02.421147 | PLAY [localhost]
2025-11-24 08:58:02.439569 | 
2025-11-24 08:58:02.439707 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-24 08:58:02.880922 | localhost | changed
2025-11-24 08:58:02.893233 | 
2025-11-24 08:58:02.893410 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-24 08:58:02.930803 | localhost | ok
2025-11-24 08:58:02.949518 | 
2025-11-24 08:58:02.949665 | TASK [add-fileserver : Create SSH private key tempfile]
2025-11-24 08:58:03.384102 | localhost | changed
2025-11-24 08:58:03.391552 | 
2025-11-24 08:58:03.391707 | TASK [add-fileserver : Create SSH private key from secret]
2025-11-24 08:58:04.198089 | localhost | changed
2025-11-24 08:58:04.203600 | 
2025-11-24 08:58:04.203700 | TASK [add-fileserver : Add fileserver ssh key]
2025-11-24 08:58:04.711240 | localhost | Identity added: /var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/tmp/ansible.nrttm31a (/var/lib/zuul/builds/73460b62a45f402b9c79057064b21881/work/tmp/ansible.nrttm31a)
2025-11-24 08:58:04.711604 | localhost | ok: Runtime: 0:00:00.014734
2025-11-24 08:58:04.722350 | 
2025-11-24 08:58:04.722519 | TASK [add-fileserver : Remove SSH private key from disk]
2025-11-24 08:58:05.045483 | localhost | ok: Runtime: 0:00:00.006870
2025-11-24 08:58:05.052476 | 
2025-11-24 08:58:05.052567 | TASK [add-fileserver : Add fileserver to inventory]
2025-11-24 08:58:05.118974 | localhost | changed
2025-11-24 08:58:05.128625 | 
2025-11-24 08:58:05.128803 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-11-24 08:58:05.588911 | localhost | changed
2025-11-24 08:58:05.610482 | 
2025-11-24 08:58:05.610550 | PLAY [localhost]
2025-11-24 08:58:05.623203 | 
2025-11-24 08:58:05.623269 | TASK [Generate bulk log download script]
2025-11-24 08:58:05.649128 | localhost | ok
2025-11-24 08:58:05.674732 | 
2025-11-24 08:58:05.674901 | TASK [local-log-download : Check API endpoint is defined]
2025-11-24 08:58:05.706240 | localhost | ok: All assertions passed
2025-11-24 08:58:05.713309 | 
2025-11-24 08:58:05.713409 | TASK [local-log-download : Create download script]
2025-11-24 08:58:06.200541 | localhost -> localhost | changed
2025-11-24 08:58:06.232582 | 
2025-11-24 08:58:06.232872 | TASK [Register quick-download link]
2025-11-24 08:58:06.309580 | localhost | ok
2025-11-24 08:58:06.330813 | 
2025-11-24 08:58:06.330969 | PLAY [logserver.rdoproject.org]
2025-11-24 08:58:06.340981 | 
2025-11-24 08:58:06.341044 | TASK [Set zuul-log-path fact]
2025-11-24 08:58:06.369301 | logserver.rdoproject.org | ok
2025-11-24 08:58:06.382064 | 
2025-11-24 08:58:06.382191 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:58:06.421901 | logserver.rdoproject.org | ok
2025-11-24 08:58:06.429586 | 
2025-11-24 08:58:06.429674 | TASK [upload-logs : Create log directories]
2025-11-24 08:58:07.312256 | logserver.rdoproject.org | changed
2025-11-24 08:58:07.320353 | 
2025-11-24 08:58:07.320482 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-11-24 08:58:07.692612 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008206
2025-11-24 08:58:07.698610 | 
2025-11-24 08:58:07.698713 | TASK [upload-logs : Upload logs to log server]
2025-11-24 08:58:08.493439 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-11-24 08:58:08.506377 | 
2025-11-24 08:58:08.506579 | LOOP [upload-logs : Compress console log and json output]
2025-11-24 08:58:08.553550 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:08.562238 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:08.574327 | 
2025-11-24 08:58:08.574577 | LOOP [upload-logs : Upload compressed console log and json output]
2025-11-24 08:58:08.619489 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:08.619968 | 
2025-11-24 08:58:08.621854 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:08.632014 | 
2025-11-24 08:58:08.632301 | LOOP [upload-logs : Upload console log and json output]