Action jobs sometimes hang forever

[EvilOlaf]

What happened?

Sometimes build jobs on actions runners do not complete their job and eat up resources running in circles. I noticed in increased load of journald and it seems like the stuck jobs spam the logs with stuff like

Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/tmp: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/tmp: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: [🐳|🔨]   chsys /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/sys sysfs rw,relatime 0 0
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: [🐳|🔨]   efivarfs /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/sys/firmware/efi/efivars efivarfs rw,nosuid,nodev,noexec,relatime 0 0
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: [🐳|🔨]   chsys /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/sys sysfs rw,relatime 0 0
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: [🐳|🔨]   efivarfs /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/sys/firmware/efi/efivars efivarfs rw,nosuid,nodev,noexec,relatime 0 0
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: [🐳|🔨]   chsys /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/sys sysfs rw,relatime 0 0
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: [🐳|🔨]   efivarfs /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/sys/firmware/efi/efivars efivarfs rw,nosuid,nodev,noexec,relatime 0 0
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/dev/pts: no mount point specified.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/dev/pts: no mount point specified.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/dev/pts: no mount point specified.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/dev: not mounted
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/dev: not mounted
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/proc: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/dev: not mounted
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/sys: target is busy.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/proc: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/proc: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/sys: target is busy.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/sys: target is busy.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/tmp: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/tmp: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: [🐳|🔨]   chsys /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/sys sysfs rw,relatime 0 0
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: [🐳|🔨]   efivarfs /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/sys/firmware/efi/efivars efivarfs rw,nosuid,nodev,noexec,relatime 0 0
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: [🐳|🔨]   chsys /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/sys sysfs rw,relatime 0 0
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: [🐳|🔨]   efivarfs /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/sys/firmware/efi/efivars efivarfs rw,nosuid,nodev,noexec,relatime 0 0
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: [🐳|🔨]   chsys /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/sys sysfs rw,relatime 0 0
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: [🐳|🔨]   efivarfs /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/sys/firmware/efi/efivars efivarfs rw,nosuid,nodev,noexec,relatime 0 0
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/dev/pts: no mount point specified.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/dev/pts: no mount point specified.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/dev/pts: no mount point specified.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/dev: not mounted
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/dev: not mounted
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/dev: not mounted
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/proc: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/proc: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/proc: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/sys: target is busy.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/sys: target is busy.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/sys: target is busy.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/tmp: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/tmp: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/var/tmp: not mounted.
Jul 19 05:27:25 littlebeast beautiful_hawking[2981]: umount: /armbian/.tmp/mount-c9d80eb6-a6e1-4709-8669-4db5513d9cdd/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast sleepy_hypatia[2981]: umount: /armbian/.tmp/mount-b79698cf-388d-4c5c-9412-352f6d46a0ae/run/user/0: not mounted.
Jul 19 05:27:25 littlebeast pedantic_morse[2981]: umount: /armbian/.tmp/mount-44646dd0-c05f-4079-8303-151c71de7f83/run/user/0: not mounted.

systemctl restart docker fixes this temporary until a new job decides to get hickups.

How to reproduce?

Not reproducible yet.
Noticed on both fi,mirror runnervm and littlebeast.

Branch

main (main development branch)

On which host OS are you running the build script and observing this problem?

Ubuntu 22.04 Jammy

Are you building on Windows WSL2?

• Yes, my Ubuntu/Debian/OtherOS is running on WSL2

Relevant log URL

No response

Code of Conduct

• I agree to follow this project's Code of Conduct

[github-actions]

Jira ticket: AR-2425

[EvilOlaf]

Might be related to some improper cleanup.
I ran into this issue locally while building an image on an OPi5. Did not capture the output since it was more or less the same as above. It stopped once I forced the umount of all three mount points from a different shell, which then obviously lead into build failure. This was reproducible.
The issue disappeared after wiping .tmp (not sure if it wasn't empty already) and the entire cache folder.

[igorpecovnik]

Might be related to some improper cleanup

It is possible this was produced by us in past several months.

[rpardini]

It stopped once I forced the umount of all three mount points from a different shell

Which umounts you had to do manually is probably the key to this. Looks to me it might be /sys chroot.

We do have code that "recursively" umounts so that definitely shouldn't happen -- the code should chase the mounts and get rid of them, no matter what -- but probably some usage has changed / is-in use during the umount / etc

The key here is reproducing it, and capturing DEBUG=yes SHARE_LOG=yes -- if you manage to umount manually, build will finish and upload logs which should contain the answer.

[EvilOlaf]

The funny thing is that I had to umount /proc and / (the 3rd one I don't remember) which are not listed in the errors above. Maybe this is a nested issue?

Best chance for reproduction is via CI since chances are way higher to hit something there.