Re: Fedora 26 Alpha 1.5 compose check report
On Wed, 2017-03-29 at 15:22 +0200, Jan Sedlak wrote:
2017-03-29 4:07 GMT+02:00 Fedora compose checker
<rawhide(a)fedoraproject.org>:
> Average CPU usage changed from 2.28571429 to 24.55238095
In what units is this? Isn't this like, really high?
It's percentage - the values are read from top. And yeah, seems pretty
high. I'm so overwhelmed with stuff to do right now I hadn't actually
looked at these comparisons for a while.
The thing to do when looking into these comparisons is to take
advantage of the 'test data' links shown in the mail. They link to the
asset download page for the relevant openQA tests, and there you can
find the raw logs that check-compose parses. For the CPU usage check,
you want to be looking at the '_collect_data-top.log' files:
https://openqa.fedoraproject.org/tests/71611/file/_collect_data-top.log
https://openqa.fedoraproject.org/tests/72629/file/_collect_data-top.log
This is just the output of:
top -i -n20 -b
which basically runs top 20 times, once every three seconds, in 'batch
mode' (non-interactive). The '-i' makes it only show processes which
actually took some CPU time since the previous run.
the difference here is actually quite interesting. It's easy to see
that the thing that actually takes the CPU time is packagekitd. But in
the very first sample where the packagekitd process shows up in the
list, we see a fwupd process:
top - 19:56:26 up 2 min, 2 users, load average: 0.65, 0.41, 0.16
Tasks: 227 total, 2 running, 225 sleeping, 0 stopped, 0 zombie
%Cpu(s): 2.7 us, 2.7 sy, 0.0 ni, 74.6 id, 19.8 wa, 0.0 hi, 0.0 si, 0.3 st
KiB Mem : 2046968 total, 503808 free, 830268 used, 712892 buff/cache
KiB Swap: 1048572 total, 1048572 free, 0 used. 1009740 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1926 root 20 0 633232 44532 11636 S 3.0 2.2 0:00.78 fwupd
1101 root 20 0 637068 26652 20180 S 2.3 1.3 0:00.16 packagekitd
1652 test 20 0 1088544 78048 30956 S 1.7 3.8 0:01.28 gnome-software
1 root 20 0 158048 11588 8160 S 0.7 0.6 0:01.59 systemd
626 dbus 20 0 76868 6296 4304 S 0.7 0.3 0:00.64 dbus-daemon
7 root 20 0 0 0 0 S 0.3 0.0 0:00.22 rcu_sched
2117 root 20 0 167192 4644 3964 R 0.3 0.2 0:00.08 top
So I'm wondering if this fix:
https://bugzilla.redhat.com/show_bug.cgi?id=1429341
is involved - i.e. if that denial was somehow preventing some package
metadata refresh operation or other from running.
Alternatively it could just be dumb luck: a case of whether GNOME's
initial update check happens to fire while the 'top' check is running
or not. It seems plausible that that could sometimes happen and
sometimes not. These numbers *are* a bit susceptible to that kind of
variation. I meant to keep an eye on them after I implemented them and
try to tweak the tests to make them as reliable as possible, but I've
been kinda overtaken with other work.
--
Adam Williamson
Fedora QA Community Monkey
IRC: adamw | Twitter: AdamW_Fedora | XMPP: adamw AT happyassassin . net
http://www.happyassassin.net