2025-12-10 13:44:27.233857 | Job console starting...
2025-12-10 13:44:27.445690 | Updating repositories
2025-12-10 13:44:28.170024 | Preparing job workspace
2025-12-10 13:44:34.954436 | Running Ansible setup...
2025-12-10 13:44:37.589672 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-10 13:44:38.090718 | 
2025-12-10 13:44:38.090841 | PLAY [localhost]
2025-12-10 13:44:38.099064 | 
2025-12-10 13:44:38.099131 | TASK [Gathering Facts]
2025-12-10 13:44:38.866070 | localhost | ok
2025-12-10 13:44:38.879425 | 
2025-12-10 13:44:38.879506 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-10 13:44:39.176222 | localhost -> localhost | changed
2025-12-10 13:44:39.181416 | 
2025-12-10 13:44:39.181495 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-10 13:44:39.811809 | localhost -> localhost | changed
2025-12-10 13:44:39.819541 | 
2025-12-10 13:44:39.819633 | TASK [Setup log path fact]
2025-12-10 13:44:39.836584 | localhost | ok
2025-12-10 13:44:39.846687 | 
2025-12-10 13:44:39.846752 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-10 13:44:39.863822 | localhost | ok
2025-12-10 13:44:39.870521 | 
2025-12-10 13:44:39.870588 | TASK [emit-job-header : Print job information]
2025-12-10 13:44:39.896943 | # Job Information
2025-12-10 13:44:39.897059 | Ansible Version: 2.15.12
2025-12-10 13:44:39.897088 | Job: cifmw-molecule-nat64_appliance
2025-12-10 13:44:39.897110 | Pipeline: github-check
2025-12-10 13:44:39.897130 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-12-10 13:44:39.897149 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3545
2025-12-10 13:44:39.897168 | Log URL (when completed): https://logserver.rdoproject.org/b47/rdoproject.org/b4749d56795e4be2a1ab589ee9b170a5/
2025-12-10 13:44:39.897187 | Event ID: 37295400-d5ce-11f0-9a96-d576850b8605
2025-12-10 13:44:39.900766 | 
2025-12-10 13:44:39.900824 | LOOP [emit-job-header : Print node information]
2025-12-10 13:44:39.977627 | localhost | ok:
2025-12-10 13:44:39.977818 | localhost | # Node Information
2025-12-10 13:44:39.977851 | localhost | Inventory Hostname: controller
2025-12-10 13:44:39.977877 | localhost | Hostname: np0005553710
2025-12-10 13:44:39.977898 | localhost | Username: zuul
2025-12-10 13:44:39.977944 | localhost | Distro: CentOS 9
2025-12-10 13:44:39.977966 | localhost | Provider: ibm-bm4-nodepool
2025-12-10 13:44:39.977987 | localhost | Region: regionOne
2025-12-10 13:44:39.978007 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-12-10 13:44:39.978026 | localhost | Product Name: OpenStack Compute
2025-12-10 13:44:39.978044 | localhost | Interface IP: 192.168.26.235
2025-12-10 13:44:40.001974 | 
2025-12-10 13:44:40.002043 | PLAY [all]
2025-12-10 13:44:40.008215 | 
2025-12-10 13:44:40.008277 | TASK [Gather network facts]
2025-12-10 13:44:40.331455 | controller | ok
2025-12-10 13:44:40.344863 | 
2025-12-10 13:44:40.344944 | TASK [include_role : start-zuul-console]
2025-12-10 13:44:40.362858 | controller | ok
2025-12-10 13:44:40.374583 | 
2025-12-10 13:44:40.374653 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-10 13:44:40.656233 | controller | ok
2025-12-10 13:44:40.664720 | 
2025-12-10 13:44:40.664779 | TASK [include_role : add-build-sshkey]
2025-12-10 13:44:40.682540 | controller | ok
2025-12-10 13:44:40.694670 | 
2025-12-10 13:44:40.694736 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-10 13:44:40.869933 | controller -> localhost | ok
2025-12-10 13:44:40.875211 | 
2025-12-10 13:44:40.875270 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-10 13:44:40.892867 | controller | ok
2025-12-10 13:44:40.905157 | controller | included: /var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-10 13:44:40.910186 | 
2025-12-10 13:44:40.910243 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-10 13:44:41.483332 | controller -> localhost | Generating public/private rsa key pair.
2025-12-10 13:44:41.483535 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/b4749d56795e4be2a1ab589ee9b170a5_id_rsa.
2025-12-10 13:44:41.483565 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/b4749d56795e4be2a1ab589ee9b170a5_id_rsa.pub.
2025-12-10 13:44:41.483587 | controller -> localhost | The key fingerprint is:
2025-12-10 13:44:41.483606 | controller -> localhost | SHA256:ULglLV0pbWtZDPWHFHNBpuG4LHtv8r92+6LnHWuOVAg zuul-build-sshkey
2025-12-10 13:44:41.483635 | controller -> localhost | The key's randomart image is:
2025-12-10 13:44:41.483654 | controller -> localhost | +---[RSA 3072]----+
2025-12-10 13:44:41.483671 | controller -> localhost | |       +.oo=..==o|
2025-12-10 13:44:41.483690 | controller -> localhost | |      +.= + =o++ |
2025-12-10 13:44:41.483707 | controller -> localhost | |      .= o E oo .|
2025-12-10 13:44:41.483724 | controller -> localhost | |      ..  = o .. |
2025-12-10 13:44:41.483740 | controller -> localhost | |        So o . . |
2025-12-10 13:44:41.483756 | controller -> localhost | |          o   .  |
2025-12-10 13:44:41.483772 | controller -> localhost | |         . . . . |
2025-12-10 13:44:41.483789 | controller -> localhost | |          ..o.+++|
2025-12-10 13:44:41.483805 | controller -> localhost | |            =B*BB|
2025-12-10 13:44:41.483822 | controller -> localhost | +----[SHA256]-----+
2025-12-10 13:44:41.483866 | controller -> localhost | ok: Runtime: 0:00:00.265068
2025-12-10 13:44:41.489118 | 
2025-12-10 13:44:41.489175 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-10 13:44:41.506576 | controller | ok
2025-12-10 13:44:41.515094 | controller | included: /var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-10 13:44:41.522212 | 
2025-12-10 13:44:41.522269 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-10 13:44:41.535413 | controller | skipping: Conditional result was False
2025-12-10 13:44:41.540331 | 
2025-12-10 13:44:41.540394 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-10 13:44:41.873936 | controller | changed
2025-12-10 13:44:41.878470 | 
2025-12-10 13:44:41.878533 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-10 13:44:42.058290 | controller | ok
2025-12-10 13:44:42.062663 | 
2025-12-10 13:44:42.062722 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-10 13:44:42.559736 | controller | changed
2025-12-10 13:44:42.564485 | 
2025-12-10 13:44:42.564545 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-10 13:44:43.070006 | controller | changed
2025-12-10 13:44:43.074781 | 
2025-12-10 13:44:43.074841 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-10 13:44:43.088139 | controller | skipping: Conditional result was False
2025-12-10 13:44:43.093664 | 
2025-12-10 13:44:43.093732 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-10 13:44:43.371625 | controller -> localhost | changed
2025-12-10 13:44:43.381200 | 
2025-12-10 13:44:43.381282 | TASK [add-build-sshkey : Add back temp key]
2025-12-10 13:44:43.586876 | controller -> localhost | Identity added: /var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/b4749d56795e4be2a1ab589ee9b170a5_id_rsa (zuul-build-sshkey)
2025-12-10 13:44:43.587077 | controller -> localhost | ok: Runtime: 0:00:00.006523
2025-12-10 13:44:43.592050 | 
2025-12-10 13:44:43.592108 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-10 13:44:43.864365 | controller | ok
2025-12-10 13:44:43.868636 | 
2025-12-10 13:44:43.868702 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-10 13:44:43.892226 | controller | skipping: Conditional result was False
2025-12-10 13:44:43.900517 | 
2025-12-10 13:44:43.900578 | TASK [include_role : validate-host]
2025-12-10 13:44:43.917733 | controller | ok
2025-12-10 13:44:43.936258 | 
2025-12-10 13:44:43.936315 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-10 13:44:43.964329 | controller | ok
2025-12-10 13:44:43.968344 | 
2025-12-10 13:44:43.968403 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-10 13:44:44.154364 | controller -> localhost | ok
2025-12-10 13:44:44.159904 | 
2025-12-10 13:44:44.159977 | TASK [validate-host : Collect information about the host]
2025-12-10 13:44:44.728957 | controller | ok
2025-12-10 13:44:44.736597 | 
2025-12-10 13:44:44.736667 | TASK [validate-host : Sanitize hostname]
2025-12-10 13:44:44.804090 | controller | ok
2025-12-10 13:44:44.808693 | 
2025-12-10 13:44:44.808758 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-10 13:44:45.167726 | controller -> localhost | changed
2025-12-10 13:44:45.191241 | 
2025-12-10 13:44:45.191333 | TASK [validate-host : Collect information about zuul worker]
2025-12-10 13:44:45.483073 | controller | ok
2025-12-10 13:44:45.487438 | 
2025-12-10 13:44:45.487502 | TASK [validate-host : Write out all zuul information for each host]
2025-12-10 13:44:45.814884 | controller -> localhost | changed
2025-12-10 13:44:45.823404 | 
2025-12-10 13:44:45.823463 | TASK [include_role : prepare-workspace-openshift]
2025-12-10 13:44:45.836611 | controller | skipping: Conditional result was False
2025-12-10 13:44:45.840674 | 
2025-12-10 13:44:45.840732 | TASK [include_role : remove-zuul-sshkey]
2025-12-10 13:44:45.853034 | controller | skipping: Conditional result was False
2025-12-10 13:44:45.857466 | 
2025-12-10 13:44:45.857525 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-10 13:44:46.046383 | controller | ok: "logs"
2025-12-10 13:44:46.046640 | controller | ok: All items complete
2025-12-10 13:44:46.046673 | 
2025-12-10 13:44:46.204391 | controller | ok: "artifacts"
2025-12-10 13:44:46.358172 | controller | ok: "docs"
2025-12-10 13:44:46.373013 | 
2025-12-10 13:44:46.373117 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-10 13:44:46.565439 | controller | changed: "logs"
2025-12-10 13:44:46.726105 | controller | changed: "artifacts"
2025-12-10 13:44:46.902534 | controller | changed: "docs"
2025-12-10 13:44:46.927428 | 
2025-12-10 13:44:46.927494 | PLAY RECAP
2025-12-10 13:44:46.927532 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-10 13:44:46.927556 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-10 13:44:46.927573 | 
2025-12-10 13:44:46.998269 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-10 13:44:46.999049 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-10 13:44:47.495668 | 
2025-12-10 13:44:47.495810 | PLAY [all]
2025-12-10 13:44:47.515471 | 
2025-12-10 13:44:47.515543 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-10 13:44:47.563839 | controller | ok
2025-12-10 13:44:47.568404 | 
2025-12-10 13:44:47.568482 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-10 13:44:47.880649 | controller | changed
2025-12-10 13:44:47.885866 | 
2025-12-10 13:44:47.885955 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-10 13:44:48.615146 | controller | changed
2025-12-10 13:44:48.624353 | 
2025-12-10 13:44:48.624423 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-12-10 13:44:48.964794 | controller | changed:
2025-12-10 13:44:48.964970 | controller | {
2025-12-10 13:44:48.965001 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-12-10 13:44:48.965028 | controller | }
2025-12-10 13:44:49.162040 | controller | changed:
2025-12-10 13:44:49.162093 | controller | {
2025-12-10 13:44:49.162121 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-12-10 13:44:49.162142 | controller | }
2025-12-10 13:44:49.354122 | controller | changed:
2025-12-10 13:44:49.354168 | controller | {
2025-12-10 13:44:49.354192 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-12-10 13:44:49.354211 | controller | }
2025-12-10 13:44:49.562425 | controller | changed:
2025-12-10 13:44:49.562477 | controller | {
2025-12-10 13:44:49.562504 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-12-10 13:44:49.562525 | controller | }
2025-12-10 13:44:49.757728 | controller | changed:
2025-12-10 13:44:49.757780 | controller | {
2025-12-10 13:44:49.757805 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-12-10 13:44:49.757825 | controller | }
2025-12-10 13:44:49.948759 | controller | changed:
2025-12-10 13:44:49.948813 | controller | {
2025-12-10 13:44:49.948840 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-12-10 13:44:49.948861 | controller | }
2025-12-10 13:44:50.141213 | controller | changed:
2025-12-10 13:44:50.141264 | controller | {
2025-12-10 13:44:50.141290 | 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-12-10 13:44:50.141311 | controller | }
2025-12-10 13:44:50.330683 | controller | changed:
2025-12-10 13:44:50.330733 | controller | {
2025-12-10 13:44:50.330760 | 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-12-10 13:44:50.330781 | controller | }
2025-12-10 13:44:50.525070 | controller | changed:
2025-12-10 13:44:50.525130 | controller | {
2025-12-10 13:44:50.525157 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-12-10 13:44:50.525177 | controller | }
2025-12-10 13:44:50.744436 | controller | changed:
2025-12-10 13:44:50.744485 | controller | {
2025-12-10 13:44:50.744511 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-12-10 13:44:50.744530 | controller | }
2025-12-10 13:44:50.933474 | controller | changed:
2025-12-10 13:44:50.933524 | controller | {
2025-12-10 13:44:50.933550 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-12-10 13:44:50.933569 | controller | }
2025-12-10 13:44:51.144406 | controller | changed:
2025-12-10 13:44:51.144476 | controller | {
2025-12-10 13:44:51.144502 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-12-10 13:44:51.144522 | controller | }
2025-12-10 13:44:51.318147 | controller | changed:
2025-12-10 13:44:51.318199 | controller | {
2025-12-10 13:44:51.318225 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-12-10 13:44:51.318244 | controller | }
2025-12-10 13:44:51.501714 | controller | changed:
2025-12-10 13:44:51.501763 | controller | {
2025-12-10 13:44:51.501788 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-12-10 13:44:51.501806 | controller | }
2025-12-10 13:44:51.688859 | controller | changed:
2025-12-10 13:44:51.688923 | controller | {
2025-12-10 13:44:51.688954 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-12-10 13:44:51.688975 | controller | }
2025-12-10 13:44:51.873107 | controller | changed:
2025-12-10 13:44:51.873158 | controller | {
2025-12-10 13:44:51.873184 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-12-10 13:44:51.873203 | controller | }
2025-12-10 13:44:52.068227 | controller | changed:
2025-12-10 13:44:52.068277 | controller | {
2025-12-10 13:44:52.068303 | 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-12-10 13:44:52.068324 | controller | }
2025-12-10 13:44:52.262363 | controller | changed:
2025-12-10 13:44:52.262413 | controller | {
2025-12-10 13:44:52.262439 | 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-12-10 13:44:52.262467 | controller | }
2025-12-10 13:44:52.449411 | controller | changed:
2025-12-10 13:44:52.449461 | controller | {
2025-12-10 13:44:52.449487 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-12-10 13:44:52.449507 | controller | }
2025-12-10 13:44:52.640106 | controller | changed:
2025-12-10 13:44:52.640158 | controller | {
2025-12-10 13:44:52.640184 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-12-10 13:44:52.640204 | controller | }
2025-12-10 13:44:52.830015 | controller | changed:
2025-12-10 13:44:52.830066 | controller | {
2025-12-10 13:44:52.830091 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-12-10 13:44:52.830110 | controller | }
2025-12-10 13:44:53.022620 | controller | changed:
2025-12-10 13:44:53.022671 | controller | {
2025-12-10 13:44:53.022697 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-12-10 13:44:53.022717 | controller | }
2025-12-10 13:44:53.211847 | controller | changed:
2025-12-10 13:44:53.211896 | controller | {
2025-12-10 13:44:53.211954 | 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-12-10 13:44:53.211979 | controller | }
2025-12-10 13:44:53.396558 | controller | changed:
2025-12-10 13:44:53.396627 | controller | {
2025-12-10 13:44:53.396662 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-12-10 13:44:53.396690 | controller | }
2025-12-10 13:44:53.586394 | controller | changed:
2025-12-10 13:44:53.586445 | controller | {
2025-12-10 13:44:53.586470 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-12-10 13:44:53.586490 | controller | }
2025-12-10 13:44:53.772378 | controller | changed:
2025-12-10 13:44:53.772430 | controller | {
2025-12-10 13:44:53.772457 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-12-10 13:44:53.772476 | controller | }
2025-12-10 13:44:53.796378 | 
2025-12-10 13:44:53.796495 | TASK [Set timezone to UTC]
2025-12-10 13:44:54.151024 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-12-10 13:44:54.155427 | 
2025-12-10 13:44:54.155487 | TASK [Create nodepool directory]
2025-12-10 13:44:54.347529 | controller | changed
2025-12-10 13:44:54.352715 | 
2025-12-10 13:44:54.352782 | TASK [Create nodepool sub_nodes file]
2025-12-10 13:44:54.828825 | controller | changed
2025-12-10 13:44:54.833423 | 
2025-12-10 13:44:54.833496 | TASK [Create nodepool sub_nodes_private file]
2025-12-10 13:44:55.308748 | controller | changed
2025-12-10 13:44:55.314026 | 
2025-12-10 13:44:55.314085 | LOOP [Populate nodepool sub_nodes file]
2025-12-10 13:44:55.343055 | 
2025-12-10 13:44:55.343174 | LOOP [Populate nodepool sub_nodes_private file]
2025-12-10 13:44:55.371901 | 
2025-12-10 13:44:55.372077 | TASK [Create nodepool primary file]
2025-12-10 13:44:55.395531 | controller | skipping: Conditional result was False
2025-12-10 13:44:55.400858 | 
2025-12-10 13:44:55.400945 | TASK [Create nodepool node_private for this node]
2025-12-10 13:44:55.905094 | controller | changed
2025-12-10 13:44:55.910228 | 
2025-12-10 13:44:55.910287 | LOOP [Copy ssh keys to nodepool directory]
2025-12-10 13:44:56.210320 | controller | ok: Item: id_rsa Runtime: 0:00:00.004015
2025-12-10 13:44:56.210506 | 
2025-12-10 13:44:56.358957 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004145
2025-12-10 13:44:56.366939 | 
2025-12-10 13:44:56.367023 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-12-10 13:44:56.872509 | controller | changed
2025-12-10 13:44:56.877504 | 
2025-12-10 13:44:56.877581 | TASK [Validate sudoers config after edits]
2025-12-10 13:44:57.084206 | controller | /etc/sudoers: parsed OK
2025-12-10 13:44:57.084272 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-12-10 13:44:57.084282 | controller | /etc/sudoers.d/zuul: parsed OK
2025-12-10 13:44:57.084289 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-12-10 13:44:57.403771 | controller | ok: Runtime: 0:00:00.004749
2025-12-10 13:44:57.408645 | 
2025-12-10 13:44:57.408702 | TASK [Show the environment passed in to job shell scripts]
2025-12-10 13:44:57.601681 | controller | SHELL=/bin/bash
2025-12-10 13:44:57.601730 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-12-10 13:44:57.601739 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-12-10 13:44:57.601759 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/45/3545/95f3db89fcdb71d855d98440e2c0cb9ef0da95e0
2025-12-10 13:44:57.601812 | controller | PWD=/home/zuul
2025-12-10 13:44:57.601821 | controller | ZUUL_PIPELINE=github-check
2025-12-10 13:44:57.601827 | controller | LOGNAME=zuul
2025-12-10 13:44:57.601832 | controller | XDG_SESSION_TYPE=tty
2025-12-10 13:44:57.601837 | controller | _=/usr/bin/env
2025-12-10 13:44:57.601842 | controller | MOTD_SHOWN=pam
2025-12-10 13:44:57.601846 | controller | HOME=/home/zuul
2025-12-10 13:44:57.601851 | controller | LANG=en_US.UTF-8
2025-12-10 13:44:57.601856 | controller | SSH_CONNECTION=192.168.26.12 49054 192.168.26.235 22
2025-12-10 13:44:57.601861 | 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-12-10 13:44:57.601870 | controller | ZUUL_CHANGE_IDS=3545,95f3db89fcdb71d855d98440e2c0cb9ef0da95e0
2025-12-10 13:44:57.601875 | controller | WORKSPACE=/home/zuul/workspace
2025-12-10 13:44:57.601880 | controller | XDG_SESSION_CLASS=user
2025-12-10 13:44:57.601885 | controller | SELINUX_ROLE_REQUESTED=
2025-12-10 13:44:57.601890 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-12-10 13:44:57.601895 | controller | USER=zuul
2025-12-10 13:44:57.601900 | controller | ZUUL_VOTING=True
2025-12-10 13:44:57.601904 | controller | BUILD_TIMEOUT=1800000
2025-12-10 13:44:57.601909 | controller | SELINUX_USE_CURRENT_RANGE=
2025-12-10 13:44:57.601914 | controller | SHLVL=1
2025-12-10 13:44:57.601919 | controller | ZUUL_PATCHSET=95f3db89fcdb71d855d98440e2c0cb9ef0da95e0
2025-12-10 13:44:57.601924 | controller | XDG_SESSION_ID=1
2025-12-10 13:44:57.601929 | controller | ZUUL_BRANCH=main
2025-12-10 13:44:57.601934 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-12-10 13:44:57.601939 | controller | SSH_CLIENT=192.168.26.12 49054 22
2025-12-10 13:44:57.601944 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-12-10 13:44:57.601949 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-12-10 13:44:57.601954 | controller | which_declare=declare -f
2025-12-10 13:44:57.601960 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-12-10 13:44:57.601965 | controller | SELINUX_LEVEL_REQUESTED=
2025-12-10 13:44:57.601971 | controller | ZUUL_CHANGE=3545
2025-12-10 13:44:57.601976 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-12-10 13:44:57.601980 | controller | ZUUL_UUID=b4749d56795e4be2a1ab589ee9b170a5
2025-12-10 13:44:57.601985 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-12-10 13:44:57.601990 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-12-10 13:44:57.601995 | controller | }
2025-12-10 13:44:57.933173 | controller | ok: Runtime: 0:00:00.005356
2025-12-10 13:44:57.938047 | 
2025-12-10 13:44:57.938110 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-12-10 13:44:57.950975 | controller | skipping: Conditional result was False
2025-12-10 13:44:57.955983 | 
2025-12-10 13:44:57.956046 | TASK [Symlink /home/zuul-worker/workspace]
2025-12-10 13:44:58.480646 | controller | skipping: Conditional result was False
2025-12-10 13:44:58.485995 | 
2025-12-10 13:44:58.486060 | TASK [Ensure legacy workspace directory]
2025-12-10 13:44:58.666640 | controller | changed
2025-12-10 13:44:58.684066 | 
2025-12-10 13:44:58.684120 | PLAY RECAP
2025-12-10 13:44:58.684166 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-10 13:44:58.684189 | 
2025-12-10 13:44:58.757688 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-10 13:44:58.758540 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-10 13:44:59.245480 | 
2025-12-10 13:44:59.245579 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-12-10 13:44:59.265528 | 
2025-12-10 13:44:59.265604 | TASK [Create zuul-output directory]
2025-12-10 13:44:59.579308 | controller | changed
2025-12-10 13:44:59.584032 | 
2025-12-10 13:44:59.584107 | TASK [Slurp Zuul inventory test]
2025-12-10 13:44:59.841378 | controller -> localhost | ok
2025-12-10 13:44:59.847876 | 
2025-12-10 13:44:59.847975 | TASK [Save zuul inventory]
2025-12-10 13:45:00.598500 | controller | changed
2025-12-10 13:45:00.603321 | 
2025-12-10 13:45:00.603400 | TASK [Save zuul vars without the change_message]
2025-12-10 13:45:01.191112 | controller | changed
2025-12-10 13:45:01.208546 | 
2025-12-10 13:45:01.208599 | PLAY RECAP
2025-12-10 13:45:01.208653 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-10 13:45:01.208677 | 
2025-12-10 13:45:01.270139 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-10 13:45:01.270892 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-10 13:45:01.784625 | 
2025-12-10 13:45:01.784730 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-12-10 13:45:01.804449 | 
2025-12-10 13:45:01.804520 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-12-10 13:45:01.822685 | controller | ok
2025-12-10 13:45:01.838109 | 
2025-12-10 13:45:01.838189 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-10 13:45:01.861650 | controller | skipping: Conditional result was False
2025-12-10 13:45:01.867125 | 
2025-12-10 13:45:01.867202 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-10 13:45:02.180159 | controller | ok
2025-12-10 13:45:02.185352 | 
2025-12-10 13:45:02.185422 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-10 13:45:02.793552 | controller | ok
2025-12-10 13:45:02.803036 | 
2025-12-10 13:45:02.803101 | TASK [Prepare workspace]
2025-12-10 13:45:02.820679 | controller | ok
2025-12-10 13:45:02.836313 | 
2025-12-10 13:45:02.836379 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-10 13:45:03.137953 | controller | ok
2025-12-10 13:45:03.143540 | 
2025-12-10 13:45:03.143616 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-10 13:45:05.472942 | controller | Output suppressed because no_log was given
2025-12-10 13:45:05.481484 | 
2025-12-10 13:45:05.481549 | LOOP [Create zuul-output directory]
2025-12-10 13:45:05.673623 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-12-10 13:45:05.835109 | controller | ok: "/home/zuul/zuul-output/logs"
2025-12-10 13:45:05.847086 | 
2025-12-10 13:45:05.847166 | TASK [Install required packages]
2025-12-10 13:45:54.627761 | controller | changed
2025-12-10 13:45:54.632636 | 
2025-12-10 13:45:54.632698 | TASK [Install venv]
2025-12-10 13:46:57.666656 | controller | changed
2025-12-10 13:46:57.691233 | 
2025-12-10 13:46:57.691330 | PLAY RECAP
2025-12-10 13:46:57.691377 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-10 13:46:57.691401 | 
2025-12-10 13:46:57.759592 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-10 13:46:57.760411 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-10 13:46:58.234099 | 
2025-12-10 13:46:58.234197 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-12-10 13:46:58.252698 | 
2025-12-10 13:46:58.252765 | TASK [Gather required facts]
2025-12-10 13:46:58.697358 | controller | ok
2025-12-10 13:46:58.702482 | 
2025-12-10 13:46:58.702564 | TASK [Load environment var if instructed to]
2025-12-10 13:46:58.726473 | controller | skipping: Conditional result was False
2025-12-10 13:46:58.731379 | 
2025-12-10 13:46:58.731441 | TASK [Ensure group_vars dir exists]
2025-12-10 13:46:59.031731 | controller | ok
2025-12-10 13:46:59.037401 | 
2025-12-10 13:46:59.037466 | TASK [Print related variables]
2025-12-10 13:46:59.065400 | controller | ok:
2025-12-10 13:46:59.065509 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-12-10 13:46:59.065550 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/nat64_appliance
2025-12-10 13:46:59.070084 | 
2025-12-10 13:46:59.070169 | TASK [Run molecule]
2025-12-10 13:46:59.946141 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-12-10 13:47:00.071484 | controller | INFO     Performing prerun with role_name_check=0...
2025-12-10 13:47:16.813637 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.814029 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.814464 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.814861 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.815307 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+95f3db89 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0+95f3db89 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.815743 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.816206 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.816646 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.817059 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.817447 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.817852 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.818288 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.818684 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.819093 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.819514 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:47:16.828522 | controller | INFO     Running build > prepare
2025-12-10 13:47:17.471435 | controller |
2025-12-10 13:47:17.471509 | controller | PLAY [Prepare] *****************************************************************
2025-12-10 13:47:17.471594 | controller |
2025-12-10 13:47:17.471685 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 13:47:17.471786 | controller | Wednesday 10 December 2025  13:47:17 +0000 (0:00:00.018)       0:00:00.018 ****
2025-12-10 13:47:18.285857 | controller | ok: [instance]
2025-12-10 13:47:18.285930 | controller |
2025-12-10 13:47:18.286035 | controller | TASK [Create custom basedir] ***************************************************
2025-12-10 13:47:18.286168 | controller | Wednesday 10 December 2025  13:47:18 +0000 (0:00:00.814)       0:00:00.833 ****
2025-12-10 13:47:18.568191 | controller | ok: [instance]
2025-12-10 13:47:18.568261 | controller |
2025-12-10 13:47:18.568365 | controller | TASK [Install some debug utils] ************************************************
2025-12-10 13:47:18.568478 | controller | Wednesday 10 December 2025  13:47:18 +0000 (0:00:00.282)       0:00:01.116 ****
2025-12-10 13:47:23.472089 | controller | changed: [instance]
2025-12-10 13:47:23.472142 | controller |
2025-12-10 13:47:23.472201 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-12-10 13:47:23.472302 | controller | Wednesday 10 December 2025  13:47:23 +0000 (0:00:04.903)       0:00:06.019 ****
2025-12-10 13:47:23.491734 | controller | skipping: [instance]
2025-12-10 13:47:23.491819 | controller |
2025-12-10 13:47:23.491914 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-12-10 13:47:23.492014 | controller | Wednesday 10 December 2025  13:47:23 +0000 (0:00:00.020)       0:00:06.039 ****
2025-12-10 13:47:23.531896 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-12-10 13:47:23.532026 | controller |
2025-12-10 13:47:23.532205 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-12-10 13:47:23.532335 | controller | Wednesday 10 December 2025  13:47:23 +0000 (0:00:00.040)       0:00:06.079 ****
2025-12-10 13:47:23.797563 | controller | ok: [instance]
2025-12-10 13:47:23.797646 | controller |
2025-12-10 13:47:23.797759 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-12-10 13:47:23.797861 | controller | Wednesday 10 December 2025  13:47:23 +0000 (0:00:00.265)       0:00:06.345 ****
2025-12-10 13:47:24.002568 | controller | ok: [instance]
2025-12-10 13:47:24.002621 | controller |
2025-12-10 13:47:24.002746 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-12-10 13:47:24.002860 | controller | Wednesday 10 December 2025  13:47:24 +0000 (0:00:00.204)       0:00:06.550 ****
2025-12-10 13:47:24.649115 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-12-10 13:47:24.649173 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-12-10 13:47:24.649268 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-12-10 13:47:24.649575 | controller |
2025-12-10 13:47:24.706703 | controller | TASK [Deploy repo-setup] *******************************************************
2025-12-10 13:47:24.706730 | controller | Wednesday 10 December 2025  13:47:24 +0000 (0:00:00.646)       0:00:07.196 ****
2025-12-10 13:47:24.706741 | controller |
2025-12-10 13:47:25.227144 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-12-10 13:47:25.227178 | controller | Wednesday 10 December 2025  13:47:24 +0000 (0:00:00.057)       0:00:07.254 ****
2025-12-10 13:47:25.227193 | controller | changed: [instance] => (item=tmp)
2025-12-10 13:47:25.227219 | controller | changed: [instance] => (item=artifacts/repositories)
2025-12-10 13:47:25.227227 | controller | changed: [instance] => (item=venv/repo_setup)
2025-12-10 13:47:25.227249 | controller |
2025-12-10 13:47:25.227517 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-12-10 13:47:25.869393 | controller | Wednesday 10 December 2025  13:47:25 +0000 (0:00:00.520)       0:00:07.774 ****
2025-12-10 13:47:25.869435 | controller | ok: [instance]
2025-12-10 13:47:26.944579 | controller |
2025-12-10 13:47:26.944621 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-12-10 13:47:26.944630 | controller | Wednesday 10 December 2025  13:47:25 +0000 (0:00:00.642)       0:00:08.416 ****
2025-12-10 13:47:26.944641 | controller | changed: [instance]
2025-12-10 13:47:34.515149 | controller |
2025-12-10 13:47:34.515180 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-12-10 13:47:34.515188 | controller | Wednesday 10 December 2025  13:47:26 +0000 (0:00:01.075)       0:00:09.491 ****
2025-12-10 13:47:34.515197 | controller | changed: [instance]
2025-12-10 13:47:34.515219 | controller |
2025-12-10 13:47:34.515227 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-12-10 13:47:34.515330 | controller | Wednesday 10 December 2025  13:47:34 +0000 (0:00:07.570)       0:00:17.062 ****
2025-12-10 13:47:35.222177 | controller | changed: [instance]
2025-12-10 13:47:35.243145 | controller |
2025-12-10 13:47:35.243180 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-12-10 13:47:35.243188 | controller | Wednesday 10 December 2025  13:47:35 +0000 (0:00:00.706)       0:00:17.769 ****
2025-12-10 13:47:35.243199 | controller | skipping: [instance]
2025-12-10 13:47:35.243225 | controller |
2025-12-10 13:47:35.243578 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-12-10 13:47:36.042133 | controller | Wednesday 10 December 2025  13:47:35 +0000 (0:00:00.021)       0:00:17.790 ****
2025-12-10 13:47:36.042175 | controller | changed: [instance]
2025-12-10 13:47:36.042194 | controller |
2025-12-10 13:47:36.042202 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-12-10 13:47:36.042485 | controller | Wednesday 10 December 2025  13:47:36 +0000 (0:00:00.798)       0:00:18.589 ****
2025-12-10 13:47:36.078150 | controller | skipping: [instance]
2025-12-10 13:47:36.079031 | controller |
2025-12-10 13:47:36.113565 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-12-10 13:47:36.113583 | controller | Wednesday 10 December 2025  13:47:36 +0000 (0:00:00.035)       0:00:18.625 ****
2025-12-10 13:47:36.113593 | controller | skipping: [instance]
2025-12-10 13:47:36.148371 | controller |
2025-12-10 13:47:36.148402 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-12-10 13:47:36.148415 | controller | Wednesday 10 December 2025  13:47:36 +0000 (0:00:00.035)       0:00:18.660 ****
2025-12-10 13:47:36.148429 | controller | skipping: [instance]
2025-12-10 13:47:36.148662 | controller |
2025-12-10 13:47:36.148916 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-12-10 13:47:36.149191 | controller | Wednesday 10 December 2025  13:47:36 +0000 (0:00:00.035)       0:00:18.696 ****
2025-12-10 13:47:36.678988 | controller | changed: [instance]
2025-12-10 13:47:37.083667 | controller |
2025-12-10 13:47:37.083688 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-12-10 13:47:37.083696 | controller | Wednesday 10 December 2025  13:47:36 +0000 (0:00:00.530)       0:00:19.226 ****
2025-12-10 13:47:37.083708 | controller | changed: [instance]
2025-12-10 13:47:37.111506 | controller |
2025-12-10 13:47:37.111524 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-12-10 13:47:37.111532 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.404)       0:00:19.631 ****
2025-12-10 13:47:37.111541 | controller | skipping: [instance]
2025-12-10 13:47:37.139000 | controller |
2025-12-10 13:47:37.139017 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-12-10 13:47:37.139025 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.027)       0:00:19.659 ****
2025-12-10 13:47:37.139033 | controller | skipping: [instance]
2025-12-10 13:47:37.168791 | controller |
2025-12-10 13:47:37.168811 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-12-10 13:47:37.168818 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.027)       0:00:19.686 ****
2025-12-10 13:47:37.168827 | controller | skipping: [instance]
2025-12-10 13:47:37.209216 | controller |
2025-12-10 13:47:37.209253 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-12-10 13:47:37.209262 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.029)       0:00:19.716 ****
2025-12-10 13:47:37.209277 | controller | ok: [instance]
2025-12-10 13:47:37.236078 | controller |
2025-12-10 13:47:37.236098 | controller | TASK [repo_setup : Create download directory] **********************************
2025-12-10 13:47:37.236107 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.040)       0:00:19.757 ****
2025-12-10 13:47:37.236118 | controller | skipping: [instance]
2025-12-10 13:47:37.236184 | controller |
2025-12-10 13:47:37.236294 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-12-10 13:47:37.236399 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.027)       0:00:19.784 ****
2025-12-10 13:47:37.263240 | controller | skipping: [instance]
2025-12-10 13:47:37.263333 | controller |
2025-12-10 13:47:37.263431 | controller | TASK [Download the RPM] ********************************************************
2025-12-10 13:47:37.263531 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.027)       0:00:19.811 ****
2025-12-10 13:47:37.289582 | controller | skipping: [instance]
2025-12-10 13:47:37.289670 | controller |
2025-12-10 13:47:37.289778 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-12-10 13:47:37.289878 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.026)       0:00:19.837 ****
2025-12-10 13:47:37.315337 | controller | skipping: [instance]
2025-12-10 13:47:37.315429 | controller |
2025-12-10 13:47:37.315536 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-12-10 13:47:37.315634 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.025)       0:00:19.863 ****
2025-12-10 13:47:37.341436 | controller | skipping: [instance]
2025-12-10 13:47:37.341531 | controller |
2025-12-10 13:47:37.341642 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-12-10 13:47:37.341739 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.026)       0:00:19.889 ****
2025-12-10 13:47:37.369048 | controller | skipping: [instance]
2025-12-10 13:47:37.369174 | controller |
2025-12-10 13:47:37.369285 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-12-10 13:47:37.369383 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.027)       0:00:19.917 ****
2025-12-10 13:47:37.394920 | controller | skipping: [instance]
2025-12-10 13:47:37.395005 | controller |
2025-12-10 13:47:37.395139 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-12-10 13:47:37.395240 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.025)       0:00:19.942 ****
2025-12-10 13:47:37.570151 | controller | ok: [instance]
2025-12-10 13:47:37.570201 | controller |
2025-12-10 13:47:37.570417 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-12-10 13:47:37.776830 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.175)       0:00:20.118 ****
2025-12-10 13:47:37.776860 | controller | changed: [instance]
2025-12-10 13:47:37.998009 | controller |
2025-12-10 13:47:37.998040 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-12-10 13:47:37.998048 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.206)       0:00:20.324 ****
2025-12-10 13:47:37.998058 | controller | changed: [instance]
2025-12-10 13:47:38.018492 | controller |
2025-12-10 13:47:38.018514 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-12-10 13:47:38.018522 | controller | Wednesday 10 December 2025  13:47:37 +0000 (0:00:00.221)       0:00:20.545 ****
2025-12-10 13:47:38.018532 | controller | skipping: [instance]
2025-12-10 13:47:38.040138 | controller |
2025-12-10 13:47:38.040175 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-12-10 13:47:38.040211 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.020)       0:00:20.566 ****
2025-12-10 13:47:38.040223 | controller | skipping: [instance]
2025-12-10 13:47:38.040259 | controller |
2025-12-10 13:47:38.040432 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-12-10 13:47:38.062171 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.021)       0:00:20.588 ****
2025-12-10 13:47:38.062189 | controller | skipping: [instance]
2025-12-10 13:47:38.083742 | controller |
2025-12-10 13:47:38.083762 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-12-10 13:47:38.083790 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.021)       0:00:20.609 ****
2025-12-10 13:47:38.083801 | controller | skipping: [instance]
2025-12-10 13:47:38.105118 | controller |
2025-12-10 13:47:38.105155 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-12-10 13:47:38.105164 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.021)       0:00:20.631 ****
2025-12-10 13:47:38.105175 | controller | skipping: [instance]
2025-12-10 13:47:38.105203 | controller |
2025-12-10 13:47:38.105212 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-12-10 13:47:38.105257 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.021)       0:00:20.652 ****
2025-12-10 13:47:38.128729 | controller | skipping: [instance]
2025-12-10 13:47:38.146147 | controller |
2025-12-10 13:47:38.146174 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-12-10 13:47:38.146183 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.023)       0:00:20.676 ****
2025-12-10 13:47:38.146192 | controller | skipping: [instance]
2025-12-10 13:47:38.146218 | controller |
2025-12-10 13:47:38.146423 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-12-10 13:47:38.174165 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.017)       0:00:20.694 ****
2025-12-10 13:47:38.174184 | controller | skipping: [instance]
2025-12-10 13:47:38.190758 | controller |
2025-12-10 13:47:38.190788 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-12-10 13:47:38.190796 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.027)       0:00:20.722 ****
2025-12-10 13:47:38.190806 | controller | skipping: [instance]
2025-12-10 13:47:38.211165 | controller |
2025-12-10 13:47:38.211195 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-12-10 13:47:38.211205 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.016)       0:00:20.738 ****
2025-12-10 13:47:38.211217 | controller | skipping: [instance]
2025-12-10 13:47:38.211248 | controller |
2025-12-10 13:47:38.211259 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-12-10 13:47:38.211364 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.020)       0:00:20.759 ****
2025-12-10 13:47:38.240700 | controller | skipping: [instance]
2025-12-10 13:47:38.269382 | controller |
2025-12-10 13:47:38.269399 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-12-10 13:47:38.269406 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.029)       0:00:20.788 ****
2025-12-10 13:47:38.269415 | controller | skipping: [instance]
2025-12-10 13:47:38.296923 | controller |
2025-12-10 13:47:38.296938 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-12-10 13:47:38.296945 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.028)       0:00:20.817 ****
2025-12-10 13:47:38.296952 | controller | skipping: [instance]
2025-12-10 13:47:38.323984 | controller |
2025-12-10 13:47:38.324003 | controller | TASK [test_deps : Install additional packages] *********************************
2025-12-10 13:47:38.324012 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.027)       0:00:20.844 ****
2025-12-10 13:47:38.324022 | controller | skipping: [instance]
2025-12-10 13:48:17.577594 | controller |
2025-12-10 13:48:17.577627 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-12-10 13:48:17.577635 | controller | Wednesday 10 December 2025  13:47:38 +0000 (0:00:00.026)       0:00:20.871 ****
2025-12-10 13:48:17.577645 | controller | ok: [instance]
2025-12-10 13:48:18.827146 | controller |
2025-12-10 13:48:18.827205 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-12-10 13:48:18.827215 | controller | Wednesday 10 December 2025  13:48:17 +0000 (0:00:39.253)       0:01:00.125 ****
2025-12-10 13:48:18.827228 | controller | ok: [instance]
2025-12-10 13:48:18.858050 | controller |
2025-12-10 13:48:18.858095 | controller | TASK [test_deps : Install extra packages] **************************************
2025-12-10 13:48:18.858109 | controller | Wednesday 10 December 2025  13:48:18 +0000 (0:00:01.248)       0:01:01.374 ****
2025-12-10 13:48:18.858122 | controller | skipping: [instance]
2025-12-10 13:48:19.055417 | controller |
2025-12-10 13:48:19.055457 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-12-10 13:48:19.055466 | controller | Wednesday 10 December 2025  13:48:18 +0000 (0:00:00.031)       0:01:01.405 ****
2025-12-10 13:48:19.055485 | controller | ok: [instance]
2025-12-10 13:48:19.244258 | controller |
2025-12-10 13:48:19.244280 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-12-10 13:48:19.244289 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.197)       0:01:01.602 ****
2025-12-10 13:48:19.244299 | controller | changed: [instance]
2025-12-10 13:48:19.440872 | controller |
2025-12-10 13:48:19.440904 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-12-10 13:48:19.440912 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.189)       0:01:01.791 ****
2025-12-10 13:48:19.440922 | controller | ok: [instance]
2025-12-10 13:48:19.470036 | controller |
2025-12-10 13:48:19.470059 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-12-10 13:48:19.470095 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.196)       0:01:01.988 ****
2025-12-10 13:48:19.470110 | controller | skipping: [instance]
2025-12-10 13:48:19.487197 | controller |
2025-12-10 13:48:19.487253 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-12-10 13:48:19.487264 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.029)       0:01:02.017 ****
2025-12-10 13:48:19.487277 | controller | skipping: [instance]
2025-12-10 13:48:19.487309 | controller |
2025-12-10 13:48:19.487318 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-12-10 13:48:19.487409 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.017)       0:01:02.034 ****
2025-12-10 13:48:19.506956 | controller | ok: [instance]
2025-12-10 13:48:19.532879 | controller |
2025-12-10 13:48:19.532895 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-12-10 13:48:19.532902 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.019)       0:01:02.054 ****
2025-12-10 13:48:19.532911 | controller | skipping: [instance]
2025-12-10 13:49:32.859054 | controller |
2025-12-10 13:49:32.859109 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-12-10 13:49:32.859117 | controller | Wednesday 10 December 2025  13:48:19 +0000 (0:00:00.026)       0:01:02.080 ****
2025-12-10 13:49:32.859127 | controller | changed: [instance]
2025-12-10 13:49:33.086721 | controller |
2025-12-10 13:49:33.086742 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-12-10 13:49:33.086750 | controller | Wednesday 10 December 2025  13:49:32 +0000 (0:01:13.325)       0:02:15.406 ****
2025-12-10 13:49:33.086758 | controller | changed: [instance]
2025-12-10 13:49:33.514648 | controller |
2025-12-10 13:49:33.514684 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-12-10 13:49:33.514692 | controller | Wednesday 10 December 2025  13:49:33 +0000 (0:00:00.227)       0:02:15.634 ****
2025-12-10 13:49:33.514702 | controller | changed: [instance]
2025-12-10 13:49:33.514759 | controller |
2025-12-10 13:49:33.514788 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-12-10 13:49:33.514800 | controller | Wednesday 10 December 2025  13:49:33 +0000 (0:00:00.427)       0:02:16.061 ****
2025-12-10 13:49:34.227509 | controller | changed: [instance]
2025-12-10 13:49:34.453637 | controller |
2025-12-10 13:49:34.453668 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-12-10 13:49:34.453676 | controller | Wednesday 10 December 2025  13:49:34 +0000 (0:00:00.712)       0:02:16.774 ****
2025-12-10 13:49:34.453686 | controller | ok: [instance]
2025-12-10 13:49:35.208527 | controller |
2025-12-10 13:49:35.208564 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-12-10 13:49:35.208573 | controller | Wednesday 10 December 2025  13:49:34 +0000 (0:00:00.226)       0:02:17.000 ****
2025-12-10 13:49:35.208584 | controller | ok: [instance]
2025-12-10 13:49:36.216109 | controller |
2025-12-10 13:49:36.216148 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-12-10 13:49:36.216157 | controller | Wednesday 10 December 2025  13:49:35 +0000 (0:00:00.754)       0:02:17.755 ****
2025-12-10 13:49:36.216178 | controller | changed: [instance]
2025-12-10 13:49:36.290802 | controller |
2025-12-10 13:49:36.290836 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-12-10 13:49:36.290844 | controller | Wednesday 10 December 2025  13:49:36 +0000 (0:00:01.007)       0:02:18.763 ****
2025-12-10 13:49:36.290855 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-12-10 13:49:36.672192 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-12-10 13:49:36.672228 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-12-10 13:49:36.672236 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-12-10 13:49:36.672241 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-12-10 13:49:36.672246 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-12-10 13:49:36.672251 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-12-10 13:49:36.672256 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-12-10 13:49:36.672262 | controller |
2025-12-10 13:49:36.672268 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-12-10 13:49:36.672273 | controller | Wednesday 10 December 2025  13:49:36 +0000 (0:00:00.074)       0:02:18.837 ****
2025-12-10 13:49:36.672282 | controller | changed: [instance]
2025-12-10 13:49:37.053417 | controller |
2025-12-10 13:49:37.053454 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-12-10 13:49:37.053469 | controller | Wednesday 10 December 2025  13:49:36 +0000 (0:00:00.381)       0:02:19.219 ****
2025-12-10 13:49:37.053479 | controller | changed: [instance]
2025-12-10 13:49:37.405313 | controller |
2025-12-10 13:49:37.405344 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-12-10 13:49:37.405352 | controller | Wednesday 10 December 2025  13:49:37 +0000 (0:00:00.381)       0:02:19.600 ****
2025-12-10 13:49:37.405362 | controller | changed: [instance]
2025-12-10 13:49:37.771526 | controller |
2025-12-10 13:49:37.771557 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-12-10 13:49:37.771566 | controller | Wednesday 10 December 2025  13:49:37 +0000 (0:00:00.351)       0:02:19.952 ****
2025-12-10 13:49:37.771576 | controller | changed: [instance]
2025-12-10 13:49:37.771626 | controller |
2025-12-10 13:49:37.771761 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-12-10 13:49:37.771851 | controller | Wednesday 10 December 2025  13:49:37 +0000 (0:00:00.366)       0:02:20.319 ****
2025-12-10 13:49:38.137926 | controller | changed: [instance]
2025-12-10 13:49:38.137984 | controller |
2025-12-10 13:49:38.138259 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-12-10 13:49:38.527002 | controller | Wednesday 10 December 2025  13:49:38 +0000 (0:00:00.366)       0:02:20.685 ****
2025-12-10 13:49:38.527048 | controller | changed: [instance]
2025-12-10 13:49:38.902893 | controller |
2025-12-10 13:49:38.902928 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-12-10 13:49:38.902937 | controller | Wednesday 10 December 2025  13:49:38 +0000 (0:00:00.388)       0:02:21.073 ****
2025-12-10 13:49:38.902947 | controller | changed: [instance]
2025-12-10 13:49:39.270780 | controller |
2025-12-10 13:49:39.270814 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-12-10 13:49:39.270822 | controller | Wednesday 10 December 2025  13:49:38 +0000 (0:00:00.376)       0:02:21.450 ****
2025-12-10 13:49:39.270834 | controller | changed: [instance]
2025-12-10 13:49:39.271102 | controller |
2025-12-10 13:49:39.633761 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-12-10 13:49:39.633793 | controller | Wednesday 10 December 2025  13:49:39 +0000 (0:00:00.368)       0:02:21.818 ****
2025-12-10 13:49:39.633806 | controller | changed: [instance]
2025-12-10 13:49:40.002583 | controller |
2025-12-10 13:49:40.002630 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-12-10 13:49:40.002638 | controller | Wednesday 10 December 2025  13:49:39 +0000 (0:00:00.362)       0:02:22.181 ****
2025-12-10 13:49:40.002648 | controller | changed: [instance]
2025-12-10 13:49:40.368521 | controller |
2025-12-10 13:49:40.368556 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-12-10 13:49:40.368565 | controller | Wednesday 10 December 2025  13:49:39 +0000 (0:00:00.368)       0:02:22.549 ****
2025-12-10 13:49:40.368575 | controller | changed: [instance]
2025-12-10 13:49:41.722774 | controller |
2025-12-10 13:49:41.722805 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-12-10 13:49:41.722813 | controller | Wednesday 10 December 2025  13:49:40 +0000 (0:00:00.366)       0:02:22.915 ****
2025-12-10 13:49:41.722823 | controller | changed: [instance]
2025-12-10 13:49:42.079194 | controller |
2025-12-10 13:49:42.079254 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-12-10 13:49:42.079264 | controller | Wednesday 10 December 2025  13:49:41 +0000 (0:00:01.354)       0:02:24.270 ****
2025-12-10 13:49:42.079280 | controller | changed: [instance]
2025-12-10 13:49:42.079312 | controller |
2025-12-10 13:49:42.079321 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-12-10 13:49:42.439656 | controller | Wednesday 10 December 2025  13:49:42 +0000 (0:00:00.356)       0:02:24.626 ****
2025-12-10 13:49:42.439706 | controller | changed: [instance]
2025-12-10 13:49:42.796675 | controller |
2025-12-10 13:49:42.796704 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-12-10 13:49:42.796713 | controller | Wednesday 10 December 2025  13:49:42 +0000 (0:00:00.360)       0:02:24.987 ****
2025-12-10 13:49:42.796722 | controller | changed: [instance]
2025-12-10 13:49:43.143256 | controller |
2025-12-10 13:49:43.143284 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-12-10 13:49:43.143292 | controller | Wednesday 10 December 2025  13:49:42 +0000 (0:00:00.356)       0:02:25.344 ****
2025-12-10 13:49:43.143302 | controller | changed: [instance]
2025-12-10 13:49:43.506035 | controller |
2025-12-10 13:49:43.506085 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-12-10 13:49:43.506099 | controller | Wednesday 10 December 2025  13:49:43 +0000 (0:00:00.346)       0:02:25.690 ****
2025-12-10 13:49:43.506116 | controller | changed: [instance]
2025-12-10 13:49:43.865145 | controller |
2025-12-10 13:49:43.865180 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-12-10 13:49:43.865188 | controller | Wednesday 10 December 2025  13:49:43 +0000 (0:00:00.362)       0:02:26.053 ****
2025-12-10 13:49:43.865199 | controller | changed: [instance]
2025-12-10 13:49:43.865347 | controller |
2025-12-10 13:49:43.865359 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-12-10 13:49:43.865368 | controller | Wednesday 10 December 2025  13:49:43 +0000 (0:00:00.359)       0:02:26.412 ****
2025-12-10 13:49:44.218991 | controller | changed: [instance]
2025-12-10 13:49:44.571283 | controller |
2025-12-10 13:49:44.571305 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-12-10 13:49:44.571314 | controller | Wednesday 10 December 2025  13:49:44 +0000 (0:00:00.353)       0:02:26.766 ****
2025-12-10 13:49:44.571323 | controller | changed: [instance]
2025-12-10 13:49:44.933707 | controller |
2025-12-10 13:49:44.933737 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-12-10 13:49:44.933746 | controller | Wednesday 10 December 2025  13:49:44 +0000 (0:00:00.352)       0:02:27.118 ****
2025-12-10 13:49:44.933756 | controller | changed: [instance]
2025-12-10 13:49:45.291819 | controller |
2025-12-10 13:49:45.291857 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-12-10 13:49:45.291865 | controller | Wednesday 10 December 2025  13:49:44 +0000 (0:00:00.362)       0:02:27.481 ****
2025-12-10 13:49:45.291883 | controller | changed: [instance]
2025-12-10 13:49:45.656809 | controller |
2025-12-10 13:49:45.656843 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-12-10 13:49:45.656850 | controller | Wednesday 10 December 2025  13:49:45 +0000 (0:00:00.357)       0:02:27.839 ****
2025-12-10 13:49:45.656860 | controller | changed: [instance]
2025-12-10 13:49:46.021744 | controller |
2025-12-10 13:49:46.021773 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-12-10 13:49:46.021782 | controller | Wednesday 10 December 2025  13:49:45 +0000 (0:00:00.365)       0:02:28.204 ****
2025-12-10 13:49:46.021792 | controller | changed: [instance]
2025-12-10 13:49:46.047648 | controller |
2025-12-10 13:49:46.047691 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-12-10 13:49:46.047700 | controller | Wednesday 10 December 2025  13:49:46 +0000 (0:00:00.365)       0:02:28.569 ****
2025-12-10 13:49:46.047709 | controller | skipping: [instance]
2025-12-10 13:49:46.357985 | controller |
2025-12-10 13:49:46.358018 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-12-10 13:49:46.358027 | controller | Wednesday 10 December 2025  13:49:46 +0000 (0:00:00.024)       0:02:28.593 ****
2025-12-10 13:49:46.358037 | controller | ok: [instance]
2025-12-10 13:49:46.800123 | controller |
2025-12-10 13:49:46.800155 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-12-10 13:49:46.800164 | controller | Wednesday 10 December 2025  13:49:46 +0000 (0:00:00.311)       0:02:28.905 ****
2025-12-10 13:49:46.800175 | controller | changed: [instance]
2025-12-10 13:49:47.149175 | controller |
2025-12-10 13:49:47.149199 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-12-10 13:49:47.149207 | controller | Wednesday 10 December 2025  13:49:46 +0000 (0:00:00.442)       0:02:29.347 ****
2025-12-10 13:49:47.149217 | controller | changed: [instance]
2025-12-10 13:49:47.149312 | controller |
2025-12-10 13:49:47.149322 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-12-10 13:49:47.149330 | controller | Wednesday 10 December 2025  13:49:47 +0000 (0:00:00.348)       0:02:29.696 ****
2025-12-10 13:49:47.470133 | controller | [WARNING]: Reset is not implemented for this connection
2025-12-10 13:49:47.492261 | controller | changed: [instance]
2025-12-10 13:49:47.492326 | controller |
2025-12-10 13:49:47.492335 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-12-10 13:49:47.492342 | controller | Wednesday 10 December 2025  13:49:47 +0000 (0:00:00.316)       0:02:30.012 ****
2025-12-10 13:49:47.492348 | controller |
2025-12-10 13:49:47.492354 | controller | PLAY RECAP *********************************************************************
2025-12-10 13:49:47.492360 | controller | instance                   : ok=68   changed=43   unreachable=0    failed=0    skipped=34   rescued=0    ignored=0
2025-12-10 13:49:47.492366 | controller |
2025-12-10 13:49:47.492371 | controller | Wednesday 10 December 2025  13:49:47 +0000 (0:00:00.026)       0:02:30.038 ****
2025-12-10 13:49:47.492377 | controller | ===============================================================================
2025-12-10 13:49:47.492382 | controller | libvirt_manager : Install packages required for using KVM -------------- 73.33s
2025-12-10 13:49:47.492390 | controller | test_deps : Install selinux python libs -------------------------------- 39.25s
2025-12-10 13:49:47.492421 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.57s
2025-12-10 13:49:47.493186 | controller | Install some debug utils ------------------------------------------------ 4.90s
2025-12-10 13:49:47.493933 | controller | libvirt_manager : Ensure admin socket is enabled for nodedev. ----------- 1.35s
2025-12-10 13:49:47.493958 | controller | test_deps : Install python yaml libs ------------------------------------ 1.25s
2025-12-10 13:49:47.493965 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.08s
2025-12-10 13:49:47.493971 | controller | libvirt_manager : Ensure firewalld service is up ------------------------ 1.01s
2025-12-10 13:49:47.493977 | controller | Gathering Facts --------------------------------------------------------- 0.81s
2025-12-10 13:49:47.493982 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.80s
2025-12-10 13:49:47.493988 | controller | libvirt_manager : Reload systemctl and start/enable virtproxyd.service --- 0.75s
2025-12-10 13:49:47.494004 | controller | libvirt_manager : Restart service polkit service ------------------------ 0.71s
2025-12-10 13:49:47.561020 | controller | repo_setup : Install repo-setup package --------------------------------- 0.71s
2025-12-10 13:49:47.561054 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.65s
2025-12-10 13:49:47.561084 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.64s
2025-12-10 13:49:47.561094 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.53s
2025-12-10 13:49:47.561101 | controller | repo_setup : Ensure directories are present ----------------------------- 0.52s
2025-12-10 13:49:47.561107 | controller | libvirt_manager : Add user if not exists in libvirt group --------------- 0.44s
2025-12-10 13:49:47.561112 | controller | libvirt_manager : Enable UNIX socket PolicyKit auth --------------------- 0.43s
2025-12-10 13:49:47.561118 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.40s
2025-12-10 13:49:47.561128 | controller | INFO     Running build > converge
2025-12-10 13:49:48.032377 | controller |
2025-12-10 13:49:48.860170 | controller | PLAY [Converge] ****************************************************************
2025-12-10 13:49:48.860208 | controller |
2025-12-10 13:49:48.860217 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 13:49:48.860223 | controller | Wednesday 10 December 2025  13:49:48 +0000 (0:00:00.014)       0:00:00.014 ****
2025-12-10 13:49:48.860235 | controller | ok: [instance]
2025-12-10 13:49:48.860261 | controller |
2025-12-10 13:49:48.860271 | controller | TASK [Crate SSH keypair] *******************************************************
2025-12-10 13:49:48.860380 | controller | Wednesday 10 December 2025  13:49:48 +0000 (0:00:00.830)       0:00:00.844 ****
2025-12-10 13:49:49.250102 | controller | changed: [instance]
2025-12-10 13:49:49.748681 | controller |
2025-12-10 13:49:49.748712 | controller | TASK [Enable forwarding in the libvirt zone] ***********************************
2025-12-10 13:49:49.748720 | controller | Wednesday 10 December 2025  13:49:49 +0000 (0:00:00.389)       0:00:01.234 ****
2025-12-10 13:49:49.748730 | controller | changed: [instance]
2025-12-10 13:49:50.788266 | controller |
2025-12-10 13:49:50.788302 | controller | TASK [Restart firewalld.service] ***********************************************
2025-12-10 13:49:50.788310 | controller | Wednesday 10 December 2025  13:49:49 +0000 (0:00:00.498)       0:00:01.733 ****
2025-12-10 13:49:50.788321 | controller | changed: [instance]
2025-12-10 13:49:50.788490 | controller |
2025-12-10 13:49:50.788500 | controller | TASK [Discover latest image] ***************************************************
2025-12-10 13:49:50.788508 | controller | Wednesday 10 December 2025  13:49:50 +0000 (0:00:01.039)       0:00:02.772 ****
2025-12-10 13:49:50.837191 | controller |
2025-12-10 13:49:50.837417 | controller | TASK [discover_latest_image : Get latest image] ********************************
2025-12-10 13:49:52.738486 | controller | Wednesday 10 December 2025  13:49:50 +0000 (0:00:00.049)       0:00:02.822 ****
2025-12-10 13:49:52.738531 | controller | changed: [instance]
2025-12-10 13:49:52.764858 | controller |
2025-12-10 13:49:52.764876 | controller | TASK [discover_latest_image : Export facts accordingly] ************************
2025-12-10 13:49:52.764885 | controller | Wednesday 10 December 2025  13:49:52 +0000 (0:00:01.900)       0:00:04.723 ****
2025-12-10 13:49:52.764895 | controller | ok: [instance]
2025-12-10 13:50:12.216783 | controller |
2025-12-10 13:50:12.216849 | controller | TASK [Download latest image] ***************************************************
2025-12-10 13:50:12.216859 | controller | Wednesday 10 December 2025  13:49:52 +0000 (0:00:00.026)       0:00:04.749 ****
2025-12-10 13:50:12.216875 | controller | changed: [instance]
2025-12-10 13:50:12.263029 | controller |
2025-12-10 13:50:12.263113 | controller | TASK [Build nat64 appliance image] *********************************************
2025-12-10 13:50:12.263126 | controller | Wednesday 10 December 2025  13:50:12 +0000 (0:00:19.450)       0:00:24.199 ****
2025-12-10 13:50:12.263139 | controller |
2025-12-10 13:50:12.811191 | controller | TASK [nat64_appliance : Ensure needed directories exist] ***********************
2025-12-10 13:50:12.811244 | controller | Wednesday 10 December 2025  13:50:12 +0000 (0:00:00.047)       0:00:24.247 ****
2025-12-10 13:50:12.811267 | controller | ok: [instance] => (item=artifacts)
2025-12-10 13:50:12.811298 | controller | ok: [instance] => (item=logs)
2025-12-10 13:50:12.811305 | controller |
2025-12-10 13:50:12.811314 | controller | TASK [nat64_appliance : Ensure working directory exists] ***********************
2025-12-10 13:50:12.811341 | controller | Wednesday 10 December 2025  13:50:12 +0000 (0:00:00.548)       0:00:24.795 ****
2025-12-10 13:50:13.027629 | controller | changed: [instance]
2025-12-10 13:50:17.656837 | controller |
2025-12-10 13:50:17.656872 | controller | TASK [nat64_appliance : Install required RPM packages] *************************
2025-12-10 13:50:17.656880 | controller | Wednesday 10 December 2025  13:50:13 +0000 (0:00:00.216)       0:00:25.011 ****
2025-12-10 13:50:17.656891 | controller | ok: [instance]
2025-12-10 13:50:25.622513 | controller |
2025-12-10 13:50:25.622550 | controller | TASK [nat64_appliance : Install diskimage-builder in virtualenv] ***************
2025-12-10 13:50:25.622558 | controller | Wednesday 10 December 2025  13:50:17 +0000 (0:00:04.629)       0:00:29.641 ****
2025-12-10 13:50:25.622569 | controller | changed: [instance]
2025-12-10 13:50:35.919195 | controller |
2025-12-10 13:50:35.919233 | controller | TASK [nat64_appliance : Copy files to cifmw_nat64_appliance_dir] ***************
2025-12-10 13:50:35.919241 | controller | Wednesday 10 December 2025  13:50:25 +0000 (0:00:07.965)       0:00:37.606 ****
2025-12-10 13:50:35.919252 | controller | changed: [instance] => (item=elements/)
2025-12-10 13:50:35.919277 | controller | changed: [instance] => (item=nat64-appliance.yaml)
2025-12-10 13:50:35.919286 | controller |
2025-12-10 13:50:35.919308 | controller | TASK [nat64_appliance : Clone edpm-image-builder (reset-bls-entries dib element)] ***
2025-12-10 13:50:35.919485 | controller | Wednesday 10 December 2025  13:50:35 +0000 (0:00:10.296)       0:00:47.903 ****
2025-12-10 13:50:37.059033 | controller | changed: [instance]
2025-12-10 13:57:30.801867 | controller |
2025-12-10 13:57:30.802078 | controller | TASK [nat64_appliance : Build the nat64-appliance image using DIB] *************
2025-12-10 13:57:30.802094 | controller | Wednesday 10 December 2025  13:50:37 +0000 (0:00:01.139)       0:00:49.043 ****
2025-12-10 13:57:30.802107 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_build_the_nat64_appliance.log
2025-12-10 13:57:30.834616 | controller | changed: [instance]
2025-12-10 13:57:30.834650 | controller |
2025-12-10 13:57:30.834658 | controller | TASK [nat64_appliance : Download pre-built NAT64 appliance image] **************
2025-12-10 13:57:30.834664 | controller | Wednesday 10 December 2025  13:57:30 +0000 (0:06:53.741)       0:07:42.785 ****
2025-12-10 13:57:30.834674 | controller | skipping: [instance]
2025-12-10 13:57:31.046090 | controller |
2025-12-10 13:57:31.046122 | controller | TASK [Fix permissions on logs dir - because we ran dib as root] ****************
2025-12-10 13:57:31.046133 | controller | Wednesday 10 December 2025  13:57:30 +0000 (0:00:00.034)       0:07:42.819 ****
2025-12-10 13:57:31.046143 | controller | changed: [instance]
2025-12-10 13:57:38.027227 | controller |
2025-12-10 13:57:38.027263 | controller | TASK [Fix permissions on nat64_appliance dir - because we ran dib as root] *****
2025-12-10 13:57:38.027270 | controller | Wednesday 10 December 2025  13:57:31 +0000 (0:00:00.211)       0:07:43.030 ****
2025-12-10 13:57:38.027280 | controller | changed: [instance]
2025-12-10 13:57:38.070829 | controller |
2025-12-10 13:57:38.070859 | controller | TASK [Deploy the nat64 appliance and networks] *********************************
2025-12-10 13:57:38.070866 | controller | Wednesday 10 December 2025  13:57:38 +0000 (0:00:06.981)       0:07:50.011 ****
2025-12-10 13:57:38.070875 | controller |
2025-12-10 13:57:38.120968 | controller | TASK [nat64_appliance : Set MAC address facts] *********************************
2025-12-10 13:57:38.121001 | controller | Wednesday 10 December 2025  13:57:38 +0000 (0:00:00.044)       0:07:50.055 ****
2025-12-10 13:57:38.121020 | controller | ok: [instance]
2025-12-10 13:57:38.852130 | controller |
2025-12-10 13:57:38.852158 | controller | TASK [nat64_appliance : Create the IPv4 libvirt network for nat64] *************
2025-12-10 13:57:38.852170 | controller | Wednesday 10 December 2025  13:57:38 +0000 (0:00:00.049)       0:07:50.105 ****
2025-12-10 13:57:38.852180 | controller | changed: [instance]
2025-12-10 13:57:38.852499 | controller |
2025-12-10 13:57:39.154132 | controller | TASK [nat64_appliance : Ensure the IPv4 libvirt network for nat64 is created/started] ***
2025-12-10 13:57:39.154160 | controller | Wednesday 10 December 2025  13:57:38 +0000 (0:00:00.731)       0:07:50.837 ****
2025-12-10 13:57:39.154176 | controller | ok: [instance]
2025-12-10 13:57:39.370788 | controller |
2025-12-10 13:57:39.370820 | controller | TASK [nat64_appliance : Ensure the IPv4 libvirt network for nat64 is active] ***
2025-12-10 13:57:39.370828 | controller | Wednesday 10 December 2025  13:57:39 +0000 (0:00:00.301)       0:07:51.138 ****
2025-12-10 13:57:39.370837 | controller | ok: [instance]
2025-12-10 13:57:39.579170 | controller |
2025-12-10 13:57:39.579195 | controller | TASK [nat64_appliance : Ensure the IPv4 libvirt network for nat64 is enabled to autostart] ***
2025-12-10 13:57:39.579203 | controller | Wednesday 10 December 2025  13:57:39 +0000 (0:00:00.216)       0:07:51.355 ****
2025-12-10 13:57:39.579213 | controller | changed: [instance]
2025-12-10 13:57:39.794165 | controller |
2025-12-10 13:57:39.794198 | controller | TASK [nat64_appliance : Create the IPv6 libvirt network for nat64] *************
2025-12-10 13:57:39.794205 | controller | Wednesday 10 December 2025  13:57:39 +0000 (0:00:00.208)       0:07:51.563 ****
2025-12-10 13:57:39.794216 | controller | changed: [instance]
2025-12-10 13:57:40.018544 | controller |
2025-12-10 13:57:40.018578 | controller | TASK [nat64_appliance : Ensure the IPv6 libvirt network for nat64 is created/started] ***
2025-12-10 13:57:40.018586 | controller | Wednesday 10 December 2025  13:57:39 +0000 (0:00:00.215)       0:07:51.779 ****
2025-12-10 13:57:40.018598 | controller | ok: [instance]
2025-12-10 13:57:40.224504 | controller |
2025-12-10 13:57:40.224536 | controller | TASK [nat64_appliance : Ensure the IPv6 libvirt network for nat64 network is active] ***
2025-12-10 13:57:40.224543 | controller | Wednesday 10 December 2025  13:57:40 +0000 (0:00:00.224)       0:07:52.003 ****
2025-12-10 13:57:40.224554 | controller | ok: [instance]
2025-12-10 13:57:40.432140 | controller |
2025-12-10 13:57:40.432169 | controller | TASK [nat64_appliance : Ensure the IPv6 libvirt network for nat64 is enabled to autostart] ***
2025-12-10 13:57:40.432177 | controller | Wednesday 10 December 2025  13:57:40 +0000 (0:00:00.205)       0:07:52.209 ****
2025-12-10 13:57:40.432187 | controller | changed: [instance]
2025-12-10 13:57:41.126148 | controller |
2025-12-10 13:57:41.126179 | controller | TASK [nat64_appliance : Make sure all bridges are in the libvirt firewalld zone] ***
2025-12-10 13:57:41.126188 | controller | Wednesday 10 December 2025  13:57:40 +0000 (0:00:00.207)       0:07:52.416 ****
2025-12-10 13:57:41.126200 | controller | changed: [instance] => (item=br-64v6)
2025-12-10 13:57:41.126226 | controller | changed: [instance] => (item=br-64v4)
2025-12-10 13:57:41.126236 | controller |
2025-12-10 13:57:41.126260 | controller | TASK [nat64_appliance : Restart firewalld.service] *****************************
2025-12-10 13:57:41.126402 | controller | Wednesday 10 December 2025  13:57:41 +0000 (0:00:00.694)       0:07:53.111 ****
2025-12-10 13:57:41.924905 | controller | changed: [instance]
2025-12-10 13:57:41.954679 | controller |
2025-12-10 13:57:41.954700 | controller | TASK [nat64_appliance : Generate nat64-appliance UUID] *************************
2025-12-10 13:57:41.954708 | controller | Wednesday 10 December 2025  13:57:41 +0000 (0:00:00.797)       0:07:53.908 ****
2025-12-10 13:57:41.954717 | controller | ok: [instance]
2025-12-10 13:57:41.990758 | controller |
2025-12-10 13:57:41.990776 | controller | TASK [Create the config-drive ISO for the nat64-appliance] *********************
2025-12-10 13:57:41.990784 | controller | Wednesday 10 December 2025  13:57:41 +0000 (0:00:00.030)       0:07:53.939 ****
2025-12-10 13:57:41.990794 | controller |
2025-12-10 13:57:42.352257 | controller | TASK [config_drive : Ensure needed directories exist] **************************
2025-12-10 13:57:42.352287 | controller | Wednesday 10 December 2025  13:57:41 +0000 (0:00:00.036)       0:07:53.975 ****
2025-12-10 13:57:42.352298 | controller | ok: [instance] => (item=artifacts)
2025-12-10 13:57:43.553237 | controller | ok: [instance] => (item=logs)
2025-12-10 13:57:43.553269 | controller |
2025-12-10 13:57:43.553277 | controller | TASK [config_drive : Install required RPM packages] ****************************
2025-12-10 13:57:43.553283 | controller | Wednesday 10 December 2025  13:57:42 +0000 (0:00:00.361)       0:07:54.336 ****
2025-12-10 13:57:43.553293 | controller | ok: [instance]
2025-12-10 13:57:43.735451 | controller |
2025-12-10 13:57:43.735468 | controller | TASK [config_drive : Crate config drive instance directory] ********************
2025-12-10 13:57:43.735475 | controller | Wednesday 10 December 2025  13:57:43 +0000 (0:00:01.201)       0:07:55.537 ****
2025-12-10 13:57:43.735483 | controller | changed: [instance]
2025-12-10 13:57:44.052150 | controller |
2025-12-10 13:57:44.052184 | controller | TASK [config_drive : Generate meta-data] ***************************************
2025-12-10 13:57:44.052192 | controller | Wednesday 10 December 2025  13:57:43 +0000 (0:00:00.182)       0:07:55.720 ****
2025-12-10 13:57:44.052207 | controller | changed: [instance]
2025-12-10 13:57:44.052225 | controller |
2025-12-10 13:57:44.052239 | controller | TASK [config_drive : Generate user-data] ***************************************
2025-12-10 13:57:44.052256 | controller | Wednesday 10 December 2025  13:57:44 +0000 (0:00:00.316)       0:07:56.037 ****
2025-12-10 13:57:44.418597 | controller | changed: [instance]
2025-12-10 13:57:44.418647 | controller |
2025-12-10 13:57:44.418747 | controller | TASK [config_drive : Generate network-data] ************************************
2025-12-10 13:57:44.418848 | controller | Wednesday 10 December 2025  13:57:44 +0000 (0:00:00.366)       0:07:56.403 ****
2025-12-10 13:57:44.751516 | controller | changed: [instance]
2025-12-10 13:57:44.751563 | controller |
2025-12-10 13:57:44.751671 | controller | TASK [config_drive : Check ISO availability] ***********************************
2025-12-10 13:57:44.751759 | controller | Wednesday 10 December 2025  13:57:44 +0000 (0:00:00.332)       0:07:56.736 ****
2025-12-10 13:57:44.923368 | controller | ok: [instance]
2025-12-10 13:57:44.923413 | controller |
2025-12-10 13:57:44.923540 | controller | TASK [config_drive : Assert we don't try to change an existing ISO] ************
2025-12-10 13:57:44.923609 | controller | Wednesday 10 December 2025  13:57:44 +0000 (0:00:00.171)       0:07:56.908 ****
2025-12-10 13:57:44.940279 | controller | skipping: [instance]
2025-12-10 13:57:44.940368 | controller |
2025-12-10 13:57:44.940462 | controller | TASK [config_drive : Generate nocloud iso image] *******************************
2025-12-10 13:57:44.940556 | controller | Wednesday 10 December 2025  13:57:44 +0000 (0:00:00.017)       0:07:56.925 ****
2025-12-10 13:57:45.156106 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_generate_nocloud_iso.log
2025-12-10 13:57:46.235116 | controller | changed: [instance]
2025-12-10 13:57:46.235149 | controller |
2025-12-10 13:57:46.235157 | controller | TASK [nat64_appliance : Define nat64-appliance VM] *****************************
2025-12-10 13:57:46.235163 | controller | Wednesday 10 December 2025  13:57:45 +0000 (0:00:00.215)       0:07:57.140 ****
2025-12-10 13:57:46.235173 | controller | changed: [instance]
2025-12-10 13:57:46.733138 | controller |
2025-12-10 13:57:46.733166 | controller | TASK [nat64_appliance : Start nat64-appliance VM] ******************************
2025-12-10 13:57:46.733174 | controller | Wednesday 10 December 2025  13:57:46 +0000 (0:00:01.079)       0:07:58.219 ****
2025-12-10 13:57:46.733183 | controller | changed: [instance]
2025-12-10 13:57:46.755127 | controller |
2025-12-10 13:57:46.755149 | controller | TASK [nat64_appliance : Set nat64 facts] ***************************************
2025-12-10 13:57:46.755156 | controller | Wednesday 10 December 2025  13:57:46 +0000 (0:00:00.497)       0:07:58.717 ****
2025-12-10 13:57:46.755165 | controller | ok: [instance]
2025-12-10 13:57:46.791096 | controller |
2025-12-10 13:57:46.791118 | controller | TASK [Set MAC address facts] ***************************************************
2025-12-10 13:57:46.791125 | controller | Wednesday 10 December 2025  13:57:46 +0000 (0:00:00.022)       0:07:58.740 ****
2025-12-10 13:57:46.791135 | controller | ok: [instance]
2025-12-10 13:57:47.002060 | controller |
2025-12-10 13:57:47.002095 | controller | TASK [Define a IPv6 network for test node] *************************************
2025-12-10 13:57:47.002103 | controller | Wednesday 10 December 2025  13:57:46 +0000 (0:00:00.035)       0:07:58.776 ****
2025-12-10 13:57:47.002112 | controller | changed: [instance]
2025-12-10 13:57:47.257025 | controller |
2025-12-10 13:57:47.257052 | controller | TASK [Create a IPv6 network for test node] *************************************
2025-12-10 13:57:47.257060 | controller | Wednesday 10 December 2025  13:57:46 +0000 (0:00:00.210)       0:07:58.986 ****
2025-12-10 13:57:47.257085 | controller | ok: [instance]
2025-12-10 13:57:47.460036 | controller |
2025-12-10 13:57:47.460057 | controller | TASK [Ensure the IPv6 network for test node is active] *************************
2025-12-10 13:57:47.460085 | controller | Wednesday 10 December 2025  13:57:47 +0000 (0:00:00.254)       0:07:59.241 ****
2025-12-10 13:57:47.460098 | controller | ok: [instance]
2025-12-10 13:57:47.678283 | controller |
2025-12-10 13:57:47.678300 | controller | TASK [Ensure the IPv6 network for test node is enabled to autostart] ***********
2025-12-10 13:57:47.678313 | controller | Wednesday 10 December 2025  13:57:47 +0000 (0:00:00.203)       0:07:59.444 ****
2025-12-10 13:57:47.678321 | controller | changed: [instance]
2025-12-10 13:57:47.994142 | controller |
2025-12-10 13:57:47.994168 | controller | TASK [Make sure br-mol bridge is in the libvirt firewalld zone] ****************
2025-12-10 13:57:47.994176 | controller | Wednesday 10 December 2025  13:57:47 +0000 (0:00:00.215)       0:07:59.660 ****
2025-12-10 13:57:47.994185 | controller | changed: [instance]
2025-12-10 13:57:48.722501 | controller |
2025-12-10 13:57:48.722532 | controller | TASK [Restart firewalld.service] ***********************************************
2025-12-10 13:57:48.722540 | controller | Wednesday 10 December 2025  13:57:47 +0000 (0:00:00.318)       0:07:59.978 ****
2025-12-10 13:57:48.722549 | controller | changed: [instance]
2025-12-10 13:57:48.751049 | controller |
2025-12-10 13:57:48.751081 | controller | TASK [Generate test node UUID] *************************************************
2025-12-10 13:57:48.751096 | controller | Wednesday 10 December 2025  13:57:48 +0000 (0:00:00.728)       0:08:00.707 ****
2025-12-10 13:57:48.751105 | controller | ok: [instance]
2025-12-10 13:57:56.281616 | controller |
2025-12-10 13:57:56.281651 | controller | TASK [Make an a copy of the discovered/downloaded image] ***********************
2025-12-10 13:57:56.281659 | controller | Wednesday 10 December 2025  13:57:48 +0000 (0:00:00.028)       0:08:00.735 ****
2025-12-10 13:57:56.281668 | controller | changed: [instance]
2025-12-10 13:57:56.364431 | controller |
2025-12-10 13:57:56.364453 | controller | TASK [Create the config-drive ISO for the test node] ***************************
2025-12-10 13:57:56.364460 | controller | Wednesday 10 December 2025  13:57:56 +0000 (0:00:07.530)       0:08:08.266 ****
2025-12-10 13:57:56.364469 | controller |
2025-12-10 13:57:56.758660 | controller | TASK [config_drive : Ensure needed directories exist] **************************
2025-12-10 13:57:56.758682 | controller | Wednesday 10 December 2025  13:57:56 +0000 (0:00:00.082)       0:08:08.348 ****
2025-12-10 13:57:56.758693 | controller | ok: [instance] => (item=artifacts)
2025-12-10 13:57:58.157583 | controller | ok: [instance] => (item=logs)
2025-12-10 13:57:58.157614 | controller |
2025-12-10 13:57:58.157622 | controller | TASK [config_drive : Install required RPM packages] ****************************
2025-12-10 13:57:58.157629 | controller | Wednesday 10 December 2025  13:57:56 +0000 (0:00:00.393)       0:08:08.742 ****
2025-12-10 13:57:58.157638 | controller | ok: [instance]
2025-12-10 13:57:58.348123 | controller |
2025-12-10 13:57:58.348156 | controller | TASK [config_drive : Crate config drive instance directory] ********************
2025-12-10 13:57:58.348163 | controller | Wednesday 10 December 2025  13:57:58 +0000 (0:00:01.399)       0:08:10.142 ****
2025-12-10 13:57:58.348173 | controller | changed: [instance]
2025-12-10 13:57:58.696797 | controller |
2025-12-10 13:57:58.696843 | controller | TASK [config_drive : Generate meta-data] ***************************************
2025-12-10 13:57:58.696852 | controller | Wednesday 10 December 2025  13:57:58 +0000 (0:00:00.190)       0:08:10.332 ****
2025-12-10 13:57:58.696861 | controller | changed: [instance]
2025-12-10 13:57:59.028213 | controller |
2025-12-10 13:57:59.028245 | controller | TASK [config_drive : Generate user-data] ***************************************
2025-12-10 13:57:59.028253 | controller | Wednesday 10 December 2025  13:57:58 +0000 (0:00:00.348)       0:08:10.681 ****
2025-12-10 13:57:59.028263 | controller | changed: [instance]
2025-12-10 13:57:59.028507 | controller |
2025-12-10 13:57:59.028520 | controller | TASK [config_drive : Generate network-data] ************************************
2025-12-10 13:57:59.372006 | controller | Wednesday 10 December 2025  13:57:59 +0000 (0:00:00.331)       0:08:11.012 ****
2025-12-10 13:57:59.372043 | controller | changed: [instance]
2025-12-10 13:57:59.565911 | controller |
2025-12-10 13:57:59.565934 | controller | TASK [config_drive : Check ISO availability] ***********************************
2025-12-10 13:57:59.565942 | controller | Wednesday 10 December 2025  13:57:59 +0000 (0:00:00.343)       0:08:11.356 ****
2025-12-10 13:57:59.565950 | controller | ok: [instance]
2025-12-10 13:57:59.581974 | controller |
2025-12-10 13:57:59.581992 | controller | TASK [config_drive : Assert we don't try to change an existing ISO] ************
2025-12-10 13:57:59.582000 | controller | Wednesday 10 December 2025  13:57:59 +0000 (0:00:00.193)       0:08:11.550 ****
2025-12-10 13:57:59.582008 | controller | skipping: [instance]
2025-12-10 13:57:59.784705 | controller |
2025-12-10 13:57:59.784733 | controller | TASK [config_drive : Generate nocloud iso image] *******************************
2025-12-10 13:57:59.784741 | controller | Wednesday 10 December 2025  13:57:59 +0000 (0:00:00.016)       0:08:11.567 ****
2025-12-10 13:57:59.784750 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_generate_nocloud_iso.log
2025-12-10 13:58:00.040589 | controller | changed: [instance]
2025-12-10 13:58:00.040623 | controller |
2025-12-10 13:58:00.040631 | controller | TASK [Define test-node VM] *****************************************************
2025-12-10 13:58:00.040638 | controller | Wednesday 10 December 2025  13:57:59 +0000 (0:00:00.202)       0:08:11.769 ****
2025-12-10 13:58:00.040647 | controller | changed: [instance]
2025-12-10 13:58:00.509019 | controller |
2025-12-10 13:58:00.509057 | controller | TASK [Start test-node VM] ******************************************************
2025-12-10 13:58:00.509088 | controller | Wednesday 10 December 2025  13:58:00 +0000 (0:00:00.255)       0:08:12.025 ****
2025-12-10 13:58:00.509100 | controller | changed: [instance]
2025-12-10 13:58:24.108323 | controller |
2025-12-10 13:58:24.108374 | controller | TASK [Wait for test node to be reachable via ssh] ******************************
2025-12-10 13:58:24.108382 | controller | Wednesday 10 December 2025  13:58:00 +0000 (0:00:00.468)       0:08:12.493 ****
2025-12-10 13:58:24.108392 | controller | ok: [instance]
2025-12-10 13:58:24.108412 | controller |
2025-12-10 13:58:24.108458 | controller | TASK [Add test node to inventory] **********************************************
2025-12-10 13:58:24.108550 | controller | Wednesday 10 December 2025  13:58:24 +0000 (0:00:23.599)       0:08:36.093 ****
2025-12-10 13:58:24.133619 | controller | changed: [instance]
2025-12-10 13:58:24.154707 | controller |
2025-12-10 13:58:24.154731 | controller | TASK [Add nat64 appliance to the invetory] *************************************
2025-12-10 13:58:24.154738 | controller | Wednesday 10 December 2025  13:58:24 +0000 (0:00:00.025)       0:08:36.118 ****
2025-12-10 13:58:24.154747 | controller | changed: [instance]
2025-12-10 13:58:44.198846 | controller |
2025-12-10 13:58:44.198878 | controller | TASK [Wait a little to let the test instance boot.] ****************************
2025-12-10 13:58:44.198886 | controller | Wednesday 10 December 2025  13:58:24 +0000 (0:00:00.021)       0:08:36.139 ****
2025-12-10 13:58:44.198896 | controller | Pausing for 20 seconds
2025-12-10 13:58:50.699937 | controller | ok: [instance]
2025-12-10 13:58:50.699971 | controller |
2025-12-10 13:58:50.699979 | controller | TASK [Run some commands to test the nat64-appliance DNS64 functions] ***********
2025-12-10 13:58:50.699985 | controller | Wednesday 10 December 2025  13:58:44 +0000 (0:00:20.043)       0:08:56.183 ****
2025-12-10 13:58:50.699994 | controller | changed: [instance]
2025-12-10 13:58:51.669060 | controller |
2025-12-10 13:58:51.669112 | controller | TASK [Grab some info from the test node] ***************************************
2025-12-10 13:58:51.669120 | controller | Wednesday 10 December 2025  13:58:50 +0000 (0:00:06.501)       0:09:02.684 ****
2025-12-10 13:58:51.669131 | controller | changed: [instance -> test-node(2620:cf:cf:aaaa::101)]
2025-12-10 13:58:51.669157 | controller |
2025-12-10 13:58:51.669165 | controller | TASK [Grab some info from the nat64 appliance] *********************************
2025-12-10 13:58:51.669298 | controller | Wednesday 10 December 2025  13:58:51 +0000 (0:00:00.969)       0:09:03.653 ****
2025-12-10 13:58:52.656871 | controller | changed: [instance -> nat64-appliance(172.31.255.2)]
2025-12-10 13:58:53.187570 | controller |
2025-12-10 13:58:53.187601 | controller | TASK [Grab the journal from the nat64 appliance] *******************************
2025-12-10 13:58:53.187608 | controller | Wednesday 10 December 2025  13:58:52 +0000 (0:00:00.987)       0:09:04.641 ****
2025-12-10 13:58:53.187618 | controller | changed: [instance -> nat64-appliance(172.31.255.2)]
2025-12-10 13:58:53.696141 | controller |
2025-12-10 13:58:53.696185 | controller | TASK [Grab some info from hypervisor] ******************************************
2025-12-10 13:58:53.696194 | controller | Wednesday 10 December 2025  13:58:53 +0000 (0:00:00.530)       0:09:05.172 ****
2025-12-10 13:58:53.696204 | controller | changed: [instance]
2025-12-10 13:58:54.016887 | controller |
2025-12-10 13:58:54.016924 | controller | TASK [Write test-node info to file] ********************************************
2025-12-10 13:58:54.016932 | controller | Wednesday 10 December 2025  13:58:53 +0000 (0:00:00.508)       0:09:05.680 ****
2025-12-10 13:58:54.016942 | controller | changed: [instance]
2025-12-10 13:58:54.335562 | controller |
2025-12-10 13:58:54.335591 | controller | TASK [Write nat64-appliance info to file] **************************************
2025-12-10 13:58:54.335599 | controller | Wednesday 10 December 2025  13:58:54 +0000 (0:00:00.320)       0:09:06.001 ****
2025-12-10 13:58:54.335608 | controller | changed: [instance]
2025-12-10 13:58:54.647153 | controller |
2025-12-10 13:58:54.647187 | controller | TASK [Write nat64-appliance journal to file] ***********************************
2025-12-10 13:58:54.647195 | controller | Wednesday 10 December 2025  13:58:54 +0000 (0:00:00.318)       0:09:06.320 ****
2025-12-10 13:58:54.647205 | controller | changed: [instance]
2025-12-10 13:58:54.949356 | controller |
2025-12-10 13:58:54.949388 | controller | TASK [Write nat64-appliance DNS64 debug to file] *******************************
2025-12-10 13:58:54.949396 | controller | Wednesday 10 December 2025  13:58:54 +0000 (0:00:00.311)       0:09:06.631 ****
2025-12-10 13:58:54.949407 | controller | changed: [instance]
2025-12-10 13:58:55.260275 | controller |
2025-12-10 13:58:55.260304 | controller | TASK [Write hypervisor info to file] *******************************************
2025-12-10 13:58:55.260312 | controller | Wednesday 10 December 2025  13:58:54 +0000 (0:00:00.302)       0:09:06.934 ****
2025-12-10 13:58:55.260327 | controller | changed: [instance]
2025-12-10 13:58:55.260346 | controller |
2025-12-10 13:58:55.260450 | controller | TASK [Ping example.com (delegate to test-node)] ********************************
2025-12-10 13:58:55.260549 | controller | Wednesday 10 December 2025  13:58:55 +0000 (0:00:00.311)       0:09:07.245 ****
2025-12-10 13:58:56.862293 | controller | changed: [instance -> test-node(2620:cf:cf:aaaa::101)]
2025-12-10 13:58:56.862358 | controller |
2025-12-10 13:58:56.862551 | controller | TASK [Debug the ping example.com result] ***************************************
2025-12-10 13:58:56.916210 | controller | Wednesday 10 December 2025  13:58:56 +0000 (0:00:01.601)       0:09:08.847 ****
2025-12-10 13:58:56.916287 | controller | ok: [instance] => (item=0) =>
2025-12-10 13:58:56.916341 | controller |   msg: '0'
2025-12-10 13:58:56.916353 | controller | ok: [instance] => (item=['PING example.com(a23-220-75-245.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4bf5)) 56 data bytes', '64 bytes from a23-220-75-245.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4bf5): icmp_seq=1 ttl=44 time=41.0 ms', '64 bytes from a23-220-75-245.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4bf5): icmp_seq=2 ttl=44 time=41.7 ms', '', '--- example.com ping statistics ---', '2 packets transmitted, 2 received, 0% packet loss, time 1002ms', 'rtt min/avg/max/mdev = 40.995/41.336/41.678/0.341 ms']) =>
2025-12-10 13:58:56.917119 | controller |   msg:
2025-12-10 13:58:56.917134 | controller |   - PING example.com(a23-220-75-245.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4bf5)) 56 data bytes
2025-12-10 13:58:56.918189 | controller |   - '64 bytes from a23-220-75-245.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4bf5): icmp_seq=1 ttl=44 time=41.0 ms'
2025-12-10 13:58:56.918229 | controller |   - '64 bytes from a23-220-75-245.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4bf5): icmp_seq=2 ttl=44 time=41.7 ms'
2025-12-10 13:58:56.918239 | controller |   - ''
2025-12-10 13:58:56.918249 | controller |   - '--- example.com ping statistics ---'
2025-12-10 13:58:56.918258 | controller |   - 2 packets transmitted, 2 received, 0% packet loss, time 1002ms
2025-12-10 13:58:56.918268 | controller |   - rtt min/avg/max/mdev = 40.995/41.336/41.678/0.341 ms
2025-12-10 13:58:56.918277 | controller | ok: [instance] => (item=[]) =>
2025-12-10 13:58:56.918285 | controller |   msg: []
2025-12-10 13:58:56.918298 | controller |
2025-12-10 13:58:56.918331 | controller | PLAY RECAP *********************************************************************
2025-12-10 13:58:56.918341 | controller | instance                   : ok=74   changed=50   unreachable=0    failed=0    skipped=3    rescued=0    ignored=0
2025-12-10 13:58:56.918349 | controller |
2025-12-10 13:58:56.918357 | controller | Wednesday 10 December 2025  13:58:56 +0000 (0:00:00.053)       0:09:08.900 ****
2025-12-10 13:58:56.918365 | controller | ===============================================================================
2025-12-10 13:58:56.918392 | controller | nat64_appliance : Build the nat64-appliance image using DIB ----------- 413.74s
2025-12-10 13:58:56.918400 | controller | Wait for test node to be reachable via ssh ----------------------------- 23.60s
2025-12-10 13:58:56.918420 | controller | Wait a little to let the test instance boot. --------------------------- 20.04s
2025-12-10 13:58:56.918428 | controller | Download latest image -------------------------------------------------- 19.45s
2025-12-10 13:58:56.918435 | controller | nat64_appliance : Copy files to cifmw_nat64_appliance_dir -------------- 10.30s
2025-12-10 13:58:56.918442 | controller | nat64_appliance : Install diskimage-builder in virtualenv --------------- 7.97s
2025-12-10 13:58:56.918450 | controller | Make an a copy of the discovered/downloaded image ----------------------- 7.53s
2025-12-10 13:58:56.918460 | controller | Fix permissions on nat64_appliance dir - because we ran dib as root ----- 6.98s
2025-12-10 13:58:56.918468 | controller | Run some commands to test the nat64-appliance DNS64 functions ----------- 6.50s
2025-12-10 13:58:56.918475 | controller | nat64_appliance : Install required RPM packages ------------------------- 4.63s
2025-12-10 13:58:56.918485 | controller | discover_latest_image : Get latest image -------------------------------- 1.90s
2025-12-10 13:58:56.918581 | controller | Ping example.com (delegate to test-node) -------------------------------- 1.60s
2025-12-10 13:58:56.918688 | controller | config_drive : Install required RPM packages ---------------------------- 1.40s
2025-12-10 13:58:56.918804 | controller | config_drive : Install required RPM packages ---------------------------- 1.20s
2025-12-10 13:58:56.918907 | controller | nat64_appliance : Clone edpm-image-builder (reset-bls-entries dib element) --- 1.14s
2025-12-10 13:58:56.919008 | controller | nat64_appliance : Define nat64-appliance VM ----------------------------- 1.08s
2025-12-10 13:58:56.919152 | controller | Restart firewalld.service ----------------------------------------------- 1.04s
2025-12-10 13:58:56.919267 | controller | Grab some info from the nat64 appliance --------------------------------- 0.99s
2025-12-10 13:58:56.919365 | controller | Grab some info from the test node --------------------------------------- 0.97s
2025-12-10 13:58:56.919468 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-12-10 13:58:57.025827 | controller | INFO     Running build > cleanup
2025-12-10 13:58:57.499176 | controller |
2025-12-10 13:58:57.499867 | controller | PLAY [Cleanup] *****************************************************************
2025-12-10 13:58:58.501947 | controller |
2025-12-10 13:58:58.502014 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 13:58:58.502023 | controller | Wednesday 10 December 2025  13:58:57 +0000 (0:00:00.052)       0:00:00.052 ****
2025-12-10 13:58:58.502036 | controller | ok: [instance]
2025-12-10 13:58:59.112803 | controller |
2025-12-10 13:58:59.112867 | controller | TASK [Destroy the test-node] ***************************************************
2025-12-10 13:58:59.112877 | controller | Wednesday 10 December 2025  13:58:58 +0000 (0:00:01.003)       0:00:01.055 ****
2025-12-10 13:58:59.112890 | controller | ok: [instance]
2025-12-10 13:58:59.387538 | controller |
2025-12-10 13:58:59.387593 | controller | TASK [Undefine the test-node] **************************************************
2025-12-10 13:58:59.387602 | controller | Wednesday 10 December 2025  13:58:59 +0000 (0:00:00.610)       0:00:01.666 ****
2025-12-10 13:58:59.387616 | controller | ok: [instance]
2025-12-10 13:58:59.795449 | controller |
2025-12-10 13:58:59.795508 | controller | TASK [Destroy the test network] ************************************************
2025-12-10 13:58:59.795517 | controller | Wednesday 10 December 2025  13:58:59 +0000 (0:00:00.274)       0:00:01.941 ****
2025-12-10 13:58:59.795530 | controller | ok: [instance]
2025-12-10 13:59:00.057148 | controller |
2025-12-10 13:59:00.057210 | controller | TASK [Undefine the test network] ***********************************************
2025-12-10 13:59:00.057222 | controller | Wednesday 10 December 2025  13:58:59 +0000 (0:00:00.408)       0:00:02.349 ****
2025-12-10 13:59:00.057248 | controller | ok: [instance]
2025-12-10 13:59:00.096213 | controller |
2025-12-10 13:59:00.096252 | controller | TASK [Cleanup the nat64 appliance and networks] ********************************
2025-12-10 13:59:00.096263 | controller | Wednesday 10 December 2025  13:59:00 +0000 (0:00:00.261)       0:00:02.610 ****
2025-12-10 13:59:00.096279 | controller |
2025-12-10 13:59:00.412988 | controller | TASK [nat64_appliance : Cleaning up nat64_appliance image] *********************
2025-12-10 13:59:00.413040 | controller | Wednesday 10 December 2025  13:59:00 +0000 (0:00:00.039)       0:00:02.650 ****
2025-12-10 13:59:00.413140 | controller | changed: [instance]
2025-12-10 13:59:00.713301 | controller |
2025-12-10 13:59:00.713340 | controller | TASK [nat64_appliance : Get virtqemud socket] **********************************
2025-12-10 13:59:00.713349 | controller | Wednesday 10 December 2025  13:59:00 +0000 (0:00:00.316)       0:00:02.966 ****
2025-12-10 13:59:00.713361 | controller | ok: [instance]
2025-12-10 13:59:00.986218 | controller |
2025-12-10 13:59:00.986274 | controller | TASK [nat64_appliance : List VMs] **********************************************
2025-12-10 13:59:00.986283 | controller | Wednesday 10 December 2025  13:59:00 +0000 (0:00:00.300)       0:00:03.267 ****
2025-12-10 13:59:00.986296 | controller | ok: [instance]
2025-12-10 13:59:00.986458 | controller |
2025-12-10 13:59:00.986470 | controller | TASK [nat64_appliance : Get nat64_appliance VM state] **************************
2025-12-10 13:59:00.986480 | controller | Wednesday 10 December 2025  13:59:00 +0000 (0:00:00.272)       0:00:03.539 ****
2025-12-10 13:59:01.241224 | controller | ok: [instance]
2025-12-10 13:59:01.241273 | controller |
2025-12-10 13:59:01.241292 | controller | TASK [nat64_appliance : Stop the nat64_appliance VM] ***************************
2025-12-10 13:59:01.241303 | controller | Wednesday 10 December 2025  13:59:01 +0000 (0:00:00.255)       0:00:03.795 ****
2025-12-10 13:59:01.742373 | controller | ok: [instance]
2025-12-10 13:59:02.001873 | controller |
2025-12-10 13:59:02.001932 | controller | TASK [nat64_appliance : Undefine the nat64_appliance VM] ***********************
2025-12-10 13:59:02.001943 | controller | Wednesday 10 December 2025  13:59:01 +0000 (0:00:00.500)       0:00:04.296 ****
2025-12-10 13:59:02.001957 | controller | ok: [instance]
2025-12-10 13:59:02.797423 | controller |
2025-12-10 13:59:02.797465 | controller | TASK [nat64_appliance : Destroy the nat64 networks] ****************************
2025-12-10 13:59:02.797474 | controller | Wednesday 10 December 2025  13:59:01 +0000 (0:00:00.259)       0:00:04.555 ****
2025-12-10 13:59:02.797486 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 13:59:03.314848 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 13:59:03.314913 | controller |
2025-12-10 13:59:03.314923 | controller | TASK [nat64_appliance : Undefine the nat64 networks] ***************************
2025-12-10 13:59:03.314930 | controller | Wednesday 10 December 2025  13:59:02 +0000 (0:00:00.795)       0:00:05.351 ****
2025-12-10 13:59:03.314944 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 13:59:03.367250 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 13:59:03.367328 | controller |
2025-12-10 13:59:03.367337 | controller | PLAY RECAP *********************************************************************
2025-12-10 13:59:03.367344 | controller | instance                   : ok=13   changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-12-10 13:59:03.367350 | controller |
2025-12-10 13:59:03.367356 | controller | Wednesday 10 December 2025  13:59:03 +0000 (0:00:00.515)       0:00:05.866 ****
2025-12-10 13:59:03.367362 | controller | ===============================================================================
2025-12-10 13:59:03.367367 | controller | Gathering Facts --------------------------------------------------------- 1.00s
2025-12-10 13:59:03.367373 | controller | nat64_appliance : Destroy the nat64 networks ---------------------------- 0.80s
2025-12-10 13:59:03.367378 | controller | Destroy the test-node --------------------------------------------------- 0.61s
2025-12-10 13:59:03.367384 | controller | nat64_appliance : Undefine the nat64 networks --------------------------- 0.52s
2025-12-10 13:59:03.367389 | controller | nat64_appliance : Stop the nat64_appliance VM --------------------------- 0.50s
2025-12-10 13:59:03.367395 | controller | Destroy the test network ------------------------------------------------ 0.41s
2025-12-10 13:59:03.367400 | controller | nat64_appliance : Cleaning up nat64_appliance image --------------------- 0.32s
2025-12-10 13:59:03.367405 | controller | nat64_appliance : Get virtqemud socket ---------------------------------- 0.30s
2025-12-10 13:59:03.367411 | controller | Undefine the test-node -------------------------------------------------- 0.27s
2025-12-10 13:59:03.367416 | controller | nat64_appliance : List VMs ---------------------------------------------- 0.27s
2025-12-10 13:59:03.367430 | controller | Undefine the test network ----------------------------------------------- 0.26s
2025-12-10 13:59:03.367443 | controller | nat64_appliance : Undefine the nat64_appliance VM ----------------------- 0.26s
2025-12-10 13:59:03.367449 | controller | nat64_appliance : Get nat64_appliance VM state -------------------------- 0.26s
2025-12-10 13:59:03.367454 | controller | Cleanup the nat64 appliance and networks -------------------------------- 0.04s
2025-12-10 13:59:03.367466 | controller | INFO     Performing prerun with role_name_check=0...
2025-12-10 13:59:20.982608 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.983144 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.983599 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.984080 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.984581 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+95f3db89 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0+95f3db89 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.985029 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.985489 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.985937 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.986384 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.986833 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.987527 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.987991 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.988443 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.988891 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.989347 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 13:59:20.997291 | controller | INFO     Running download > prepare
2025-12-10 13:59:21.430155 | controller |
2025-12-10 13:59:22.328874 | controller | PLAY [Prepare] *****************************************************************
2025-12-10 13:59:22.328907 | controller |
2025-12-10 13:59:22.328915 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 13:59:22.328921 | controller | Wednesday 10 December 2025  13:59:21 +0000 (0:00:00.023)       0:00:00.023 ****
2025-12-10 13:59:22.328930 | controller | ok: [instance]
2025-12-10 13:59:22.654498 | controller |
2025-12-10 13:59:22.654538 | controller | TASK [Create custom basedir] ***************************************************
2025-12-10 13:59:22.654547 | controller | Wednesday 10 December 2025  13:59:22 +0000 (0:00:00.899)       0:00:00.923 ****
2025-12-10 13:59:22.654557 | controller | ok: [instance]
2025-12-10 13:59:24.020572 | controller |
2025-12-10 13:59:24.020605 | controller | TASK [Install some debug utils] ************************************************
2025-12-10 13:59:24.020613 | controller | Wednesday 10 December 2025  13:59:22 +0000 (0:00:00.325)       0:00:01.248 ****
2025-12-10 13:59:24.020623 | controller | ok: [instance]
2025-12-10 13:59:24.055008 | controller |
2025-12-10 13:59:24.055027 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-12-10 13:59:24.055034 | controller | Wednesday 10 December 2025  13:59:24 +0000 (0:00:01.365)       0:00:02.614 ****
2025-12-10 13:59:24.055042 | controller | skipping: [instance]
2025-12-10 13:59:24.100167 | controller |
2025-12-10 13:59:24.100191 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-12-10 13:59:24.100199 | controller | Wednesday 10 December 2025  13:59:24 +0000 (0:00:00.034)       0:00:02.649 ****
2025-12-10 13:59:24.100210 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-12-10 13:59:24.382081 | controller |
2025-12-10 13:59:24.382113 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-12-10 13:59:24.382121 | controller | Wednesday 10 December 2025  13:59:24 +0000 (0:00:00.045)       0:00:02.694 ****
2025-12-10 13:59:24.382131 | controller | ok: [instance]
2025-12-10 13:59:24.644765 | controller |
2025-12-10 13:59:24.644796 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-12-10 13:59:24.644804 | controller | Wednesday 10 December 2025  13:59:24 +0000 (0:00:00.281)       0:00:02.976 ****
2025-12-10 13:59:24.644814 | controller | ok: [instance]
2025-12-10 13:59:25.339535 | controller |
2025-12-10 13:59:25.339569 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-12-10 13:59:25.339577 | controller | Wednesday 10 December 2025  13:59:24 +0000 (0:00:00.262)       0:00:03.239 ****
2025-12-10 13:59:25.339587 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-12-10 13:59:25.406228 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-12-10 13:59:25.406267 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-12-10 13:59:25.406281 | controller |
2025-12-10 13:59:25.406291 | controller | TASK [Deploy repo-setup] *******************************************************
2025-12-10 13:59:25.406301 | controller | Wednesday 10 December 2025  13:59:25 +0000 (0:00:00.694)       0:00:03.933 ****
2025-12-10 13:59:25.406317 | controller |
2025-12-10 13:59:25.965830 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-12-10 13:59:25.965863 | controller | Wednesday 10 December 2025  13:59:25 +0000 (0:00:00.067)       0:00:04.000 ****
2025-12-10 13:59:25.965875 | controller | ok: [instance] => (item=tmp)
2025-12-10 13:59:27.299156 | controller | ok: [instance] => (item=artifacts/repositories)
2025-12-10 13:59:27.299189 | controller | ok: [instance] => (item=venv/repo_setup)
2025-12-10 13:59:27.299197 | controller |
2025-12-10 13:59:27.299203 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-12-10 13:59:27.299215 | controller | Wednesday 10 December 2025  13:59:25 +0000 (0:00:00.559)       0:00:04.559 ****
2025-12-10 13:59:27.299224 | controller | ok: [instance]
2025-12-10 13:59:27.299230 | controller |
2025-12-10 13:59:27.299235 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-12-10 13:59:27.299242 | controller | Wednesday 10 December 2025  13:59:27 +0000 (0:00:01.333)       0:00:05.893 ****
2025-12-10 13:59:27.897875 | controller | ok: [instance]
2025-12-10 13:59:29.220326 | controller |
2025-12-10 13:59:29.220358 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-12-10 13:59:29.220366 | controller | Wednesday 10 December 2025  13:59:27 +0000 (0:00:00.598)       0:00:06.492 ****
2025-12-10 13:59:29.220382 | controller | ok: [instance]
2025-12-10 13:59:29.510986 | controller |
2025-12-10 13:59:29.511015 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-12-10 13:59:29.511022 | controller | Wednesday 10 December 2025  13:59:29 +0000 (0:00:01.322)       0:00:07.814 ****
2025-12-10 13:59:29.511032 | controller | ok: [instance]
2025-12-10 13:59:29.543700 | controller |
2025-12-10 13:59:29.543727 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-12-10 13:59:29.543734 | controller | Wednesday 10 December 2025  13:59:29 +0000 (0:00:00.290)       0:00:08.105 ****
2025-12-10 13:59:29.543742 | controller | skipping: [instance]
2025-12-10 13:59:30.413305 | controller |
2025-12-10 13:59:30.413337 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-12-10 13:59:30.413345 | controller | Wednesday 10 December 2025  13:59:29 +0000 (0:00:00.033)       0:00:08.138 ****
2025-12-10 13:59:30.413355 | controller | changed: [instance]
2025-12-10 13:59:30.464583 | controller |
2025-12-10 13:59:30.464600 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-12-10 13:59:30.464607 | controller | Wednesday 10 December 2025  13:59:30 +0000 (0:00:00.869)       0:00:09.007 ****
2025-12-10 13:59:30.464615 | controller | skipping: [instance]
2025-12-10 13:59:30.509915 | controller |
2025-12-10 13:59:30.509938 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-12-10 13:59:30.509945 | controller | Wednesday 10 December 2025  13:59:30 +0000 (0:00:00.051)       0:00:09.059 ****
2025-12-10 13:59:30.509953 | controller | skipping: [instance]
2025-12-10 13:59:30.554134 | controller |
2025-12-10 13:59:30.554196 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-12-10 13:59:30.554210 | controller | Wednesday 10 December 2025  13:59:30 +0000 (0:00:00.045)       0:00:09.104 ****
2025-12-10 13:59:30.554227 | controller | skipping: [instance]
2025-12-10 13:59:30.554524 | controller |
2025-12-10 13:59:32.118856 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-12-10 13:59:32.118889 | controller | Wednesday 10 December 2025  13:59:30 +0000 (0:00:00.044)       0:00:09.149 ****
2025-12-10 13:59:32.118901 | controller | changed: [instance]
2025-12-10 13:59:32.501098 | controller |
2025-12-10 13:59:32.501132 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-12-10 13:59:32.501140 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:01.564)       0:00:10.713 ****
2025-12-10 13:59:32.501151 | controller | ok: [instance]
2025-12-10 13:59:32.547326 | controller |
2025-12-10 13:59:32.547350 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-12-10 13:59:32.547359 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.382)       0:00:11.095 ****
2025-12-10 13:59:32.547370 | controller | skipping: [instance]
2025-12-10 13:59:32.587144 | controller |
2025-12-10 13:59:32.587167 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-12-10 13:59:32.587177 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.045)       0:00:11.141 ****
2025-12-10 13:59:32.587188 | controller | skipping: [instance]
2025-12-10 13:59:32.587215 | controller |
2025-12-10 13:59:32.587225 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-12-10 13:59:32.587327 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.040)       0:00:11.181 ****
2025-12-10 13:59:32.625143 | controller | skipping: [instance]
2025-12-10 13:59:32.668667 | controller |
2025-12-10 13:59:32.668687 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-12-10 13:59:32.668699 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.037)       0:00:11.219 ****
2025-12-10 13:59:32.668718 | controller | ok: [instance]
2025-12-10 13:59:32.702250 | controller |
2025-12-10 13:59:32.702272 | controller | TASK [repo_setup : Create download directory] **********************************
2025-12-10 13:59:32.702280 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.043)       0:00:11.263 ****
2025-12-10 13:59:32.702291 | controller | skipping: [instance]
2025-12-10 13:59:32.702396 | controller |
2025-12-10 13:59:32.702458 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-12-10 13:59:32.702474 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.033)       0:00:11.296 ****
2025-12-10 13:59:32.767719 | controller | skipping: [instance]
2025-12-10 13:59:32.801123 | controller |
2025-12-10 13:59:32.801153 | controller | TASK [Download the RPM] ********************************************************
2025-12-10 13:59:32.801163 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.065)       0:00:11.362 ****
2025-12-10 13:59:32.801175 | controller | skipping: [instance]
2025-12-10 13:59:32.833860 | controller |
2025-12-10 13:59:32.833885 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-12-10 13:59:32.833902 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.033)       0:00:11.395 ****
2025-12-10 13:59:32.833914 | controller | skipping: [instance]
2025-12-10 13:59:32.834116 | controller |
2025-12-10 13:59:32.834298 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-12-10 13:59:32.834454 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.033)       0:00:11.428 ****
2025-12-10 13:59:32.866953 | controller | skipping: [instance]
2025-12-10 13:59:32.867128 | controller |
2025-12-10 13:59:32.867272 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-12-10 13:59:32.867428 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.033)       0:00:11.461 ****
2025-12-10 13:59:32.904546 | controller | skipping: [instance]
2025-12-10 13:59:32.904695 | controller |
2025-12-10 13:59:32.904863 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-12-10 13:59:32.905003 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.037)       0:00:11.499 ****
2025-12-10 13:59:32.935994 | controller | skipping: [instance]
2025-12-10 13:59:33.133620 | controller |
2025-12-10 13:59:33.133651 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-12-10 13:59:33.133659 | controller | Wednesday 10 December 2025  13:59:32 +0000 (0:00:00.031)       0:00:11.530 ****
2025-12-10 13:59:33.133669 | controller | ok: [instance]
2025-12-10 13:59:33.354841 | controller |
2025-12-10 13:59:33.354874 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-12-10 13:59:33.354881 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.197)       0:00:11.728 ****
2025-12-10 13:59:33.354892 | controller | changed: [instance]
2025-12-10 13:59:33.578951 | controller |
2025-12-10 13:59:33.578982 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-12-10 13:59:33.578991 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.221)       0:00:11.949 ****
2025-12-10 13:59:33.579002 | controller | changed: [instance]
2025-12-10 13:59:33.601981 | controller |
2025-12-10 13:59:33.602007 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-12-10 13:59:33.602015 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.223)       0:00:12.173 ****
2025-12-10 13:59:33.602025 | controller | skipping: [instance]
2025-12-10 13:59:33.629490 | controller |
2025-12-10 13:59:33.629512 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-12-10 13:59:33.629520 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.023)       0:00:12.196 ****
2025-12-10 13:59:33.629529 | controller | skipping: [instance]
2025-12-10 13:59:33.654619 | controller |
2025-12-10 13:59:33.654638 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-12-10 13:59:33.654646 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.027)       0:00:12.224 ****
2025-12-10 13:59:33.654655 | controller | skipping: [instance]
2025-12-10 13:59:33.680115 | controller |
2025-12-10 13:59:33.680134 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-12-10 13:59:33.680142 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.025)       0:00:12.249 ****
2025-12-10 13:59:33.680150 | controller | skipping: [instance]
2025-12-10 13:59:33.680523 | controller |
2025-12-10 13:59:33.705131 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-12-10 13:59:33.705151 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.025)       0:00:12.274 ****
2025-12-10 13:59:33.705163 | controller | skipping: [instance]
2025-12-10 13:59:33.705200 | controller |
2025-12-10 13:59:33.705209 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-12-10 13:59:33.705218 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.025)       0:00:12.300 ****
2025-12-10 13:59:33.731801 | controller | skipping: [instance]
2025-12-10 13:59:33.731893 | controller |
2025-12-10 13:59:33.731997 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-12-10 13:59:33.732103 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.026)       0:00:12.326 ****
2025-12-10 13:59:33.752030 | controller | skipping: [instance]
2025-12-10 13:59:33.782973 | controller |
2025-12-10 13:59:33.782995 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-12-10 13:59:33.783004 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.019)       0:00:12.346 ****
2025-12-10 13:59:33.783015 | controller | skipping: [instance]
2025-12-10 13:59:33.801616 | controller |
2025-12-10 13:59:33.801636 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-12-10 13:59:33.801644 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.030)       0:00:12.377 ****
2025-12-10 13:59:33.801654 | controller | skipping: [instance]
2025-12-10 13:59:33.826934 | controller |
2025-12-10 13:59:33.826948 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-12-10 13:59:33.826954 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.018)       0:00:12.396 ****
2025-12-10 13:59:33.826962 | controller | skipping: [instance]
2025-12-10 13:59:33.859956 | controller |
2025-12-10 13:59:33.859989 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-12-10 13:59:33.859999 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.025)       0:00:12.421 ****
2025-12-10 13:59:33.860024 | controller | skipping: [instance]
2025-12-10 13:59:33.891116 | controller |
2025-12-10 13:59:33.891133 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-12-10 13:59:33.891139 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.032)       0:00:12.454 ****
2025-12-10 13:59:33.891147 | controller | skipping: [instance]
2025-12-10 13:59:33.922177 | controller |
2025-12-10 13:59:33.922201 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-12-10 13:59:33.922210 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.030)       0:00:12.485 ****
2025-12-10 13:59:33.922221 | controller | skipping: [instance]
2025-12-10 13:59:33.956948 | controller |
2025-12-10 13:59:33.956971 | controller | TASK [test_deps : Install additional packages] *********************************
2025-12-10 13:59:33.956980 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.031)       0:00:12.517 ****
2025-12-10 13:59:33.956991 | controller | skipping: [instance]
2025-12-10 14:00:17.430049 | controller |
2025-12-10 14:00:17.430094 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-12-10 14:00:17.430102 | controller | Wednesday 10 December 2025  13:59:33 +0000 (0:00:00.034)       0:00:12.551 ****
2025-12-10 14:00:17.430111 | controller | ok: [instance]
2025-12-10 14:00:18.651026 | controller |
2025-12-10 14:00:18.651055 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-12-10 14:00:18.651077 | controller | Wednesday 10 December 2025  14:00:17 +0000 (0:00:43.473)       0:00:56.024 ****
2025-12-10 14:00:18.651091 | controller | ok: [instance]
2025-12-10 14:00:18.683687 | controller |
2025-12-10 14:00:18.683709 | controller | TASK [test_deps : Install extra packages] **************************************
2025-12-10 14:00:18.683718 | controller | Wednesday 10 December 2025  14:00:18 +0000 (0:00:01.220)       0:00:57.245 ****
2025-12-10 14:00:18.683737 | controller | skipping: [instance]
2025-12-10 14:00:18.864867 | controller |
2025-12-10 14:00:18.864899 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-12-10 14:00:18.864907 | controller | Wednesday 10 December 2025  14:00:18 +0000 (0:00:00.032)       0:00:57.278 ****
2025-12-10 14:00:18.864916 | controller | ok: [instance]
2025-12-10 14:00:19.034142 | controller |
2025-12-10 14:00:19.034170 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-12-10 14:00:19.034178 | controller | Wednesday 10 December 2025  14:00:18 +0000 (0:00:00.181)       0:00:57.459 ****
2025-12-10 14:00:19.034188 | controller | changed: [instance]
2025-12-10 14:00:19.034210 | controller |
2025-12-10 14:00:19.034380 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-12-10 14:00:19.202830 | controller | Wednesday 10 December 2025  14:00:19 +0000 (0:00:00.169)       0:00:57.629 ****
2025-12-10 14:00:19.202858 | controller | ok: [instance]
2025-12-10 14:00:19.229119 | controller |
2025-12-10 14:00:19.229136 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-12-10 14:00:19.229143 | controller | Wednesday 10 December 2025  14:00:19 +0000 (0:00:00.168)       0:00:57.797 ****
2025-12-10 14:00:19.229151 | controller | skipping: [instance]
2025-12-10 14:00:19.229303 | controller |
2025-12-10 14:00:19.229319 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-12-10 14:00:19.246117 | controller | Wednesday 10 December 2025  14:00:19 +0000 (0:00:00.026)       0:00:57.824 ****
2025-12-10 14:00:19.246158 | controller | skipping: [instance]
2025-12-10 14:00:19.265083 | controller |
2025-12-10 14:00:19.265106 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-12-10 14:00:19.265115 | controller | Wednesday 10 December 2025  14:00:19 +0000 (0:00:00.016)       0:00:57.840 ****
2025-12-10 14:00:19.265125 | controller | ok: [instance]
2025-12-10 14:00:19.290523 | controller |
2025-12-10 14:00:19.290538 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-12-10 14:00:19.290545 | controller | Wednesday 10 December 2025  14:00:19 +0000 (0:00:00.018)       0:00:57.859 ****
2025-12-10 14:00:19.290552 | controller | skipping: [instance]
2025-12-10 14:00:20.445133 | controller |
2025-12-10 14:00:20.445162 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-12-10 14:00:20.445170 | controller | Wednesday 10 December 2025  14:00:19 +0000 (0:00:00.025)       0:00:57.885 ****
2025-12-10 14:00:20.445179 | controller | ok: [instance]
2025-12-10 14:00:20.445200 | controller |
2025-12-10 14:00:20.445207 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-12-10 14:00:20.445255 | controller | Wednesday 10 December 2025  14:00:20 +0000 (0:00:01.154)       0:00:59.039 ****
2025-12-10 14:00:20.633529 | controller | ok: [instance]
2025-12-10 14:00:20.999390 | controller |
2025-12-10 14:00:20.999422 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-12-10 14:00:20.999436 | controller | Wednesday 10 December 2025  14:00:20 +0000 (0:00:00.188)       0:00:59.227 ****
2025-12-10 14:00:20.999446 | controller | ok: [instance]
2025-12-10 14:00:21.023932 | controller |
2025-12-10 14:00:21.023954 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-12-10 14:00:21.023962 | controller | Wednesday 10 December 2025  14:00:20 +0000 (0:00:00.365)       0:00:59.593 ****
2025-12-10 14:00:21.023972 | controller | skipping: [instance]
2025-12-10 14:00:21.219742 | controller |
2025-12-10 14:00:21.219768 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-12-10 14:00:21.219776 | controller | Wednesday 10 December 2025  14:00:21 +0000 (0:00:00.024)       0:00:59.618 ****
2025-12-10 14:00:21.219785 | controller | ok: [instance]
2025-12-10 14:00:21.832703 | controller |
2025-12-10 14:00:21.832734 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-12-10 14:00:21.832742 | controller | Wednesday 10 December 2025  14:00:21 +0000 (0:00:00.195)       0:00:59.814 ****
2025-12-10 14:00:21.832752 | controller | ok: [instance]
2025-12-10 14:00:22.130028 | controller |
2025-12-10 14:00:22.130058 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-12-10 14:00:22.130105 | controller | Wednesday 10 December 2025  14:00:21 +0000 (0:00:00.612)       0:01:00.427 ****
2025-12-10 14:00:22.130119 | controller | ok: [instance]
2025-12-10 14:00:22.210201 | controller |
2025-12-10 14:00:22.210242 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-12-10 14:00:22.210253 | controller | Wednesday 10 December 2025  14:00:22 +0000 (0:00:00.297)       0:01:00.724 ****
2025-12-10 14:00:22.210267 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-12-10 14:00:22.210300 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-12-10 14:00:22.210310 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-12-10 14:00:22.210323 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-12-10 14:00:22.210331 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-12-10 14:00:22.210341 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-12-10 14:00:22.210370 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-12-10 14:00:22.210735 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-12-10 14:00:22.709753 | controller |
2025-12-10 14:00:22.709783 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-12-10 14:00:22.709790 | controller | Wednesday 10 December 2025  14:00:22 +0000 (0:00:00.080)       0:01:00.804 ****
2025-12-10 14:00:22.709800 | controller | ok: [instance]
2025-12-10 14:00:23.010959 | controller |
2025-12-10 14:00:23.010988 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-12-10 14:00:23.010996 | controller | Wednesday 10 December 2025  14:00:22 +0000 (0:00:00.499)       0:01:01.304 ****
2025-12-10 14:00:23.011005 | controller | ok: [instance]
2025-12-10 14:00:23.309569 | controller |
2025-12-10 14:00:23.309598 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-12-10 14:00:23.309606 | controller | Wednesday 10 December 2025  14:00:23 +0000 (0:00:00.301)       0:01:01.605 ****
2025-12-10 14:00:23.309616 | controller | ok: [instance]
2025-12-10 14:00:23.625932 | controller |
2025-12-10 14:00:23.625965 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-12-10 14:00:23.625973 | controller | Wednesday 10 December 2025  14:00:23 +0000 (0:00:00.298)       0:01:01.904 ****
2025-12-10 14:00:23.625983 | controller | ok: [instance]
2025-12-10 14:00:23.933632 | controller |
2025-12-10 14:00:23.933677 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-12-10 14:00:23.933686 | controller | Wednesday 10 December 2025  14:00:23 +0000 (0:00:00.316)       0:01:02.220 ****
2025-12-10 14:00:23.933695 | controller | ok: [instance]
2025-12-10 14:00:24.254673 | controller |
2025-12-10 14:00:24.254707 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-12-10 14:00:24.254715 | controller | Wednesday 10 December 2025  14:00:23 +0000 (0:00:00.307)       0:01:02.528 ****
2025-12-10 14:00:24.254724 | controller | ok: [instance]
2025-12-10 14:00:24.558659 | controller |
2025-12-10 14:00:24.558694 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-12-10 14:00:24.558703 | controller | Wednesday 10 December 2025  14:00:24 +0000 (0:00:00.321)       0:01:02.849 ****
2025-12-10 14:00:24.558713 | controller | ok: [instance]
2025-12-10 14:00:24.867648 | controller |
2025-12-10 14:00:24.867689 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-12-10 14:00:24.867697 | controller | Wednesday 10 December 2025  14:00:24 +0000 (0:00:00.303)       0:01:03.153 ****
2025-12-10 14:00:24.867710 | controller | ok: [instance]
2025-12-10 14:00:25.168131 | controller |
2025-12-10 14:00:25.168162 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-12-10 14:00:25.168170 | controller | Wednesday 10 December 2025  14:00:24 +0000 (0:00:00.309)       0:01:03.462 ****
2025-12-10 14:00:25.168180 | controller | ok: [instance]
2025-12-10 14:00:25.468050 | controller |
2025-12-10 14:00:25.468142 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-12-10 14:00:25.468151 | controller | Wednesday 10 December 2025  14:00:25 +0000 (0:00:00.300)       0:01:03.762 ****
2025-12-10 14:00:25.468167 | controller | ok: [instance]
2025-12-10 14:00:25.788840 | controller |
2025-12-10 14:00:25.788877 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-12-10 14:00:25.788887 | controller | Wednesday 10 December 2025  14:00:25 +0000 (0:00:00.299)       0:01:04.062 ****
2025-12-10 14:00:25.788900 | controller | ok: [instance]
2025-12-10 14:00:26.089239 | controller |
2025-12-10 14:00:26.089272 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-12-10 14:00:26.089279 | controller | Wednesday 10 December 2025  14:00:25 +0000 (0:00:00.320)       0:01:04.383 ****
2025-12-10 14:00:26.089288 | controller | ok: [instance]
2025-12-10 14:00:26.389014 | controller |
2025-12-10 14:00:26.389046 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-12-10 14:00:26.389054 | controller | Wednesday 10 December 2025  14:00:26 +0000 (0:00:00.300)       0:01:04.683 ****
2025-12-10 14:00:26.389083 | controller | ok: [instance]
2025-12-10 14:00:26.698538 | controller |
2025-12-10 14:00:26.698569 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-12-10 14:00:26.698577 | controller | Wednesday 10 December 2025  14:00:26 +0000 (0:00:00.299)       0:01:04.983 ****
2025-12-10 14:00:26.698587 | controller | ok: [instance]
2025-12-10 14:00:27.005243 | controller |
2025-12-10 14:00:27.005275 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-12-10 14:00:27.005283 | controller | Wednesday 10 December 2025  14:00:26 +0000 (0:00:00.309)       0:01:05.293 ****
2025-12-10 14:00:27.005292 | controller | ok: [instance]
2025-12-10 14:00:27.309722 | controller |
2025-12-10 14:00:27.309753 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-12-10 14:00:27.309762 | controller | Wednesday 10 December 2025  14:00:27 +0000 (0:00:00.306)       0:01:05.599 ****
2025-12-10 14:00:27.309771 | controller | ok: [instance]
2025-12-10 14:00:27.613495 | controller |
2025-12-10 14:00:27.613524 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-12-10 14:00:27.613532 | controller | Wednesday 10 December 2025  14:00:27 +0000 (0:00:00.304)       0:01:05.904 ****
2025-12-10 14:00:27.613541 | controller | ok: [instance]
2025-12-10 14:00:27.918677 | controller |
2025-12-10 14:00:27.918707 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-12-10 14:00:27.918714 | controller | Wednesday 10 December 2025  14:00:27 +0000 (0:00:00.303)       0:01:06.208 ****
2025-12-10 14:00:27.918724 | controller | ok: [instance]
2025-12-10 14:00:28.222837 | controller |
2025-12-10 14:00:28.222868 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-12-10 14:00:28.222875 | controller | Wednesday 10 December 2025  14:00:27 +0000 (0:00:00.305)       0:01:06.513 ****
2025-12-10 14:00:28.222885 | controller | ok: [instance]
2025-12-10 14:00:28.523710 | controller |
2025-12-10 14:00:28.523738 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-12-10 14:00:28.523746 | controller | Wednesday 10 December 2025  14:00:28 +0000 (0:00:00.304)       0:01:06.817 ****
2025-12-10 14:00:28.523755 | controller | ok: [instance]
2025-12-10 14:00:28.825899 | controller |
2025-12-10 14:00:28.825930 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-12-10 14:00:28.825937 | controller | Wednesday 10 December 2025  14:00:28 +0000 (0:00:00.300)       0:01:07.118 ****
2025-12-10 14:00:28.825947 | controller | ok: [instance]
2025-12-10 14:00:29.132691 | controller |
2025-12-10 14:00:29.132722 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-12-10 14:00:29.132730 | controller | Wednesday 10 December 2025  14:00:28 +0000 (0:00:00.302)       0:01:07.420 ****
2025-12-10 14:00:29.132744 | controller | ok: [instance]
2025-12-10 14:00:29.436149 | controller |
2025-12-10 14:00:29.436181 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-12-10 14:00:29.436189 | controller | Wednesday 10 December 2025  14:00:29 +0000 (0:00:00.306)       0:01:07.727 ****
2025-12-10 14:00:29.436199 | controller | ok: [instance]
2025-12-10 14:00:29.436224 | controller |
2025-12-10 14:00:29.436430 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-12-10 14:00:29.737121 | controller | Wednesday 10 December 2025  14:00:29 +0000 (0:00:00.303)       0:01:08.030 ****
2025-12-10 14:00:29.737156 | controller | ok: [instance]
2025-12-10 14:00:29.758850 | controller |
2025-12-10 14:00:29.758867 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-12-10 14:00:29.758874 | controller | Wednesday 10 December 2025  14:00:29 +0000 (0:00:00.300)       0:01:08.331 ****
2025-12-10 14:00:29.758882 | controller | skipping: [instance]
2025-12-10 14:00:30.004930 | controller |
2025-12-10 14:00:30.004961 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-12-10 14:00:30.004975 | controller | Wednesday 10 December 2025  14:00:29 +0000 (0:00:00.021)       0:01:08.353 ****
2025-12-10 14:00:30.004985 | controller | ok: [instance]
2025-12-10 14:00:30.363148 | controller |
2025-12-10 14:00:30.363178 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-12-10 14:00:30.363186 | controller | Wednesday 10 December 2025  14:00:30 +0000 (0:00:00.245)       0:01:08.599 ****
2025-12-10 14:00:30.363195 | controller | ok: [instance]
2025-12-10 14:00:30.647823 | controller |
2025-12-10 14:00:30.647853 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-12-10 14:00:30.647861 | controller | Wednesday 10 December 2025  14:00:30 +0000 (0:00:00.358)       0:01:08.957 ****
2025-12-10 14:00:30.647871 | controller | ok: [instance]
2025-12-10 14:00:30.929104 | controller |
2025-12-10 14:00:30.929136 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-12-10 14:00:30.929144 | controller | Wednesday 10 December 2025  14:00:30 +0000 (0:00:00.284)       0:01:09.242 ****
2025-12-10 14:00:30.929153 | controller | [WARNING]: Reset is not implemented for this connection
2025-12-10 14:00:30.960177 | controller | ok: [instance]
2025-12-10 14:00:30.960229 | controller |
2025-12-10 14:00:30.960237 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-12-10 14:00:30.960244 | controller | Wednesday 10 December 2025  14:00:30 +0000 (0:00:00.275)       0:01:09.517 ****
2025-12-10 14:00:30.960250 | controller |
2025-12-10 14:00:30.960255 | controller | PLAY RECAP *********************************************************************
2025-12-10 14:00:30.960260 | controller | instance                   : ok=67   changed=5    unreachable=0    failed=0    skipped=35   rescued=0    ignored=0
2025-12-10 14:00:30.960266 | controller |
2025-12-10 14:00:30.960271 | controller | Wednesday 10 December 2025  14:00:30 +0000 (0:00:00.036)       0:01:09.553 ****
2025-12-10 14:00:30.960276 | controller | ===============================================================================
2025-12-10 14:00:30.960281 | controller | test_deps : Install selinux python libs -------------------------------- 43.47s
2025-12-10 14:00:30.960286 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 1.56s
2025-12-10 14:00:30.960291 | controller | Install some debug utils ------------------------------------------------ 1.37s
2025-12-10 14:00:30.960296 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.33s
2025-12-10 14:00:30.960301 | controller | repo_setup : Initialize python venv and install requirements ------------ 1.32s
2025-12-10 14:00:30.960306 | controller | test_deps : Install python yaml libs ------------------------------------ 1.22s
2025-12-10 14:00:30.960311 | controller | libvirt_manager : Install packages required for using KVM --------------- 1.15s
2025-12-10 14:00:30.960318 | controller | Gathering Facts --------------------------------------------------------- 0.90s
2025-12-10 14:00:30.960339 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.87s
2025-12-10 14:00:30.961189 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.69s
2025-12-10 14:00:31.021416 | controller | libvirt_manager : Reload systemctl and start/enable virtproxyd.service --- 0.61s
2025-12-10 14:00:31.021454 | controller | repo_setup : Get repo-setup repository ---------------------------------- 0.60s
2025-12-10 14:00:31.021461 | controller | repo_setup : Ensure directories are present ----------------------------- 0.56s
2025-12-10 14:00:31.021467 | controller | libvirt_manager : Ensure read-write socket is enabled for qemu. --------- 0.50s
2025-12-10 14:00:31.021473 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.38s
2025-12-10 14:00:31.021479 | controller | libvirt_manager : Enable UNIX socket PolicyKit auth --------------------- 0.37s
2025-12-10 14:00:31.021484 | controller | libvirt_manager : Add user if not exists in libvirt group --------------- 0.36s
2025-12-10 14:00:31.021489 | controller | Create custom basedir --------------------------------------------------- 0.33s
2025-12-10 14:00:31.021495 | controller | libvirt_manager : Ensure admin socket is enabled for interface. --------- 0.32s
2025-12-10 14:00:31.021503 | controller | libvirt_manager : Ensure read-only socket is enabled for nodedev. ------- 0.32s
2025-12-10 14:00:31.021513 | controller | INFO     Running download > converge
2025-12-10 14:00:31.408803 | controller |
2025-12-10 14:00:32.195803 | controller | PLAY [Converge - Test build and download modes] ********************************
2025-12-10 14:00:32.195833 | controller |
2025-12-10 14:00:32.195841 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 14:00:32.195847 | controller | Wednesday 10 December 2025  14:00:31 +0000 (0:00:00.014)       0:00:00.014 ****
2025-12-10 14:00:32.195856 | controller | ok: [instance]
2025-12-10 14:00:32.540119 | controller |
2025-12-10 14:00:32.540143 | controller | TASK [Create SSH keypair] ******************************************************
2025-12-10 14:00:32.540151 | controller | Wednesday 10 December 2025  14:00:32 +0000 (0:00:00.787)       0:00:00.801 ****
2025-12-10 14:00:32.540160 | controller | ok: [instance]
2025-12-10 14:00:33.000978 | controller |
2025-12-10 14:00:33.001011 | controller | TASK [Enable forwarding in the libvirt zone] ***********************************
2025-12-10 14:00:33.001020 | controller | Wednesday 10 December 2025  14:00:32 +0000 (0:00:00.344)       0:00:01.146 ****
2025-12-10 14:00:33.001030 | controller | changed: [instance]
2025-12-10 14:00:34.016176 | controller |
2025-12-10 14:00:34.016207 | controller | TASK [Restart firewalld.service] ***********************************************
2025-12-10 14:00:34.016215 | controller | Wednesday 10 December 2025  14:00:32 +0000 (0:00:00.460)       0:00:01.606 ****
2025-12-10 14:00:34.016225 | controller | changed: [instance]
2025-12-10 14:00:34.050486 | controller |
2025-12-10 14:00:34.050519 | controller | TASK [PHASE 1: Build nat64 appliance image from source] ************************
2025-12-10 14:00:34.050527 | controller | Wednesday 10 December 2025  14:00:34 +0000 (0:00:01.015)       0:00:02.622 ****
2025-12-10 14:00:34.050537 | controller |
2025-12-10 14:00:34.136158 | controller | TASK [nat64_appliance : Ensure needed directories exist] ***********************
2025-12-10 14:00:34.136192 | controller | Wednesday 10 December 2025  14:00:34 +0000 (0:00:00.034)       0:00:02.656 ****
2025-12-10 14:00:34.136205 | controller | fatal: [instance]: FAILED! =>
2025-12-10 14:00:34.136815 | controller |   msg: |-
2025-12-10 14:00:34.136838 | controller |     An unhandled exception occurred while templating '{{
2025-12-10 14:00:34.136846 | controller |       cifmw_basedir | default(ansible_user_dir ~ '/ci-framework-data')
2025-12-10 14:00:34.136903 | controller |     }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_basedir }}/nat64_build'. Error was a <class 'ansible.errors.AnsibleError'>, original message: An unhandled exception occurred while templating '{{ cifmw_nat64_build_dir }}'. Error was a <class 'ansible.errors.AnsibleError'>, original message: recursive loop detected in template string: {{ cifmw_nat64_build_dir }}. maximum recursion depth exceeded
2025-12-10 14:00:34.138115 | controller |
2025-12-10 14:00:34.138464 | controller | PLAY RECAP *********************************************************************
2025-12-10 14:00:34.138476 | controller | instance                   : ok=4    changed=2    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0
2025-12-10 14:00:34.138483 | controller |
2025-12-10 14:00:34.138489 | controller | Wednesday 10 December 2025  14:00:34 +0000 (0:00:00.087)       0:00:02.744 ****
2025-12-10 14:00:34.138495 | controller | ===============================================================================
2025-12-10 14:00:34.138500 | controller | Restart firewalld.service ----------------------------------------------- 1.02s
2025-12-10 14:00:34.138506 | controller | Gathering Facts --------------------------------------------------------- 0.79s
2025-12-10 14:00:34.138520 | controller | Enable forwarding in the libvirt zone ----------------------------------- 0.46s
2025-12-10 14:00:34.194679 | controller | Create SSH keypair ------------------------------------------------------ 0.34s
2025-12-10 14:00:34.194717 | controller | nat64_appliance : Ensure needed directories exist ----------------------- 0.09s
2025-12-10 14:00:34.194725 | controller | PHASE 1: Build nat64 appliance image from source ------------------------ 0.03s
2025-12-10 14:00:34.194740 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/nat64_appliance/download/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/nat64_appliance/molecule/download/converge.yml']
2025-12-10 14:00:34.195086 | controller | WARNING  An error occurred during the test sequence action: 'converge'. Cleaning up.
2025-12-10 14:00:34.203959 | controller | INFO     Running download > cleanup
2025-12-10 14:00:34.613735 | controller |
2025-12-10 14:00:35.396854 | controller | PLAY [Cleanup] *****************************************************************
2025-12-10 14:00:35.396885 | controller |
2025-12-10 14:00:35.396892 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 14:00:35.396898 | controller | Wednesday 10 December 2025  14:00:34 +0000 (0:00:00.014)       0:00:00.014 ****
2025-12-10 14:00:35.396907 | controller | ok: [instance]
2025-12-10 14:00:35.668202 | controller |
2025-12-10 14:00:35.668231 | controller | TASK [Stop HTTP server if running] *********************************************
2025-12-10 14:00:35.668239 | controller | Wednesday 10 December 2025  14:00:35 +0000 (0:00:00.783)       0:00:00.798 ****
2025-12-10 14:00:35.668249 | controller | changed: [instance]
2025-12-10 14:00:35.699771 | controller |
2025-12-10 14:00:35.699794 | controller | TASK [Cleanup nat64 appliance] *************************************************
2025-12-10 14:00:35.699801 | controller | Wednesday 10 December 2025  14:00:35 +0000 (0:00:00.271)       0:00:01.069 ****
2025-12-10 14:00:35.699813 | controller |
2025-12-10 14:00:35.978103 | controller | TASK [nat64_appliance : Cleaning up nat64_appliance image] *********************
2025-12-10 14:00:35.978133 | controller | Wednesday 10 December 2025  14:00:35 +0000 (0:00:00.032)       0:00:01.101 ****
2025-12-10 14:00:35.978145 | controller | ok: [instance]
2025-12-10 14:00:36.241767 | controller |
2025-12-10 14:00:36.241796 | controller | TASK [nat64_appliance : Get virtqemud socket] **********************************
2025-12-10 14:00:36.241804 | controller | Wednesday 10 December 2025  14:00:35 +0000 (0:00:00.277)       0:00:01.379 ****
2025-12-10 14:00:36.241814 | controller | ok: [instance]
2025-12-10 14:00:36.541448 | controller |
2025-12-10 14:00:36.541478 | controller | TASK [nat64_appliance : List VMs] **********************************************
2025-12-10 14:00:36.541486 | controller | Wednesday 10 December 2025  14:00:36 +0000 (0:00:00.263)       0:00:01.643 ****
2025-12-10 14:00:36.541496 | controller | ok: [instance]
2025-12-10 14:00:36.561163 | controller |
2025-12-10 14:00:36.561232 | controller | TASK [nat64_appliance : Get nat64_appliance VM state] **************************
2025-12-10 14:00:36.561243 | controller | Wednesday 10 December 2025  14:00:36 +0000 (0:00:00.299)       0:00:01.943 ****
2025-12-10 14:00:36.561260 | controller | skipping: [instance]
2025-12-10 14:00:36.561305 | controller |
2025-12-10 14:00:36.561315 | controller | TASK [nat64_appliance : Stop the nat64_appliance VM] ***************************
2025-12-10 14:00:36.561343 | controller | Wednesday 10 December 2025  14:00:36 +0000 (0:00:00.020)       0:00:01.963 ****
2025-12-10 14:00:36.580133 | controller | skipping: [instance]
2025-12-10 14:00:36.580419 | controller |
2025-12-10 14:00:36.600153 | controller | TASK [nat64_appliance : Undefine the nat64_appliance VM] ***********************
2025-12-10 14:00:36.600180 | controller | Wednesday 10 December 2025  14:00:36 +0000 (0:00:00.019)       0:00:01.982 ****
2025-12-10 14:00:36.600194 | controller | skipping: [instance]
2025-12-10 14:00:36.600203 | controller |
2025-12-10 14:00:36.600211 | controller | TASK [nat64_appliance : Destroy the nat64 networks] ****************************
2025-12-10 14:00:36.600220 | controller | Wednesday 10 December 2025  14:00:36 +0000 (0:00:00.019)       0:00:02.002 ****
2025-12-10 14:00:37.091428 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 14:00:37.515107 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 14:00:37.515146 | controller |
2025-12-10 14:00:37.515154 | controller | TASK [nat64_appliance : Undefine the nat64 networks] ***************************
2025-12-10 14:00:37.515160 | controller | Wednesday 10 December 2025  14:00:37 +0000 (0:00:00.490)       0:00:02.493 ****
2025-12-10 14:00:37.515169 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 14:00:37.572002 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 14:00:37.572034 | controller |
2025-12-10 14:00:37.572042 | controller | PLAY RECAP *********************************************************************
2025-12-10 14:00:37.572048 | controller | instance                   : ok=7    changed=1    unreachable=0    failed=0    skipped=3    rescued=0    ignored=0
2025-12-10 14:00:37.572053 | controller |
2025-12-10 14:00:37.572058 | controller | Wednesday 10 December 2025  14:00:37 +0000 (0:00:00.422)       0:00:02.915 ****
2025-12-10 14:00:37.572095 | controller | ===============================================================================
2025-12-10 14:00:37.572103 | controller | Gathering Facts --------------------------------------------------------- 0.78s
2025-12-10 14:00:37.572108 | controller | nat64_appliance : Destroy the nat64 networks ---------------------------- 0.49s
2025-12-10 14:00:37.572113 | controller | nat64_appliance : Undefine the nat64 networks --------------------------- 0.42s
2025-12-10 14:00:37.572118 | controller | nat64_appliance : List VMs ---------------------------------------------- 0.30s
2025-12-10 14:00:37.572124 | controller | nat64_appliance : Cleaning up nat64_appliance image --------------------- 0.28s
2025-12-10 14:00:37.572128 | controller | Stop HTTP server if running --------------------------------------------- 0.27s
2025-12-10 14:00:37.572133 | controller | nat64_appliance : Get virtqemud socket ---------------------------------- 0.26s
2025-12-10 14:00:37.572138 | controller | Cleanup nat64 appliance ------------------------------------------------- 0.03s
2025-12-10 14:00:37.572143 | controller | nat64_appliance : Get nat64_appliance VM state -------------------------- 0.02s
2025-12-10 14:00:37.572148 | controller | nat64_appliance : Undefine the nat64_appliance VM ----------------------- 0.02s
2025-12-10 14:00:37.572153 | controller | nat64_appliance : Stop the nat64_appliance VM --------------------------- 0.02s
2025-12-10 14:00:37.572162 | controller | INFO     Running download > destroy
2025-12-10 14:00:37.572511 | controller | WARNING  Skipping, instances are delegated.
2025-12-10 14:00:37.572846 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-12-10 14:00:37.574383 | controller | INFO     Writing /tmp/report.html report.
2025-12-10 14:00:38.036179 | [controller] Waiting on logger
2025-12-10 14:00:43.186599 | [controller] Waiting on logger
2025-12-10 14:00:53.618437 | [controller] Waiting on logger
2025-12-10 14:01:04.050636 | [controller] Waiting on logger
2025-12-10 14:01:07.652418 | [Zuul] Log Stream did not terminate
2025-12-10 14:01:07.652699 | controller | ERROR
2025-12-10 14:01:07.652823 | controller | {
2025-12-10 14:01:07.652896 | controller |   "delta": "0:13:38.257801",
2025-12-10 14:01:07.652970 | controller |   "end": "2025-12-10 14:00:37.620684",
2025-12-10 14:01:07.653006 | controller |   "msg": "non-zero return code",
2025-12-10 14:01:07.653037 | controller |   "rc": 1,
2025-12-10 14:01:07.653066 | controller |   "start": "2025-12-10 13:46:59.362883"
2025-12-10 14:01:07.653093 | controller | }
failure
2025-12-10 14:01:07.699025 | 
2025-12-10 14:01:07.699099 | PLAY RECAP
2025-12-10 14:01:07.699143 | controller | ok: 3 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2025-12-10 14:01:07.699166 | 
2025-12-10 14:01:07.754678 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-10 14:01:07.755489 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-10 14:01:08.245652 | 
2025-12-10 14:01:08.245753 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-12-10 14:01:08.264767 | 
2025-12-10 14:01:08.264836 | TASK [Filter out host if needed]
2025-12-10 14:01:08.272692 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-12-10 14:01:08.276735 | 
2025-12-10 14:01:08.276797 | TASK [Ensure file is present]
2025-12-10 14:01:08.568364 | controller | ok
2025-12-10 14:01:08.575066 | 
2025-12-10 14:01:08.575134 | TASK [Manage molecule report file]
2025-12-10 14:01:08.598012 | [controller] Waiting on logger
2025-12-10 14:01:19.026450 | [controller] Waiting on logger
2025-12-10 14:01:28.370299 | [controller] Waiting on logger
2025-12-10 14:01:38.802841 | [controller] Waiting on logger
2025-12-10 14:01:38.876631 | [Zuul] Log Stream did not terminate
2025-12-10 14:01:38.877015 | controller | changed
2025-12-10 14:01:38.882366 | 
2025-12-10 14:01:38.882429 | TASK [Check if we get ci-framework-data basedir]
2025-12-10 14:01:39.063512 | controller | ok
2025-12-10 14:01:39.068413 | 
2025-12-10 14:01:39.068475 | TASK [Create ci-framework-data log directory for zuul]
2025-12-10 14:01:39.350229 | controller | changed
2025-12-10 14:01:39.355161 | 
2025-12-10 14:01:39.355226 | TASK [Copy ci-framework interesting files]
2025-12-10 14:01:39.376711 | [controller] Waiting on logger
2025-12-10 14:01:49.810386 | [controller] Waiting on logger
2025-12-10 14:01:59.154696 | [controller] Waiting on logger
2025-12-10 14:02:09.556941 | [Zuul] Log Stream did not terminate
2025-12-10 14:02:09.558548 | controller | changed
2025-12-10 14:02:09.564541 | 
2025-12-10 14:02:09.564604 | TASK [Get SELinux listing]
2025-12-10 14:02:09.583637 | [controller] Waiting on logger
2025-12-10 14:02:11.634569 | [controller] Waiting on logger
2025-12-10 14:02:22.066376 | [controller] Waiting on logger
2025-12-10 14:02:31.410324 | [controller] Waiting on logger
2025-12-10 14:02:39.773473 | [Zuul] Log Stream did not terminate
2025-12-10 14:02:39.773634 | controller | changed
2025-12-10 14:02:39.779291 | 
2025-12-10 14:02:39.779369 | TASK [Generate log index]
2025-12-10 14:02:40.375467 | controller | changed
2025-12-10 14:02:40.380167 | 
2025-12-10 14:02:40.380232 | TASK [Get some env related data]
2025-12-10 14:02:40.400222 | [controller] Waiting on logger
2025-12-10 14:02:50.802379 | [controller] Waiting on logger
2025-12-10 14:03:00.183229 | [controller] Waiting on logger
2025-12-10 14:03:10.578453 | [controller] Waiting on logger
2025-12-10 14:03:11.554290 | [Zuul] Log Stream did not terminate
2025-12-10 14:03:11.554538 | controller | changed
2025-12-10 14:03:11.559505 | 
2025-12-10 14:03:11.559562 | TASK [Generate list of logs to collect in home directory]
2025-12-10 14:03:11.831542 | controller | ok: All paths examined
2025-12-10 14:03:11.836419 | 
2025-12-10 14:03:11.836483 | LOOP [Copy logs from home directory]
2025-12-10 14:03:12.123279 | controller | changed:
2025-12-10 14:03:12.123389 | controller | {
2025-12-10 14:03:12.123415 | controller |   "atime": 1765374401.2127295,
2025-12-10 14:03:12.123433 | controller |   "ctime": 1765374417.2488246,
2025-12-10 14:03:12.123450 | controller |   "dev": 64513,
2025-12-10 14:03:12.123466 | controller |   "gid": 1000,
2025-12-10 14:03:12.123481 | controller |   "gr_name": "zuul",
2025-12-10 14:03:12.123495 | controller |   "inode": 4330013,
2025-12-10 14:03:12.123510 | controller |   "isblk": false,
2025-12-10 14:03:12.123525 | controller |   "ischr": false,
2025-12-10 14:03:12.123538 | controller |   "isdir": false,
2025-12-10 14:03:12.123552 | controller |   "isfifo": false,
2025-12-10 14:03:12.123567 | controller |   "isgid": false,
2025-12-10 14:03:12.123581 | controller |   "islnk": false,
2025-12-10 14:03:12.123595 | controller |   "isreg": true,
2025-12-10 14:03:12.123608 | controller |   "issock": false,
2025-12-10 14:03:12.123621 | controller |   "isuid": false,
2025-12-10 14:03:12.123634 | controller |   "mode": "0644",
2025-12-10 14:03:12.123646 | controller |   "mtime": 1765374417.2488246,
2025-12-10 14:03:12.123659 | controller |   "nlink": 1,
2025-12-10 14:03:12.123672 | controller |   "path": "/home/zuul/ansible.log",
2025-12-10 14:03:12.123686 | controller |   "pw_name": "zuul",
2025-12-10 14:03:12.123699 | controller |   "rgrp": true,
2025-12-10 14:03:12.123712 | controller |   "roth": true,
2025-12-10 14:03:12.123725 | controller |   "rusr": true,
2025-12-10 14:03:12.123737 | controller |   "size": 6749,
2025-12-10 14:03:12.123760 | controller |   "uid": 1000,
2025-12-10 14:03:12.123775 | controller |   "wgrp": false,
2025-12-10 14:03:12.123789 | controller |   "woth": false,
2025-12-10 14:03:12.123803 | controller |   "wusr": true,
2025-12-10 14:03:12.123816 | controller |   "xgrp": false,
2025-12-10 14:03:12.123829 | controller |   "xoth": false,
2025-12-10 14:03:12.123843 | controller |   "xusr": false
2025-12-10 14:03:12.123856 | controller | }
2025-12-10 14:03:12.136098 | 
2025-12-10 14:03:12.136158 | TASK [Copy crio stats log file]
2025-12-10 14:03:12.149659 | controller | skipping: Conditional result was False
2025-12-10 14:03:12.154714 | 
2025-12-10 14:03:12.154774 | TASK [Get SELinux related data]
2025-12-10 14:03:12.173964 | [controller] Waiting on logger
2025-12-10 14:03:22.610607 | [controller] Waiting on logger
2025-12-10 14:03:33.042536 | [controller] Waiting on logger
2025-12-10 14:03:42.373658 | [Zuul] Log Stream did not terminate
2025-12-10 14:03:42.373969 | controller | ERROR
2025-12-10 14:03:42.374086 | controller | {
2025-12-10 14:03:42.374118 | controller |   "delta": "0:00:00.007836",
2025-12-10 14:03:42.374139 | controller |   "end": "2025-12-10 14:03:12.346163",
2025-12-10 14:03:42.374157 | controller |   "msg": "non-zero return code",
2025-12-10 14:03:42.374173 | controller |   "rc": 1,
2025-12-10 14:03:42.374188 | controller |   "start": "2025-12-10 14:03:12.338327"
2025-12-10 14:03:42.374203 | controller | }
2025-12-10 14:03:42.374223 | controller | ERROR: Ignoring Errors
2025-12-10 14:03:42.379381 | 
2025-12-10 14:03:42.379443 | TASK [Create system configuration directory]
2025-12-10 14:03:42.387579 | [controller] Waiting on logger
2025-12-10 14:03:42.560745 | controller | changed
2025-12-10 14:03:42.565489 | 
2025-12-10 14:03:42.565556 | TASK [Get some of the system configurations]
2025-12-10 14:03:45.650654 | [controller] Waiting on logger
2025-12-10 14:03:51.909067 | controller | changed
2025-12-10 14:03:51.913848 | 
2025-12-10 14:03:51.913923 | TASK [Copy generated documentation if available]
2025-12-10 14:03:51.926991 | controller | skipping: Conditional result was False
2025-12-10 14:03:51.931650 | 
2025-12-10 14:03:51.931709 | TASK [Copy generated AsciiDoc documentation if available]
2025-12-10 14:03:51.944054 | controller | skipping: Conditional result was False
2025-12-10 14:03:51.949107 | 
2025-12-10 14:03:51.949167 | TASK [Compress logs bigger than 2MB]
2025-12-10 14:03:54.866500 | [controller] Waiting on logger
2025-12-10 14:03:55.058558 | [controller] Waiting on logger
2025-12-10 14:04:02.469067 | controller | changed
2025-12-10 14:04:02.474180 | 
2025-12-10 14:04:02.474242 | TASK [Copy files from workspace on node]
2025-12-10 14:04:02.491765 | controller | ok
2025-12-10 14:04:02.511596 | 
2025-12-10 14:04:02.511661 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-10 14:04:02.525120 | controller | skipping: Conditional result was False
2025-12-10 14:04:02.530141 | 
2025-12-10 14:04:02.530222 | TASK [fetch-output : Set log path for single node]
2025-12-10 14:04:02.548120 | controller | ok
2025-12-10 14:04:02.553668 | 
2025-12-10 14:04:02.553724 | LOOP [fetch-output : Ensure local output dirs]
2025-12-10 14:04:02.731358 | controller -> localhost | ok: "/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/logs"
2025-12-10 14:04:02.731587 | controller -> localhost | changed: All items complete
2025-12-10 14:04:02.731618 | 
2025-12-10 14:04:02.896503 | controller -> localhost | changed: "/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/artifacts"
2025-12-10 14:04:03.067258 | controller -> localhost | changed: "/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/docs"
2025-12-10 14:04:03.079212 | 
2025-12-10 14:04:03.079298 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-10 14:04:03.617660 | controller | changed:
2025-12-10 14:04:03.617862 | controller | .d..t...... ./
2025-12-10 14:04:03.617893 | controller | >f+++++++++ README.html
2025-12-10 14:04:03.617949 | controller | >f+++++++++ ansible-execution.log
2025-12-10 14:04:03.617982 | controller | >f+++++++++ ansible.log
2025-12-10 14:04:03.618007 | controller | >f+++++++++ dmesg.log
2025-12-10 14:04:03.618026 | controller | >f+++++++++ installed-pkgs.log
2025-12-10 14:04:03.618043 | controller | >f+++++++++ python.log
2025-12-10 14:04:03.618060 | controller | >f+++++++++ registries.conf
2025-12-10 14:04:03.618077 | controller | >f+++++++++ report.html
2025-12-10 14:04:03.618093 | controller | >f+++++++++ selinux-denials.log
2025-12-10 14:04:03.618110 | controller | >f+++++++++ selinux-listing.log
2025-12-10 14:04:03.618125 | controller | cd+++++++++ ci-framework-data/
2025-12-10 14:04:03.618141 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-12-10 14:04:03.618158 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_build_the_nat64_appliance.sh
2025-12-10 14:04:03.618174 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_generate_nocloud_iso.sh
2025-12-10 14:04:03.618191 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_generate_nocloud_iso.sh
2025-12-10 14:04:03.618208 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-12-10 14:04:03.618224 | controller | cd+++++++++ ci-framework-data/artifacts/cifmw_config_drive/
2025-12-10 14:04:03.618240 | controller | cd+++++++++ ci-framework-data/artifacts/cifmw_config_drive/49ee6ce9-d621-5f7e-b364-5d4b5781d286/
2025-12-10 14:04:03.618256 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/49ee6ce9-d621-5f7e-b364-5d4b5781d286/meta-data
2025-12-10 14:04:03.618272 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/49ee6ce9-d621-5f7e-b364-5d4b5781d286/network-config
2025-12-10 14:04:03.618288 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/49ee6ce9-d621-5f7e-b364-5d4b5781d286/user-data
2025-12-10 14:04:03.618304 | controller | cd+++++++++ ci-framework-data/artifacts/cifmw_config_drive/f55c44ee-caf0-5e3c-90cf-e5df97a04574/
2025-12-10 14:04:03.618320 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/f55c44ee-caf0-5e3c-90cf-e5df97a04574/meta-data
2025-12-10 14:04:03.618336 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/f55c44ee-caf0-5e3c-90cf-e5df97a04574/network-config
2025-12-10 14:04:03.618351 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/f55c44ee-caf0-5e3c-90cf-e5df97a04574/user-data
2025-12-10 14:04:03.618366 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-12-10 14:04:03.618382 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-12-10 14:04:03.618397 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-12-10 14:04:03.618413 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-12-10 14:04:03.618428 | controller | cd+++++++++ ci-framework-data/logs/
2025-12-10 14:04:03.618443 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_build_the_nat64_appliance.log
2025-12-10 14:04:03.618457 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_generate_nocloud_iso.log
2025-12-10 14:04:03.618473 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_generate_nocloud_iso.log
2025-12-10 14:04:03.618488 | controller | >f+++++++++ ci-framework-data/logs/hypervisor_info.log
2025-12-10 14:04:03.618502 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-12-10 14:04:03.618518 | controller | >f+++++++++ ci-framework-data/logs/nat64_appliance_dns64_debug.log
2025-12-10 14:04:03.618532 | controller | >f+++++++++ ci-framework-data/logs/nat64_appliance_journal.log
2025-12-10 14:04:03.618547 | controller | >f+++++++++ ci-framework-data/logs/nat64_appliance_node_info.log
2025-12-10 14:04:03.618561 | controller | >f+++++++++ ci-framework-data/logs/test_node_info.log
2025-12-10 14:04:03.618575 | controller | cd+++++++++ registries.conf.d/
2025-12-10 14:04:03.618591 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-12-10 14:04:03.618609 | controller | cd+++++++++ system-config/
2025-12-10 14:04:03.618626 | controller | cd+++++++++ system-config/libvirt/
2025-12-10 14:04:03.618642 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-12-10 14:04:03.618658 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-12-10 14:04:03.618673 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-12-10 14:04:03.618688 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-12-10 14:04:03.618703 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-12-10 14:04:03.618719 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-12-10 14:04:03.618734 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-12-10 14:04:03.618750 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-12-10 14:04:03.618767 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-12-10 14:04:03.618782 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-12-10 14:04:03.618797 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-12-10 14:04:03.618812 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-12-10 14:04:03.618828 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-12-10 14:04:03.618842 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-12-10 14:04:03.618857 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-12-10 14:04:03.618871 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-12-10 14:04:03.958163 | controller | changed: .d..t...... ./
2025-12-10 14:04:04.298466 | controller | changed: .d..t...... ./
2025-12-10 14:04:04.309289 | 
2025-12-10 14:04:04.309385 | TASK [Return artifact to Zuul]
2025-12-10 14:04:04.337305 | controller | ok
2025-12-10 14:04:04.354314 | 
2025-12-10 14:04:04.354368 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-12-10 14:04:04.354456 | 
2025-12-10 14:04:04.354481 | PLAY RECAP
2025-12-10 14:04:04.354517 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-12-10 14:04:04.354537 | 
2025-12-10 14:04:04.423642 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-10 14:04:04.424370 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-10 14:04:04.906645 | 
2025-12-10 14:04:04.906744 | PLAY [all]
2025-12-10 14:04:04.923483 | 
2025-12-10 14:04:04.923552 | TASK [include_role : fetch-output]
2025-12-10 14:04:04.952064 | controller | ok
2025-12-10 14:04:04.968414 | 
2025-12-10 14:04:04.968492 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-10 14:04:05.003192 | controller | skipping: Conditional result was False
2025-12-10 14:04:05.008425 | 
2025-12-10 14:04:05.008492 | TASK [fetch-output : Set log path for single node]
2025-12-10 14:04:05.036619 | controller | ok
2025-12-10 14:04:05.041120 | 
2025-12-10 14:04:05.041184 | LOOP [fetch-output : Ensure local output dirs]
2025-12-10 14:04:05.353305 | controller -> localhost | ok: "/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/logs"
2025-12-10 14:04:05.523467 | controller -> localhost | ok: "/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/artifacts"
2025-12-10 14:04:05.692695 | controller -> localhost | ok: "/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/docs"
2025-12-10 14:04:05.700039 | 
2025-12-10 14:04:05.700134 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-10 14:04:06.181002 | controller | ok
2025-12-10 14:04:06.181176 | controller | ok: All items complete
2025-12-10 14:04:06.181204 | 
2025-12-10 14:04:06.534733 | controller | ok
2025-12-10 14:04:06.880542 | controller | ok
2025-12-10 14:04:06.892086 | 
2025-12-10 14:04:06.892190 | TASK [include_role : fetch-output-openshift]
2025-12-10 14:04:06.905569 | controller | skipping: Conditional result was False
2025-12-10 14:04:06.911098 | 
2025-12-10 14:04:06.911173 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-10 14:04:07.229988 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006142
2025-12-10 14:04:07.407844 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006219
2025-12-10 14:04:07.433686 | 
2025-12-10 14:04:07.433770 | PLAY [all]
2025-12-10 14:04:07.447036 | 
2025-12-10 14:04:07.447103 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-10 14:04:07.829366 | controller | changed
2025-12-10 14:04:07.850895 | 
2025-12-10 14:04:07.850978 | PLAY RECAP
2025-12-10 14:04:07.851025 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-10 14:04:07.851047 | 
2025-12-10 14:04:07.916238 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-10 14:04:07.917012 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-10 14:04:08.446206 | 
2025-12-10 14:04:08.446302 | PLAY [localhost]
2025-12-10 14:04:08.462103 | 
2025-12-10 14:04:08.462178 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-10 14:04:08.752404 | localhost | changed
2025-12-10 14:04:08.756530 | 
2025-12-10 14:04:08.756613 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-10 14:04:08.773789 | localhost | ok
2025-12-10 14:04:08.781138 | 
2025-12-10 14:04:08.781202 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-10 14:04:09.052006 | localhost | changed
2025-12-10 14:04:09.057398 | 
2025-12-10 14:04:09.057467 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-10 14:04:09.581049 | localhost | changed
2025-12-10 14:04:09.585852 | 
2025-12-10 14:04:09.585966 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-10 14:04:09.906627 | localhost | Identity added: /var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/tmp/ansible.sytqd7r2 (/var/lib/zuul/builds/b4749d56795e4be2a1ab589ee9b170a5/work/tmp/ansible.sytqd7r2)
2025-12-10 14:04:09.906799 | localhost | ok: Runtime: 0:00:00.005450
2025-12-10 14:04:09.910960 | 
2025-12-10 14:04:09.911028 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-10 14:04:10.120363 | localhost | ok: Runtime: 0:00:00.004091
2025-12-10 14:04:10.124759 | 
2025-12-10 14:04:10.124827 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-10 14:04:10.172344 | localhost | changed
2025-12-10 14:04:10.177246 | 
2025-12-10 14:04:10.177311 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-10 14:04:10.477390 | localhost | changed
2025-12-10 14:04:10.495069 | 
2025-12-10 14:04:10.495122 | PLAY [localhost]
2025-12-10 14:04:10.505432 | 
2025-12-10 14:04:10.505494 | TASK [Generate bulk log download script]
2025-12-10 14:04:10.522823 | localhost | ok
2025-12-10 14:04:10.533130 | 
2025-12-10 14:04:10.533197 | TASK [local-log-download : Check API endpoint is defined]
2025-12-10 14:04:10.559318 | localhost | ok: All assertions passed
2025-12-10 14:04:10.563411 | 
2025-12-10 14:04:10.563468 | TASK [local-log-download : Create download script]
2025-12-10 14:04:10.879738 | localhost -> localhost | changed
2025-12-10 14:04:10.887614 | 
2025-12-10 14:04:10.887674 | TASK [Register quick-download link]
2025-12-10 14:04:10.903787 | localhost | ok
2025-12-10 14:04:10.935440 | 
2025-12-10 14:04:10.935517 | PLAY [logserver.rdoproject.org]
2025-12-10 14:04:10.944175 | 
2025-12-10 14:04:10.944238 | TASK [Set zuul-log-path fact]
2025-12-10 14:04:10.959181 | logserver.rdoproject.org | ok
2025-12-10 14:04:10.967396 | 
2025-12-10 14:04:10.967460 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-10 14:04:10.982406 | logserver.rdoproject.org | ok
2025-12-10 14:04:10.987160 | 
2025-12-10 14:04:10.987220 | TASK [upload-logs : Create log directories]
2025-12-10 14:04:12.712174 | logserver.rdoproject.org | changed
2025-12-10 14:04:12.714890 | 
2025-12-10 14:04:12.714975 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-10 14:04:12.930688 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005209
2025-12-10 14:04:12.934790 | 
2025-12-10 14:04:12.934851 | TASK [upload-logs : Upload logs to log server]
2025-12-10 14:04:14.364440 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-10 14:04:14.367059 | 
2025-12-10 14:04:14.367121 | LOOP [upload-logs : Compress console log and json output]
2025-12-10 14:04:14.414415 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 14:04:14.421988 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 14:04:14.434154 | 
2025-12-10 14:04:14.434232 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-10 14:04:14.475649 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 14:04:14.475863 | 
2025-12-10 14:04:14.479310 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 14:04:14.492298 | 
2025-12-10 14:04:14.492373 | LOOP [upload-logs : Upload console log and json output]