Skip site navigation (1)Skip section navigation (2)
Date:      Mon, 02 Jan 2012 17:19:27 -0500
From:      "Dieter BSD" <dieterbsd@engineer.com>
To:        freebsd-performance@freebsd.org
Subject:   cmp(1) has a bottleneck, but where?
Message-ID:  <20120102221929.218250@gmx.com>

next in thread | raw e-mail | index | archive | help
Task: cp(1) a several-GB file from one drive to another,
then run cmp(1) to verify.  Cp runs as expected, but
cmp runs slower than expected.  Neither the disks
nor the cpu is maxed out.  Local drives, no network
involved.  Machine is otherwise idle.

FreeBSD 8.2
amd64
4 GiB main memory
FFS soft updates
SATA 2TB drives
Doesn't matter which drives/controllers, the example below uses
3132 (siis) with 3726 PM, and JMB363 (ahci), both on PCIe x1 cards

Since this ML seems obscessed with the scheduler:
kern.sched.preemption: 1
kern.sched.idlespinthresh: 4
kern.sched.idlespins: 10000
kern.sched.static_boost: 160
kern.sched.preempt_thresh: 64
kern.sched.interact: 30
kern.sched.slice: 13
kern.sched.name: ULE

cp:

extended device statistics                                             
device    r/s    w/s     kr/s     kw/s wait  svc_t  %b  controller     
  ada3  610.9    0.0  77968.6      0.0    1    1.0  64  siisch0_pm3 NCQ
 ada12    0.5  607.4      8.0  77736.7    6    4.4  60  ahcich1     NCQ


    6 users    Load  0.54  0.46  0.33                  Jan  2 13:16

Mem:KB    REAL            VIRTUAL                       VN PAGER   SWAP PAGER
        Tot   Share      Tot    Share    Free           in   out     in   out
Act  276728   42264  3615536   100420  117572  count
All  335744   43452 1077460k   135596          pages
Proc:                                                            Interrupts
  r   p   d   s   w   Csw  Trp  Sys  Int  Sof  Flt        cow    3921 total
  1         153      8076  191 1277 1920 1341             zfod        atkbd0 1
                                                          ozfod       uart0 irq4
32.7%Sys   3.4%Intr  0.7%User  0.0%Nice 63.1%Idle        %ozfod    66 psm0 irq12
|    |    |    |    |    |    |    |    |    |    |       daefr       cx23880mpe
================++                                        prcfr   619 siis0 puc0
                                       120 dtbuf          totfr  1235 cx23880mpe
Namei     Name-cache   Dir-cache    135408 desvn          react     1 fwohci1 bg
   Calls    hits   %    hits   %     51442 numvn        2 pdwak       ohci0+ 21
      25      25 100                 33843 frevn    36283 pdpgs       ehci0+ 22
                                                          intrn       pcm0 nfe0
Disks  ada3 ada12                                  322804 wire   2000 cpu0: time
KB/t    128   127                                 1441764 act
tps     619   620                                 1670132 inact
MB/s  77.07 77.01                                  107684 cache
%busy    65    63                                    9888 free
                                                   380800 buf

cmp:

extended device statistics                                             
device    r/s    w/s     kr/s     kw/s wait  svc_t  %b  controller     
  ada3  705.2    0.0  45042.3      0.0    0    0.6  40  siisch0_pm3 NCQ
 ada12  706.2    0.0  45042.3      0.0    0    0.5  33  ahcich1     NCQ


    6 users    Load  0.00  0.07  0.17                  Jan  2 13:32

Mem:KB    REAL            VIRTUAL                       VN PAGER   SWAP PAGER
        Tot   Share      Tot    Share    Free           in   out     in   out
Act 1970756   45312 37243128   100420  145224  count  1399             
All 2029948   46696 1111086k   135596          pages 22348
Proc:                                                            Interrupts
  r   p   d   s   w   Csw  Trp  Sys  Int  Sof  Flt        cow    4187 total
  2   1     153       10k 7161 1312 2187 1524 7024        zfod        atkbd0 1
                                                          ozfod       uart0 irq4
10.6%Sys   2.5%Intr 19.3%User  0.0%Nice 67.5%Idle        %ozfod    88 psm0 irq12
|    |    |    |    |    |    |    |    |    |    |       daefr       cx23880mpe
=====++>>>>>>>>>                                          prcfr   700 siis0 puc0
                                        11 dtbuf     1321 totfr  1399 cx23880mpe
Namei     Name-cache   Dir-cache    135408 desvn          react       fwohci1 bg
   Calls    hits   %    hits   %     51442 numvn          pdwak       ohci0+ 21
                                     33639 frevn          pdpgs       ehci0+ 22
                                                          intrn       pcm0 nfe0
Disks  ada3 ada12                                  312052 wire   2000 cpu0: time
KB/t  63.88 63.88                                 1764068 act
tps     700   700                                 1330864 inact
MB/s  43.65 43.65                                  134912 cache
%busy    38    33                                   10312 free
                                                   380800 buf

The disks can read much faster:
cat file > /dev/null:

extended device statistics                                             
device    r/s    w/s     kr/s     kw/s wait  svc_t  %b  controller     
  ada3  781.2    0.0  99663.3      0.0    0    1.1  83  siisch0_pm3 NCQ
 ada12  712.3    0.0  90642.3      0.0    1    1.1  78  ahcich1     NCQ

    6 users    Load  0.16  0.14  0.20                  Jan  2 13:49

Mem:KB    REAL            VIRTUAL                       VN PAGER   SWAP PAGER
        Tot   Share      Tot    Share    Free           in   out     in   out
Act  276604   41864  3630548   100420  191588  count
All  335608   43064 1077474k   135596          pages
Proc:                                                            Interrupts
  r   p   d   s   w   Csw  Trp  Sys  Int  Sof  Flt        cow    4270 total
  3         153       12k 1599  95k 2271 1582             zfod        atkbd0 1
                                                          ozfod       uart0 irq4
37.2%Sys   3.7%Intr  0.9%User  0.0%Nice 58.2%Idle        %ozfod    82 psm0 irq12
|    |    |    |    |    |    |    |    |    |    |       daefr       cx23880mpe
===================+>                                     prcfr   757 siis0 puc0
                                         4 dtbuf          totfr  1431 cx23880mpe
Namei     Name-cache   Dir-cache    135408 desvn          react       fwohci1 bg
   Calls    hits   %    hits   %     51441 numvn        2 pdwak       ohci0+ 21
      25      25 100                 33826 frevn    49879 pdpgs       ehci0+ 22
                                                          intrn       pcm0 nfe0
Disks  ada3 ada12                                  305216 wire   2000 cpu0: time
KB/t    128   128                                 1442164 act
tps     757   716                                 1613304 inact
MB/s  94.31 89.20                                  181700 cache
%busy    80    79                                    9888 free
                                                   380800 buf

So reading from the disks isn't the bottleneck, and systat reports that the
cpu is 67% idle so the cpu isn't the bottleneck, I'm wondering what *is* cmp's
bottleneck?  What else is there that wouldn't show up as one or the other?



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20120102221929.218250>