Trouble interpreting iostat's tps measure

Question

Prelude: I dumped a 5.2 GB database using the mysqldump command. I did this on an underpowered virtual server with only 512 MB of memory. It took about an hour. I'm now reloading that database on my desktop machine that has a dual core cpu and 2 GB of memory. The reload is on it's 9th hour and I don't know if it's even close to finishing. I've reloaded this database on the same machine about a year ago and it took only two hours. The difference between then and now is that I replaced my single ATA hard disk with two SATA disks in raid1 mode. I know that raid1 will write slower (in theory) but definitely not 4.5x slower! So I broke out iostat and I just became more confused.

$ sudo iostat 
Linux 2.6.30-2-amd64 (lukahn)  12/12/2009  _x86_64_ (2 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           7.13    0.00    1.94   27.96    0.00   62.97

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda             144.02       198.41     11139.44    9322418  523399320
sdb             143.78       165.59     11137.39    7780516  523303000
hda               0.01         0.05         0.00       2492          0
md0               0.66         6.44         0.71     302538      33496
md1               7.32        67.02         7.51    3148938     352960
md2               6.08       240.02        18.95   11277610     890584
md3            1389.80        46.85     11106.55    2201410  521853640
md4               0.41         3.03         0.21     142322       9824

sda and sdb are the real SATA drives that back the md devices, as you can see in /proc/mdstat:

$ cat /proc/mdstat 
Personalities : [raid0] [raid1] 
md4 : active raid0 sda6[0] sdb6[1]
      48821248 blocks 64k chunks

md3 : active raid1 sda5[0] sdb5[1]
      48829440 blocks [2/2] [UU]

md2 : active raid1 sda4[0] sdb4[1]
      1318358080 blocks [2/2] [UU]

md1 : active raid1 sda2[0] sdb2[1]
      48829440 blocks [2/2] [UU]

md0 : active raid1 sda1[0] sdb1[1]
      9767424 blocks [2/2] [UU]

The .sql file I am reloading from is on the /home partition on md2 and the /var partition is on md3. I assume that the blocks written to md3 is so much higher than the blocks read from md2 due to MySql regenerating indexes. However the big question I have is how can the tps measure for md3 be so much higher than the tps measure for sda and sdb?

The -m option to iostat shows the same amount of data (5.55 MB/s) being written to disk for both md3 and sda/sdb:

$ sudo iostat -m
Linux 2.6.30-2-amd64 (lukahn)   12/12/2009  _x86_64_    (2 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           7.39    0.00    2.00   28.16    0.00   62.44

Device:            tps    MB_read/s    MB_wrtn/s    MB_read    MB_wrtn
sda             145.16         0.10         5.55       4976     267768
sdb             144.90         0.09         5.55       4143     267716
hda               0.01         0.00         0.00          1          0
md0               0.66         0.00         0.00        154         16
md1               7.18         0.03         0.00       1580        172
md2               6.19         0.13         0.01       6153        443
md3            1418.41         0.02         5.53       1146     266994
md4               0.40         0.00         0.00         69          5

The iostat man page says:

tps

Indicate the number of transfers per second that were issued to the device. A transfer is an I/O request to the device. Multiple logical requests can be combined into a single I/O request to the device. A transfer is of indeterminate size.

I don't expect them to be exactly the same, but surely not 864% different! Is this a sign of a bottleneck due to my misconfiguration of the md device or am I just worried about nothing?

You probably have the wrong cover sheet on your TPS report. – Paul Tomblin Dec 12 '09 at 17:11 — Paul Tomblin, Dec 12 '09 at 17:11

Richlv · Answer 1 · 2018-04-10T11:40:19.747

12

That's a single iostat invocation, which does not provide meaningful data for "per second" values, only counters are useful - it can not calculate change per second from a single value, it needs to know two values and time between them. To see real values, try something like :

iostat -d 1 2

The second output will be real values.

From the iostat manpage:

The first report generated by the iostat command provides statistics concerning the time since the system was booted. Each subsequent report covers the time since the previous report.

edited Apr 10 '18 at 11:40

answered Jul 07 '10 at 16:09

Richlv

2,334
1
13
17

so where is the first tps value coming from? is it a meaningless number that is being generated based on an infinite timeframe? – Chris Oct 11 '13 at 17:55
all of the values in the first line are since system startup. from iostat manpage : "The first report generated by the iostat command provides statistics concerning the time since the system was booted. Each subsequent report covers the time since the previous report." – Richlv Dec 25 '14 at 09:36

score 2 · Answer 2 · answered Dec 12 '09 at 20:05

Since the transfer rates are the same, the output you provide says to me that the MD layer caches transactions and then writes them to the physical disk in larger chunks.

The slowness you're seeing with reloading the database is likely due to indexes, as you said. You can avoid this by just not having the indexes update as you load the data, then just recreate the indexes at the end.

score 0 · Answer 3 · answered Jan 26 '10 at 03:19

The transaction rate a given disk will support is a function of the track seek time. For SATA drives this is typically around 5-8ms, so I'd expect somewhere in the vicinity of 125-200 transactions per second.

You're seeing ~145 tps on each of the drives, so that seems pretty reasonable.

Trouble interpreting iostat's tps measure

3 Answers3