Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

c9s: ext.config.shared.rpm-ostree.kernel-replace fails #1673

Open
c4rt0 opened this issue Dec 6, 2024 · 8 comments
Open

c9s: ext.config.shared.rpm-ostree.kernel-replace fails #1673

c4rt0 opened this issue Dec 6, 2024 · 8 comments

Comments

@c4rt0
Copy link
Contributor

c4rt0 commented Dec 6, 2024

Needs investigation.

[2024-12-05T13:50:11.182Z] --- FAIL: ext.config.shared.rpm-ostree.kernel-replace (1206.05s)
[2024-12-05T13:50:11.182Z]         harness.go:106: TIMEOUT[20m0s]: ssh: sudo /usr/local/bin/kolet run-test-unit kola-runext.service
[2024-12-05T13:50:11.182Z]         harness.go:106: TIMEOUT[20m0s]: ssh: journalctl -t kola-runext-kernel-replace

I failed to find useful info in console.txt.

journal.txt presents:

Dec  5 13:01:40.836001 rpm-ostreed.service[2992]: dracut:     microcode_ctl: kernel version "5.14.0-533.el9.x86_64" failed early load check for "intel-06-4e-03", skipping

Attaching also journal-raw.txt.gz
@c4rt0 c4rt0 mentioned this issue Dec 6, 2024
Closed
@jbtrystram
Copy link
Contributor

@c4rt0 maybe we can try to update the test to replace to a kernel more recent than "5.14.0-533.el9.x86_64" ?

@jbtrystram
Copy link
Contributor

@c4rt0 maybe we can try to update the test to replace to a kernel more recent than "5.14.0-533.el9.x86_64" ?

we investigated this today and the kernel version the test tries to switch to is automatically pulled from what's available in the repos, so that is not a concern. let's investigate it more

@c4rt0
Copy link
Contributor Author

c4rt0 commented Jan 8, 2025

/label jira

@openshift-ci OpenShift CI
Copy link
Contributor

openshift-ci bot commented Jan 8, 2025

@c4rt0: The label(s) /label jira cannot be applied. These labels are supported: acknowledge-critical-fixes-only, platform/aws, platform/azure, platform/baremetal, platform/google, platform/libvirt, platform/openstack, ga, tide/merge-method-merge, tide/merge-method-rebase, tide/merge-method-squash, px-approved, docs-approved, qe-approved, no-qe, downstream-change-needed, rebase/manual, cluster-config-api-changed, approved, backport-risk-assessed, bugzilla/valid-bug, cherry-pick-approved, jira/valid-bug, staff-eng-approved. Is this label configured under labels -> additional_labels or labels -> restricted_labels in plugin.yaml?

In response to this:

/label jira

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

@c4rt0
Copy link
Contributor Author

c4rt0 commented Jan 20, 2025

Upon further investigation, latest scos build passes the test.

from journal.txt:

