On (09/05/15 13:33), Linus Torvalds wrote:
> > ... And those are sort of interesting. I was expecting to see more
> > diverged behaviours.
> >
> > Attached.
Hello, sorry for long reply.
> So I'm not sure how really conclusive these graphs are, but they are
> certainly fun to look at. So I have a few reactions:
>
> - that 'nomerge' spike at roughly 780s is interesting. I wonder why
> it does that.
>
Please find some stats below (with TOP 5 slabs). ~780s looks like the
time when glibc build script begins to package glibc (gzip, xz...).
> - it would be interesting to see - for example - which slabs are the
> top memory users, and not _just_ the total (it could clarify the
> spike, for example). That's obviously something that works much better
> for the no-merge case, but could your script be changed to show (say)
> the "top 5 slabs". Showing all of them would probably be too messy,
> but "top 5" could be interesting.
OFFTOP: Capturing is not a problem; visualizing -- is. With a huge number of samples
the graph quickly becomes impossible to read. We have different N `top' slabs
after every measurement, labeling them on a graph is a bit messy. So my script right
now just picks the first slab (most Memory Used or biggest Loss value) per sample
(e.g. every second) and does something like this (in png):
20 +-+---+------------+------------+------------+---+-+
| + + + + |
| +------------+ SIZE +-----+ |
18 +-+ | | LOSS +-----+-+
| | | |
| | | |
| | | |
16 +-+ | | +-+
| | | |
|------------+ | |
14 +-+ | | +-+
| | | |
| | | +------------|
| | | | |
12 +-+ |------------| | +-+
| | | | |
| | | | |
10 +-+ | |-----------+ +-+
| | | | |
| | | | |
| | | | |
8 +-+----------| | | +-+
| | | |------------|
| + | + | + | + |
6 +-+---+------------+------------+------------+---+-+
slab1 slab2 slab3 slab1
samples
^ ^ ^ ^
1s 2s 3s 4s ... (<< not part of the graph)
BACK to spikes.
I modified `slabinfo' tool to report top N (5 in this case) slabs sorted by
Memory usage and by Loss, along with Slab totals (+report everything in bytes,
w/o the dynamic G/M/K scaling. well, techically Loss is `Space - Objects * Objsize'
and can be calculated from the existing output, but I'm lazy. Besides top N biggest
slabs and top N most fragmented ones do not necessarily overlap, so I print both
sets).
Some of the spikes. Samples are separated by "Sample #d".
Test
===============================================================================================
Sample -- 1 second. 98828288 -> 107409408 -> 100171776
Sample #408
Slabcache Totals
----------------
Slabcaches : 140 Aliases : 0->0 Active: 105
Memory used: 98828288 # Loss : 3872736 MRatio: 4%
# Objects : 329484 # PartObj: 484 ORatio: 0%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 3137 16 92313 329484
#Slabs 93 1 2367 9766
#PartSlab 0 0 8 57
%PartSlab 2% 0% 58% 0%
PartObjs 0 0 142 484
% PartObj 0% 0% 38% 0%
Memory 941221 4096 35258368 98828288
Used 904338 4096 33622848 94955552
Loss 36883 0 1635520 3872736
Per Object Average Min Max
---------------------------------------------
Memory 289 8 8192
User 288 8 8192
Loss 1 0 64
Slabs sorted by size (5)
---------------------------------------------------------
Name Objects Objsize Space Slabs/Part/Cpu O/S O %Fr %Ef Flg
ext4_inode_cache 19368 1736 35258368 1072/0/4 18 3 0 95 a
dentry 46200 288 13516800 1635/0/15 28 1 0 98 a
inode_cache 12150 864 11059200 665/0/10 18 2 0 94 a
buffer_head 92313 104 9695232 2363/0/4 39 0 0 99 a
radix_tree_node 6832 576 3997696 240/0/4 28 2 0 98 a
Slabs sorted by loss (5)
---------------------------------------------------------
ext4_inode_cache 19368 1736 1635520 1072/0/4 18 3 0 95 a
inode_cache 12150 864 561600 665/0/10 18 2 0 94 a
dentry 46200 288 211200 1635/0/15 28 1 0 98 a
biovec-256 46 4096 204800 7/7/5 8 3 58 47 A
task_struct 174 4928 125568 19/3/11 6 3 10 87
Sample #409
Slabcache Totals
----------------
Slabcaches : 140 Aliases : 0->0 Active: 105
Memory used: 107409408 # Loss : 3782600 MRatio: 3%
# Objects : 335908 # PartObj: 485 ORatio: 0%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 3199 16 92742 335908
#Slabs 96 1 2378 10081
#PartSlab 0 0 39 67
%PartSlab 1% 0% 50% 0%
# Objects : 335908 # PartObj: 485 ORatio: 0%
# Objects : 335908 # PartObj: 485 ORatio: 0%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 3199 16 92742 335908
#Slabs 96 1 2378 10081
#PartSlab 0 0 39 67
%PartSlab 1% 0% 50% 0%
PartObjs 0 0 274 485
% PartObj 0% 0% 38% 0%
Memory 1022946 4096 35422208 107409408
Used 986921 4096 33779088 103626808
Loss 36024 0 1643120 3782600
Per Object Average Min Max
---------------------------------------------
Memory 310 8 8192
User 308 8 8192
Loss 1 0 64
Slabs sorted by size (5)
---------------------------------------------------------
Name Objects Objsize Space Slabs/Part/Cpu O/S O %Fr %Ef Flg
ext4_inode_cache 19458 1736 35422208 1077/0/4 18 3 0 95 a
dentry 46620 288 13639680 1658/0/7 28 1 0 98 a
inode_cache 12150 864 11059200 665/0/10 18 2 0 94 a
buffer_head 92742 104 9740288 2367/0/11 39 0 0 99 a
biovec-256 2128 4096 8749056 263/0/4 8 3 0 99 A
Slabs sorted by loss (5)
---------------------------------------------------------
ext4_inode_cache 19458 1736 1643120 1077/0/4 18 3 0 95 a
inode_cache 12150 864 561600 665/0/10 18 2 0 94 a
filp 2169 432 267216 134/39/13 18 1 26 77 A
dentry 46620 288 213120 1658/0/7 28 1 0 98 a
task_struct 165 4928 104384 18/2/10 6 3 7 88
Sample #410
Slabcache Totals
----------------
Slabcaches : 140 Aliases : 0->0 Active: 105
Memory used: 100171776 # Loss : 3975712 MRatio: 4%
# Objects : 334759 # PartObj: 633 ORatio: 0%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 3188 16 92859 334759
#Slabs 94 1 2381 9922
#PartSlab 0 0 12 74
%PartSlab 2% 0% 57% 0%
PartObjs 0 0 209 633
% PartObj 0% 0% 38% 0%
Memory 954016 4096 35618816 100171776
Used 916152 4096 33966576 96196064
Loss 37863 0 1652240 3975712
Per Object Average Min Max
---------------------------------------------
Memory 289 8 8192
User 287 8 8192
Loss 1 0 64
Slabs sorted by size (5)
---------------------------------------------------------
Name Objects Objsize Space Slabs/Part/Cpu O/S O %Fr %Ef Flg
ext4_inode_cache 19566 1736 35618816 1083/0/4 18 3 0 95 a
dentry 46788 288 13688832 1661/0/10 28 1 0 98 a
inode_cache 12150 864 11059200 665/0/10 18 2 0 94 a
buffer_head 92859 104 9752576 2371/0/10 39 0 0 99 a
radix_tree_node 6888 576 4030464 242/0/4 28 2 0 98 a
Slabs sorted by loss (5)
---------------------------------------------------------
ext4_inode_cache 19566 1736 1652240 1083/0/4 18 3 0 95 a
inode_cache 12150 864 561600 665/0/10 18 2 0 94 a
biovec-256 54 4096 237568 8/8/6 8 3 57 48 A
dentry 46788 288 213888 1661/0/10 28 1 0 98 a
task_struct 169 4928 182976 20/5/11 6 3 16 81
Another test.
===============================================================================================
Sample -- 1 second. 251637760 -> 306782208 -> 252264448
Sample #426
Slabcache Totals
----------------
Slabcaches : 140 Aliases : 0->0 Active: 107
Memory used: 251637760 # Loss : 11002192 MRatio: 4%
# Objects : 528119 # PartObj: 6437 ORatio: 1%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 4935 11 114582 528119
#Slabs 164 1 4718 17594
#PartSlab 3 0 141 394
%PartSlab 4% 0% 65% 2%
PartObjs 1 0 2422 6437
% PartObj 2% 0% 42% 1%
Memory 2351754 4096 154599424 251637760
Used 2248930 3584 147428064 240635568
Loss 102824 0 7171360 11002192
Per Object Average Min Max
---------------------------------------------
Memory 457 8 8192
User 455 8 8192
Loss 2 0 64
Slabs sorted by size (5)
---------------------------------------------------------
Name Objects Objsize Space Slabs/Part/Cpu O/S O %Fr %Ef Flg
ext4_inode_cache 84924 1736 154599424 4714/0/4 18 3 0 95 a
dentry 114408 288 33472512 4080/0/6 28 1 0 98 a
buffer_head 114582 104 12034048 2934/0/4 39 0 0 99 a
inode_cache 12186 864 11091968 667/0/10 18 2 0 94 a
radix_tree_node 10388 576 6078464 367/0/4 28 2 0 98 a
Slabs sorted by loss (5)
---------------------------------------------------------
ext4_inode_cache 84924 1736 7171360 4714/0/4 18 3 0 95 a
inode_cache 12186 864 563264 667/0/10 18 2 0 94 a
dentry 114408 288 523008 4080/0/6 28 1 0 98 a
kmalloc-128 4117 128 353664 160/141/55 32 0 65 59
kmalloc-2048 1421 2048 202752 80/27/15 16 3 28 93
Sample #427
Slabcache Totals
----------------
Slabcaches : 140 Aliases : 0->0 Active: 107
Memory used: 306782208 # Loss : 11304176 MRatio: 3%
# Objects : 569050 # PartObj: 6538 ORatio: 1%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 5318 11 114777 569050
#Slabs 187 1 4725 20096
#PartSlab 3 0 141 391
%PartSlab 3% 0% 65% 1%
PartObjs 1 0 2422 6538
% PartObj 1% 0% 42% 1%
Memory 2867123 4096 154828800 306782208
Used 2761476 3584 147646800 295478032
Loss 105646 0 7182000 11304176
Per Object Average Min Max
---------------------------------------------
Memory 521 8 8192
User 519 8 8192
Loss 2 0 64
Slabs sorted by size (5)
---------------------------------------------------------
Name Objects Objsize Space Slabs/Part/Cpu O/S O %Fr %Ef Flg
ext4_inode_cache 85050 1736 154828800 4721/0/4 18 3 0 95 a
biovec-256 12416 4096 50954240 1550/3/5 8 3 0 99 A
dentry 114548 288 33513472 4075/0/16 28 1 0 98 a
buffer_head 114777 104 12054528 2939/0/4 39 0 0 99 a
inode_cache 12186 864 11091968 667/0/10 18 2 0 94 a
Slabs sorted by loss (5)
---------------------------------------------------------
ext4_inode_cache 85050 1736 7182000 4721/0/4 18 3 0 95 a
inode_cache 12186 864 563264 667/0/10 18 2 0 94 a
dentry 114548 288 523648 4075/0/16 28 1 0 98 a
kmalloc-128 4117 128 353664 160/141/55 32 0 65 59
bio-0 12852 176 244800 589/0/23 21 0 0 90 A
Sample #428
Slabcache Totals
----------------
Slabcaches : 140 Aliases : 0->0 Active: 107
Memory used: 252264448 # Loss : 11537008 MRatio: 4%
# Objects : 529408 # PartObj: 8649 ORatio: 1%
Per Cache Average Min Max Total
---------------------------------------------------------
#Objects 4947 11 115947 529408
#Slabs 165 1 4725 17655
#PartSlab 5 0 141 566
%PartSlab 5% 0% 65% 3%
PartObjs 1 0 2422 8649
% PartObj 2% 0% 42% 1%
Memory 2357611 4096 154828800 252264448
Used 2249789 3584 147646800 240727440
Loss 107822 0 7182000 11537008
Per Object Average Min Max
---------------------------------------------
Memory 456 8 8192
User 454 8 8192
Loss 2 0 64
Slabs sorted by size (5)
---------------------------------------------------------
Name Objects Objsize Space Slabs/Part/Cpu O/S O %Fr %Ef Flg
ext4_inode_cache 85050 1736 154828800 4721/0/4 18 3 0 95 a
dentry 114660 288 33546240 4075/0/20 28 1 0 98 a
buffer_head 115947 104 12177408 2942/0/31 39 0 0 99 a
inode_cache 12186 864 11091968 667/0/10 18 2 0 94 a
radix_tree_node 10444 576 6111232 369/0/4 28 2 0 98 a
Slabs sorted by loss (5)
---------------------------------------------------------
ext4_inode_cache 85050 1736 7182000 4721/0/4 18 3 0 95 a
inode_cache 12186 864 563264 667/0/10 18 2 0 94 a
dentry 114660 288 524160 4075/0/20 28 1 0 98 a
filp 3572 432 447552 227/113/16 18 1 46 77 A
kmalloc-128 4117 128 353664 160/141/55 32 0 65 59
Attached some graphs for NOMERGE kernel. So far, I haven't seen those spikes
for 'merge' kernel.
> - assuming the times are comparable, it looks like 'merge' really is
> noticeably faster. But that might just be noise too, so this may not
> be real data.
>
> - regardless of how meaningful the graphs are, and whether they
> really tell us anything, I do like the concept, and I'd love to see
> people do things like this more often. Visualization to show behavior
> is great.
>
> That last point in particular means that if you scripted this and your
> scripts aren't *too* ugly and not too tied to your particular setup, I
> think it would perhaps not be a bad idea to encourage plots like this
> by making those kinds of scripts available in the kernel tree. That's
> particularly true if you used something like the tools/testing/ktest/
> scripts to run these things automatically (which can be a *big* issue
> to show that something is actually stable across multiple boots, and
> see the variance).
Oh, that's a good idea. I didn't use tools/testing/ktest/, it's a bit too
massive for my toy script. I have some modifications to slabinfo and a rather
ugly script to parse files and feed them to gnuplot (and yes, I use gnuplot
for plotting). slabinfo patches are not entirely dumb and close to being ready
(well.. except that I need to clean up all those %6s sprintfs that worked fine
for dynamically scalled sizes and do not work so nicely for sizes in bytes). I
can send them out later. Less sure about the script (bash) tho. In a nutshell
it's just a number of
grep | awk > FOO; gnuplot ... FOO
So I'll finish some plotting improvements first (not ready yet) and then
I'll take a look how quickly I can land it (rewrite in perl) in
tools/testing/ktest/.
> So maybe these graphs are meaningful, and maybe they aren't. But I'd
> still like to see more of them ;)
Thanks.
-ss
Attachment:
nomerge-mm-loss-usage-1.png
Description: PNG image
Attachment:
nomerge-mm-loss-usage-2.png
Description: PNG image
