[4.19-9.6]: `ostree.sync` kola test fails on `s390x`

[marmijo]

In s390x, the ostree.sync kola test is failing in the 4.19-9.6 stream with the following output.
This test passed successfully in a recent run, but fails most of the time.

[2025-01-27T16:43:40.293Z] --- FAIL: ostree.sync (604.38s)
[2025-01-27T16:43:40.293Z]         sync.go:201: Got NFS mount.
[2025-01-27T16:43:40.293Z]         sync.go:229: Set link down and rebooting.
[2025-01-27T16:43:40.293Z]         cluster.go:151: Running as unit: run-rd0aaf58e6eb14d4fb456769f3bbb393f.service
[2025-01-27T16:43:40.293Z]         harness.go:106: TIMEOUT[10m0s]: ssh: sudo sh /usr/local/bin/nfs-random-write.sh
[2025-01-27T16:43:40.293Z]         harness.go:106: TIMEOUT[10m0s]: ssh: cat /proc/cmdline
[2025-01-27T16:43:40.293Z] FAIL, output in /home/jenkins/agent/workspace/build-arch/tmp/kola-0nsQt/kola/rerun

The journal log of one of the recent failed s90x build jobs shows:

Jan 27 16:33:36.020474 coreos-teardown-initramfs.service[1276]: info: taking down network device: enc3
Jan 27 16:33:36.021223 coreos-teardown-initramfs.service[1296]: RTNETLINK answers: Operation not supported
Jan 27 16:33:36.023099 coreos-teardown-initramfs.service[1276]: info: flushing all routing
Jan 27 16:33:36.025557 coreos-teardown-initramfs.service[1276]: info: no initramfs hostname information to propagate
Jan 27 16:33:36.027205 coreos-teardown-initramfs.service[1276]: info: no networking config is defined in the real root

journal.txt

console.txt

[marmijo]

Also, for completeness, this test was recently added to coreos-assembler in: coreos/coreos-assembler#3998

[HuijingHei]

I will take it, @marmijo can you sync this to jira and assign it to me, I have no permission to do the sync, thanks!

[marmijo]

/jira

[jlebon]

I think you're looking for:
/label jira

@HuijingHei, next time try that yourself too. If you don't have access, we should look into it.

[openshift-ci]

@jlebon: 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:

I think you're looking for:
/label jira

@HuijingHei, next time try that yourself too. If you don't have access, we should look into it.

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.

[jlebon]

Hmm, I think we still have to wire it up for issues. Anyway, added it manually for now.

[HuijingHei]

Run ostree.sync on rhcos-419.96.202502180531-0 with s390x, the failed rate is 3/5, and check the failed log (on test vm), stuck in:

A stop job is running for OSTree Fi_ed Deployment (9min 6s / no limit)

I thought it was because of low memory, and update memory of test VM to 8G (default 2G), but no lucky.

console.txt

[jmarrero]

I wonder if the changes in
ostreedev/ostree#2968
&
ostreedev/ostree#2969

act different on s390x...

Do we see anything like

ot_journal_print (LOG_INFO, "Completed global sync()");

in the journal or anything interesting around that output?

In your console log I see

�M
�[K[     �[0;31m*�[0m] A stop job is running for OSTree Fi…d Deployment (7min 36s / no limit)
[  489.660159] INFO: task (sd-sync):2546 blocked for more than 368 seconds.

Not sure if that is the same sync we are calling.

[HuijingHei]

I wonder if the changes in ostreedev/ostree#2968 & ostreedev/ostree#2969

act different on s390x...

Do we see anything like

ot_journal_print (LOG_INFO, "Completed global sync()");

in the journal or anything interesting around that output?

No, seems hang in ostree-finalize-staged.service, can not see any other useful journal log.

In your console log I see

�M
�[K[     �[0;31m*�[0m] A stop job is running for OSTree Fi…d Deployment (7min 36s / no limit)
[  489.660159] INFO: task (sd-sync):2546 blocked for more than 368 seconds.

Not sure if that is the same sync we are calling.

[  366.780159] INFO: task dd:2438 blocked for more than 245 seconds.
^M[  366.780184]       Not tainted 5.14.0-570.el9.s390x #1
^M[  366.780186] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
^M[  366.780388] INFO: task dd:2439 blocked for more than 245 seconds.
..
^M[  366.780460] INFO: task dd:2471 blocked for more than 245 seconds.
..
^M[  366.780530] INFO: task (sd-sync):2505 blocked for more than 245 seconds.
..
^M[  366.780562] INFO: task zipl:2546 blocked for more than 245 seconds.

Not sure if it is blocked by dd, sd-sync, zipl. IMU, if reach the timeout (DefaultTimeoutStopSec=10s), will kill all process and restart.