2025-10-02 16:38:10.104885 | Job console starting...
2025-10-02 16:38:10.340335 | Updating repositories
2025-10-02 16:38:11.110444 | Preparing job workspace
2025-10-02 16:38:24.483706 | Running Ansible setup...
2025-10-02 16:38:31.898952 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-02 16:38:34.399152 | 
2025-10-02 16:38:34.399370 | PLAY [localhost]
2025-10-02 16:38:34.452866 | 
2025-10-02 16:38:34.461066 | TASK [Gathering Facts]
2025-10-02 16:38:37.188146 | localhost | ok
2025-10-02 16:38:37.223624 | 
2025-10-02 16:38:37.223750 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-02 16:38:38.800392 | localhost -> localhost | changed
2025-10-02 16:38:38.806529 | 
2025-10-02 16:38:38.806603 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-02 16:38:41.442288 | localhost -> localhost | changed
2025-10-02 16:38:41.450650 | 
2025-10-02 16:38:41.450729 | TASK [Setup log path fact]
2025-10-02 16:38:41.497802 | localhost | ok
2025-10-02 16:38:41.517094 | 
2025-10-02 16:38:41.517165 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 16:38:41.586135 | localhost | ok
2025-10-02 16:38:41.599074 | 
2025-10-02 16:38:41.599144 | TASK [emit-job-header : Print job information]
2025-10-02 16:38:41.674529 | # Job Information
2025-10-02 16:38:41.674712 | Ansible Version: 2.15.12
2025-10-02 16:38:41.674747 | Job: cifmw-molecule-cifmw_ntp
2025-10-02 16:38:41.674770 | Pipeline: github-check
2025-10-02 16:38:41.674790 | Executor: ibm-bm3-ze.softwarefactory-project.io
2025-10-02 16:38:41.674810 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-02 16:38:41.674830 | Log URL (when completed): https://logserver.rdoproject.org/ff4/rdoproject.org/ff4211878959452a9e92b4a6ddcda25b/
2025-10-02 16:38:41.674853 | Event ID: 0b5c9c70-9fae-11f0-9df5-29799d33dc04
2025-10-02 16:38:41.679238 | 
2025-10-02 16:38:41.679365 | LOOP [emit-job-header : Print node information]
2025-10-02 16:38:41.879828 | localhost | ok:
2025-10-02 16:38:41.880077 | localhost | # Node Information
2025-10-02 16:38:41.880113 | localhost | Inventory Hostname: controller
2025-10-02 16:38:41.880139 | localhost | Hostname: np0005466912
2025-10-02 16:38:41.880161 | localhost | Username: zuul
2025-10-02 16:38:41.880183 | localhost | Distro: CentOS 9
2025-10-02 16:38:41.880203 | localhost | Provider: ibm-bm3-nodepool
2025-10-02 16:38:41.880221 | localhost | Region: regionOne
2025-10-02 16:38:41.880241 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-02 16:38:41.880260 | localhost | Product Name: OpenStack Compute
2025-10-02 16:38:41.880279 | localhost | Interface IP: 192.168.25.176
2025-10-02 16:38:41.945204 | 
2025-10-02 16:38:41.945274 | PLAY [all]
2025-10-02 16:38:41.971938 | 
2025-10-02 16:38:41.975102 | TASK [Gather network facts]
2025-10-02 16:38:42.380667 | controller | ok
2025-10-02 16:38:42.422023 | 
2025-10-02 16:38:42.422110 | TASK [include_role : start-zuul-console]
2025-10-02 16:38:42.503496 | controller | ok
2025-10-02 16:38:42.556348 | 
2025-10-02 16:38:42.576487 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-02 16:38:43.211420 | controller | ok
2025-10-02 16:38:43.251070 | 
2025-10-02 16:38:43.251179 | TASK [include_role : add-build-sshkey]
2025-10-02 16:38:43.295850 | controller | ok
2025-10-02 16:38:43.351594 | 
2025-10-02 16:38:43.351692 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-02 16:38:43.865045 | controller -> localhost | ok
2025-10-02 16:38:43.871783 | 
2025-10-02 16:38:43.871848 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-02 16:38:43.955162 | controller | ok
2025-10-02 16:38:44.006355 | controller | included: /var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-02 16:38:44.029856 | 
2025-10-02 16:38:44.029951 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-02 16:38:47.229017 | controller -> localhost | Generating public/private rsa key pair.
2025-10-02 16:38:47.229222 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/ff4211878959452a9e92b4a6ddcda25b_id_rsa.
2025-10-02 16:38:47.229260 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/ff4211878959452a9e92b4a6ddcda25b_id_rsa.pub.
2025-10-02 16:38:47.229286 | controller -> localhost | The key fingerprint is:
2025-10-02 16:38:47.229308 | controller -> localhost | SHA256:mHokv9VeZ1olVlrUUVahg7xq4KdTOuYYT6UyxlV/0oM zuul-build-sshkey
2025-10-02 16:38:47.229329 | controller -> localhost | The key's randomart image is:
2025-10-02 16:38:47.229348 | controller -> localhost | +---[RSA 3072]----+
2025-10-02 16:38:47.229366 | controller -> localhost | |               o@|
2025-10-02 16:38:47.229410 | controller -> localhost | |          . . .o.|
2025-10-02 16:38:47.229435 | controller -> localhost | |         . o o  o|
2025-10-02 16:38:47.229456 | controller -> localhost | |       o. . + .+ |
2025-10-02 16:38:47.229476 | controller -> localhost | |    . +oS. E ++ .|
2025-10-02 16:38:47.229496 | controller -> localhost | |    .=o +o. o..o |
2025-10-02 16:38:47.229515 | controller -> localhost | |    .*o+++. . +  |
2025-10-02 16:38:47.229533 | controller -> localhost | |    ..BB+. . =   |
2025-10-02 16:38:47.229552 | controller -> localhost | |     .++o . .    |
2025-10-02 16:38:47.229571 | controller -> localhost | +----[SHA256]-----+
2025-10-02 16:38:47.229620 | controller -> localhost | ok: Runtime: 0:00:01.658047
2025-10-02 16:38:47.235454 | 
2025-10-02 16:38:47.235522 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-02 16:38:47.355486 | controller | ok
2025-10-02 16:38:47.381084 | controller | included: /var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-02 16:38:47.409623 | 
2025-10-02 16:38:47.409726 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-02 16:38:47.478239 | controller | skipping: Conditional result was False
2025-10-02 16:38:47.483771 | 
2025-10-02 16:38:47.483851 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-02 16:38:48.927433 | controller | changed
2025-10-02 16:38:48.933058 | 
2025-10-02 16:38:48.933149 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-02 16:38:49.275967 | controller | ok
2025-10-02 16:38:49.280984 | 
2025-10-02 16:38:49.281061 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-02 16:38:50.329618 | controller | changed
2025-10-02 16:38:50.334435 | 
2025-10-02 16:38:50.334508 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-02 16:38:51.117608 | controller | changed
2025-10-02 16:38:51.131699 | 
2025-10-02 16:38:51.131774 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-02 16:38:51.219020 | controller | skipping: Conditional result was False
2025-10-02 16:38:51.224677 | 
2025-10-02 16:38:51.224755 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-02 16:38:52.696000 | controller -> localhost | changed
2025-10-02 16:38:52.705915 | 
2025-10-02 16:38:52.706001 | TASK [add-build-sshkey : Add back temp key]
2025-10-02 16:38:54.015553 | controller -> localhost | Identity added: /var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/ff4211878959452a9e92b4a6ddcda25b_id_rsa (zuul-build-sshkey)
2025-10-02 16:38:54.015798 | controller -> localhost | ok: Runtime: 0:00:00.028366
2025-10-02 16:38:54.021633 | 
2025-10-02 16:38:54.021709 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-02 16:38:54.749270 | controller | ok
2025-10-02 16:38:54.763313 | 
2025-10-02 16:38:54.763416 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-02 16:38:54.871101 | controller | skipping: Conditional result was False
2025-10-02 16:38:54.882139 | 
2025-10-02 16:38:54.882247 | TASK [include_role : validate-host]
2025-10-02 16:38:54.985580 | controller | ok
2025-10-02 16:38:55.057139 | 
2025-10-02 16:38:55.057233 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-02 16:38:55.143329 | controller | ok
2025-10-02 16:38:55.150897 | 
2025-10-02 16:38:55.150978 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-02 16:38:56.142270 | controller -> localhost | ok
2025-10-02 16:38:56.148082 | 
2025-10-02 16:38:56.148161 | TASK [validate-host : Collect information about the host]
2025-10-02 16:38:56.851150 | controller | ok
2025-10-02 16:38:56.877155 | 
2025-10-02 16:38:56.877242 | TASK [validate-host : Sanitize hostname]
2025-10-02 16:38:57.094182 | controller | ok
2025-10-02 16:38:57.114437 | 
2025-10-02 16:38:57.114514 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-02 16:38:58.896878 | controller -> localhost | changed
2025-10-02 16:38:58.904453 | 
2025-10-02 16:38:58.904521 | TASK [validate-host : Collect information about zuul worker]
2025-10-02 16:38:59.636944 | controller | ok
2025-10-02 16:38:59.641731 | 
2025-10-02 16:38:59.641806 | TASK [validate-host : Write out all zuul information for each host]
2025-10-02 16:39:01.750274 | controller -> localhost | changed
2025-10-02 16:39:01.761774 | 
2025-10-02 16:39:01.761841 | TASK [include_role : prepare-workspace-openshift]
2025-10-02 16:39:01.809650 | controller | skipping: Conditional result was False
2025-10-02 16:39:01.817629 | 
2025-10-02 16:39:01.817714 | TASK [include_role : remove-zuul-sshkey]
2025-10-02 16:39:01.882354 | controller | skipping: Conditional result was False
2025-10-02 16:39:01.889416 | 
2025-10-02 16:39:01.889522 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-02 16:39:02.262710 | controller | ok: "logs"
2025-10-02 16:39:02.262938 | controller | ok: All items complete
2025-10-02 16:39:02.262972 | 
2025-10-02 16:39:02.483795 | controller | ok: "artifacts"
2025-10-02 16:39:02.666190 | controller | ok: "docs"
2025-10-02 16:39:02.678083 | 
2025-10-02 16:39:02.678187 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-02 16:39:03.015648 | controller | changed: "logs"
2025-10-02 16:39:03.199727 | controller | changed: "artifacts"
2025-10-02 16:39:03.408726 | controller | changed: "docs"
2025-10-02 16:39:03.495524 | 
2025-10-02 16:39:03.495606 | PLAY RECAP
2025-10-02 16:39:03.495652 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-02 16:39:03.495696 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 16:39:03.495720 | 
2025-10-02 16:39:03.953139 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-02 16:39:03.954134 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-02 16:39:06.004795 | 
2025-10-02 16:39:06.004901 | PLAY [all]
2025-10-02 16:39:06.094924 | 
2025-10-02 16:39:06.095028 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-02 16:39:06.218713 | controller | ok
2025-10-02 16:39:06.224051 | 
2025-10-02 16:39:06.224164 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-02 16:39:07.293862 | controller | changed
2025-10-02 16:39:07.305465 | 
2025-10-02 16:39:07.305722 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-02 16:39:09.161821 | controller | changed
2025-10-02 16:39:09.184029 | 
2025-10-02 16:39:09.184126 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-02 16:39:10.244399 | controller | changed:
2025-10-02 16:39:10.244566 | controller | {
2025-10-02 16:39:10.244599 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-02 16:39:10.244632 | controller | }
2025-10-02 16:39:10.454167 | controller | changed:
2025-10-02 16:39:10.454266 | controller | {
2025-10-02 16:39:10.454338 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-02 16:39:10.454371 | controller | }
2025-10-02 16:39:10.655790 | controller | changed:
2025-10-02 16:39:10.655876 | controller | {
2025-10-02 16:39:10.655906 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-02 16:39:10.655929 | controller | }
2025-10-02 16:39:10.864772 | controller | changed:
2025-10-02 16:39:10.864865 | controller | {
2025-10-02 16:39:10.864895 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-02 16:39:10.864917 | controller | }
2025-10-02 16:39:11.084610 | controller | changed:
2025-10-02 16:39:11.084702 | controller | {
2025-10-02 16:39:11.084732 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-02 16:39:11.084755 | controller | }
2025-10-02 16:39:11.304172 | controller | changed:
2025-10-02 16:39:11.304295 | controller | {
2025-10-02 16:39:11.304328 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-02 16:39:11.304350 | controller | }
2025-10-02 16:39:11.560849 | controller | changed:
2025-10-02 16:39:11.560939 | controller | {
2025-10-02 16:39:11.560969 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-02 16:39:11.560993 | controller | }
2025-10-02 16:39:11.886911 | controller | changed:
2025-10-02 16:39:11.886996 | controller | {
2025-10-02 16:39:11.887024 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-02 16:39:11.887046 | controller | }
2025-10-02 16:39:12.024775 | controller | changed:
2025-10-02 16:39:12.024858 | controller | {
2025-10-02 16:39:12.024886 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-02 16:39:12.024906 | controller | }
2025-10-02 16:39:12.252585 | controller | changed:
2025-10-02 16:39:12.252663 | controller | {
2025-10-02 16:39:12.252701 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-02 16:39:12.252724 | controller | }
2025-10-02 16:39:12.498627 | controller | changed:
2025-10-02 16:39:12.498710 | controller | {
2025-10-02 16:39:12.498741 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-02 16:39:12.498763 | controller | }
2025-10-02 16:39:12.700992 | controller | changed:
2025-10-02 16:39:12.701077 | controller | {
2025-10-02 16:39:12.701107 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-02 16:39:12.701130 | controller | }
2025-10-02 16:39:12.930271 | controller | changed:
2025-10-02 16:39:12.930370 | controller | {
2025-10-02 16:39:12.930421 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-02 16:39:12.930446 | controller | }
2025-10-02 16:39:13.153235 | controller | changed:
2025-10-02 16:39:13.153321 | controller | {
2025-10-02 16:39:13.153349 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-02 16:39:13.153370 | controller | }
2025-10-02 16:39:13.375368 | controller | changed:
2025-10-02 16:39:13.375553 | controller | {
2025-10-02 16:39:13.375589 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-02 16:39:13.375613 | controller | }
2025-10-02 16:39:13.618630 | controller | changed:
2025-10-02 16:39:13.618729 | controller | {
2025-10-02 16:39:13.618757 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-02 16:39:13.618778 | controller | }
2025-10-02 16:39:13.852209 | controller | changed:
2025-10-02 16:39:13.852331 | controller | {
2025-10-02 16:39:13.852363 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-02 16:39:13.852407 | controller | }
2025-10-02 16:39:14.103482 | controller | changed:
2025-10-02 16:39:14.103561 | controller | {
2025-10-02 16:39:14.103590 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-02 16:39:14.103617 | controller | }
2025-10-02 16:39:14.340891 | controller | changed:
2025-10-02 16:39:14.340969 | controller | {
2025-10-02 16:39:14.340996 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-02 16:39:14.341017 | controller | }
2025-10-02 16:39:14.600494 | controller | changed:
2025-10-02 16:39:14.600620 | controller | {
2025-10-02 16:39:14.600651 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-02 16:39:14.600673 | controller | }
2025-10-02 16:39:14.885480 | controller | changed:
2025-10-02 16:39:14.885557 | controller | {
2025-10-02 16:39:14.885585 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-02 16:39:14.885606 | controller | }
2025-10-02 16:39:15.116890 | controller | changed:
2025-10-02 16:39:15.116970 | controller | {
2025-10-02 16:39:15.116998 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-02 16:39:15.117019 | controller | }
2025-10-02 16:39:15.356016 | controller | changed:
2025-10-02 16:39:15.356098 | controller | {
2025-10-02 16:39:15.356128 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-02 16:39:15.356150 | controller | }
2025-10-02 16:39:15.593039 | controller | changed:
2025-10-02 16:39:15.593113 | controller | {
2025-10-02 16:39:15.593140 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-02 16:39:15.593162 | controller | }
2025-10-02 16:39:15.824878 | controller | changed:
2025-10-02 16:39:15.827760 | controller | {
2025-10-02 16:39:15.827805 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-02 16:39:15.827836 | controller | }
2025-10-02 16:39:16.094397 | controller | changed:
2025-10-02 16:39:16.094472 | controller | {
2025-10-02 16:39:16.094500 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-02 16:39:16.094519 | controller | }
2025-10-02 16:39:16.149711 | 
2025-10-02 16:39:16.149794 | TASK [Set timezone to UTC]
2025-10-02 16:39:16.898122 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-02 16:39:16.906079 | 
2025-10-02 16:39:16.906146 | TASK [Create nodepool directory]
2025-10-02 16:39:17.160626 | controller | changed
2025-10-02 16:39:17.169090 | 
2025-10-02 16:39:17.169156 | TASK [Create nodepool sub_nodes file]
2025-10-02 16:39:17.884959 | controller | changed
2025-10-02 16:39:17.894049 | 
2025-10-02 16:39:17.894130 | TASK [Create nodepool sub_nodes_private file]
2025-10-02 16:39:18.619916 | controller | changed
2025-10-02 16:39:18.625602 | 
2025-10-02 16:39:18.625681 | LOOP [Populate nodepool sub_nodes file]
2025-10-02 16:39:18.739110 | 
2025-10-02 16:39:18.739260 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-02 16:39:18.831463 | 
2025-10-02 16:39:18.831605 | TASK [Create nodepool primary file]
2025-10-02 16:39:18.896346 | controller | skipping: Conditional result was False
2025-10-02 16:39:18.902916 | 
2025-10-02 16:39:18.903014 | TASK [Create nodepool node_private for this node]
2025-10-02 16:39:19.622089 | controller | changed
2025-10-02 16:39:19.638839 | 
2025-10-02 16:39:19.638933 | LOOP [Copy ssh keys to nodepool directory]
2025-10-02 16:39:20.699085 | controller | ok: Item: id_rsa Runtime: 0:00:00.005558
2025-10-02 16:39:20.700209 | 
2025-10-02 16:39:20.880999 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004868
2025-10-02 16:39:20.890057 | 
2025-10-02 16:39:20.890168 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-02 16:39:21.767917 | controller | changed
2025-10-02 16:39:21.773308 | 
2025-10-02 16:39:21.773372 | TASK [Validate sudoers config after edits]
2025-10-02 16:39:22.228868 | controller | /etc/sudoers: parsed OK
2025-10-02 16:39:22.228956 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-02 16:39:22.228967 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-02 16:39:22.228973 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-02 16:39:22.357986 | controller | ok: Runtime: 0:00:00.004634
2025-10-02 16:39:22.363434 | 
2025-10-02 16:39:22.363503 | TASK [Show the environment passed in to job shell scripts]
2025-10-02 16:39:22.896137 | controller | SHELL=/bin/bash
2025-10-02 16:39:22.896185 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-02 16:39:22.896195 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-02 16:39:22.896202 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/62/3362/41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-02 16:39:22.896207 | controller | PWD=/home/zuul
2025-10-02 16:39:22.896213 | controller | ZUUL_PIPELINE=github-check
2025-10-02 16:39:22.896218 | controller | LOGNAME=zuul
2025-10-02 16:39:22.896224 | controller | XDG_SESSION_TYPE=tty
2025-10-02 16:39:22.896229 | controller | _=/usr/bin/env
2025-10-02 16:39:22.896274 | controller | MOTD_SHOWN=pam
2025-10-02 16:39:22.896282 | controller | HOME=/home/zuul
2025-10-02 16:39:22.896288 | controller | LANG=en_US.UTF-8
2025-10-02 16:39:22.896293 | controller | SSH_CONNECTION=192.168.25.12 47014 192.168.25.176 22
2025-10-02 16:39:22.896299 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-02 16:39:22.896308 | controller | ZUUL_CHANGE_IDS=3362,41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-02 16:39:22.896313 | controller | WORKSPACE=/home/zuul/workspace
2025-10-02 16:39:22.896319 | controller | XDG_SESSION_CLASS=user
2025-10-02 16:39:22.896324 | controller | SELINUX_ROLE_REQUESTED=
2025-10-02 16:39:22.896329 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-02 16:39:22.896334 | controller | USER=zuul
2025-10-02 16:39:22.896340 | controller | ZUUL_VOTING=True
2025-10-02 16:39:22.896345 | controller | BUILD_TIMEOUT=1800000
2025-10-02 16:39:22.896350 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-02 16:39:22.896355 | controller | SHLVL=1
2025-10-02 16:39:22.896361 | controller | ZUUL_PATCHSET=41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-02 16:39:22.896366 | controller | XDG_SESSION_ID=1
2025-10-02 16:39:22.896371 | controller | ZUUL_BRANCH=main
2025-10-02 16:39:22.896376 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-02 16:39:22.896381 | controller | SSH_CLIENT=192.168.25.12 47014 22
2025-10-02 16:39:22.896388 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-02 16:39:22.896394 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-02 16:39:22.896399 | controller | which_declare=declare -f
2025-10-02 16:39:22.896405 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-02 16:39:22.896410 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-02 16:39:22.896416 | controller | ZUUL_CHANGE=3362
2025-10-02 16:39:22.896421 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-02 16:39:22.896426 | controller | ZUUL_UUID=ff4211878959452a9e92b4a6ddcda25b
2025-10-02 16:39:22.896431 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-02 16:39:22.896437 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-02 16:39:22.896442 | controller | }
2025-10-02 16:39:22.949234 | controller | ok: Runtime: 0:00:00.006224
2025-10-02 16:39:22.954551 | 
2025-10-02 16:39:22.954621 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-02 16:39:23.040304 | controller | skipping: Conditional result was False
2025-10-02 16:39:23.046724 | 
2025-10-02 16:39:23.046791 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-02 16:39:23.804548 | controller | skipping: Conditional result was False
2025-10-02 16:39:23.810865 | 
2025-10-02 16:39:23.810938 | TASK [Ensure legacy workspace directory]
2025-10-02 16:39:24.088848 | controller | changed
2025-10-02 16:39:24.164220 | 
2025-10-02 16:39:24.164306 | PLAY RECAP
2025-10-02 16:39:24.164354 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-02 16:39:24.164377 | 
2025-10-02 16:39:24.686320 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-02 16:39:24.687134 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-02 16:39:27.021679 | 
2025-10-02 16:39:27.021809 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-02 16:39:27.098674 | 
2025-10-02 16:39:27.098819 | TASK [Create zuul-output directory]
2025-10-02 16:39:28.065197 | controller | changed
2025-10-02 16:39:28.074085 | 
2025-10-02 16:39:28.074191 | TASK [Slurp Zuul inventory test]
2025-10-02 16:39:29.448961 | controller -> localhost | ok
2025-10-02 16:39:29.463364 | 
2025-10-02 16:39:29.463514 | TASK [Save zuul inventory]
2025-10-02 16:39:30.942827 | controller | changed
2025-10-02 16:39:30.949106 | 
2025-10-02 16:39:30.949175 | TASK [Save zuul vars without the change_message]
2025-10-02 16:39:31.995484 | controller | changed
2025-10-02 16:39:32.091305 | 
2025-10-02 16:39:32.091405 | PLAY RECAP
2025-10-02 16:39:32.091457 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 16:39:32.091481 | 
2025-10-02 16:39:32.508544 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-02 16:39:32.509291 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-02 16:39:35.011759 | 
2025-10-02 16:39:35.011873 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-02 16:39:35.075157 | 
2025-10-02 16:39:35.075239 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-02 16:39:35.124473 | controller | ok
2025-10-02 16:39:35.171022 | 
2025-10-02 16:39:35.171114 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-02 16:39:35.290752 | controller | skipping: Conditional result was False
2025-10-02 16:39:35.297074 | 
2025-10-02 16:39:35.297171 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-02 16:39:35.897189 | controller | ok
2025-10-02 16:39:35.912957 | 
2025-10-02 16:39:35.913054 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-02 16:39:37.284134 | controller | ok
2025-10-02 16:39:37.299727 | 
2025-10-02 16:39:37.299800 | TASK [Prepare workspace]
2025-10-02 16:39:37.357175 | controller | ok
2025-10-02 16:39:37.400292 | 
2025-10-02 16:39:37.412126 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-02 16:39:37.968013 | controller | ok
2025-10-02 16:39:37.985406 | 
2025-10-02 16:39:37.985490 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-02 16:39:43.430882 | controller | Output suppressed because no_log was given
2025-10-02 16:39:43.465824 | 
2025-10-02 16:39:43.465919 | LOOP [Create zuul-output directory]
2025-10-02 16:39:43.731793 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-02 16:39:43.910143 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-02 16:39:43.917328 | 
2025-10-02 16:39:43.917465 | TASK [Install required packages]
2025-10-02 16:40:32.848247 | controller | changed
2025-10-02 16:40:32.853798 | 
2025-10-02 16:40:32.853890 | TASK [Install venv]
2025-10-02 16:41:38.781340 | controller | changed
2025-10-02 16:41:38.812736 | 
2025-10-02 16:41:38.812891 | PLAY RECAP
2025-10-02 16:41:38.812947 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-02 16:41:38.812972 | 
2025-10-02 16:41:38.938076 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-02 16:41:38.939116 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-02 16:41:39.504499 | 
2025-10-02 16:41:39.504610 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-02 16:41:39.525241 | 
2025-10-02 16:41:39.525326 | TASK [Gather required facts]
2025-10-02 16:41:40.083975 | controller | ok
2025-10-02 16:41:40.090398 | 
2025-10-02 16:41:40.090562 | TASK [Load environment var if instructed to]
2025-10-02 16:41:40.118495 | controller | skipping: Conditional result was False
2025-10-02 16:41:40.125567 | 
2025-10-02 16:41:40.125664 | TASK [Run molecule]
2025-10-02 16:41:41.078493 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-02 16:41:41.148319 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-02 16:41:57.572782 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.573181 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.573663 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.574107 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.574613 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+41f2edaa was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 1.0.0+41f2edaa (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.575062 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.575519 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.575958 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.576379 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.576838 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.577261 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.577725 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.578160 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.578610 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.579058 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/ad58f1/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-02 16:41:57.588531 | controller | INFO     Running default > prepare
2025-10-02 16:41:57.588964 | controller | WARNING  Skipping, prepare playbook not configured.
2025-10-02 16:41:57.596498 | controller | INFO     Running default > converge
2025-10-02 16:41:58.247436 | controller |
2025-10-02 16:41:58.247496 | controller | PLAY [Converge] ****************************************************************
2025-10-02 16:41:58.247626 | controller |
2025-10-02 16:41:58.247726 | controller | TASK [Gathering Facts] *********************************************************
2025-10-02 16:41:58.247829 | controller | Thursday 02 October 2025  16:41:58 +0000 (0:00:00.011)       0:00:00.011 ******
2025-10-02 16:41:59.077679 | controller | ok: [instance]
2025-10-02 16:41:59.077725 | controller |
2025-10-02 16:41:59.077833 | controller | TASK [cifmw_ntp : Install chrony] **********************************************
2025-10-02 16:41:59.077934 | controller | Thursday 02 October 2025  16:41:59 +0000 (0:00:00.830)       0:00:00.842 ******
2025-10-02 16:41:59.887106 | controller | ok: [instance]
2025-10-02 16:41:59.887177 | controller |
2025-10-02 16:41:59.887296 | controller | TASK [cifmw_ntp : Configure original chrony.conf file] *************************
2025-10-02 16:41:59.887408 | controller | Thursday 02 October 2025  16:41:59 +0000 (0:00:00.809)       0:00:01.651 ******
2025-10-02 16:42:00.389765 | controller | ok: [instance] => (item={'regexp': '^(server.*)$', 'line': '#\\g<1>', 'backrefs': True})
2025-10-02 16:42:00.389849 | controller | changed: [instance] => (item={'line': 'include /etc/chrony-cifmw.conf', 'insertafter': 'EOF'})
2025-10-02 16:42:00.389949 | controller |
2025-10-02 16:42:00.390051 | controller | TASK [cifmw_ntp : Render chrony extra config file] *****************************
2025-10-02 16:42:00.390154 | controller | Thursday 02 October 2025  16:42:00 +0000 (0:00:00.502)       0:00:02.154 ******
2025-10-02 16:42:00.970552 | controller | changed: [instance]
2025-10-02 16:42:00.970642 | controller |
2025-10-02 16:42:00.970759 | controller | TASK [cifmw_ntp : Enable chrony service] ***************************************
2025-10-02 16:42:00.970857 | controller | Thursday 02 October 2025  16:42:00 +0000 (0:00:00.580)       0:00:02.735 ******
2025-10-02 16:42:01.507916 | controller | ok: [instance]
2025-10-02 16:42:01.508010 | controller |
2025-10-02 16:42:01.508140 | controller | RUNNING HANDLER [cifmw_ntp : Restart chrony] ***********************************
2025-10-02 16:42:01.508264 | controller | Thursday 02 October 2025  16:42:01 +0000 (0:00:00.537)       0:00:03.272 ******
2025-10-02 16:42:01.882068 | controller | changed: [instance]
2025-10-02 16:42:01.882125 | controller |
2025-10-02 16:42:01.882210 | controller | PLAY RECAP *********************************************************************
2025-10-02 16:42:01.882331 | controller | instance                   : ok=6    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-02 16:42:01.882441 | controller |
2025-10-02 16:42:01.882559 | controller | Thursday 02 October 2025  16:42:01 +0000 (0:00:00.374)       0:00:03.647 ******
2025-10-02 16:42:01.882655 | controller | ===============================================================================
2025-10-02 16:42:01.882778 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-10-02 16:42:01.882867 | controller | cifmw_ntp : Install chrony ---------------------------------------------- 0.81s
2025-10-02 16:42:01.882961 | controller | cifmw_ntp : Render chrony extra config file ----------------------------- 0.58s
2025-10-02 16:42:01.883057 | controller | cifmw_ntp : Enable chrony service --------------------------------------- 0.54s
2025-10-02 16:42:01.883155 | controller | cifmw_ntp : Configure original chrony.conf file ------------------------- 0.50s
2025-10-02 16:42:01.883244 | controller | cifmw_ntp : Restart chrony ---------------------------------------------- 0.37s
2025-10-02 16:42:01.937059 | controller | INFO     Running default > verify
2025-10-02 16:42:01.937343 | controller | INFO     Running Ansible Verifier
2025-10-02 16:42:02.376396 | controller |
2025-10-02 16:42:02.376454 | controller | PLAY [Verify] ******************************************************************
2025-10-02 16:42:02.376560 | controller |
2025-10-02 16:42:02.376678 | controller | TASK [Gathering Facts] *********************************************************
2025-10-02 16:42:02.376771 | controller | Thursday 02 October 2025  16:42:02 +0000 (0:00:00.016)       0:00:00.016 ******
2025-10-02 16:42:03.163841 | controller | ok: [instance]
2025-10-02 16:42:03.163902 | controller |
2025-10-02 16:42:03.164003 | controller | TASK [Get service facts] *******************************************************
2025-10-02 16:42:03.164111 | controller | Thursday 02 October 2025  16:42:03 +0000 (0:00:00.787)       0:00:00.803 ******
2025-10-02 16:42:05.068533 | controller | ok: [instance]
2025-10-02 16:42:05.068974 | controller |
2025-10-02 16:42:05.105486 | controller | TASK [Assert that the service exists, is enabled and running] ******************
2025-10-02 16:42:05.105532 | controller | Thursday 02 October 2025  16:42:05 +0000 (0:00:01.904)       0:00:02.707 ******
2025-10-02 16:42:05.105546 | controller | ok: [instance] => changed=false
2025-10-02 16:42:05.603561 | controller |   msg: All assertions passed
2025-10-02 16:42:05.603619 | controller |
2025-10-02 16:42:05.603628 | controller | TASK [Check if the chrony.conf file has been configured properly] **************
2025-10-02 16:42:05.603635 | controller | Thursday 02 October 2025  16:42:05 +0000 (0:00:00.037)       0:00:02.745 ******
2025-10-02 16:42:05.603648 | controller | ok: [instance] => (item={'regexp': '^(server.*)$', 'line': '#\\g<1>', 'backrefs': True})
2025-10-02 16:42:05.804095 | controller | ok: [instance] => (item={'line': 'include /etc/chrony-cifmw.conf'})
2025-10-02 16:42:05.804159 | controller |
2025-10-02 16:42:05.804168 | controller | TASK [Check if the provided ntp server is configured in the custom configuration file] ***
2025-10-02 16:42:05.804175 | controller | Thursday 02 October 2025  16:42:05 +0000 (0:00:00.497)       0:00:03.242 ******
2025-10-02 16:42:05.804188 | controller | ok: [instance]
2025-10-02 16:42:05.841662 | controller |
2025-10-02 16:42:05.841715 | controller | TASK [Assert that chrony.conf has been correctly configured] *******************
2025-10-02 16:42:05.841724 | controller | Thursday 02 October 2025  16:42:05 +0000 (0:00:00.200)       0:00:03.443 ******
2025-10-02 16:42:05.841738 | controller | ok: [instance] => (item={'changed': False, 'msg': '', 'backup': '', 'diff': [{'before': '', 'after': '', 'before_header': '/etc/chrony.conf (content)', 'after_header': '/etc/chrony.conf (content)'}, {'before_header': '/etc/chrony.conf (file attributes)', 'after_header': '/etc/chrony.conf (file attributes)'}], 'invocation': {'module_args': {'path': '/etc/chrony.conf', 'regexp': '^(server.*)$', 'line': '#\\g<1>', 'backrefs': True, 'state': 'present', 'create': False, 'backup': False, 'firstmatch': False, 'unsafe_writes': False, 'search_string': None, 'insertafter': None, 'insertbefore': None, 'validate': None, 'mode': None, 'owner': None, 'group': None, 'seuser': None, 'serole': None, 'selevel': None, 'setype': None, 'attributes': None}}, 'failed': False, 'item': {'regexp': '^(server.*)$', 'line': '#\\g<1>', 'backrefs': True}, 'ansible_loop_var': 'item'}) => changed=false
2025-10-02 16:42:05.841769 | controller |   ansible_loop_var: item
2025-10-02 16:42:05.841778 | controller |   item:
2025-10-02 16:42:05.841804 | controller |     ansible_loop_var: item
2025-10-02 16:42:05.842575 | controller |     backup: ''
2025-10-02 16:42:05.843556 | controller |     changed: false
2025-10-02 16:42:05.843574 | controller |     diff:
2025-10-02 16:42:05.843581 | controller |     - after: ''
2025-10-02 16:42:05.843587 | controller |       after_header: /etc/chrony.conf (content)
2025-10-02 16:42:05.843593 | controller |       before: ''
2025-10-02 16:42:05.843599 | controller |       before_header: /etc/chrony.conf (content)
2025-10-02 16:42:05.843608 | controller |     - after_header: /etc/chrony.conf (file attributes)
2025-10-02 16:42:05.843694 | controller |       before_header: /etc/chrony.conf (file attributes)
2025-10-02 16:42:05.843703 | controller |     failed: false
2025-10-02 16:42:05.843709 | controller |     invocation:
2025-10-02 16:42:05.843715 | controller |       module_args:
2025-10-02 16:42:05.843720 | controller |         attributes: null
2025-10-02 16:42:05.843726 | controller |         backrefs: true
2025-10-02 16:42:05.843731 | controller |         backup: false
2025-10-02 16:42:05.843737 | controller |         create: false
2025-10-02 16:42:05.843742 | controller |         firstmatch: false
2025-10-02 16:42:05.843748 | controller |         group: null
2025-10-02 16:42:05.843756 | controller |         insertafter: null
2025-10-02 16:42:05.843826 | controller |         insertbefore: null
2025-10-02 16:42:05.843954 | controller |         line: '#\g<1>'
2025-10-02 16:42:05.844071 | controller |         mode: null
2025-10-02 16:42:05.844178 | controller |         owner: null
2025-10-02 16:42:05.844308 | controller |         path: /etc/chrony.conf
2025-10-02 16:42:05.844432 | controller |         regexp: ^(server.*)$
2025-10-02 16:42:05.844623 | controller |         search_string: null
2025-10-02 16:42:05.844807 | controller |         selevel: null
2025-10-02 16:42:05.844953 | controller |         serole: null
2025-10-02 16:42:05.845085 | controller |         setype: null
2025-10-02 16:42:05.845215 | controller |         seuser: null
2025-10-02 16:42:05.845352 | controller |         state: present
2025-10-02 16:42:05.845525 | controller |         unsafe_writes: false
2025-10-02 16:42:05.845692 | controller |         validate: null
2025-10-02 16:42:05.845836 | controller |     item:
2025-10-02 16:42:05.845971 | controller |       backrefs: true
2025-10-02 16:42:05.846104 | controller |       line: '#\g<1>'
2025-10-02 16:42:05.846235 | controller |       regexp: ^(server.*)$
2025-10-02 16:42:05.846364 | controller |     msg: ''
2025-10-02 16:42:05.846532 | controller |   msg: All assertions passed
2025-10-02 16:42:05.846718 | controller | ok: [instance] => (item={'changed': False, 'msg': '', 'backup': '', 'diff': [{'before': '', 'after': '', 'before_header': '/etc/chrony.conf (content)', 'after_header': '/etc/chrony.conf (content)'}, {'before_header': '/etc/chrony.conf (file attributes)', 'after_header': '/etc/chrony.conf (file attributes)'}], 'invocation': {'module_args': {'path': '/etc/chrony.conf', 'line': 'include /etc/chrony-cifmw.conf', 'state': 'present', 'backrefs': False, 'create': False, 'backup': False, 'firstmatch': False, 'unsafe_writes': False, 'regexp': None, 'search_string': None, 'insertafter': None, 'insertbefore': None, 'validate': None, 'mode': None, 'owner': None, 'group': None, 'seuser': None, 'serole': None, 'selevel': None, 'setype': None, 'attributes': None}}, 'failed': False, 'item': {'line': 'include /etc/chrony-cifmw.conf'}, 'ansible_loop_var': 'item'}) => changed=false
2025-10-02 16:42:05.846865 | controller |   ansible_loop_var: item
2025-10-02 16:42:05.846997 | controller |   item:
2025-10-02 16:42:05.847129 | controller |     ansible_loop_var: item
2025-10-02 16:42:05.847259 | controller |     backup: ''
2025-10-02 16:42:05.847412 | controller |     changed: false
2025-10-02 16:42:05.847574 | controller |     diff:
2025-10-02 16:42:05.847713 | controller |     - after: ''
2025-10-02 16:42:05.847855 | controller |       after_header: /etc/chrony.conf (content)
2025-10-02 16:42:05.847986 | controller |       before: ''
2025-10-02 16:42:05.848116 | controller |       before_header: /etc/chrony.conf (content)
2025-10-02 16:42:05.848258 | controller |     - after_header: /etc/chrony.conf (file attributes)
2025-10-02 16:42:05.848405 | controller |       before_header: /etc/chrony.conf (file attributes)
2025-10-02 16:42:05.848560 | controller |     failed: false
2025-10-02 16:42:05.848696 | controller |     invocation:
2025-10-02 16:42:05.848824 | controller |       module_args:
2025-10-02 16:42:05.848950 | controller |         attributes: null
2025-10-02 16:42:05.849080 | controller |         backrefs: false
2025-10-02 16:42:05.849207 | controller |         backup: false
2025-10-02 16:42:05.849333 | controller |         create: false
2025-10-02 16:42:05.849475 | controller |         firstmatch: false
2025-10-02 16:42:05.849634 | controller |         group: null
2025-10-02 16:42:05.849778 | controller |         insertafter: null
2025-10-02 16:42:05.849910 | controller |         insertbefore: null
2025-10-02 16:42:05.850040 | controller |         line: include /etc/chrony-cifmw.conf
2025-10-02 16:42:05.850167 | controller |         mode: null
2025-10-02 16:42:05.850293 | controller |         owner: null
2025-10-02 16:42:05.850436 | controller |         path: /etc/chrony.conf
2025-10-02 16:42:05.850601 | controller |         regexp: null
2025-10-02 16:42:05.850737 | controller |         search_string: null
2025-10-02 16:42:05.850864 | controller |         selevel: null
2025-10-02 16:42:05.850990 | controller |         serole: null
2025-10-02 16:42:05.851115 | controller |         setype: null
2025-10-02 16:42:05.851242 | controller |         seuser: null
2025-10-02 16:42:05.851367 | controller |         state: present
2025-10-02 16:42:05.851544 | controller |         unsafe_writes: false
2025-10-02 16:42:05.851694 | controller |         validate: null
2025-10-02 16:42:05.851826 | controller |     item:
2025-10-02 16:42:05.851962 | controller |       line: include /etc/chrony-cifmw.conf
2025-10-02 16:42:05.852091 | controller |     msg: ''
2025-10-02 16:42:05.852223 | controller |   msg: All assertions passed
2025-10-02 16:42:05.852350 | controller |
2025-10-02 16:42:05.852530 | controller | TASK [Assert that the correct server is configured in the custom configuration file] ***
2025-10-02 16:42:05.852694 | controller | Thursday 02 October 2025  16:42:05 +0000 (0:00:00.038)       0:00:03.481 ******
2025-10-02 16:42:05.903140 | controller | ok: [instance] => changed=false
2025-10-02 16:42:05.903312 | controller |   msg: '[''rhel.pool.ntp.org''] was successfully configured in /etc/chrony-cifmw.conf file'
2025-10-02 16:42:05.903471 | controller |
2025-10-02 16:42:05.903634 | controller | PLAY RECAP *********************************************************************
2025-10-02 16:42:05.903795 | controller | instance                   : ok=7    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-02 16:42:05.903928 | controller |
2025-10-02 16:42:05.904061 | controller | Thursday 02 October 2025  16:42:05 +0000 (0:00:00.062)       0:00:03.543 ******
2025-10-02 16:42:05.904189 | controller | ===============================================================================
2025-10-02 16:42:05.904317 | controller | Get service facts ------------------------------------------------------- 1.90s
2025-10-02 16:42:05.904466 | controller | Gathering Facts --------------------------------------------------------- 0.79s
2025-10-02 16:42:05.904625 | controller | Check if the chrony.conf file has been configured properly -------------- 0.50s
2025-10-02 16:42:05.904776 | controller | Check if the provided ntp server is configured in the custom configuration file --- 0.20s
2025-10-02 16:42:05.904915 | controller | Assert that the correct server is configured in the custom configuration file --- 0.06s
2025-10-02 16:42:05.905046 | controller | Assert that chrony.conf has been correctly configured ------------------- 0.04s
2025-10-02 16:42:05.905185 | controller | Assert that the service exists, is enabled and running ------------------ 0.04s
2025-10-02 16:42:05.952920 | controller | INFO     Verifier completed successfully.
2025-10-02 16:42:05.961997 | controller | INFO     Running default > cleanup
2025-10-02 16:42:06.371324 | controller |
2025-10-02 16:42:06.371590 | controller | PLAY [Cleanup] *****************************************************************
2025-10-02 16:42:06.371736 | controller |
2025-10-02 16:42:06.371879 | controller | TASK [Gathering Facts] *********************************************************
2025-10-02 16:42:06.372017 | controller | Thursday 02 October 2025  16:42:06 +0000 (0:00:00.038)       0:00:00.038 ******
2025-10-02 16:42:07.155619 | controller | ok: [instance]
2025-10-02 16:42:07.155672 | controller |
2025-10-02 16:42:07.155928 | controller | TASK [Cleanup chrony role] *****************************************************
2025-10-02 16:42:07.188855 | controller | Thursday 02 October 2025  16:42:07 +0000 (0:00:00.784)       0:00:00.822 ******
2025-10-02 16:42:07.188881 | controller |
2025-10-02 16:42:07.885593 | controller | TASK [cifmw_ntp : Disable chrony service] **************************************
2025-10-02 16:42:07.885624 | controller | Thursday 02 October 2025  16:42:07 +0000 (0:00:00.033)       0:00:00.855 ******
2025-10-02 16:42:07.885636 | controller | changed: [instance]
2025-10-02 16:42:08.186776 | controller |
2025-10-02 16:42:08.186806 | controller | TASK [cifmw_ntp : Delete chrony custom config file] ****************************
2025-10-02 16:42:08.186815 | controller | Thursday 02 October 2025  16:42:07 +0000 (0:00:00.696)       0:00:01.552 ******
2025-10-02 16:42:08.186825 | controller | changed: [instance]
2025-10-02 16:42:09.551603 | controller |
2025-10-02 16:42:09.551659 | controller | TASK [cifmw_ntp : Uninstall chrony] ********************************************
2025-10-02 16:42:09.551668 | controller | Thursday 02 October 2025  16:42:08 +0000 (0:00:00.301)       0:00:01.853 ******
2025-10-02 16:42:09.551682 | controller | changed: [instance]
2025-10-02 16:42:09.551716 | controller |
2025-10-02 16:42:09.551722 | controller | PLAY RECAP *********************************************************************
2025-10-02 16:42:09.551728 | controller | instance                   : ok=4    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-02 16:42:09.551734 | controller |
2025-10-02 16:42:09.551739 | controller | Thursday 02 October 2025  16:42:09 +0000 (0:00:01.364)       0:00:03.218 ******
2025-10-02 16:42:09.551746 | controller | ===============================================================================
2025-10-02 16:42:09.551768 | controller | cifmw_ntp : Uninstall chrony -------------------------------------------- 1.36s
2025-10-02 16:42:09.552200 | controller | Gathering Facts --------------------------------------------------------- 0.78s
2025-10-02 16:42:09.597843 | controller | cifmw_ntp : Disable chrony service -------------------------------------- 0.70s
2025-10-02 16:42:09.597878 | controller | cifmw_ntp : Delete chrony custom config file ---------------------------- 0.30s
2025-10-02 16:42:09.597886 | controller | Cleanup chrony role ----------------------------------------------------- 0.03s
2025-10-02 16:42:09.597897 | controller | INFO     Writing /tmp/report.html report.
2025-10-02 16:42:09.689832 | controller | changed
2025-10-02 16:42:09.724013 | 
2025-10-02 16:42:09.724093 | PLAY RECAP
2025-10-02 16:42:09.724134 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-02 16:42:09.724156 | 
2025-10-02 16:42:09.790379 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-02 16:42:09.791199 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-02 16:42:10.338741 | 
2025-10-02 16:42:10.338835 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-02 16:42:10.358757 | 
2025-10-02 16:42:10.358843 | TASK [Filter out host if needed]
2025-10-02 16:42:10.367186 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-02 16:42:10.371570 | 
2025-10-02 16:42:10.371636 | TASK [Ensure file is present]
2025-10-02 16:42:10.673443 | controller | ok
2025-10-02 16:42:10.680049 | 
2025-10-02 16:42:10.680116 | TASK [Manage molecule report file]
2025-10-02 16:42:11.205416 | controller | changed
2025-10-02 16:42:11.211673 | 
2025-10-02 16:42:11.211776 | TASK [Check if we get ci-framework-data basedir]
2025-10-02 16:42:11.394013 | controller | ok
2025-10-02 16:42:11.399127 | 
2025-10-02 16:42:11.399191 | TASK [Create ci-framework-data log directory for zuul]
2025-10-02 16:42:11.713767 | controller | changed
2025-10-02 16:42:11.719082 | 
2025-10-02 16:42:11.719161 | TASK [Copy ci-framework interesting files]
2025-10-02 16:42:11.908124 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-02 16:42:12.244967 | controller | changed
2025-10-02 16:42:12.250540 | 
2025-10-02 16:42:12.250607 | TASK [Get SELinux listing]
2025-10-02 16:42:12.775061 | controller | changed
2025-10-02 16:42:12.781398 | 
2025-10-02 16:42:12.781486 | TASK [Generate log index]
2025-10-02 16:42:13.409767 | controller | changed
2025-10-02 16:42:13.414985 | 
2025-10-02 16:42:13.415056 | TASK [Get some env related data]
2025-10-02 16:42:13.991726 | controller | /home/zuul/.local/bin/ansible
2025-10-02 16:42:14.941930 | controller | changed
2025-10-02 16:42:14.947209 | 
2025-10-02 16:42:14.947296 | TASK [Generate list of logs to collect in home directory]
2025-10-02 16:42:15.232017 | controller | ok: All paths examined
2025-10-02 16:42:15.238286 | 
2025-10-02 16:42:15.238378 | LOOP [Copy logs from home directory]
2025-10-02 16:42:15.553084 | controller | changed:
2025-10-02 16:42:15.553206 | controller | {
2025-10-02 16:42:15.553235 | controller |   "atime": 1759423278.1065023,
2025-10-02 16:42:15.553257 | controller |   "ctime": 1759423298.3635285,
2025-10-02 16:42:15.553275 | controller |   "dev": 64513,
2025-10-02 16:42:15.553293 | controller |   "gid": 1000,
2025-10-02 16:42:15.553310 | controller |   "gr_name": "zuul",
2025-10-02 16:42:15.553328 | controller |   "inode": 4453300,
2025-10-02 16:42:15.553344 | controller |   "isblk": false,
2025-10-02 16:42:15.553361 | controller |   "ischr": false,
2025-10-02 16:42:15.553376 | controller |   "isdir": false,
2025-10-02 16:42:15.553432 | controller |   "isfifo": false,
2025-10-02 16:42:15.553454 | controller |   "isgid": false,
2025-10-02 16:42:15.553471 | controller |   "islnk": false,
2025-10-02 16:42:15.553486 | controller |   "isreg": true,
2025-10-02 16:42:15.553501 | controller |   "issock": false,
2025-10-02 16:42:15.553517 | controller |   "isuid": false,
2025-10-02 16:42:15.553532 | controller |   "mode": "0644",
2025-10-02 16:42:15.553554 | controller |   "mtime": 1759423298.3635285,
2025-10-02 16:42:15.553571 | controller |   "nlink": 1,
2025-10-02 16:42:15.553587 | controller |   "path": "/home/zuul/ansible.log",
2025-10-02 16:42:15.553603 | controller |   "pw_name": "zuul",
2025-10-02 16:42:15.553619 | controller |   "rgrp": true,
2025-10-02 16:42:15.553634 | controller |   "roth": true,
2025-10-02 16:42:15.553649 | controller |   "rusr": true,
2025-10-02 16:42:15.553663 | controller |   "size": 6749,
2025-10-02 16:42:15.553678 | controller |   "uid": 1000,
2025-10-02 16:42:15.553706 | controller |   "wgrp": false,
2025-10-02 16:42:15.553722 | controller |   "woth": false,
2025-10-02 16:42:15.553739 | controller |   "wusr": true,
2025-10-02 16:42:15.553755 | controller |   "xgrp": false,
2025-10-02 16:42:15.553770 | controller |   "xoth": false,
2025-10-02 16:42:15.553784 | controller |   "xusr": false
2025-10-02 16:42:15.553799 | controller | }
2025-10-02 16:42:15.567352 | 
2025-10-02 16:42:15.567478 | TASK [Copy crio stats log file]
2025-10-02 16:42:15.582156 | controller | skipping: Conditional result was False
2025-10-02 16:42:15.589044 | 
2025-10-02 16:42:15.589113 | TASK [Get SELinux related data]
2025-10-02 16:42:15.795338 | controller | <no matches>
2025-10-02 16:42:16.117896 | controller | ERROR
2025-10-02 16:42:16.118069 | controller | {
2025-10-02 16:42:16.118105 | controller |   "delta": "0:00:00.009535",
2025-10-02 16:42:16.118129 | controller |   "end": "2025-10-02 16:42:15.796306",
2025-10-02 16:42:16.118149 | controller |   "msg": "non-zero return code",
2025-10-02 16:42:16.118167 | controller |   "rc": 1,
2025-10-02 16:42:16.118185 | controller |   "start": "2025-10-02 16:42:15.786771"
2025-10-02 16:42:16.118203 | controller | }
2025-10-02 16:42:16.118229 | controller | ERROR: Ignoring Errors
2025-10-02 16:42:16.123983 | 
2025-10-02 16:42:16.124052 | TASK [Create system configuration directory]
2025-10-02 16:42:16.319345 | controller | changed
2025-10-02 16:42:16.324255 | 
2025-10-02 16:42:16.324320 | TASK [Get some of the system configurations]
2025-10-02 16:42:16.850933 | controller | changed
2025-10-02 16:42:16.856213 | 
2025-10-02 16:42:16.856283 | TASK [Copy generated documentation if available]
2025-10-02 16:42:16.890054 | controller | skipping: Conditional result was False
2025-10-02 16:42:16.895873 | 
2025-10-02 16:42:16.895946 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-02 16:42:16.911584 | controller | skipping: Conditional result was False
2025-10-02 16:42:16.920109 | 
2025-10-02 16:42:16.920225 | TASK [Compress logs bigger than 2MB]
2025-10-02 16:42:17.448565 | controller | changed
2025-10-02 16:42:17.454664 | 
2025-10-02 16:42:17.454912 | TASK [Copy files from workspace on node]
2025-10-02 16:42:17.473815 | controller | ok
2025-10-02 16:42:17.499030 | 
2025-10-02 16:42:17.499111 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-02 16:42:17.522270 | controller | skipping: Conditional result was False
2025-10-02 16:42:17.529501 | 
2025-10-02 16:42:17.529591 | TASK [fetch-output : Set log path for single node]
2025-10-02 16:42:17.560187 | controller | ok
2025-10-02 16:42:17.564980 | 
2025-10-02 16:42:17.565057 | LOOP [fetch-output : Ensure local output dirs]
2025-10-02 16:42:17.776673 | controller -> localhost | ok: "/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/logs"
2025-10-02 16:42:17.776918 | controller -> localhost | changed: All items complete
2025-10-02 16:42:17.776948 | 
2025-10-02 16:42:17.971446 | controller -> localhost | changed: "/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/artifacts"
2025-10-02 16:42:18.189721 | controller -> localhost | changed: "/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/docs"
2025-10-02 16:42:18.203373 | 
2025-10-02 16:42:18.203464 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-02 16:42:18.767959 | controller | changed:
2025-10-02 16:42:18.768142 | controller | .d..t...... ./
2025-10-02 16:42:18.768173 | controller | >f+++++++++ README.html
2025-10-02 16:42:18.768206 | controller | >f+++++++++ ansible-execution.log
2025-10-02 16:42:18.768230 | controller | >f+++++++++ ansible.log
2025-10-02 16:42:18.768251 | controller | >f+++++++++ dmesg.log
2025-10-02 16:42:18.768270 | controller | >f+++++++++ installed-pkgs.log
2025-10-02 16:42:18.768290 | controller | >f+++++++++ python.log
2025-10-02 16:42:18.768311 | controller | >f+++++++++ registries.conf
2025-10-02 16:42:18.768327 | controller | >f+++++++++ report.html
2025-10-02 16:42:18.768346 | controller | >f+++++++++ selinux-denials.log
2025-10-02 16:42:18.768362 | controller | >f+++++++++ selinux-listing.log
2025-10-02 16:42:18.768377 | controller | cd+++++++++ ci-framework-data/
2025-10-02 16:42:18.768422 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-02 16:42:18.768442 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-02 16:42:18.768460 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-02 16:42:18.768476 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-02 16:42:18.768492 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-02 16:42:18.768507 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-02 16:42:18.768521 | controller | cd+++++++++ registries.conf.d/
2025-10-02 16:42:18.768536 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-02 16:42:18.768550 | controller | cd+++++++++ system-config/
2025-10-02 16:42:18.768564 | controller | cd+++++++++ system-config/libvirt/
2025-10-02 16:42:18.768578 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-02 16:42:18.768593 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-02 16:42:19.135900 | controller | changed: .d..t...... ./
2025-10-02 16:42:19.532991 | controller | changed: .d..t...... ./
2025-10-02 16:42:19.554879 | 
2025-10-02 16:42:19.554997 | TASK [Return artifact to Zuul]
2025-10-02 16:42:19.584854 | controller | ok
2025-10-02 16:42:19.604093 | 
2025-10-02 16:42:19.604160 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-02 16:42:19.604259 | 
2025-10-02 16:42:19.604285 | PLAY RECAP
2025-10-02 16:42:19.604321 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-02 16:42:19.604340 | 
2025-10-02 16:42:19.689817 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-02 16:42:19.690567 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-02 16:42:20.266301 | 
2025-10-02 16:42:20.266485 | PLAY [all]
2025-10-02 16:42:20.291291 | 
2025-10-02 16:42:20.291435 | TASK [include_role : fetch-output]
2025-10-02 16:42:20.320761 | controller | ok
2025-10-02 16:42:20.338137 | 
2025-10-02 16:42:20.338245 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-02 16:42:20.385067 | controller | skipping: Conditional result was False
2025-10-02 16:42:20.390756 | 
2025-10-02 16:42:20.390830 | TASK [fetch-output : Set log path for single node]
2025-10-02 16:42:20.420309 | controller | ok
2025-10-02 16:42:20.425719 | 
2025-10-02 16:42:20.425826 | LOOP [fetch-output : Ensure local output dirs]
2025-10-02 16:42:20.798520 | controller -> localhost | ok: "/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/logs"
2025-10-02 16:42:20.989236 | controller -> localhost | ok: "/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/artifacts"
2025-10-02 16:42:21.204249 | controller -> localhost | ok: "/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/docs"
2025-10-02 16:42:21.220807 | 
2025-10-02 16:42:21.220902 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-02 16:42:21.766477 | controller | ok
2025-10-02 16:42:21.766738 | controller | ok: All items complete
2025-10-02 16:42:21.766774 | 
2025-10-02 16:42:22.152065 | controller | ok
2025-10-02 16:42:22.569482 | controller | ok
2025-10-02 16:42:22.582553 | 
2025-10-02 16:42:22.582657 | TASK [include_role : fetch-output-openshift]
2025-10-02 16:42:22.616404 | controller | skipping: Conditional result was False
2025-10-02 16:42:22.624880 | 
2025-10-02 16:42:22.625017 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-02 16:42:22.997855 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006457
2025-10-02 16:42:23.212477 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006951
2025-10-02 16:42:23.238362 | 
2025-10-02 16:42:23.238491 | PLAY [all]
2025-10-02 16:42:23.252316 | 
2025-10-02 16:42:23.252402 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-02 16:42:23.648126 | controller | changed
2025-10-02 16:42:23.669829 | 
2025-10-02 16:42:23.669887 | PLAY RECAP
2025-10-02 16:42:23.669928 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-02 16:42:23.670022 | 
2025-10-02 16:42:23.768313 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-02 16:42:23.769099 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-02 16:42:24.345712 | 
2025-10-02 16:42:24.345848 | PLAY [localhost]
2025-10-02 16:42:24.365740 | 
2025-10-02 16:42:24.365884 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-02 16:42:24.710293 | localhost | changed
2025-10-02 16:42:24.715722 | 
2025-10-02 16:42:24.715824 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-02 16:42:24.744240 | localhost | ok
2025-10-02 16:42:24.752299 | 
2025-10-02 16:42:24.752406 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-02 16:42:25.115573 | localhost | changed
2025-10-02 16:42:25.121074 | 
2025-10-02 16:42:25.121143 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-02 16:42:25.697859 | localhost | changed
2025-10-02 16:42:25.702894 | 
2025-10-02 16:42:25.702965 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-02 16:42:26.060483 | localhost | Identity added: /var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/tmp/ansible.l_dimmc0 (/var/lib/zuul/builds/ff4211878959452a9e92b4a6ddcda25b/work/tmp/ansible.l_dimmc0)
2025-10-02 16:42:26.060659 | localhost | ok: Runtime: 0:00:00.011961
2025-10-02 16:42:26.066099 | 
2025-10-02 16:42:26.066169 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-02 16:42:26.356340 | localhost | ok: Runtime: 0:00:00.008925
2025-10-02 16:42:26.361078 | 
2025-10-02 16:42:26.361154 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-02 16:42:26.420877 | localhost | changed
2025-10-02 16:42:26.425186 | 
2025-10-02 16:42:26.433491 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-02 16:42:26.907234 | localhost | changed
2025-10-02 16:42:26.943012 | 
2025-10-02 16:42:26.943100 | PLAY [localhost]
2025-10-02 16:42:26.959240 | 
2025-10-02 16:42:26.959347 | TASK [Generate bulk log download script]
2025-10-02 16:42:26.980310 | localhost | ok
2025-10-02 16:42:26.992544 | 
2025-10-02 16:42:26.992665 | TASK [local-log-download : Check API endpoint is defined]
2025-10-02 16:42:27.030867 | localhost | ok: All assertions passed
2025-10-02 16:42:27.035428 | 
2025-10-02 16:42:27.035501 | TASK [local-log-download : Create download script]
2025-10-02 16:42:27.426443 | localhost -> localhost | changed
2025-10-02 16:42:27.435823 | 
2025-10-02 16:42:27.435902 | TASK [Register quick-download link]
2025-10-02 16:42:27.476927 | localhost | ok
2025-10-02 16:42:27.512697 | 
2025-10-02 16:42:27.512783 | PLAY [logserver.rdoproject.org]
2025-10-02 16:42:27.522832 | 
2025-10-02 16:42:27.522898 | TASK [Set zuul-log-path fact]
2025-10-02 16:42:27.538369 | logserver.rdoproject.org | ok
2025-10-02 16:42:27.547498 | 
2025-10-02 16:42:27.547571 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 16:42:27.574028 | logserver.rdoproject.org | ok
2025-10-02 16:42:27.579975 | 
2025-10-02 16:42:27.580041 | TASK [upload-logs : Create log directories]
2025-10-02 16:42:29.273667 | logserver.rdoproject.org | changed
2025-10-02 16:42:29.277059 | 
2025-10-02 16:42:29.277125 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-02 16:42:29.543914 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007876
2025-10-02 16:42:29.549401 | 
2025-10-02 16:42:29.549482 | TASK [upload-logs : Upload logs to log server]
2025-10-02 16:42:31.237983 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-02 16:42:31.240876 | 
2025-10-02 16:42:31.240942 | LOOP [upload-logs : Compress console log and json output]
2025-10-02 16:42:31.284536 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 16:42:31.292876 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 16:42:31.298411 | 
2025-10-02 16:42:31.298517 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-02 16:42:31.332880 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 16:42:31.333196 | 
2025-10-02 16:42:31.336181 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 16:42:31.346861 | 
2025-10-02 16:42:31.346958 | LOOP [upload-logs : Upload console log and json output]