Jan 20 15:31:41.210716 kola-runext.service[1380]: ++ . /etc/os-release
Jan 20 15:31:41.210916 kola-runext.service[1380]: +++ NAME='CentOS Stream CoreOS'
Jan 20 15:31:41.210971 kola-runext.service[1380]: +++ VERSION=9.0.20250120-0
Jan 20 15:31:41.211021 kola-runext.service[1380]: +++ ID=centos
Jan 20 15:31:41.211056 kola-runext.service[1380]: +++ ID_LIKE='rhel fedora'
Jan 20 15:31:41.211094 kola-runext.service[1380]: +++ VERSION_ID=9
Jan 20 15:31:41.211125 kola-runext.service[1380]: +++ PLATFORM_ID=platform:el9
Jan 20 15:31:41.211156 kola-runext.service[1380]: +++ PRETTY_NAME='CentOS Stream CoreOS 9.0.20250120-0'
Jan 20 15:31:41.211187 kola-runext.service[1380]: +++ ANSI_COLOR='0;31'
Jan 20 15:31:41.211227 kola-runext.service[1380]: +++ LOGO=fedora-logo-icon
Jan 20 15:31:41.211259 kola-runext.service[1380]: +++ CPE_NAME=cpe:/o:centos:centos:9
Jan 20 15:31:41.211290 kola-runext.service[1380]: +++ HOME_URL=https://centos.org/
Jan 20 15:31:41.211321 kola-runext.service[1380]: +++ BUG_REPORT_URL=https://issues.redhat.com/
Jan 20 15:31:41.211359 kola-runext.service[1380]: +++ REDHAT_SUPPORT_PRODUCT='Red Hat Enterprise Linux 9'
Jan 20 15:31:41.211394 kola-runext.service[1380]: +++ REDHAT_SUPPORT_PRODUCT_VERSION='CentOS Stream'
Jan 20 15:31:41.211426 kola-runext.service[1380]: +++ OSTREE_VERSION=9.0.20250120-0
Jan 20 15:31:41.211456 kola-runext.service[1380]: +++ VARIANT=CoreOS
Jan 20 15:31:41.211485 kola-runext.service[1380]: +++ VARIANT_ID=coreos
Jan 20 15:31:41.211523 kola-runext.service[1380]: ++ echo centos
Jan 20 15:31:41.211703 kola-runext.service[1377]: + OS_ID=centos
Jan 20 15:31:41.211802 kola-runext.service[1377]: + image_dir=/var/tmp/coreos
Jan 20 15:31:41.211850 kola-runext.service[1377]: + image=oci:/var/tmp/coreos
Jan 20 15:31:41.211892 kola-runext.service[1377]: + image_pull=ostree-unverified-image:oci:/var/tmp/coreos
Jan 20 15:31:41.212003 kola-runext.service[1377]: + tmp_imagedir=/var/tmp/coreos-tmp
Jan 20 15:31:41.212205 kola-runext.service[1381]: ++ arch
Jan 20 15:31:41.215017 kola-runext.service[1377]: + arch=x86_64
Jan 20 15:31:41.215185 kola-runext.service[1377]: + '[' '!' -f /var/kola-kernel.evr ']'
Jan 20 15:31:41.215751 kola-runext.service[1382]: ++ cat /var/kola-kernel.evr
Jan 20 15:31:41.217120 kola-runext.service[1377]: + kver=5.14.0-547.el9.x86_64
Jan 20 15:31:41.217414 kola-runext.service[1383]: ++ cat /var/kola-kernel.url
Jan 20 15:31:41.218746 session-13.scope[1371]: Awaiting events
Jan 20 15:31:41.221999 session-13.scope[1371]: Dispatching kola-runext.service
Jan 20 15:31:41.222161 kola-runext.service[1377]: + url=https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel
Jan 20 15:31:41.222309 kola-runext.service[1377]: + case "${AUTOPKGTEST_REBOOT_MARK:-}" in
Jan 20 15:31:41.222533 kola-runext.service[1384]: ++ uname -r
Jan 20 15:31:41.224176 session-13.scope[1371]: Done dispatching kola-runext.service
Jan 20 15:31:41.224666 kola-runext.service[1377]: + un=5.14.0-547.el9.x86_64
Jan 20 15:31:41.224731 kola-runext.service[1377]: + test 5.14.0-547.el9.x86_64 '!=' 5.14.0-547.el9.x86_64
Jan 20 15:31:41.224771 kola-runext.service[1377]: + echo 'Kernel switch to 5.14.0-547.el9.x86_64 was successful'
Jan 20 15:31:41.224802 kola-runext.service[1377]: Kernel switch to 5.14.0-547.el9.x86_64 was successful

@c4rt0
Copy link
Contributor Author

c4rt0 commented Jan 21, 2025

Test still fails when executed on the pod:

Just for reference:

First attempt:

journal:

Jan 21 10:43:12 qemu0 kola-runext-kernel-replace[1402]: STEP 1/2: FROM localhost/coreos
Jan 21 10:43:12 qemu0 kola-runext-kernel-replace[1402]: STEP 2/2: RUN rpm-ostree override replace     https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-{,core-,modules-,modules-core-,modules-extra-}5.14.0-547.el9.x86_64.rpm &&     rpm-ostree cleanup -m &&     ostree container commit
Jan 21 10:43:13 qemu0 kola-runext-kernel-replace[1434]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-5.14.0-547.el9.x86_64.rpm...done
Jan 21 10:43:14 qemu0 kola-runext-kernel-replace[1434]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-core-5.14.0-547.el9.x86_64.rpm...done
Jan 21 10:43:15 qemu0 kola-runext-kernel-replace[1434]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-5.14.0-547.el9.x86_64.rpm...done
Jan 21 10:43:16 qemu0 kola-runext-kernel-replace[1434]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-core-5.14.0-547.el9.x86_64.rpm...done
Jan 21 10:43:17 qemu0 kola-runext-kernel-replace[1434]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-extra-5.14.0-547.el9.x86_64.rpm...done
Jan 21 10:43:17 qemu0 kola-runext-kernel-replace[1434]: Enabled rpm-md repositories: extras-common baseos appstream
Jan 21 10:47:19 qemu0 kola-runext-kernel-replace[1434]: Updating metadata for 'extras-common'...done
Jan 21 10:57:23 qemu0 kola-runext-kernel-replace[1434]: Updating metadata for 'baseos'...done
Jan 21 10:57:23 qemu0 kola-runext-kernel-replace[1434]: error: Updating rpm-md repo 'baseos': cannot update repo 'baseos': Cannot download repomd.xml: Cannot download repodata/repomd.xml: All mirrors were tried; Last error: Curl error (28): Timeout was reached for http://ftp-nyc.osuosl.org/pub/centos-stream/9-stream/BaseOS/x86_64/os/repodata/repomd.xml [Failed to connect to ftp-nyc.osuosl.org port 80: Connection timed out]
Jan 21 10:57:23 qemu0 kola-runext-kernel-replace[1402]: Error: building at STEP "RUN rpm-ostree override replace     https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-{,core-,modules-,modules-core-,modules-extra-}5.14.0-547.el9.x86_64.rpm &&     rpm-ostree cleanup -m &&     ostree container commit": while running runtime: exit status 1
sh-5.2$

