Post 9.1 stable file system problems

[Dominic Fandrey]

On 01/01/2013 07:51, Konstantin Belousov wrote:
> On Tue, Jan 01, 2013 at 02:05:11AM +0100, Dominic Fandrey wrote:
>> On 01/01/2013 01:49, Dominic Fandrey wrote:
>>> On 01/01/2013 01:29, Chris Rees wrote:
>>>> On 1 Jan 2013 00:01, "Dominic Fandrey" <kamikaze at bsdforen.de> wrote:
>>>>>
>>>>> I have a Tinderbox that I just updated to the current RELENG_9.
>>>>> Following the update build times for packages have increased by a
>>>>> factor between 5 and 20. I.e. I have packages that used to build in
>>>>> 5 minutes and now take an hour.
>>>>>
>>>>> I'm suspecting the file system ever since I saw that the majority of CPU
>>>>> load was caused by ls when I looked at top (more than 2 minutes of CPU
>>>>> time were counted that moment). The majority of the time most of the CPU
>>>>> load is caused by bsdtar, pkg_add, qmake-qt4, etc. Without exception
>>>>> tools that access a lot of files.
>>>>>
>>>>> The file system on which packages are built is nullfs mounted from
>>>>> an async mounted UFS. I turned async off, to no avail.
>>>>>
>>>>> /usr/src/UPDATING says that there were nullfs optimisations. So I
>>>>> think this is where the problem originates. I might hack the tinderbox to
>>>>> use 'ln -s' or set it up for NFS to verify this.
>>>>
>>>> Is your kernel newer than the Jail?  The converse causes problems.
>>>
>>> I ran makeJail for all jails after updating.
>>>
>>> I also seem to have similar problems when building in the host-system.
>>> The unzip for openjdk-7 has just passed the 11 minutes CPU time mark.
>>> On my notebook it takes less than 10 seconds.
>>
>> Just set WRKOBJDIRPREFIX to a tmpfs on the Tinderbox host system
>> and the extract takes less than a second. Originally WRKOBJDIRPREFIX
>> also pointed to a nullfs mount.
>>
>> Afterwards I pointed WRKOBJDIRPREFIX to a UFS file system (without
>> nullfs involvement). The entire make extract took 20s.
>>
>> So still faster by at least factor 30 than running it on a nullfs mount
>> (I eventually SIGINTed so I don't know how long it would've run).
> 
> Start providing some useful debugging information ?
> 
> At least dmesg, mount -v and sysctl kern.maxvnodes,
> 'sysctl vfs | grep vnodes' outputs.

Started roughly about the same time the make extract was started.

# while /bin/sleep 60; do sysctl vfs | grep vnodes; done
vfs.freevnodes: 50577
vfs.wantfreevnodes: 51587
vfs.numvnodes: 102006
vfs.freevnodes: 51583
vfs.wantfreevnodes: 51587
vfs.numvnodes: 104237
vfs.freevnodes: 51592
vfs.wantfreevnodes: 51587
vfs.numvnodes: 104319
vfs.freevnodes: 51557
vfs.wantfreevnodes: 51587
vfs.numvnodes: 105367
^C

> What is shown when you press ^T while slow process runs on nullfs ?

I sent the SIGINFO at the end of minutes 1, 2, 3 and 4

# make extract
===>  License GPLv2 accepted by the user
===>  Found saved configuration for openjdk-7.9.05_1
===>  Extracting for openjdk-7.9.05_2
=> SHA256 Checksum OK for openjdk-7u6-fcs-src-b24-09_aug_2012.zip.
=> SHA256 Checksum OK for apache-ant-1.8.4-bin.zip.
===>   openjdk-7.9.05_2 depends on file: /usr/local/bin/unzip - found
load: 2.92  cmd: unzip 44418 [running] 59.75r 0.20u 59.02s 100% 4412k
load: 3.10  cmd: unzip 44418 [running] 118.53r 0.35u 117.39s 100% 4412k
load: 3.04  cmd: unzip 44418 [running] 177.95r 0.48u 176.17s 99% 4424k
load: 3.12  cmd: unzip 44418 [running] 237.81r 0.74u 235.00s 100% 4424k
^C

> Was the ^C reaction by terminating the process instant ?

Yes.

-- 
A: Because it fouls the order in which people normally read text.
Q: Why is top-posting such a bad thing?
A: Top-posting.
Q: What is the most annoying thing on usenet and in e-mail?