Bug 12267

I've tried running pieces of the code in lib/bb/monitordisk.py in an interactive interpreter on the workers shortly after seeing this and see 3.4 billion free inodes as expected. I'm open to ideas for further testing.

which hosts is this happening on? all? any idea how many simultaneous builds are running when this occurs?

It's occurred on several different hosts. If I remember correctly it usually happens when all the build slots are in use.

On ubuntu1704 I looked at this after it happened again:

rpurdie@ubuntu1704:~$ df -i
Filesystem                                 Inodes       IUsed      IFree IUse% Mounted on
udev                                     16484406         437   16483969    1% /dev
tmpfs                                    16490077         977   16489100    1% /run
/dev/sda2                                12214272      269339   11944933    3% /
tmpfs                                    16490077          28   16490049    1% /dev/shm
tmpfs                                    16490077           3   16490074    1% /run/lock
tmpfs                                    16490077          16   16490061    1% /sys/fs/cgroup
/dev/sda3                               231849984    35075552  196774432   16% /home
tmpfs                                    16490077           6   16490071    1% /run/user/6000
tmpfs                                    16490077           5   16490072    1% /run/user/1050
172.29.10.206:/mnt/download/autobuilder  33092806 -4233148762 4266241568     - /srv/autobuilder
tmpfs                                    16490077           5   16490072    1% /run/user/1004

rpurdie@ubuntu1704:~$ strace df -i
[...]
statfs("/srv/autobuilder", {f_type=NFS_SUPER_MAGIC, f_bsize=131072, f_blocks=603882626, f_bfree=217991351, f_bavail=217991351, f_files=33029551, f_ffree=4266178272, f_fsid={0, 0}, f_namelen=255, f_frsize=131072, f_flags=ST_VALID|ST_RELATIME}) = 0
[...]
write(1, "172.29.10.206:/mnt/download/auto"..., 96172.29.10.206:/mnt/download/autobuilder  33029551 -4233148721 4266178272     - /srv/autobuilder
) = 96

So its saying the NFS mount has 33029551 inodes of which 4266178272 are free and the data is coming from the statfs syscall.

rpurdie@ubuntu1604:~$ df -i
Filesystem                                 Inodes       IUsed      IFree IUse% Mounted on
172.29.10.206:/mnt/download/autobuilder  31424748 -4233147612 4264572360     - /srv/autobuilder

[rpurdie@fedora26 ~]$ df -i
Filesystem                                 Inodes       IUsed      IFree IUse% Mounted on
172.29.10.206:/mnt/download/autobuilder  31344723 -4233147605 4264492328     - /srv/autobuilder

So given three workers all report odd inode counts, I think the nas has to be sharing some odd data to them.

Assigning to Michael as this looks like a server issue of some kind (reproduced outside bitbake).

I haven't been able to catch it in this state. Thank you. I'm excited to look at nfs issues again with this new info in hand.

*** Bug 12310 has been marked as a duplicate of this bug. ***

At this point in time we clearly need more data. Can we perhaps put some monitoring in place to keep an eye on the inode count, perhaps every 5mins via a cron job, and emails the interested parties when the inode count is negative?

Once we are able to identify a time window during which the system was in a bad state we may be able to correlate it to other events.

An additional detail that would be interesting is to know what the NAS device itself reports as the inode count when the workers observe this issue, i.e. is this strictly an issue in the exported fs or something that's also observed locally on the NAS itself?

Is our NAS a vendor provided device? If so perhaps we can request support from them once we have a few more details?

Sure we can add a cronjob for that. Which other stats should we gather at the same time? Load averages and process list. Some additional nfs stats. What else?

Are we seeing this issue anywhere other than the yocto.io AB cluster? And has it appeared since Richard lowered the pre-failure limits?

The inodes on the NAS are stable with more than 40 billion available and around 70 million used. Nowhere near running low at any point. This is something to do with nfs and not the filesystem as far as I can tell.

Our NAS doesn't match vendors specs and we don't have a support contract at the moment. I can look into this but it isn't in the 2018 budget.

Unless this is hitting users elsewhere I think we should sidestep the problem at this point. We can try moving shared-state to a different volume and see if the problem goes away. Have we seen file creation fail due to lack of inodes? We could try adding a flag to disable bitbake's preemptive failure and see what happens.

(In reply to comment #9)
> Sure we can add a cronjob for that. Which other stats should we gather at
> the same time? Load averages and process list. Some additional nfs stats.
> What else?

Load average and process list could be good. Not sure what else.

> Are we seeing this issue anywhere other than the yocto.io AB cluster? And
> has it appeared since Richard lowered the pre-failure limits?

We're not seeing it anywhere else. Richard's change disables the inode count check, rather than lowering any limits.

> The inodes on the NAS are stable with more than 40 billion available and
> around 70 million used. Nowhere near running low at any point. This is
> something to do with nfs and not the filesystem as far as I can tell.
> 
> Our NAS doesn't match vendors specs and we don't have a support contract at
> the moment. I can look into this but it isn't in the 2018 budget.

Ah, no problem. I had the impression that we were running something vendor provided and hoped/assumed there might be some support attached.

> Unless this is hitting users elsewhere I think we should sidestep the
> problem at this point. We can try moving shared-state to a different volume
> and see if the problem goes away. Have we seen file creation fail due to
> lack of inodes? We could try adding a flag to disable bitbake's preemptive
> failure and see what happens.

We've been running any recent builds with the inode check disabled and haven't run into any issues with file creation. This does just seem to be incorrect reporting of the inode count when checking the available inodes…

I've patched the yocto.io autobuilder to disable the inode count test for now. Once we've fixed the underlying issue this workaround can be reverted.

We have indeed worked around the problem for now.

Michael: Can you add something to the NAS and workers in cron which every 10 minutes runs "df" and "df -i" into a log file with timestamps? That way we'll get an idea of what happens on the NAS when the workers see issues. I do agree its probably an NFS issue and we may just end up having to ignore it. It probably is worth collecting a bit more data quietly behind the scenes though as a lower priority now we have a workaround.

When this issue last occurred it was to corrected after deleting several old nightly builds.  I wonder if the huge amount of available inodes on this filesystem is causing the issue. We could try creating a smaller filesystem for builds to see if that prevents the problem.

We found the incorrect inode counts are on the workers but not the server. As Michael notes, deleting files does seem to help and its likely some kind of counter overflow on large disks. We have a workaround in place to ignore the incorrect counts so we'll deprioritise this issue as we have other more pressing problems to deal with.

We've worked around this issue by disabling the low inode tests on the autobuilder and have had no problems since. It appears NFS gracefully deals with correcting the inode count before there are any issues just not soon enough for our tests.