Second attempt:

journal:

Jan 21 11:39:00.711809 kola-runext.service[1398]: STEP 1/2: FROM localhost/coreos
Jan 21 11:39:00.739846 init.scope[1]: var-lib-containers-storage-overlay-volatile\x2dcheck3019804649-merged.mount: Deactivated successfully.
Jan 21 11:39:00.750582 kola-runext.service[1398]: STEP 2/2: RUN rpm-ostree override replace     https://mirror.stream.centos.org/9-stream/BaseOS/x86t
Jan 21 11:39:00.953898 init.scope[1]: Started libcrun container.
Jan 21 11:39:01.452569 kola-runext.service[1430]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-5.14.0-547.e
Jan 21 11:39:01.971311 kola-runext.service[1430]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-core-5.14.0e
Jan 21 11:39:02.697857 kola-runext.service[1430]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-5.1e
Jan 21 11:39:03.490892 kola-runext.service[1430]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-core
Jan 21 11:39:03.891437 kola-runext.service[1430]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-exte
Jan 21 11:39:03.918262 kola-runext.service[1430]: Enabled rpm-md repositories: extras-common baseos appstream
Jan 21 11:40:21.571913 chronyd.service[890]: Source 15.204.87.223 replaced with 2001:4998:58:183a::1001 (2.centos.pool.ntp.org)
Jan 21 11:43:16.181456 [email protected][1029]: Created slice User Background Tasks Slice.
Jan 21 11:43:16.185567 [email protected][1029]: Starting Cleanup of User's Temporary Files and Directories...
Jan 21 11:43:16.197648 [email protected][1029]: Finished Cleanup of User's Temporary Files and Directories.
Jan 21 11:50:12.144580 kola-runext.service[1430]: Updating metadata for 'extras-common'...done
Jan 21 11:52:49.731794 init.scope[1]: Starting Cleanup of Temporary Directories...
Jan 21 11:52:49.803039 init.scope[1]: systemd-tmpfiles-clean.service: Deactivated successfully.
Jan 21 11:52:49.803360 init.scope[1]: Finished Cleanup of Temporary Directories.
Jan 21 11:52:49.808214 init.scope[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully.
Jan 21 11:54:59.284849 sshd.service[11106]: Accepted publickey for core from 10.0.2.2 port 33932 ssh2: RSA SHA256:tzRLTixsn5WCOw6gyqz0ZC9JQeAlrNUwmf8
Jan 21 11:54:59.298568 init.scope[1]: Started Session 14 of User core.
Jan 21 11:54:59.302453 systemd-logind.service[862]: New session 14 of user core.
Jan 21 11:54:59.309854 sshd.service[11106]: pam_unix(sshd:session): session opened for user core(uid=1000) by core(uid=0)
Jan 21 11:54:59.356313 sshd.service[11106]: pam_unix(sshd:session): session closed for user core
Jan 21 11:54:59.360444 systemd-logind.service[862]: Session 14 logged out. Waiting for processes to exit.
Jan 21 11:54:59.362780 init.scope[1]: session-14.scope: Deactivated successfully.
Jan 21 11:54:59.364401 systemd-logind.service[862]: Removed session 14.
sh-5.2$

result:

2025-01-21T11:55:01Z kola: Test timed out. Adding as candidate for rerun success: ext.config.shared.rpm-ostree.kernel-replace
--- FAIL: ext.config.shared.rpm-ostree.kernel-replace (1205.88s)
        harness.go:106: TIMEOUT[20m0s]: ssh: sudo /usr/local/bin/kolet run-test-unit kola-runext.service
        harness.go:106: TIMEOUT[20m0s]: ssh: journalctl -t kola-runext-kernel-replace

After cosa clean --all and a fresh build:

Third attempt:

journal:

Jan 21 12:51:27.586297 kola-runext.service[1397]: STEP 1/2: FROM localhost/coreos
Jan 21 12:51:27.611901 init.scope[1]: var-lib-containers-storage-overlay-volatile\x2dcheck1581847337-merged.mount: Deactivated successfully.
Jan 21 12:51:27.623612 kola-runext.service[1397]: STEP 2/2: RUN rpm-ostree override replace     https://mirror.stream.centos.org/9-stream/BaseOS/x86t
Jan 21 12:51:27.830441 init.scope[1]: Started libcrun container.
Jan 21 12:51:28.228054 kola-runext.service[1429]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-5.14.0-547.e
Jan 21 12:51:28.523867 kola-runext.service[1429]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-core-5.14.0e
Jan 21 12:51:29.009237 kola-runext.service[1429]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-5.1e
Jan 21 12:51:29.542292 kola-runext.service[1429]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-core
Jan 21 12:51:29.816949 kola-runext.service[1429]: Downloading https://mirror.stream.centos.org/9-stream/BaseOS/x86_64/os/Packages/kernel-modules-exte
Jan 21 12:51:29.859031 kola-runext.service[1429]: Enabled rpm-md repositories: extras-common baseos appstream
Jan 21 12:52:01.353860 kola-runext.service[1429]: Updating metadata for 'extras-common'...done
Jan 21 12:52:45.701604 chronyd.service[893]: Source 162.159.200.123 replaced with 2600:3c01:e000:7e6::123 (2.centos.pool.ntp.org)
Jan 21 12:56:31.276801 [email protected][1032]: Created slice User Background Tasks Slice.
Jan 21 12:56:31.280440 [email protected][1032]: Starting Cleanup of User's Temporary Files and Directories...
Jan 21 12:56:31.291365 [email protected][1032]: Finished Cleanup of User's Temporary Files and Directories.
Jan 21 13:02:04.787713 kola-runext.service[1429]: Updating metadata for 'baseos'...done
Jan 21 13:02:04.793601 kola-runext.service[1429]: error: Updating rpm-md repo 'baseos': cannot update repo 'baseos': Cannot download repomd.xml: Can]
Jan 21 13:02:04.802264 init.scope[1]: crun-buildah-buildah1002636531.scope: Deactivated successfully.
Jan 21 13:02:04.927053 init.scope[1]: var-lib-containers-storage-overlay-d92f0b59d7e0735a70d8e3d7283c5529c2ad792526ce84324f98bd8cc960cd4a-merged.mou.
Jan 21 13:02:04.948188 kola-runext.service[1397]: 2025-01-21 13:02:04.947846872 +0000 UTC m=+637.444596739 image build  
Jan 21 13:02:04.948587 kola-runext.service[1397]: Error: building at STEP "RUN rpm-ostree override replace     https://mirror.stream.centos.org/9-st1
Jan 21 13:02:04.951649 init.scope[1]: var-lib-containers-storage-overlay.mount: Deactivated successfully.
Jan 21 13:02:04.958015 init.scope[1]: kola-runext.service: Main process exited, code=exited, status=1/FAILURE
Jan 21 13:02:04.958196 init.scope[1]: kola-runext.service: Failed with result 'exit-code'.
Jan 21 13:02:04.959017 init.scope[1]: kola-runext.service: Consumed 1min 1.273s CPU time.
Jan 21 13:02:05.075618 session-13.scope[1351]: Dispatching kola-runext.service
Jan 21 13:02:05.080968 session-13.scope[1351]: Done dispatching kola-runext.service
Jan 21 13:02:05.083901 session-13.scope[1331]: pam_unix(sudo:session): session closed for user root
Jan 21 13:02:05.094912 session-13.scope[1325]: pam_unix(sshd:session): session closed for user core
Jan 21 13:02:05.102958 systemd-logind.service[864]: Session 13 logged out. Waiting for processes to exit.
Jan 21 13:02:05.105369 init.scope[1]: session-13.scope: Deactivated successfully.
Jan 21 13:02:05.105744 init.scope[1]: session-13.scope: Consumed 2.299s CPU time.
Jan 21 13:02:05.106846 systemd-logind.service[864]: Removed session 13.
Jan 21 13:02:05.141873 sshd.service[7887]: Accepted publickey for core from 10.0.2.2 port 44072 ssh2: RSA SHA256:aGyJ2Th2ty0B4IwSvHMXvyUSgJlY6zCtV/hw
Jan 21 13:02:05.150508 systemd-logind.service[864]: New session 14 of user core.
Jan 21 13:02:05.156446 init.scope[1]: Started Session 14 of User core.
Jan 21 13:02:05.161266 sshd.service[7887]: pam_unix(sshd:session): session opened for user core(uid=1000) by core(uid=0)
Jan 21 13:02:05.210013 session-14.scope[7893]:     core : PWD=/var/home/core ; USER=root ; COMMAND=/bin/systemctl status --lines=40 kola-runext.serve
Jan 21 13:02:05.213204 session-14.scope[7893]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=1000)
Jan 21 13:02:05.225246 session-14.scope[7893]: pam_unix(sudo:session): session closed for user root
Jan 21 13:02:05.230327 sshd.service[7887]: pam_unix(sshd:session): session closed for user core
Jan 21 13:02:05.233728 systemd-logind.service[864]: Session 14 logged out. Waiting for processes to exit.
Jan 21 13:02:05.235862 init.scope[1]: session-14.scope: Deactivated successfully.
Jan 21 13:02:05.237431 systemd-logind.service[864]: Removed session 14.
Jan 21 13:02:07.269350 sshd.service[7914]: Accepted publickey for core from 10.0.2.2 port 44076 ssh2: RSA SHA256:aGyJ2Th2ty0B4IwSvHMXvyUSgJlY6zCtV/hw
Jan 21 13:02:07.277227 systemd-logind.service[864]: New session 15 of user core.
Jan 21 13:02:07.282443 init.scope[1]: Started Session 15 of User core.
Jan 21 13:02:07.287407 sshd.service[7914]: pam_unix(sshd:session): session opened for user core(uid=1000) by core(uid=0)
Jan 21 13:02:07.327076 sshd.service[7914]: pam_unix(sshd:session): session closed for user core
Jan 21 13:02:07.330892 systemd-logind.service[864]: Session 15 logged out. Waiting for processes to exit.
Jan 21 13:02:07.332802 init.scope[1]: session-15.scope: Deactivated successfully.
Jan 21 13:02:07.334112 systemd-logind.service[864]: Removed session 15.

