#3825 kojid not able to clean up epel7 buildroots
Opened by kevin. Modified

We have been seeing:

May 18 17:19:16 buildvm-x86-29.iad2.fedoraproject.org [localhost] kojid[230392]: 2023-05-18 17:19:16,081 [WARNING] {230392} koji.build:96 file removal failed for /var/lib/mock/epel7-build-43024634-5180373/root/var
May 18 17:19:16 buildvm-x86-29.iad2.fedoraproject.org [localhost] kojid[230392]: 2023-05-18 17:19:16,081 [INFO] {230392} koji.TaskManager:903 43025048/epel7-build/x86_64: clearing rootdir
May 18 17:19:16 buildvm-x86-29.iad2.fedoraproject.org [localhost] kojid[230392]: 2023-05-18 17:19:16,081 [ERROR] {230392} koji:517 Unable to remove directory lib: [Errno 39] Directory not empty: 'lib'
[root@buildvm-x86-29 ~][PROD-IAD2]# ls -lR /var/lib/mock/epel7-build-43025048-5180373
/var/lib/mock/epel7-build-43025048-5180373:
total 0
dr-xr-xr-x. 1 root root 6 May 18 16:50 root
/var/lib/mock/epel7-build-43025048-5180373/root:
total 0
drwxr-xr-x. 1 root root 6 May 18 16:50 var
/var/lib/mock/epel7-build-43025048-5180373/root/var:
total 0
drwxr-xr-x. 1 root root 16 May 18 16:50 lib
/var/lib/mock/epel7-build-43025048-5180373/root/var/lib:
total 0
drwx------. 1 root root 0 May 17 16:40 machines
/var/lib/mock/epel7-build-43025048-5180373/root/var/lib/machines:
total 0

This seems to only be epel7 for whatever reason, but it causes kojid to not clean up other repos and run low on disk space. ;(


It shouldn't stop there. It just emits the warning and continues (after buildroot_final_cleanup_delay is the moment when it should be removed completely). What's the message or error which is related to other buildroots?

Metadata Update from @tkopecek:
- Custom field Size adjusted to None

So, it appeared at the time it was not cleaning up other ones after it hit that one.

But of course I have upgraded all the builders and now I can't see that. I only see the failures for epel7 in logs and it's correctly cleaning up other repos.

FYI, we are still seeing this. ;(

I guess with rhel7 eol so soon it might not be worth digging into?

EUS EOL is 2028, so it is still worth.

Yes, if it continues it would be good to see more details on the issue. Though as Tomas points out, buildroot deletion happens in multiple stages and ideally the process will recover from an error like this one.

The pains we've seen with rmtree recently shouldn't apply here, so I suspect that if rmtree is hitting "directory not empty" then it is likely racing with a stray lingering build process that is still writing.

So, the reason I updated this was that our central log host alerted on disk space. It was caused by all the builders sending lots of these. (about 65GB of logs). :(

I have just been manually deleteing them (ie, 'rm -rf /var/lib/mock/epel7-build*')

Happy to gather more info if you tell me what to get.

By EOL, I mean that in our case epel7 will be retired when rhel7 goes to EUS, so it won't be a problem for us anymore after that. Of course other installs may have the same thing...

It would be good to understand what is happening in case it is an issue that could pop up elsewhere.

I'm probably going to need to see a live instance of this. Next time it happens, leave me at least one buildroot to poke at before you delete it.

ok, here's one (there are a bunch more):

Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,820 [INFO] {508223} koji.TaskManager:878 Removing buildroot: 49450606/epel7-build/x86_64
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,822 [ERROR] {508223} koji:530 Unable to remove directory lib: [Errno 39] Directory not empty: 'lib'
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,823 [ERROR] {508223} koji:498 CWD: /var/lib/mock/epel7-build-49450606-5878197/root/var
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,823 [ERROR] {508223} koji:502 dirstack: [['root'], ['var']]
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,823 [ERROR] {508223} koji:535 Found these entries: machines
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,823 [ERROR] {508223} koji:530 Unable to remove directory var: [Errno 39] Directory not empty: 'var'
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,823 [ERROR] {508223} koji:498 CWD: /var/lib/mock/epel7-build-49450606-5878197/root
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,823 [ERROR] {508223} koji:502 dirstack: [['root']]
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [ERROR] {508223} koji:535 Found these entries: lib
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [ERROR] {508223} koji:530 Unable to remove directory root: [Errno 39] Directory not empty: 'root'
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [ERROR] {508223} koji:498 CWD: /var/lib/mock/epel7-build-49450606-5878197
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [ERROR] {508223} koji:502 dirstack: []
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [ERROR] {508223} koji:535 Found these entries: var
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [ERROR] {508223} koji:481 Found these entries: root
Mar 04 23:23:50 buildvm-x86-06.iad2.fedoraproject.org kojid[508223]: 2024-03-04 23:23:50,824 [WARNING] {508223} koji.build:96 file removal failed for /var/lib/mock/epel7-build-49450606-5878197

The problem is that our rmtree function is working exactly as intended and refusing to cross a filesystem boundary.

The var/lib/machines directory in these buildroots have a different st_dev value.

579             if st.st_dev != dev:
580                 # don't cross fs boundary
581  ->             continue
(Pdb) dev
32
(Pdb) st.st_dev
47

I was going a little crazy trying to figure out how, since there is no such mount point in /proc/mounts, but I found it eventually. It's a btrfs subvolume.

[root@buildvm-ppc64le-30 lib][PROD-IAD2]# btrfs subvolume list .
ID 256 gen 155772 top level 5 path root
ID 257 gen 151112 top level 256 path var/lib/portables
ID 258 gen 151112 top level 256 path var/lib/machines
ID 346 gen 150530 top level 256 path var/lib/mock/epel7-build-49438849-5878197/root/var/lib/machines
ID 347 gen 155672 top level 256 path var/lib/mock/epel7-build-49454209-5878197/root/var/lib/machines

The equivalent rm invocation has the same behavior.

[root@buildvm-ppc64le-30 lib][PROD-IAD2]# rm -rf --one-file-system /var/lib/mock/epel7-build-49454209-5878197/
rm: skipping '/var/lib/mock/epel7-build-49454209-5878197/root/var/lib/machines', since it's on a different device

Our rmtree call even attempts to umount first, but that doesn't help since it's not exactly a mount.

I'm not quite sure what to do here. I'm extremely hesitant to allow crossing fs boundaries. I'm wondering if it is even sane for this sort of subvolume to be created by a buildroot.

There are at least a few clear issues to fix here:

  1. kojid shouldn't fill up /var with incessant errors about this. There needs to be some sort of throttling.
  2. this was a real pain to debug. The rmtree code should at least log when it hits such a boundary.

Ah ha. Great detective work. :)

So, I guess the only reason epel7 is hitting this is because it's the only thing we have left using oldchroot/simple mock and somehow mock decides to use subvolumes if btrfs is detected?

@praiskup perhaps we could fix this in mock? have a way to disable btrfs subvolume use, or just disable it in simple chroots by default?

+1 to better/less logs.

This issue has been migrated to Fedora Forge:
https://forge.fedoraproject.org/koji/koji/issues/3825

Please continue any further discussion there.

Metadata