2025-07-31 18:32:35.997303 | Job console starting 2025-07-31 18:32:36.008244 | Updating git repos 2025-07-31 18:32:36.031455 | Cloning repos into workspace 2025-07-31 18:32:36.084734 | Restoring repo states 2025-07-31 18:32:36.092814 | Merging changes 2025-07-31 18:32:36.092833 | Checking out repos 2025-07-31 18:32:36.137391 | Preparing playbooks 2025-07-31 18:32:36.768834 | Running Ansible setup 2025-07-31 18:32:42.440227 | PRE-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/pre.yaml@main] 2025-07-31 18:32:43.192531 | 2025-07-31 18:32:43.192730 | PLAY [Base pre] 2025-07-31 18:32:43.218776 | 2025-07-31 18:32:43.218991 | TASK [Setup log path fact] 2025-07-31 18:32:43.253564 | noble | ok 2025-07-31 18:32:43.273088 | 2025-07-31 18:32:43.273246 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-07-31 18:32:43.314584 | noble | ok 2025-07-31 18:32:43.327522 | 2025-07-31 18:32:43.327672 | TASK [emit-job-header : Print job information] 2025-07-31 18:32:43.379447 | # Job Information 2025-07-31 18:32:43.379680 | Ansible Version: 2.16.14 2025-07-31 18:32:43.379726 | Job: openstack-ironic-images-publish-osism-ipa-stable 2025-07-31 18:32:43.379767 | Pipeline: post 2025-07-31 18:32:43.379796 | Executor: 521e9411259a 2025-07-31 18:32:43.379822 | Triggered by: https://github.com/osism/openstack-ironic-images/commit/bd1c3f55c201fc9475189a1c23c97f8bec1c44b0 2025-07-31 18:32:43.379850 | Event ID: 5a8e22f8-6e3c-11f0-80eb-441a99d683a0 2025-07-31 18:32:43.397121 | 2025-07-31 18:32:43.397279 | LOOP [emit-job-header : Print node information] 2025-07-31 18:32:43.512895 | noble | ok: 2025-07-31 18:32:43.513166 | noble | # Node Information 2025-07-31 18:32:43.513212 | noble | Inventory Hostname: noble 2025-07-31 18:32:43.513248 | noble | Hostname: ubuntu 2025-07-31 18:32:43.513279 | noble | Username: zuul 2025-07-31 18:32:43.513309 | noble | Distro: Ubuntu 24.04 2025-07-31 18:32:43.513344 | noble | Provider: regiocloud-a 2025-07-31 18:32:43.513374 | noble | Region: 2025-07-31 18:32:43.513404 | noble | Label: ubuntu-noble-uefi 2025-07-31 18:32:43.513432 | noble | Product Name: OpenStack Nova 2025-07-31 18:32:43.513459 | noble | Interface IP: 2a13:1a81:8000:3124:f816:3eff:fe1f:9cd1 2025-07-31 18:32:43.538084 | 2025-07-31 18:32:43.538276 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-07-31 18:32:44.029454 | noble -> localhost | changed 2025-07-31 18:32:44.038022 | 2025-07-31 18:32:44.038159 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-07-31 18:32:45.081528 | noble -> localhost | changed 2025-07-31 18:32:45.096397 | 2025-07-31 18:32:45.096546 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-07-31 18:32:45.373882 | noble -> localhost | ok 2025-07-31 18:32:45.381734 | 2025-07-31 18:32:45.381893 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-07-31 18:32:45.411509 | noble | ok 2025-07-31 18:32:45.428009 | noble | included: /var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-07-31 18:32:45.436212 | 2025-07-31 18:32:45.436325 | TASK [add-build-sshkey : Create Temp SSH key] 2025-07-31 18:32:46.475147 | noble -> localhost | Generating public/private rsa key pair. 2025-07-31 18:32:46.475744 | noble -> localhost | Your identification has been saved in /var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/work/9c8613ae53894bc99a684b05f37e7b83_id_rsa 2025-07-31 18:32:46.475865 | noble -> localhost | Your public key has been saved in /var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/work/9c8613ae53894bc99a684b05f37e7b83_id_rsa.pub 2025-07-31 18:32:46.475944 | noble -> localhost | The key fingerprint is: 2025-07-31 18:32:46.476015 | noble -> localhost | SHA256:VyvzDvlHJfHpPtz/BHvReJ9xfIwUSXs1gC/ZvCJhbek zuul-build-sshkey 2025-07-31 18:32:46.476080 | noble -> localhost | The key's randomart image is: 2025-07-31 18:32:46.476141 | noble -> localhost | +---[RSA 3072]----+ 2025-07-31 18:32:46.476200 | noble -> localhost | | .o+o.| 2025-07-31 18:32:46.476302 | noble -> localhost | | . ooo| 2025-07-31 18:32:46.476408 | noble -> localhost | | . B ooo| 2025-07-31 18:32:46.476498 | noble -> localhost | | o B *.B+| 2025-07-31 18:32:46.476561 | noble -> localhost | | S B o *=B| 2025-07-31 18:32:46.476671 | noble -> localhost | | o E ..=B| 2025-07-31 18:32:46.476737 | noble -> localhost | | + o.+.=| 2025-07-31 18:32:46.476796 | noble -> localhost | | + .*.| 2025-07-31 18:32:46.476856 | noble -> localhost | | o. *| 2025-07-31 18:32:46.476914 | noble -> localhost | +----[SHA256]-----+ 2025-07-31 18:32:46.477060 | noble -> localhost | ok: Runtime: 0:00:00.532509 2025-07-31 18:32:46.493163 | 2025-07-31 18:32:46.493328 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-07-31 18:32:46.531111 | noble | ok 2025-07-31 18:32:46.544548 | noble | included: /var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/trusted/project_1/github.com/osism/openinfra-zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-07-31 18:32:46.553976 | 2025-07-31 18:32:46.554080 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-07-31 18:32:46.578212 | noble | skipping: Conditional result was False 2025-07-31 18:32:46.588071 | 2025-07-31 18:32:46.588191 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-07-31 18:32:47.224010 | noble | changed 2025-07-31 18:32:47.232671 | 2025-07-31 18:32:47.232800 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-07-31 18:32:47.554476 | noble | ok 2025-07-31 18:32:47.564374 | 2025-07-31 18:32:47.564548 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-07-31 18:32:48.336659 | noble | changed 2025-07-31 18:32:48.345876 | 2025-07-31 18:32:48.346011 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-07-31 18:32:49.125516 | noble | changed 2025-07-31 18:32:49.134595 | 2025-07-31 18:32:49.134745 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-07-31 18:32:49.159571 | noble | skipping: Conditional result was False 2025-07-31 18:32:49.168785 | 2025-07-31 18:32:49.168909 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-07-31 18:32:49.629831 | noble -> localhost | changed 2025-07-31 18:32:49.653585 | 2025-07-31 18:32:49.653727 | TASK [add-build-sshkey : Add back temp key] 2025-07-31 18:32:50.013130 | noble -> localhost | Identity added: /var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/work/9c8613ae53894bc99a684b05f37e7b83_id_rsa (zuul-build-sshkey) 2025-07-31 18:32:50.013772 | noble -> localhost | ok: Runtime: 0:00:00.019193 2025-07-31 18:32:50.027221 | 2025-07-31 18:32:50.027365 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-07-31 18:32:50.482159 | noble | ok 2025-07-31 18:32:50.491584 | 2025-07-31 18:32:50.491739 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-07-31 18:32:50.526175 | noble | skipping: Conditional result was False 2025-07-31 18:32:50.582929 | 2025-07-31 18:32:50.583055 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-07-31 18:32:51.018635 | noble | ok 2025-07-31 18:32:51.030093 | 2025-07-31 18:32:51.030210 | TASK [validate-host : Define zuul_info_dir fact] 2025-07-31 18:32:51.070659 | noble | ok 2025-07-31 18:32:51.078083 | 2025-07-31 18:32:51.078193 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-07-31 18:32:51.363994 | noble -> localhost | ok 2025-07-31 18:32:51.377806 | 2025-07-31 18:32:51.377949 | TASK [validate-host : Collect information about the host] 2025-07-31 18:32:52.789953 | noble | ok 2025-07-31 18:32:52.817966 | 2025-07-31 18:32:52.818155 | TASK [validate-host : Sanitize hostname] 2025-07-31 18:32:52.886777 | noble | ok 2025-07-31 18:32:52.895776 | 2025-07-31 18:32:52.895931 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-07-31 18:32:53.473457 | noble -> localhost | changed 2025-07-31 18:32:53.483786 | 2025-07-31 18:32:53.483937 | TASK [validate-host : Collect information about zuul worker] 2025-07-31 18:32:53.946554 | noble | ok 2025-07-31 18:32:53.954785 | 2025-07-31 18:32:53.954943 | TASK [validate-host : Write out all zuul information for each host] 2025-07-31 18:32:54.499042 | noble -> localhost | changed 2025-07-31 18:32:54.510178 | 2025-07-31 18:32:54.510296 | TASK [prepare-workspace-log : Start zuul_console daemon.] 2025-07-31 18:32:54.801748 | noble | ok 2025-07-31 18:32:54.808030 | 2025-07-31 18:32:54.808137 | TASK [prepare-workspace-log : Synchronize src repos to workspace directory.] 2025-07-31 18:32:55.757901 | noble | changed: 2025-07-31 18:32:55.758170 | noble | cd+++++++++ src/ 2025-07-31 18:32:55.758220 | noble | cd+++++++++ src/github.com/ 2025-07-31 18:32:55.758257 | noble | cd+++++++++ src/github.com/osism/ 2025-07-31 18:32:55.758290 | noble | cd+++++++++ src/github.com/osism/openstack-ironic-images/ 2025-07-31 18:32:55.758319 | noble | 2025-07-31 18:36:23.481800 | noble | sys.exit(main()) 2025-07-31 18:36:23.481826 | noble | ^^^^^^ 2025-07-31 18:36:23.481832 | noble | File "/tmp/venv/lib/python3.12/site-packages/diskimage_builder/diskimage_builder.py", line 572, in main 2025-07-31 18:36:23.481837 | noble | raise subprocess.CalledProcessError( 2025-07-31 18:36:23.481853 | noble | subprocess.CalledProcessError: Command '['bash', '/tmp/venv/lib/python3.12/site-packages/diskimage_builder/lib/disk-image-create', '-o', 'osism-ipa-stable', '-a', 'amd64', '--logfile', '/home/zuul/zuul-output/logs/osism-ipa-stable.log', '--checksum', '--image-size', '5', 'ubuntu', 'ironic-python-agent-ramdisk', 'burn-in', 'openssh-server', 'devuser', 'osism-ipa']' returned non-zero exit status 1. 2025-07-31 18:36:23.933570 | noble | ERROR 2025-07-31 18:36:23.934003 | noble | { 2025-07-31 18:36:23.934103 | noble | "delta": "0:02:39.408467", 2025-07-31 18:36:23.934172 | noble | "end": "2025-07-31 18:36:23.527864", 2025-07-31 18:36:23.934231 | noble | "msg": "non-zero return code", 2025-07-31 18:36:23.934294 | noble | "rc": 1, 2025-07-31 18:36:23.934386 | noble | "start": "2025-07-31 18:33:44.119397" 2025-07-31 18:36:23.934478 | noble | } failure 2025-07-31 18:36:23.939973 | 2025-07-31 18:36:23.940233 | PLAY RECAP 2025-07-31 18:36:23.940359 | noble | ok: 1 changed: 1 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2025-07-31 18:36:23.940438 | 2025-07-31 18:36:24.062657 | RUN END RESULT_NORMAL: [untrusted : github.com/osism/openstack-ironic-images/playbooks/builder.yml@main] 2025-07-31 18:36:24.064143 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-fetch.yaml@main] 2025-07-31 18:36:24.809758 | 2025-07-31 18:36:24.809908 | PLAY [Base post-fetch] 2025-07-31 18:36:24.826151 | 2025-07-31 18:36:24.826273 | TASK [fetch-output : Set log path for multiple nodes] 2025-07-31 18:36:24.881269 | noble | skipping: Conditional result was False 2025-07-31 18:36:24.892194 | 2025-07-31 18:36:24.892367 | TASK [fetch-output : Set log path for single node] 2025-07-31 18:36:24.935993 | noble | ok 2025-07-31 18:36:24.941927 | 2025-07-31 18:36:24.942037 | LOOP [fetch-output : Ensure local output dirs] 2025-07-31 18:36:25.421091 | noble -> localhost | ok: "/var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/work/logs" 2025-07-31 18:36:25.702035 | noble -> localhost | changed: "/var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/work/artifacts" 2025-07-31 18:36:25.980973 | noble -> localhost | changed: "/var/lib/zuul/builds/9c8613ae53894bc99a684b05f37e7b83/work/docs" 2025-07-31 18:36:25.996014 | 2025-07-31 18:36:25.996141 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-07-31 18:36:27.268796 | noble | changed: 2025-07-31 18:36:27.269088 | noble | .d..t...... ./ 2025-07-31 18:36:27.269138 | noble | >f+++++++++ osism-ipa-stable.log 2025-07-31 18:36:27.269204 | noble | changed: All items complete 2025-07-31 18:36:27.269242 | 2025-07-31 18:36:27.946698 | noble | changed: .d..t...... ./ 2025-07-31 18:36:28.615656 | noble | changed: .d..t...... ./ 2025-07-31 18:36:28.641876 | 2025-07-31 18:36:28.642041 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-07-31 18:36:28.678330 | noble | skipping: Conditional result was False 2025-07-31 18:36:28.681202 | noble | skipping: Conditional result was False 2025-07-31 18:36:28.700080 | 2025-07-31 18:36:28.700184 | PLAY RECAP 2025-07-31 18:36:28.700245 | noble | ok: 3 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-07-31 18:36:28.700275 | 2025-07-31 18:36:28.826769 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post-fetch.yaml@main] 2025-07-31 18:36:28.827774 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-07-31 18:36:29.581963 | 2025-07-31 18:36:29.582132 | PLAY [Base post] 2025-07-31 18:36:29.596974 | 2025-07-31 18:36:29.597112 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-07-31 18:36:30.233836 | noble | changed 2025-07-31 18:36:30.244681 | 2025-07-31 18:36:30.244815 | PLAY RECAP 2025-07-31 18:36:30.244893 | noble | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-07-31 18:36:30.244971 | 2025-07-31 18:36:30.367806 | POST-RUN END RESULT_NORMAL: [trusted : github.com/osism/zuul-config/playbooks/base/post.yaml@main] 2025-07-31 18:36:30.369689 | POST-RUN START: [trusted : github.com/osism/zuul-config/playbooks/base/post-logs.yaml@main] 2025-07-31 18:36:31.154210 | 2025-07-31 18:36:31.154378 | PLAY [Base post-logs] 2025-07-31 18:36:31.167041 | 2025-07-31 18:36:31.167191 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-07-31 18:36:31.635990 | localhost | changed 2025-07-31 18:36:31.651512 | 2025-07-31 18:36:31.651733 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-07-31 18:36:31.689734 | localhost | ok 2025-07-31 18:36:31.695544 | 2025-07-31 18:36:31.695715 | TASK [Set zuul-log-path fact] 2025-07-31 18:36:31.714020 | localhost | ok 2025-07-31 18:36:31.727965 | 2025-07-31 18:36:31.728102 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-07-31 18:36:31.755195 | localhost | ok 2025-07-31 18:36:31.762867 | 2025-07-31 18:36:31.763050 | TASK [upload-logs : Create log directories] 2025-07-31 18:36:32.250733 | localhost | changed 2025-07-31 18:36:32.253637 | 2025-07-31 18:36:32.253750 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-07-31 18:36:32.735823 | localhost -> localhost | ok: Runtime: 0:00:00.006844 2025-07-31 18:36:32.746023 | 2025-07-31 18:36:32.746234 | TASK [upload-logs : Upload logs to log server] 2025-07-31 18:36:33.301236 | localhost | Output suppressed because no_log was given 2025-07-31 18:36:33.303476 | 2025-07-31 18:36:33.303597 | LOOP [upload-logs : Compress console log and json output] 2025-07-31 18:36:33.357652 | localhost | skipping: Conditional result was False 2025-07-31 18:36:33.362282 | localhost | skipping: Conditional result was False 2025-07-31 18:36:33.375667 | 2025-07-31 18:36:33.375923 | LOOP [upload-logs : Upload compressed console log and json output] 2025-07-31 18:36:33.427847 | localhost | skipping: Conditional result was False 2025-07-31 18:36:33.428152 | 2025-07-31 18:36:33.434729 | localhost | skipping: Conditional result was False 2025-07-31 18:36:33.447929 | 2025-07-31 18:36:33.448181 | LOOP [upload-logs : Upload console log and json output]