2025-09-30 02:36:20.149294 | Job console starting...
2025-09-30 02:36:20.391793 | Updating repositories
2025-09-30 02:36:21.056834 | Preparing job workspace
2025-09-30 02:36:30.443658 | Running Ansible setup...
2025-09-30 02:36:33.726481 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 02:36:34.427766 | 
2025-09-30 02:36:34.427901 | PLAY [localhost]
2025-09-30 02:36:34.435748 | 
2025-09-30 02:36:34.435819 | TASK [Gathering Facts]
2025-09-30 02:36:35.553005 | localhost | ok
2025-09-30 02:36:35.573058 | 
2025-09-30 02:36:35.573160 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-30 02:36:36.164052 | localhost -> localhost | changed
2025-09-30 02:36:36.168889 | 
2025-09-30 02:36:36.168990 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-30 02:36:37.443591 | localhost -> localhost | changed
2025-09-30 02:36:37.455082 | 
2025-09-30 02:36:37.455153 | TASK [Setup log path fact]
2025-09-30 02:36:37.495437 | localhost | ok
2025-09-30 02:36:37.525384 | 
2025-09-30 02:36:37.525460 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 02:36:37.579726 | localhost | ok
2025-09-30 02:36:37.596558 | 
2025-09-30 02:36:37.596629 | TASK [emit-job-header : Print job information]
2025-09-30 02:36:37.635578 | # Job Information
2025-09-30 02:36:37.635715 | Ansible Version: 2.15.12
2025-09-30 02:36:37.635745 | Job: cifmw-molecule-build_push_container
2025-09-30 02:36:37.635769 | Pipeline: github-check
2025-09-30 02:36:37.635790 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-09-30 02:36:37.635810 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3332
2025-09-30 02:36:37.635838 | Log URL (when completed): https://logserver.rdoproject.org/4b8/rdoproject.org/4b8149099a1040b1ada439394e1b080d/
2025-09-30 02:36:37.635857 | Event ID: 0e973d50-9da6-11f0-93b0-093ef0192992
2025-09-30 02:36:37.640275 | 
2025-09-30 02:36:37.640342 | LOOP [emit-job-header : Print node information]
2025-09-30 02:36:37.799501 | localhost | ok:
2025-09-30 02:36:37.799654 | localhost | # Node Information
2025-09-30 02:36:37.799694 | localhost | Inventory Hostname: controller
2025-09-30 02:36:37.799720 | localhost | Hostname: np0005461190
2025-09-30 02:36:37.799742 | localhost | Username: zuul
2025-09-30 02:36:37.803349 | localhost | Distro: CentOS 9
2025-09-30 02:36:37.803414 | localhost | Provider: ibm-bm4-nodepool
2025-09-30 02:36:37.803447 | localhost | Region: regionOne
2025-09-30 02:36:37.803475 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-09-30 02:36:37.803502 | localhost | Product Name: OpenStack Compute
2025-09-30 02:36:37.803527 | localhost | Interface IP: 192.168.26.195
2025-09-30 02:36:37.844220 | 
2025-09-30 02:36:37.844342 | PLAY [all]
2025-09-30 02:36:37.858433 | 
2025-09-30 02:36:37.858934 | TASK [Gather network facts]
2025-09-30 02:36:38.222353 | controller | ok
2025-09-30 02:36:38.239768 | 
2025-09-30 02:36:38.239841 | TASK [include_role : start-zuul-console]
2025-09-30 02:36:38.268459 | controller | ok
2025-09-30 02:36:38.284822 | 
2025-09-30 02:36:38.284889 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-30 02:36:38.713866 | controller | ok
2025-09-30 02:36:38.723145 | 
2025-09-30 02:36:38.723211 | TASK [include_role : add-build-sshkey]
2025-09-30 02:36:38.751456 | controller | ok
2025-09-30 02:36:38.768483 | 
2025-09-30 02:36:38.768560 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-30 02:36:39.152408 | controller -> localhost | ok
2025-09-30 02:36:39.157713 | 
2025-09-30 02:36:39.157778 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-30 02:36:39.205795 | controller | ok
2025-09-30 02:36:39.218565 | controller | included: /var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-30 02:36:39.246924 | 
2025-09-30 02:36:39.246989 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-30 02:36:40.202695 | controller -> localhost | Generating public/private rsa key pair.
2025-09-30 02:36:40.202858 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/4b8149099a1040b1ada439394e1b080d_id_rsa.
2025-09-30 02:36:40.202889 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/4b8149099a1040b1ada439394e1b080d_id_rsa.pub.
2025-09-30 02:36:40.202928 | controller -> localhost | The key fingerprint is:
2025-09-30 02:36:40.202952 | controller -> localhost | SHA256:uHXGTsJ9wV27jyC1/TYbFTDXLc+WhropZkeYfRpQrzI zuul-build-sshkey
2025-09-30 02:36:40.202972 | controller -> localhost | The key's randomart image is:
2025-09-30 02:36:40.202991 | controller -> localhost | +---[RSA 3072]----+
2025-09-30 02:36:40.203010 | controller -> localhost | |             o .+|
2025-09-30 02:36:40.203028 | controller -> localhost | |           o .=.+|
2025-09-30 02:36:40.203045 | controller -> localhost | |          . = o*.|
2025-09-30 02:36:40.203067 | controller -> localhost | |       o + . * o*|
2025-09-30 02:36:40.203085 | controller -> localhost | |      . S % * oo.|
2025-09-30 02:36:40.203102 | controller -> localhost | |       o E O o oo|
2025-09-30 02:36:40.203118 | controller -> localhost | |      .   = * .o+|
2025-09-30 02:36:40.203136 | controller -> localhost | |         + =   .+|
2025-09-30 02:36:40.203153 | controller -> localhost | |        o o    . |
2025-09-30 02:36:40.203171 | controller -> localhost | +----[SHA256]-----+
2025-09-30 02:36:40.203211 | controller -> localhost | ok: Runtime: 0:00:00.352220
2025-09-30 02:36:40.210057 | 
2025-09-30 02:36:40.210120 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-30 02:36:40.250824 | controller | ok
2025-09-30 02:36:40.263166 | controller | included: /var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-30 02:36:40.276300 | 
2025-09-30 02:36:40.276405 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-30 02:36:40.291974 | controller | skipping: Conditional result was False
2025-09-30 02:36:40.297719 | 
2025-09-30 02:36:40.297803 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-30 02:36:40.694772 | controller | changed
2025-09-30 02:36:40.699575 | 
2025-09-30 02:36:40.699659 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-30 02:36:40.936738 | controller | ok
2025-09-30 02:36:40.942602 | 
2025-09-30 02:36:40.942688 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-30 02:36:41.635077 | controller | changed
2025-09-30 02:36:41.639772 | 
2025-09-30 02:36:41.639853 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-30 02:36:42.311750 | controller | changed
2025-09-30 02:36:42.317265 | 
2025-09-30 02:36:42.317343 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-30 02:36:42.360786 | controller | skipping: Conditional result was False
2025-09-30 02:36:42.367704 | 
2025-09-30 02:36:42.367776 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-30 02:36:42.863465 | controller -> localhost | changed
2025-09-30 02:36:42.872560 | 
2025-09-30 02:36:42.872635 | TASK [add-build-sshkey : Add back temp key]
2025-09-30 02:36:43.299436 | controller -> localhost | Identity added: /var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/4b8149099a1040b1ada439394e1b080d_id_rsa (zuul-build-sshkey)
2025-09-30 02:36:43.299604 | controller -> localhost | ok: Runtime: 0:00:00.019890
2025-09-30 02:36:43.314105 | 
2025-09-30 02:36:43.314173 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-30 02:36:43.797597 | controller | ok
2025-09-30 02:36:43.802794 | 
2025-09-30 02:36:43.802861 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-30 02:36:43.858630 | controller | skipping: Conditional result was False
2025-09-30 02:36:43.868448 | 
2025-09-30 02:36:43.868515 | TASK [include_role : validate-host]
2025-09-30 02:36:43.916798 | controller | ok
2025-09-30 02:36:43.953072 | 
2025-09-30 02:36:43.953149 | TASK [validate-host : Define zuul_info_dir fact]
2025-09-30 02:36:44.012531 | controller | ok
2025-09-30 02:36:44.057857 | 
2025-09-30 02:36:44.057954 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-09-30 02:36:44.361295 | controller -> localhost | ok
2025-09-30 02:36:44.366945 | 
2025-09-30 02:36:44.367008 | TASK [validate-host : Collect information about the host]
2025-09-30 02:36:44.964598 | controller | ok
2025-09-30 02:36:44.972040 | 
2025-09-30 02:36:44.972101 | TASK [validate-host : Sanitize hostname]
2025-09-30 02:36:45.083756 | controller | ok
2025-09-30 02:36:45.088055 | 
2025-09-30 02:36:45.088117 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-09-30 02:36:46.002550 | controller -> localhost | changed
2025-09-30 02:36:46.009372 | 
2025-09-30 02:36:46.009436 | TASK [validate-host : Collect information about zuul worker]
2025-09-30 02:36:46.477177 | controller | ok
2025-09-30 02:36:46.482069 | 
2025-09-30 02:36:46.482137 | TASK [validate-host : Write out all zuul information for each host]
2025-09-30 02:36:47.774724 | controller -> localhost | changed
2025-09-30 02:36:47.785001 | 
2025-09-30 02:36:47.785069 | TASK [include_role : prepare-workspace-openshift]
2025-09-30 02:36:47.878782 | controller | skipping: Conditional result was False
2025-09-30 02:36:47.884534 | 
2025-09-30 02:36:47.884609 | TASK [include_role : remove-zuul-sshkey]
2025-09-30 02:36:47.928186 | controller | skipping: Conditional result was False
2025-09-30 02:36:47.933575 | 
2025-09-30 02:36:47.933643 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-30 02:36:48.235713 | controller | ok: "logs"
2025-09-30 02:36:48.235952 | controller | ok: All items complete
2025-09-30 02:36:48.235990 | 
2025-09-30 02:36:48.429967 | controller | ok: "artifacts"
2025-09-30 02:36:48.644625 | controller | ok: "docs"
2025-09-30 02:36:48.670558 | 
2025-09-30 02:36:48.670651 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-30 02:36:48.957226 | controller | changed: "logs"
2025-09-30 02:36:49.143876 | controller | changed: "artifacts"
2025-09-30 02:36:49.403543 | controller | changed: "docs"
2025-09-30 02:36:49.439128 | 
2025-09-30 02:36:49.439211 | PLAY RECAP
2025-09-30 02:36:49.439257 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 02:36:49.439285 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 02:36:49.439303 | 
2025-09-30 02:36:49.758282 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 02:36:49.759060 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-30 02:36:50.978357 | 
2025-09-30 02:36:50.978451 | PLAY [all]
2025-09-30 02:36:51.027470 | 
2025-09-30 02:36:51.027551 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-30 02:36:51.086044 | controller | ok
2025-09-30 02:36:51.090944 | 
2025-09-30 02:36:51.091023 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-30 02:36:51.707250 | controller | changed
2025-09-30 02:36:51.716882 | 
2025-09-30 02:36:51.716978 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-30 02:36:53.018246 | controller | changed
2025-09-30 02:36:53.038770 | 
2025-09-30 02:36:53.038839 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-09-30 02:36:53.668609 | controller | changed:
2025-09-30 02:36:53.668816 | controller | {
2025-09-30 02:36:53.668850 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-09-30 02:36:53.668881 | controller | }
2025-09-30 02:36:53.923261 | controller | changed:
2025-09-30 02:36:53.923369 | controller | {
2025-09-30 02:36:53.923399 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-09-30 02:36:53.923423 | controller | }
2025-09-30 02:36:54.129633 | controller | changed:
2025-09-30 02:36:54.129731 | controller | {
2025-09-30 02:36:54.129788 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-09-30 02:36:54.129825 | controller | }
2025-09-30 02:36:54.381263 | controller | changed:
2025-09-30 02:36:54.381345 | controller | {
2025-09-30 02:36:54.381375 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-09-30 02:36:54.381398 | controller | }
2025-09-30 02:36:54.604273 | controller | changed:
2025-09-30 02:36:54.604386 | controller | {
2025-09-30 02:36:54.604430 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-09-30 02:36:54.604489 | controller | }
2025-09-30 02:36:54.824557 | controller | changed:
2025-09-30 02:36:54.825040 | controller | {
2025-09-30 02:36:54.825090 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-09-30 02:36:54.825118 | controller | }
2025-09-30 02:36:55.039753 | controller | changed:
2025-09-30 02:36:55.039940 | controller | {
2025-09-30 02:36:55.039985 | 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-09-30 02:36:55.040014 | controller | }
2025-09-30 02:36:55.244799 | controller | changed:
2025-09-30 02:36:55.244866 | controller | {
2025-09-30 02:36:55.244895 | 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-09-30 02:36:55.244941 | controller | }
2025-09-30 02:36:55.458348 | controller | changed:
2025-09-30 02:36:55.458420 | controller | {
2025-09-30 02:36:55.458448 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-09-30 02:36:55.458470 | controller | }
2025-09-30 02:36:55.697956 | controller | changed:
2025-09-30 02:36:55.698981 | controller | {
2025-09-30 02:36:55.699039 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-09-30 02:36:55.699067 | controller | }
2025-09-30 02:36:55.918660 | controller | changed:
2025-09-30 02:36:55.918970 | controller | {
2025-09-30 02:36:55.919014 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-09-30 02:36:55.919040 | controller | }
2025-09-30 02:36:56.141246 | controller | changed:
2025-09-30 02:36:56.141322 | controller | {
2025-09-30 02:36:56.141351 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-09-30 02:36:56.141373 | controller | }
2025-09-30 02:36:56.381408 | controller | changed:
2025-09-30 02:36:56.381484 | controller | {
2025-09-30 02:36:56.381512 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-09-30 02:36:56.381534 | controller | }
2025-09-30 02:36:56.628883 | controller | changed:
2025-09-30 02:36:56.628976 | controller | {
2025-09-30 02:36:56.629005 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-09-30 02:36:56.629026 | controller | }
2025-09-30 02:36:56.855342 | controller | changed:
2025-09-30 02:36:56.855416 | controller | {
2025-09-30 02:36:56.855443 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-09-30 02:36:56.855464 | controller | }
2025-09-30 02:36:57.070640 | controller | changed:
2025-09-30 02:36:57.070729 | controller | {
2025-09-30 02:36:57.070757 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-09-30 02:36:57.070779 | controller | }
2025-09-30 02:36:57.288715 | controller | changed:
2025-09-30 02:36:57.288882 | controller | {
2025-09-30 02:36:57.288933 | 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-09-30 02:36:57.288960 | controller | }
2025-09-30 02:36:57.497255 | controller | changed:
2025-09-30 02:36:57.497326 | controller | {
2025-09-30 02:36:57.497354 | 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-09-30 02:36:57.497382 | controller | }
2025-09-30 02:36:57.743070 | controller | changed:
2025-09-30 02:36:57.743144 | controller | {
2025-09-30 02:36:57.743171 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-09-30 02:36:57.743193 | controller | }
2025-09-30 02:36:57.982691 | controller | changed:
2025-09-30 02:36:57.982769 | controller | {
2025-09-30 02:36:57.982798 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-09-30 02:36:57.982821 | controller | }
2025-09-30 02:36:58.202026 | controller | changed:
2025-09-30 02:36:58.202105 | controller | {
2025-09-30 02:36:58.202133 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-09-30 02:36:58.202156 | controller | }
2025-09-30 02:36:58.466546 | controller | changed:
2025-09-30 02:36:58.466624 | controller | {
2025-09-30 02:36:58.466650 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-09-30 02:36:58.466707 | controller | }
2025-09-30 02:36:58.686068 | controller | changed:
2025-09-30 02:36:58.686150 | controller | {
2025-09-30 02:36:58.686180 | 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-09-30 02:36:58.686203 | controller | }
2025-09-30 02:36:58.912508 | controller | changed:
2025-09-30 02:36:58.912589 | controller | {
2025-09-30 02:36:58.912618 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-09-30 02:36:58.912639 | controller | }
2025-09-30 02:36:59.146864 | controller | changed:
2025-09-30 02:36:59.146955 | controller | {
2025-09-30 02:36:59.146985 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-09-30 02:36:59.147008 | controller | }
2025-09-30 02:36:59.378407 | controller | changed:
2025-09-30 02:36:59.378484 | controller | {
2025-09-30 02:36:59.378513 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-09-30 02:36:59.378535 | controller | }
2025-09-30 02:36:59.410271 | 
2025-09-30 02:36:59.410374 | TASK [Set timezone to UTC]
2025-09-30 02:37:00.347311 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-09-30 02:37:00.353342 | 
2025-09-30 02:37:00.353411 | TASK [Create nodepool directory]
2025-09-30 02:37:00.583376 | controller | changed
2025-09-30 02:37:00.590302 | 
2025-09-30 02:37:00.590370 | TASK [Create nodepool sub_nodes file]
2025-09-30 02:37:01.224840 | controller | changed
2025-09-30 02:37:01.230012 | 
2025-09-30 02:37:01.230089 | TASK [Create nodepool sub_nodes_private file]
2025-09-30 02:37:01.928684 | controller | changed
2025-09-30 02:37:01.938074 | 
2025-09-30 02:37:01.938138 | LOOP [Populate nodepool sub_nodes file]
2025-09-30 02:37:02.006086 | 
2025-09-30 02:37:02.006439 | LOOP [Populate nodepool sub_nodes_private file]
2025-09-30 02:37:02.120650 | 
2025-09-30 02:37:02.120816 | TASK [Create nodepool primary file]
2025-09-30 02:37:02.179224 | controller | skipping: Conditional result was False
2025-09-30 02:37:02.184465 | 
2025-09-30 02:37:02.184535 | TASK [Create nodepool node_private for this node]
2025-09-30 02:37:03.035731 | controller | changed
2025-09-30 02:37:03.051221 | 
2025-09-30 02:37:03.051286 | LOOP [Copy ssh keys to nodepool directory]
2025-09-30 02:37:03.935597 | controller | ok: Item: id_rsa Runtime: 0:00:00.005026
2025-09-30 02:37:03.935790 | 
2025-09-30 02:37:04.112962 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.003949
2025-09-30 02:37:04.129557 | 
2025-09-30 02:37:04.129673 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-09-30 02:37:04.921634 | controller | changed
2025-09-30 02:37:04.927891 | 
2025-09-30 02:37:04.927977 | TASK [Validate sudoers config after edits]
2025-09-30 02:37:05.268994 | controller | /etc/sudoers: parsed OK
2025-09-30 02:37:05.269083 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-09-30 02:37:05.269094 | controller | /etc/sudoers.d/zuul: parsed OK
2025-09-30 02:37:05.269115 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-09-30 02:37:05.528216 | controller | ok: Runtime: 0:00:00.006303
2025-09-30 02:37:05.533763 | 
2025-09-30 02:37:05.533828 | TASK [Show the environment passed in to job shell scripts]
2025-09-30 02:37:06.019264 | controller | SHELL=/bin/bash
2025-09-30 02:37:06.019318 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-09-30 02:37:06.019328 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-09-30 02:37:06.019335 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/46/3346/eb5b53fb17db92a72d33d052a56c8edd0d10ea78^openstack-k8s-operators/ci-framework:main:refs/changes/32/3332/2b7f44a769d14bbef534eeafa4b4e5c8b67650d8
2025-09-30 02:37:06.019343 | controller | PWD=/home/zuul
2025-09-30 02:37:06.019349 | controller | ZUUL_PIPELINE=github-check
2025-09-30 02:37:06.019354 | controller | LOGNAME=zuul
2025-09-30 02:37:06.019360 | controller | XDG_SESSION_TYPE=tty
2025-09-30 02:37:06.019365 | controller | _=/usr/bin/env
2025-09-30 02:37:06.019414 | controller | MOTD_SHOWN=pam
2025-09-30 02:37:06.019423 | controller | HOME=/home/zuul
2025-09-30 02:37:06.019428 | controller | LANG=en_US.UTF-8
2025-09-30 02:37:06.019434 | controller | SSH_CONNECTION=192.168.26.12 41398 192.168.26.195 22
2025-09-30 02:37:06.019440 | 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-09-30 02:37:06.019445 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3332,2b7f44a769d14bbef534eeafa4b4e5c8b67650d8
2025-09-30 02:37:06.019451 | controller | WORKSPACE=/home/zuul/workspace
2025-09-30 02:37:06.019456 | controller | XDG_SESSION_CLASS=user
2025-09-30 02:37:06.019462 | controller | SELINUX_ROLE_REQUESTED=
2025-09-30 02:37:06.019467 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-09-30 02:37:06.019472 | controller | USER=zuul
2025-09-30 02:37:06.019478 | controller | ZUUL_VOTING=True
2025-09-30 02:37:06.019483 | controller | BUILD_TIMEOUT=1800000
2025-09-30 02:37:06.019488 | controller | SELINUX_USE_CURRENT_RANGE=
2025-09-30 02:37:06.019494 | controller | SHLVL=1
2025-09-30 02:37:06.019499 | controller | ZUUL_PATCHSET=2b7f44a769d14bbef534eeafa4b4e5c8b67650d8
2025-09-30 02:37:06.019504 | controller | XDG_SESSION_ID=1
2025-09-30 02:37:06.019510 | controller | ZUUL_BRANCH=main
2025-09-30 02:37:06.019515 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-09-30 02:37:06.019520 | controller | SSH_CLIENT=192.168.26.12 41398 22
2025-09-30 02:37:06.019526 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-09-30 02:37:06.019531 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-09-30 02:37:06.019536 | controller | which_declare=declare -f
2025-09-30 02:37:06.019542 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-09-30 02:37:06.019548 | controller | SELINUX_LEVEL_REQUESTED=
2025-09-30 02:37:06.019554 | controller | ZUUL_CHANGE=3332
2025-09-30 02:37:06.019559 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-09-30 02:37:06.019564 | controller | ZUUL_UUID=4b8149099a1040b1ada439394e1b080d
2025-09-30 02:37:06.019572 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-09-30 02:37:06.019577 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-09-30 02:37:06.019583 | controller | }
2025-09-30 02:37:06.110093 | controller | ok: Runtime: 0:00:00.007221
2025-09-30 02:37:06.115862 | 
2025-09-30 02:37:06.115952 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-09-30 02:37:06.171595 | controller | skipping: Conditional result was False
2025-09-30 02:37:06.182555 | 
2025-09-30 02:37:06.182648 | TASK [Symlink /home/zuul-worker/workspace]
2025-09-30 02:37:06.859639 | controller | skipping: Conditional result was False
2025-09-30 02:37:06.865162 | 
2025-09-30 02:37:06.865230 | TASK [Ensure legacy workspace directory]
2025-09-30 02:37:07.341763 | controller | changed
2025-09-30 02:37:07.474662 | 
2025-09-30 02:37:07.474759 | PLAY RECAP
2025-09-30 02:37:07.474809 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 02:37:07.474833 | 
2025-09-30 02:37:08.347730 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-30 02:37:08.348438 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-30 02:37:09.790216 | 
2025-09-30 02:37:09.790315 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-09-30 02:37:09.840356 | 
2025-09-30 02:37:09.840451 | TASK [Create zuul-output directory]
2025-09-30 02:37:10.631065 | controller | changed
2025-09-30 02:37:10.640186 | 
2025-09-30 02:37:10.640296 | TASK [Slurp Zuul inventory test]
2025-09-30 02:37:11.922467 | controller -> localhost | ok
2025-09-30 02:37:11.933487 | 
2025-09-30 02:37:11.933564 | TASK [Save zuul inventory]
2025-09-30 02:37:13.573333 | controller | changed
2025-09-30 02:37:13.582317 | 
2025-09-30 02:37:13.582403 | TASK [Save zuul vars without the change_message]
2025-09-30 02:37:14.705395 | controller | changed
2025-09-30 02:37:14.801387 | 
2025-09-30 02:37:14.801461 | PLAY RECAP
2025-09-30 02:37:14.801509 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 02:37:14.801534 | 
2025-09-30 02:37:15.210706 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-30 02:37:15.211458 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-30 02:37:18.335179 | 
2025-09-30 02:37:18.335286 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-09-30 02:37:18.422179 | 
2025-09-30 02:37:18.422294 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-09-30 02:37:18.470561 | controller | ok
2025-09-30 02:37:18.539532 | 
2025-09-30 02:37:18.539634 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-30 02:37:18.646117 | controller | skipping: Conditional result was False
2025-09-30 02:37:18.652071 | 
2025-09-30 02:37:18.652142 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-30 02:37:19.728363 | controller | ok
2025-09-30 02:37:19.737377 | 
2025-09-30 02:37:19.737461 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-30 02:37:21.108075 | controller | ok
2025-09-30 02:37:21.141714 | 
2025-09-30 02:37:21.141805 | TASK [Prepare workspace]
2025-09-30 02:37:21.211786 | controller | ok
2025-09-30 02:37:21.323713 | 
2025-09-30 02:37:21.323813 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-30 02:37:22.293679 | controller | ok
2025-09-30 02:37:22.310394 | 
2025-09-30 02:37:22.310476 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-30 02:37:30.413896 | controller | Output suppressed because no_log was given
2025-09-30 02:37:30.458268 | 
2025-09-30 02:37:30.458364 | LOOP [Create zuul-output directory]
2025-09-30 02:37:30.780898 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-09-30 02:37:30.964027 | controller | ok: "/home/zuul/zuul-output/logs"
2025-09-30 02:37:30.978661 | 
2025-09-30 02:37:30.978771 | TASK [Install required packages]
2025-09-30 02:38:33.687960 | controller | changed
2025-09-30 02:38:33.694037 | 
2025-09-30 02:38:33.694121 | TASK [Install venv]
2025-09-30 02:39:39.292564 | controller | changed
2025-09-30 02:39:39.320627 | 
2025-09-30 02:39:39.320730 | PLAY RECAP
2025-09-30 02:39:39.320780 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 02:39:39.320805 | 
2025-09-30 02:39:39.407443 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-30 02:39:39.408294 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-30 02:39:39.930298 | 
2025-09-30 02:39:39.930405 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-09-30 02:39:39.950531 | 
2025-09-30 02:39:39.950603 | TASK [Gather required facts]
2025-09-30 02:39:40.455840 | controller | ok
2025-09-30 02:39:40.461074 | 
2025-09-30 02:39:40.461166 | TASK [Load environment var if instructed to]
2025-09-30 02:39:40.485127 | controller | skipping: Conditional result was False
2025-09-30 02:39:40.490684 | 
2025-09-30 02:39:40.490756 | TASK [Run molecule]
2025-09-30 02:39:41.430947 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-09-30 02:39:41.508754 | controller | INFO     Running default > converge
2025-09-30 02:39:42.178780 | controller |
2025-09-30 02:39:42.178872 | controller | PLAY [Converge] ****************************************************************
2025-09-30 02:39:42.178971 | controller |
2025-09-30 02:39:42.179468 | controller | TASK [Gathering Facts] *********************************************************
2025-09-30 02:39:42.179585 | controller | Tuesday 30 September 2025  02:39:42 +0000 (0:00:00.010)       0:00:00.010 *****
2025-09-30 02:39:43.017508 | controller | ok: [instance]
2025-09-30 02:39:43.017579 | controller |
2025-09-30 02:39:43.017686 | controller | TASK [Deploy Local Registry] ***************************************************
2025-09-30 02:39:43.017789 | controller | Tuesday 30 September 2025  02:39:43 +0000 (0:00:00.839)       0:00:00.849 *****
2025-09-30 02:39:43.046144 | controller |
2025-09-30 02:39:43.046265 | controller | TASK [Install Podman package] **************************************************
2025-09-30 02:39:43.046370 | controller | Tuesday 30 September 2025  02:39:43 +0000 (0:00:00.028)       0:00:00.878 *****
2025-09-30 02:39:43.071487 | controller |
2025-09-30 02:39:43.071598 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-09-30 02:39:43.071723 | controller | Tuesday 30 September 2025  02:39:43 +0000 (0:00:00.025)       0:00:00.903 *****
2025-09-30 02:39:43.856806 | controller | ok: [instance]
2025-09-30 02:39:43.856878 | controller |
2025-09-30 02:39:43.856992 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-09-30 02:39:43.857125 | controller | Tuesday 30 September 2025  02:39:43 +0000 (0:00:00.785)       0:00:01.688 *****
2025-09-30 02:39:44.196685 | controller | changed: [instance]
2025-09-30 02:39:44.196753 | controller |
2025-09-30 02:39:44.196876 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-09-30 02:39:44.196979 | controller | Tuesday 30 September 2025  02:39:44 +0000 (0:00:00.340)       0:00:02.028 *****
2025-09-30 02:39:44.220149 | controller | skipping: [instance]
2025-09-30 02:39:44.220236 | controller |
2025-09-30 02:39:44.220343 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-09-30 02:39:44.220454 | controller | Tuesday 30 September 2025  02:39:44 +0000 (0:00:00.023)       0:00:02.052 *****
2025-09-30 02:39:44.238920 | controller | skipping: [instance]
2025-09-30 02:39:44.239028 | controller |
2025-09-30 02:39:44.239242 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-09-30 02:39:44.239377 | controller | Tuesday 30 September 2025  02:39:44 +0000 (0:00:00.018)       0:00:02.071 *****
2025-09-30 02:39:44.262600 | controller | skipping: [instance]
2025-09-30 02:39:44.262717 | controller |
2025-09-30 02:39:44.262851 | controller | TASK [registry_deploy : Deploy the local registry from docker.io/library/registry:2] ***
2025-09-30 02:39:44.262977 | controller | Tuesday 30 September 2025  02:39:44 +0000 (0:00:00.023)       0:00:02.094 *****
2025-09-30 02:39:48.163733 | controller | changed: [instance]
2025-09-30 02:39:48.163812 | controller |
2025-09-30 02:39:48.163928 | controller | TASK [registry_deploy : Open port for local registry] **************************
2025-09-30 02:39:48.164036 | controller | Tuesday 30 September 2025  02:39:48 +0000 (0:00:03.900)       0:00:05.995 *****
2025-09-30 02:39:48.770488 | controller | changed: [instance] => (item=nft add table ip filter)
2025-09-30 02:39:48.770557 | controller | changed: [instance] => (item=nft add chain ip filter INPUT { type filter hook input priority 0 \; })
2025-09-30 02:39:48.770669 | controller | changed: [instance] => (item=nft insert rule ip filter INPUT tcp dport 5001 counter accept)
2025-09-30 02:39:48.770771 | controller |
2025-09-30 02:39:48.770873 | controller | TASK [registry_deploy : Ensure registries.conf.d exists] ***********************
2025-09-30 02:39:48.770973 | controller | Tuesday 30 September 2025  02:39:48 +0000 (0:00:00.606)       0:00:06.602 *****
2025-09-30 02:39:49.078367 | controller | ok: [instance]
2025-09-30 02:39:49.078414 | controller |
2025-09-30 02:39:49.078513 | controller | TASK [registry_deploy : Add the local registry to unqualified-search-registries] ***
2025-09-30 02:39:49.078620 | controller | Tuesday 30 September 2025  02:39:49 +0000 (0:00:00.307)       0:00:06.910 *****
2025-09-30 02:39:49.366021 | controller | changed: [instance]
2025-09-30 02:39:49.366166 | controller |
2025-09-30 02:39:49.366381 | controller | TASK [Run cifmw_build_push_container multi-arch] *******************************
2025-09-30 02:39:49.401645 | controller | Tuesday 30 September 2025  02:39:49 +0000 (0:00:00.287)       0:00:07.197 *****
2025-09-30 02:39:49.401671 | controller |
2025-09-30 02:39:49.765230 | controller | TASK [build_push_container : Ensure directories are present] *******************
2025-09-30 02:39:49.765259 | controller | Tuesday 30 September 2025  02:39:49 +0000 (0:00:00.035)       0:00:07.233 *****
2025-09-30 02:39:49.765272 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/artifacts/build_push_container/scripts)
2025-09-30 02:39:50.424803 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/artifacts/build_push_container/logs)
2025-09-30 02:39:50.424833 | controller |
2025-09-30 02:39:50.424841 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-09-30 02:39:50.424847 | controller | Tuesday 30 September 2025  02:39:49 +0000 (0:00:00.362)       0:00:07.596 *****
2025-09-30 02:39:50.424857 | controller | ok: [instance]
2025-09-30 02:39:50.633623 | controller |
2025-09-30 02:39:50.633654 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-09-30 02:39:50.633662 | controller | Tuesday 30 September 2025  02:39:50 +0000 (0:00:00.659)       0:00:08.256 *****
2025-09-30 02:39:50.633674 | controller | changed: [instance]
2025-09-30 02:39:50.656632 | controller |
2025-09-30 02:39:50.656658 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-09-30 02:39:50.656666 | controller | Tuesday 30 September 2025  02:39:50 +0000 (0:00:00.208)       0:00:08.465 *****
2025-09-30 02:39:50.656676 | controller | skipping: [instance]
2025-09-30 02:39:50.676780 | controller |
2025-09-30 02:39:50.676804 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-09-30 02:39:50.676812 | controller | Tuesday 30 September 2025  02:39:50 +0000 (0:00:00.023)       0:00:08.488 *****
2025-09-30 02:39:50.676822 | controller | skipping: [instance]
2025-09-30 02:39:50.703092 | controller |
2025-09-30 02:39:50.703128 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-09-30 02:39:50.703135 | controller | Tuesday 30 September 2025  02:39:50 +0000 (0:00:00.020)       0:00:08.508 *****
2025-09-30 02:39:50.703145 | controller | skipping: [instance]
2025-09-30 02:39:57.138679 | controller |
2025-09-30 02:39:57.138710 | controller | TASK [build_push_container : Install qemu-user-static for multi arch builds] ***
2025-09-30 02:39:57.138718 | controller | Tuesday 30 September 2025  02:39:50 +0000 (0:00:00.026)       0:00:08.534 *****
2025-09-30 02:39:57.138731 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_000_install_qemu_user_static_for.log
2025-09-30 02:39:57.380175 | controller | changed: [instance]
2025-09-30 02:39:57.380206 | controller |
2025-09-30 02:39:57.380215 | controller | TASK [build_push_container : Ensure manifest doesn't exist] ********************
2025-09-30 02:39:57.380222 | controller | Tuesday 30 September 2025  02:39:57 +0000 (0:00:06.435)       0:00:14.970 *****
2025-09-30 02:39:57.380232 | controller | ok: [instance]
2025-09-30 02:39:57.380257 | controller |
2025-09-30 02:39:57.380506 | controller | TASK [build_push_container : Create manifest] **********************************
2025-09-30 02:39:57.609895 | controller | Tuesday 30 September 2025  02:39:57 +0000 (0:00:00.241)       0:00:15.211 *****
2025-09-30 02:39:57.609939 | controller | changed: [instance]
2025-09-30 02:40:04.977943 | controller |
2025-09-30 02:40:04.977976 | controller | TASK [build_push_container : Build container] **********************************
2025-09-30 02:40:04.977985 | controller | Tuesday 30 September 2025  02:39:57 +0000 (0:00:00.229)       0:00:15.441 *****
2025-09-30 02:40:04.977995 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_001_build.log
2025-09-30 02:40:06.732417 | controller | changed: [instance]
2025-09-30 02:40:06.732457 | controller |
2025-09-30 02:40:06.732465 | controller | TASK [build_push_container : Push manifest] ************************************
2025-09-30 02:40:06.732472 | controller | Tuesday 30 September 2025  02:40:04 +0000 (0:00:07.367)       0:00:22.808 *****
2025-09-30 02:40:06.732482 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_002_push.log
2025-09-30 02:40:06.771212 | controller | changed: [instance] => (item=c4ee373c848aa16d1f0767117f61426f17f2a9f3)
2025-09-30 02:40:06.771245 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_003_push.log
2025-09-30 02:40:06.771253 | controller | changed: [instance] => (item=123-latest)
2025-09-30 02:40:06.771259 | controller |
2025-09-30 02:40:06.771265 | controller | TASK [build_push_container : Push container] ***********************************
2025-09-30 02:40:06.771270 | controller | Tuesday 30 September 2025  02:40:06 +0000 (0:00:01.754)       0:00:24.563 *****
2025-09-30 02:40:06.771281 | controller | skipping: [instance] => (item=c4ee373c848aa16d1f0767117f61426f17f2a9f3)
2025-09-30 02:40:07.206083 | controller | skipping: [instance] => (item=123-latest)
2025-09-30 02:40:07.206144 | controller | skipping: [instance]
2025-09-30 02:40:07.206152 | controller |
2025-09-30 02:40:07.206159 | controller | TASK [Request tags from local registry] ****************************************
2025-09-30 02:40:07.206165 | controller | Tuesday 30 September 2025  02:40:06 +0000 (0:00:00.038)       0:00:24.602 *****
2025-09-30 02:40:07.206174 | controller | ok: [instance]
2025-09-30 02:40:07.236187 | controller |
2025-09-30 02:40:07.236213 | controller | TASK [Check all tags exist] ****************************************************
2025-09-30 02:40:07.236223 | controller | Tuesday 30 September 2025  02:40:07 +0000 (0:00:00.435)       0:00:25.037 *****
2025-09-30 02:40:07.236235 | controller | ok: [instance] => (item=c4ee373c848aa16d1f0767117f61426f17f2a9f3) => changed=false
2025-09-30 02:40:07.236261 | controller |   ansible_loop_var: item
2025-09-30 02:40:07.236270 | controller |   item: c4ee373c848aa16d1f0767117f61426f17f2a9f3
2025-09-30 02:40:07.236277 | controller |   msg: All assertions passed
2025-09-30 02:40:07.236284 | controller | ok: [instance] => (item=123-latest) => changed=false
2025-09-30 02:40:07.236290 | controller |   ansible_loop_var: item
2025-09-30 02:40:07.236297 | controller |   item: 123-latest
2025-09-30 02:40:07.236303 | controller |   msg: All assertions passed
2025-09-30 02:40:07.236310 | controller |
2025-09-30 02:40:07.236319 | controller | TASK [Request manifest from local registry] ************************************
2025-09-30 02:40:07.236352 | controller | Tuesday 30 September 2025  02:40:07 +0000 (0:00:00.029)       0:00:25.067 *****
2025-09-30 02:40:07.541869 | controller | ok: [instance]
2025-09-30 02:40:07.583211 | controller |
2025-09-30 02:40:07.583247 | controller | TASK [Check manifest for multi-arch image] *************************************
2025-09-30 02:40:07.583255 | controller | Tuesday 30 September 2025  02:40:07 +0000 (0:00:00.306)       0:00:25.373 *****
2025-09-30 02:40:07.583265 | controller | ok: [instance] => changed=false
2025-09-30 02:40:07.583289 | controller |   msg: All assertions passed
2025-09-30 02:40:07.583297 | controller |
2025-09-30 02:40:07.583318 | controller | TASK [Run cifmw_build_push_container single-arch] ******************************
2025-09-30 02:40:07.583473 | controller | Tuesday 30 September 2025  02:40:07 +0000 (0:00:00.041)       0:00:25.414 *****
2025-09-30 02:40:07.616250 | controller |
2025-09-30 02:40:07.616298 | controller | TASK [build_push_container : Ensure directories are present] *******************
2025-09-30 02:40:07.616428 | controller | Tuesday 30 September 2025  02:40:07 +0000 (0:00:00.033)       0:00:25.448 *****
2025-09-30 02:40:07.974679 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/artifacts/build_push_container/scripts)
2025-09-30 02:40:08.638042 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/artifacts/build_push_container/logs)
2025-09-30 02:40:08.638073 | controller |
2025-09-30 02:40:08.638081 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-09-30 02:40:08.638088 | controller | Tuesday 30 September 2025  02:40:07 +0000 (0:00:00.357)       0:00:25.805 *****
2025-09-30 02:40:08.638140 | controller | ok: [instance]
2025-09-30 02:40:08.844202 | controller |
2025-09-30 02:40:08.844232 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-09-30 02:40:08.844240 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.663)       0:00:26.469 *****
2025-09-30 02:40:08.844250 | controller | changed: [instance]
2025-09-30 02:40:08.865805 | controller |
2025-09-30 02:40:08.865831 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-09-30 02:40:08.865839 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.206)       0:00:26.675 *****
2025-09-30 02:40:08.865862 | controller | skipping: [instance]
2025-09-30 02:40:08.883881 | controller |
2025-09-30 02:40:08.883917 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-09-30 02:40:08.883926 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.021)       0:00:26.697 *****
2025-09-30 02:40:08.883937 | controller | skipping: [instance]
2025-09-30 02:40:08.905824 | controller |
2025-09-30 02:40:08.905845 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-09-30 02:40:08.905852 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.017)       0:00:26.715 *****
2025-09-30 02:40:08.905861 | controller | skipping: [instance]
2025-09-30 02:40:08.923376 | controller |
2025-09-30 02:40:08.923396 | controller | TASK [build_push_container : Install qemu-user-static for multi arch builds] ***
2025-09-30 02:40:08.923403 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.021)       0:00:26.737 *****
2025-09-30 02:40:08.923412 | controller | skipping: [instance]
2025-09-30 02:40:08.941174 | controller |
2025-09-30 02:40:08.941197 | controller | TASK [build_push_container : Ensure manifest doesn't exist] ********************
2025-09-30 02:40:08.941206 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.017)       0:00:26.754 *****
2025-09-30 02:40:08.941217 | controller | skipping: [instance]
2025-09-30 02:40:08.959070 | controller |
2025-09-30 02:40:08.959091 | controller | TASK [build_push_container : Create manifest] **********************************
2025-09-30 02:40:08.959146 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.017)       0:00:26.772 *****
2025-09-30 02:40:08.959158 | controller | skipping: [instance]
2025-09-30 02:40:10.354150 | controller |
2025-09-30 02:40:10.354185 | controller | TASK [build_push_container : Build container] **********************************
2025-09-30 02:40:10.354193 | controller | Tuesday 30 September 2025  02:40:08 +0000 (0:00:00.017)       0:00:26.790 *****
2025-09-30 02:40:10.354205 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_004_build.log
2025-09-30 02:40:10.387116 | controller | changed: [instance]
2025-09-30 02:40:10.387156 | controller |
2025-09-30 02:40:10.387168 | controller | TASK [build_push_container : Push manifest] ************************************
2025-09-30 02:40:10.387175 | controller | Tuesday 30 September 2025  02:40:10 +0000 (0:00:01.394)       0:00:28.185 *****
2025-09-30 02:40:10.387184 | controller | skipping: [instance] => (item=c4ee373c848aa16d1f0767117f61426f17f2a9f3)
2025-09-30 02:40:10.664949 | controller | skipping: [instance] => (item=123-latest)
2025-09-30 02:40:10.664980 | controller | skipping: [instance]
2025-09-30 02:40:10.664989 | controller |
2025-09-30 02:40:10.664995 | controller | TASK [build_push_container : Push container] ***********************************
2025-09-30 02:40:10.665001 | controller | Tuesday 30 September 2025  02:40:10 +0000 (0:00:00.033)       0:00:28.218 *****
2025-09-30 02:40:10.665011 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_005_push.log
2025-09-30 02:40:10.973622 | controller | changed: [instance] => (item=c4ee373c848aa16d1f0767117f61426f17f2a9f3)
2025-09-30 02:40:10.973652 | controller | Follow script's output here: /home/zuul/ci-framework-data/artifacts/build_push_container/logs/ci_script_006_push.log
2025-09-30 02:40:10.973659 | controller | changed: [instance] => (item=123-latest)
2025-09-30 02:40:10.973666 | controller |
2025-09-30 02:40:10.973672 | controller | TASK [Request tags from local registry] ****************************************
2025-09-30 02:40:10.973677 | controller | Tuesday 30 September 2025  02:40:10 +0000 (0:00:00.277)       0:00:28.496 *****
2025-09-30 02:40:10.973687 | controller | ok: [instance]
2025-09-30 02:40:11.002195 | controller |
2025-09-30 02:40:11.002227 | controller | TASK [Check all tags exist] ****************************************************
2025-09-30 02:40:11.002235 | controller | Tuesday 30 September 2025  02:40:10 +0000 (0:00:00.308)       0:00:28.805 *****
2025-09-30 02:40:11.002246 | controller | ok: [instance] => (item=c4ee373c848aa16d1f0767117f61426f17f2a9f3) => changed=false
2025-09-30 02:40:11.002270 | controller |   ansible_loop_var: item
2025-09-30 02:40:11.002277 | controller |   item: c4ee373c848aa16d1f0767117f61426f17f2a9f3
2025-09-30 02:40:11.002283 | controller |   msg: All assertions passed
2025-09-30 02:40:11.002295 | controller | ok: [instance] => (item=123-latest) => changed=false
2025-09-30 02:40:11.002303 | controller |   ansible_loop_var: item
2025-09-30 02:40:11.002755 | controller |   item: 123-latest
2025-09-30 02:40:11.024647 | controller |   msg: All assertions passed
2025-09-30 02:40:11.024673 | controller |
2025-09-30 02:40:11.024683 | controller | TASK [Call cleanup] ************************************************************
2025-09-30 02:40:11.024690 | controller | Tuesday 30 September 2025  02:40:11 +0000 (0:00:00.028)       0:00:28.833 *****
2025-09-30 02:40:11.024702 | controller |
2025-09-30 02:40:11.399551 | controller | TASK [build_push_container : Stop and remove registry container] ***************
2025-09-30 02:40:11.399583 | controller | Tuesday 30 September 2025  02:40:11 +0000 (0:00:00.022)       0:00:28.856 *****
2025-09-30 02:40:11.399595 | controller | changed: [instance]
2025-09-30 02:40:11.634976 | controller |
2025-09-30 02:40:11.635006 | controller | TASK [build_push_container : List images created and used by role] *************
2025-09-30 02:40:11.635014 | controller | Tuesday 30 September 2025  02:40:11 +0000 (0:00:00.374)       0:00:29.230 *****
2025-09-30 02:40:11.635024 | controller | changed: [instance]
2025-09-30 02:40:11.667966 | controller |
2025-09-30 02:40:11.667993 | controller | TASK [build_push_container : Remove images created and used by role] ***********
2025-09-30 02:40:11.668001 | controller | Tuesday 30 September 2025  02:40:11 +0000 (0:00:00.235)       0:00:29.466 *****
2025-09-30 02:40:11.668015 | controller | skipping: [instance]
2025-09-30 02:40:11.716192 | controller |
2025-09-30 02:40:11.716225 | controller | PLAY RECAP *********************************************************************
2025-09-30 02:40:11.716233 | controller | instance                   : ok=28   changed=16   unreachable=0    failed=0    skipped=15   rescued=0    ignored=0
2025-09-30 02:40:11.716239 | controller |
2025-09-30 02:40:11.716245 | controller | Tuesday 30 September 2025  02:40:11 +0000 (0:00:00.030)       0:00:29.497 *****
2025-09-30 02:40:11.716256 | controller | ===============================================================================
2025-09-30 02:40:11.716261 | controller | build_push_container : Build container ---------------------------------- 7.37s
2025-09-30 02:40:11.716267 | controller | build_push_container : Install qemu-user-static for multi arch builds --- 6.44s
2025-09-30 02:40:11.716272 | controller | registry_deploy : Deploy the local registry from docker.io/library/registry:2 --- 3.90s
2025-09-30 02:40:11.716278 | controller | build_push_container : Push manifest ------------------------------------ 1.75s
2025-09-30 02:40:11.716283 | controller | build_push_container : Build container ---------------------------------- 1.39s
2025-09-30 02:40:11.716289 | controller | Gathering Facts --------------------------------------------------------- 0.84s
2025-09-30 02:40:11.716294 | controller | podman : Ensure podman is installed ------------------------------------- 0.79s
2025-09-30 02:40:11.716299 | controller | podman : Ensure podman is installed ------------------------------------- 0.66s
2025-09-30 02:40:11.716304 | controller | podman : Ensure podman is installed ------------------------------------- 0.66s
2025-09-30 02:40:11.716310 | controller | registry_deploy : Open port for local registry -------------------------- 0.61s
2025-09-30 02:40:11.716315 | controller | Request tags from local registry ---------------------------------------- 0.44s
2025-09-30 02:40:11.716320 | controller | build_push_container : Stop and remove registry container --------------- 0.37s
2025-09-30 02:40:11.716326 | controller | build_push_container : Ensure directories are present ------------------- 0.36s
2025-09-30 02:40:11.716331 | controller | build_push_container : Ensure directories are present ------------------- 0.36s
2025-09-30 02:40:11.716336 | controller | podman : Enable loginctl linger for ansible_user_id --------------------- 0.34s
2025-09-30 02:40:11.716341 | controller | Request tags from local registry ---------------------------------------- 0.31s
2025-09-30 02:40:11.716347 | controller | registry_deploy : Ensure registries.conf.d exists ----------------------- 0.31s
2025-09-30 02:40:11.716352 | controller | Request manifest from local registry ------------------------------------ 0.31s
2025-09-30 02:40:11.716357 | controller | registry_deploy : Add the local registry to unqualified-search-registries --- 0.29s
2025-09-30 02:40:11.716362 | controller | build_push_container : Push container ----------------------------------- 0.28s
2025-09-30 02:40:11.716379 | controller | INFO     Writing /tmp/report.html report.
2025-09-30 02:40:12.053271 | controller | changed
2025-09-30 02:40:12.072542 | 
2025-09-30 02:40:12.072625 | PLAY RECAP
2025-09-30 02:40:12.072668 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 02:40:12.072707 | 
2025-09-30 02:40:12.143836 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-30 02:40:12.144671 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-30 02:40:12.685240 | 
2025-09-30 02:40:12.685338 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-09-30 02:40:12.705707 | 
2025-09-30 02:40:12.705785 | TASK [Filter out host if needed]
2025-09-30 02:40:12.714442 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-09-30 02:40:12.719040 | 
2025-09-30 02:40:12.719109 | TASK [Ensure file is present]
2025-09-30 02:40:13.033615 | controller | ok
2025-09-30 02:40:13.040573 | 
2025-09-30 02:40:13.040663 | TASK [Manage molecule report file]
2025-09-30 02:40:13.567534 | controller | changed
2025-09-30 02:40:13.573302 | 
2025-09-30 02:40:13.573373 | TASK [Check if we get ci-framework-data basedir]
2025-09-30 02:40:13.754030 | controller | ok
2025-09-30 02:40:13.759361 | 
2025-09-30 02:40:13.759425 | TASK [Create ci-framework-data log directory for zuul]
2025-09-30 02:40:14.070654 | controller | changed
2025-09-30 02:40:14.075987 | 
2025-09-30 02:40:14.076064 | TASK [Copy ci-framework interesting files]
2025-09-30 02:40:14.269998 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-09-30 02:40:14.601846 | controller | changed
2025-09-30 02:40:14.607435 | 
2025-09-30 02:40:14.607506 | TASK [Get SELinux listing]
2025-09-30 02:40:15.133708 | controller | changed
2025-09-30 02:40:15.140423 | 
2025-09-30 02:40:15.140492 | TASK [Generate log index]
2025-09-30 02:40:15.771184 | controller | changed
2025-09-30 02:40:15.776280 | 
2025-09-30 02:40:15.776351 | TASK [Get some env related data]
2025-09-30 02:40:16.310801 | controller | /home/zuul/.local/bin/ansible
2025-09-30 02:40:17.303391 | controller | changed
2025-09-30 02:40:17.308830 | 
2025-09-30 02:40:17.308932 | TASK [Generate list of logs to collect in home directory]
2025-09-30 02:40:17.663142 | controller | ok: All paths examined
2025-09-30 02:40:17.677328 | 
2025-09-30 02:40:17.677411 | LOOP [Copy logs from home directory]
2025-09-30 02:40:18.025013 | controller | changed:
2025-09-30 02:40:18.025170 | controller | {
2025-09-30 02:40:18.025201 | controller |   "atime": 1759199962.580478,
2025-09-30 02:40:18.025223 | controller |   "ctime": 1759199978.860656,
2025-09-30 02:40:18.025241 | controller |   "dev": 64513,
2025-09-30 02:40:18.025258 | controller |   "gid": 1000,
2025-09-30 02:40:18.025274 | controller |   "gr_name": "zuul",
2025-09-30 02:40:18.025292 | controller |   "inode": 4412658,
2025-09-30 02:40:18.025309 | controller |   "isblk": false,
2025-09-30 02:40:18.025324 | controller |   "ischr": false,
2025-09-30 02:40:18.025342 | controller |   "isdir": false,
2025-09-30 02:40:18.025359 | controller |   "isfifo": false,
2025-09-30 02:40:18.025375 | controller |   "isgid": false,
2025-09-30 02:40:18.025390 | controller |   "islnk": false,
2025-09-30 02:40:18.025405 | controller |   "isreg": true,
2025-09-30 02:40:18.025420 | controller |   "issock": false,
2025-09-30 02:40:18.025441 | controller |   "isuid": false,
2025-09-30 02:40:18.025457 | controller |   "mode": "0644",
2025-09-30 02:40:18.025472 | controller |   "mtime": 1759199978.860656,
2025-09-30 02:40:18.025487 | controller |   "nlink": 1,
2025-09-30 02:40:18.025502 | controller |   "path": "/home/zuul/ansible.log",
2025-09-30 02:40:18.025519 | controller |   "pw_name": "zuul",
2025-09-30 02:40:18.025534 | controller |   "rgrp": true,
2025-09-30 02:40:18.025549 | controller |   "roth": true,
2025-09-30 02:40:18.025565 | controller |   "rusr": true,
2025-09-30 02:40:18.025580 | controller |   "size": 6749,
2025-09-30 02:40:18.025594 | controller |   "uid": 1000,
2025-09-30 02:40:18.025608 | controller |   "wgrp": false,
2025-09-30 02:40:18.025623 | controller |   "woth": false,
2025-09-30 02:40:18.025640 | controller |   "wusr": true,
2025-09-30 02:40:18.025655 | controller |   "xgrp": false,
2025-09-30 02:40:18.025670 | controller |   "xoth": false,
2025-09-30 02:40:18.025721 | controller |   "xusr": false
2025-09-30 02:40:18.025739 | controller | }
2025-09-30 02:40:18.038541 | 
2025-09-30 02:40:18.038648 | TASK [Copy crio stats log file]
2025-09-30 02:40:18.063158 | controller | skipping: Conditional result was False
2025-09-30 02:40:18.069345 | 
2025-09-30 02:40:18.069415 | TASK [Get SELinux related data]
2025-09-30 02:40:18.273218 | controller | <no matches>
2025-09-30 02:40:18.600170 | controller | ERROR
2025-09-30 02:40:18.600299 | controller | {
2025-09-30 02:40:18.600330 | controller |   "delta": "0:00:00.008527",
2025-09-30 02:40:18.600354 | controller |   "end": "2025-09-30 02:40:18.274082",
2025-09-30 02:40:18.600373 | controller |   "msg": "non-zero return code",
2025-09-30 02:40:18.600391 | controller |   "rc": 1,
2025-09-30 02:40:18.600409 | controller |   "start": "2025-09-30 02:40:18.265555"
2025-09-30 02:40:18.600427 | controller | }
2025-09-30 02:40:18.600449 | controller | ERROR: Ignoring Errors
2025-09-30 02:40:18.606063 | 
2025-09-30 02:40:18.606130 | TASK [Create system configuration directory]
2025-09-30 02:40:18.792513 | controller | changed
2025-09-30 02:40:18.799365 | 
2025-09-30 02:40:18.799433 | TASK [Get some of the system configurations]
2025-09-30 02:40:19.330128 | controller | changed
2025-09-30 02:40:19.335447 | 
2025-09-30 02:40:19.335531 | TASK [Copy generated documentation if available]
2025-09-30 02:40:19.349594 | controller | skipping: Conditional result was False
2025-09-30 02:40:19.355536 | 
2025-09-30 02:40:19.355614 | TASK [Copy generated AsciiDoc documentation if available]
2025-09-30 02:40:19.369277 | controller | skipping: Conditional result was False
2025-09-30 02:40:19.375952 | 
2025-09-30 02:40:19.376032 | TASK [Compress logs bigger than 2MB]
2025-09-30 02:40:19.904733 | controller | changed
2025-09-30 02:40:19.910996 | 
2025-09-30 02:40:19.911066 | TASK [Copy files from workspace on node]
2025-09-30 02:40:19.929669 | controller | ok
2025-09-30 02:40:19.953471 | 
2025-09-30 02:40:19.953555 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 02:40:19.967837 | controller | skipping: Conditional result was False
2025-09-30 02:40:19.974574 | 
2025-09-30 02:40:19.974656 | TASK [fetch-output : Set log path for single node]
2025-09-30 02:40:20.035784 | controller | ok
2025-09-30 02:40:20.040531 | 
2025-09-30 02:40:20.040593 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 02:40:20.282289 | controller -> localhost | ok: "/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/logs"
2025-09-30 02:40:20.282532 | controller -> localhost | changed: All items complete
2025-09-30 02:40:20.282567 | 
2025-09-30 02:40:20.492554 | controller -> localhost | changed: "/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/artifacts"
2025-09-30 02:40:20.693623 | controller -> localhost | changed: "/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/docs"
2025-09-30 02:40:20.707794 | 
2025-09-30 02:40:20.708006 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 02:40:21.303301 | controller | changed:
2025-09-30 02:40:21.303601 | controller | .d..t...... ./
2025-09-30 02:40:21.303639 | controller | >f+++++++++ README.html
2025-09-30 02:40:21.303665 | controller | >f+++++++++ ansible-execution.log
2025-09-30 02:40:21.303705 | controller | >f+++++++++ ansible.log
2025-09-30 02:40:21.303726 | controller | >f+++++++++ dmesg.log
2025-09-30 02:40:21.303746 | controller | >f+++++++++ installed-pkgs.log
2025-09-30 02:40:21.303766 | controller | >f+++++++++ python.log
2025-09-30 02:40:21.303787 | controller | >f+++++++++ registries.conf
2025-09-30 02:40:21.303806 | controller | >f+++++++++ report.html
2025-09-30 02:40:21.303826 | controller | >f+++++++++ selinux-denials.log
2025-09-30 02:40:21.303844 | controller | >f+++++++++ selinux-listing.log
2025-09-30 02:40:21.303861 | controller | cd+++++++++ ci-framework-data/
2025-09-30 02:40:21.303878 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-09-30 02:40:21.303895 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-09-30 02:40:21.303933 | controller | cd+++++++++ ci-framework-data/artifacts/build_push_container/
2025-09-30 02:40:21.303957 | controller | cd+++++++++ ci-framework-data/artifacts/build_push_container/logs/
2025-09-30 02:40:21.303976 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_000_install_qemu_user_static_for.log
2025-09-30 02:40:21.303995 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_001_build.log
2025-09-30 02:40:21.304013 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_002_push.log
2025-09-30 02:40:21.304030 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_003_push.log
2025-09-30 02:40:21.304046 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_004_build.log
2025-09-30 02:40:21.304063 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_005_push.log
2025-09-30 02:40:21.304080 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/logs/ci_script_006_push.log
2025-09-30 02:40:21.304097 | controller | cd+++++++++ ci-framework-data/artifacts/build_push_container/scripts/
2025-09-30 02:40:21.304113 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_000_install_qemu_user_static_for.sh
2025-09-30 02:40:21.304130 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_001_build.sh
2025-09-30 02:40:21.304147 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_002_push.sh
2025-09-30 02:40:21.304163 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_003_push.sh
2025-09-30 02:40:21.304179 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_004_build.sh
2025-09-30 02:40:21.304195 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_005_push.sh
2025-09-30 02:40:21.304211 | controller | >f+++++++++ ci-framework-data/artifacts/build_push_container/scripts/ci_script_006_push.sh
2025-09-30 02:40:21.304227 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-09-30 02:40:21.304243 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-09-30 02:40:21.304260 | controller | cd+++++++++ ci-framework-data/logs/
2025-09-30 02:40:21.304275 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-09-30 02:40:21.304291 | controller | cd+++++++++ registries.conf.d/
2025-09-30 02:40:21.304307 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-09-30 02:40:21.304323 | controller | >f+++++++++ registries.conf.d/99-local-registry.conf
2025-09-30 02:40:21.304339 | controller | cd+++++++++ system-config/
2025-09-30 02:40:21.304355 | controller | cd+++++++++ system-config/libvirt/
2025-09-30 02:40:21.304371 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-09-30 02:40:21.304390 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-09-30 02:40:21.714360 | controller | changed: .d..t...... ./
2025-09-30 02:40:22.091491 | controller | changed: .d..t...... ./
2025-09-30 02:40:22.109227 | 
2025-09-30 02:40:22.109334 | TASK [Return artifact to Zuul]
2025-09-30 02:40:22.149427 | controller | ok
2025-09-30 02:40:22.177176 | 
2025-09-30 02:40:22.177255 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-09-30 02:40:22.177357 | 
2025-09-30 02:40:22.177385 | PLAY RECAP
2025-09-30 02:40:22.177423 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-09-30 02:40:22.177445 | 
2025-09-30 02:40:22.267424 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-30 02:40:22.268246 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 02:40:22.963567 | 
2025-09-30 02:40:22.963699 | PLAY [all]
2025-09-30 02:40:23.005349 | 
2025-09-30 02:40:23.005470 | TASK [include_role : fetch-output]
2025-09-30 02:40:23.044614 | controller | ok
2025-09-30 02:40:23.079340 | 
2025-09-30 02:40:23.079498 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 02:40:23.146360 | controller | skipping: Conditional result was False
2025-09-30 02:40:23.154302 | 
2025-09-30 02:40:23.154378 | TASK [fetch-output : Set log path for single node]
2025-09-30 02:40:23.202212 | controller | ok
2025-09-30 02:40:23.207447 | 
2025-09-30 02:40:23.207525 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 02:40:23.629390 | controller -> localhost | ok: "/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/logs"
2025-09-30 02:40:23.856850 | controller -> localhost | ok: "/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/artifacts"
2025-09-30 02:40:24.133979 | controller -> localhost | ok: "/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/docs"
2025-09-30 02:40:24.148033 | 
2025-09-30 02:40:24.148136 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 02:40:24.713534 | controller | ok
2025-09-30 02:40:24.713781 | controller | ok: All items complete
2025-09-30 02:40:24.713813 | 
2025-09-30 02:40:25.155156 | controller | ok
2025-09-30 02:40:25.615594 | controller | ok
2025-09-30 02:40:25.639235 | 
2025-09-30 02:40:25.639542 | TASK [include_role : fetch-output-openshift]
2025-09-30 02:40:25.676248 | controller | skipping: Conditional result was False
2025-09-30 02:40:25.682522 | 
2025-09-30 02:40:25.682601 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-30 02:40:26.257271 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006583
2025-09-30 02:40:26.594856 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014661
2025-09-30 02:40:26.635123 | 
2025-09-30 02:40:26.635200 | PLAY [all]
2025-09-30 02:40:26.650593 | 
2025-09-30 02:40:26.650665 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-09-30 02:40:27.057730 | controller | changed
2025-09-30 02:40:27.100839 | 
2025-09-30 02:40:27.100951 | PLAY RECAP
2025-09-30 02:40:27.101003 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 02:40:27.101944 | 
2025-09-30 02:40:27.270661 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 02:40:27.271573 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-09-30 02:40:27.938419 | 
2025-09-30 02:40:27.938524 | PLAY [localhost]
2025-09-30 02:40:27.976547 | 
2025-09-30 02:40:27.976630 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-30 02:40:28.321242 | localhost | changed
2025-09-30 02:40:28.325954 | 
2025-09-30 02:40:28.326058 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-30 02:40:28.354614 | localhost | ok
2025-09-30 02:40:28.362967 | 
2025-09-30 02:40:28.363058 | TASK [add-fileserver : Create SSH private key tempfile]
2025-09-30 02:40:28.687552 | localhost | changed
2025-09-30 02:40:28.695191 | 
2025-09-30 02:40:28.695335 | TASK [add-fileserver : Create SSH private key from secret]
2025-09-30 02:40:29.270487 | localhost | changed
2025-09-30 02:40:29.278030 | 
2025-09-30 02:40:29.278101 | TASK [add-fileserver : Add fileserver ssh key]
2025-09-30 02:40:29.619335 | localhost | Identity added: /var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/tmp/ansible.4vwwmois (/var/lib/zuul/builds/4b8149099a1040b1ada439394e1b080d/work/tmp/ansible.4vwwmois)
2025-09-30 02:40:29.619509 | localhost | ok: Runtime: 0:00:00.005804
2025-09-30 02:40:29.623834 | 
2025-09-30 02:40:29.623937 | TASK [add-fileserver : Remove SSH private key from disk]
2025-09-30 02:40:29.843766 | localhost | ok: Runtime: 0:00:00.004502
2025-09-30 02:40:29.848536 | 
2025-09-30 02:40:29.848613 | TASK [add-fileserver : Add fileserver to inventory]
2025-09-30 02:40:29.896635 | localhost | changed
2025-09-30 02:40:29.900683 | 
2025-09-30 02:40:29.900754 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-09-30 02:40:30.231613 | localhost | changed
2025-09-30 02:40:30.251474 | 
2025-09-30 02:40:30.251550 | PLAY [localhost]
2025-09-30 02:40:30.262761 | 
2025-09-30 02:40:30.262826 | TASK [Generate bulk log download script]
2025-09-30 02:40:30.280884 | localhost | ok
2025-09-30 02:40:30.295973 | 
2025-09-30 02:40:30.296066 | TASK [local-log-download : Check API endpoint is defined]
2025-09-30 02:40:30.324255 | localhost | ok: All assertions passed
2025-09-30 02:40:30.329841 | 
2025-09-30 02:40:30.329947 | TASK [local-log-download : Create download script]
2025-09-30 02:40:30.740452 | localhost -> localhost | changed
2025-09-30 02:40:30.749527 | 
2025-09-30 02:40:30.749618 | TASK [Register quick-download link]
2025-09-30 02:40:30.777250 | localhost | ok
2025-09-30 02:40:30.813723 | 
2025-09-30 02:40:30.813800 | PLAY [logserver.rdoproject.org]
2025-09-30 02:40:30.823904 | 
2025-09-30 02:40:30.824004 | TASK [Set zuul-log-path fact]
2025-09-30 02:40:30.839745 | logserver.rdoproject.org | ok
2025-09-30 02:40:30.851028 | 
2025-09-30 02:40:30.851108 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 02:40:30.877061 | logserver.rdoproject.org | ok
2025-09-30 02:40:30.882898 | 
2025-09-30 02:40:30.882992 | TASK [upload-logs : Create log directories]
2025-09-30 02:40:32.829876 | logserver.rdoproject.org | changed
2025-09-30 02:40:32.833127 | 
2025-09-30 02:40:32.833196 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-09-30 02:40:33.070856 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004522
2025-09-30 02:40:33.075353 | 
2025-09-30 02:40:33.075421 | TASK [upload-logs : Upload logs to log server]
2025-09-30 02:40:34.576098 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-09-30 02:40:34.579529 | 
2025-09-30 02:40:34.579596 | LOOP [upload-logs : Compress console log and json output]
2025-09-30 02:40:34.614692 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 02:40:34.622582 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 02:40:34.626598 | 
2025-09-30 02:40:34.626710 | LOOP [upload-logs : Upload compressed console log and json output]
2025-09-30 02:40:34.661076 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 02:40:34.661274 | 
2025-09-30 02:40:34.664367 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 02:40:34.673756 | 
2025-09-30 02:40:34.673868 | LOOP [upload-logs : Upload console log and json output]