result:

Jan 21 13:02:04 qemu0 kola-runext-kernel-replace[1429]: error: Updating rpm-md repo 'baseos': cannot update repo 'baseos': Cannot download repomd.xm]
Jan 21 13:02:04 qemu0 podman[1397]: 2025-01-21 13:02:04.947846872 +0000 UTC m=+637.444596739 image build  
Jan 21 13:02:04 qemu0 kola-runext-kernel-replace[1397]: Error: building at STEP "RUN rpm-ostree override replace     https://mirror.stream.centos.or1
Jan 21 13:02:04 qemu0 systemd[1]: kola-runext.service: Main process exited, code=exited, status=1/FAILURE
Jan 21 13:02:04 qemu0 systemd[1]: kola-runext.service: Failed with result 'exit-code'.
Jan 21 13:02:04 qemu0 systemd[1]: kola-runext.service: Consumed 1min 1.273s CPU time.

--- FAIL: ext.config.shared.rpm-ostree.kernel-replace (894.53s)
        cluster.go:151: Error: Unit kola-runext.service exited with code 1
        cluster.go:151: 2025-01-21T13:02:05Z cli: Unit kola-runext.service exited with code 1
        harness.go:1265: kolet failed: : kolet run-test-unit failed: Process exited with status 1

@dustymabe
Copy link
Member 

http://ftp-nyc.osuosl.org/pub/centos-stream/9-stream/BaseOS/x86_64/os/repodata/repomd.xml [Failed to connect to ftp-nyc.osuosl.org port 80: Connection timed out]

seems likely like a random mirror that we don't have an allowlist rule for

@c4rt0
Copy link
Contributor Author

c4rt0 commented Jan 23, 2025

Specified in the test c9s mirror seemed to me already quite deterministic.For now I can't find anywhere the reference to the ftp-nyc.osuosl.org, but will keep digging ...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@dustymabe @jbtrystram @c4rt0