dump-users

[Dump-users] Dump 10 times slower on faster system

[Bob B. Jr. <bl...@da...>]

I have an IBM BladeCenter with a SAS connected TS3100 LTO4 tape drive.
I have a 6 SAS disk RAID array with 2x300GB file systems, one ext3 and
one ext4.  Disks are 15k rpm.

I have an HS21 bladeserver running 64-bit ubuntu hardy (2.6.24 kernel,
0.4b41 dump, deadline scheduler), which links to the ext3 raid fs, and a
newer HS22 bladeserver running 64-bit ubuntu lucid (2.6.32 kernel,
0.4b42 dump, cfq scheduler), which links to the ext4 raid fs.

So - same tape drive, same disk array source.

On the older blade (4 cores 12GB ram), since install, we've had very
fast dump speeds.  Here is output:
  
  DUMP: Date of this level 0 dump: Tue Jan 10 22:04:58 2012
  DUMP: Dumping /dev/sda1 (/cyrus-mail) to /dev/nst0
  DUMP: Label: none
  DUMP: Writing 1024 Kilobyte records
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 132498941 blocks.
  DUMP: Volume 1 started with block 1 at: Tue Jan 10 22:05:38 2012
  DUMP: 0.00% done at 1024 kB/s, finished in 35:56
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: 17.06% done at 75081 kB/s, finished in 0:24
  DUMP: 28.26% done at 62312 kB/s, finished in 0:25
  DUMP: 36.86% done at 54198 kB/s, finished in 0:25
  DUMP: 46.17% done at 50933 kB/s, finished in 0:23
  DUMP: 58.69% done at 51811 kB/s, finished in 0:17
  DUMP: 76.66% done at 56396 kB/s, finished in 0:09
  DUMP: 93.17% done at 58754 kB/s, finished in 0:02
  DUMP: Closing /dev/nst0
  DUMP: Volume 1 completed at: Tue Jan 10 22:42:29 2012
  DUMP: Volume 1 132504576 blocks (129399.00MB)
  DUMP: Volume 1 took 0:36:51
  DUMP: Volume 1 transfer rate: 59929 kB/s
  DUMP: 132504576 blocks (129399.00MB) on 1 volume(s)
  DUMP: finished in 2206 seconds, throughput 60065 kBytes/sec
  DUMP: Date of this level 0 dump: Tue Jan 10 22:04:58 2012
  DUMP: Date this dump completed:  Tue Jan 10 22:42:29 2012
  DUMP: Average transfer rate: 59929 kB/s
  DUMP: DUMP IS DONE

On the new blade (with 24 cores and 36 GB ram), our dumps are 10 times
slower!  Here is output:

  DUMP: Date of this level 0 dump: Tue Jan 10 22:48:48 2012
  DUMP: Dumping /dev/sda1 (/home) to /dev/nst0
  DUMP: Label: none
  DUMP: Writing 1024 Kilobyte records
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 167349242 blocks.
  DUMP: Volume 1 started with block 1 at: Tue Jan 10 22:48:55 2012
  DUMP: 0.00% done at 512 kB/s, finished in 90:47
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: 2.00% done at 11057 kB/s, finished in 4:07
  DUMP: 2.60% done at 7239 kB/s, finished in 6:15
  DUMP: 3.63% done at 6742 kB/s, finished in 6:38
  DUMP: 4.62% done at 6437 kB/s, finished in 6:53
  DUMP: 6.32% done at 7036 kB/s, finished in 6:11
  DUMP: 8.36% done at 7761 kB/s, finished in 5:29
  DUMP: 9.50% done at 7559 kB/s, finished in 5:33
  DUMP: 10.38% done at 7231 kB/s, finished in 5:45
  DUMP: 11.27% done at 6981 kB/s, finished in 5:54
  DUMP: 11.97% done at 6671 kB/s, finished in 6:08
  DUMP: 12.71% done at 6439 kB/s, finished in 6:18
  DUMP: 13.93% done at 6471 kB/s, finished in 6:10
  DUMP: 14.90% done at 6389 kB/s, finished in 6:11
  DUMP: 16.03% done at 6382 kB/s, finished in 6:06
  DUMP: 17.07% done at 6345 kB/s, finished in 6:04
  DUMP: 19.12% done at 6663 kB/s, finished in 5:38
  DUMP: 20.33% done at 6669 kB/s, finished in 5:33
  DUMP: 21.77% done at 6743 kB/s, finished in 5:23
  DUMP: 22.35% done at 6560 kB/s, finished in 5:30
  DUMP: 23.35% done at 6510 kB/s, finished in 5:28
  DUMP: 25.19% done at 6688 kB/s, finished in 5:11
  DUMP: 26.43% done at 6698 kB/s, finished in 5:06
  DUMP: 28.09% done at 6785 kB/s, finished in 4:55
  DUMP: 30.77% done at 7123 kB/s, finished in 4:31
  DUMP: 31.65% done at 7035 kB/s, finished in 4:30
  DUMP: 32.38% done at 6920 kB/s, finished in 4:32
  DUMP: 33.34% done at 6864 kB/s, finished in 4:30
  DUMP: 34.76% done at 6900 kB/s, finished in 4:23
  DUMP: 35.39% done at 6784 kB/s, finished in 4:25
  DUMP: 36.25% done at 6718 kB/s, finished in 4:24
  DUMP: 38.57% done at 6918 kB/s, finished in 4:07
  DUMP: 39.33% done at 6835 kB/s, finished in 4:07
  DUMP: 40.55% done at 6834 kB/s, finished in 4:02
  DUMP: 41.35% done at 6764 kB/s, finished in 4:01
  DUMP: 41.92% done at 6662 kB/s, finished in 4:03
  DUMP: 43.19% done at 6674 kB/s, finished in 3:57
  DUMP: 43.87% done at 6597 kB/s, finished in 3:57
  DUMP: 44.95% done at 6582 kB/s, finished in 3:53
  DUMP: 46.37% done at 6616 kB/s, finished in 3:46
  DUMP: 47.47% done at 6603 kB/s, finished in 3:41
  DUMP: 48.25% done at 6548 kB/s, finished in 3:40
  DUMP: 49.08% done at 6501 kB/s, finished in 3:38
  DUMP: 50.09% done at 6482 kB/s, finished in 3:34
  DUMP: 50.86% done at 6433 kB/s, finished in 3:33
  DUMP: 52.45% done at 6486 kB/s, finished in 3:24
  DUMP: 54.23% done at 6561 kB/s, finished in 3:14
  DUMP: 55.63% done at 6588 kB/s, finished in 3:07
  DUMP: 56.33% done at 6532 kB/s, finished in 3:06
  DUMP: 57.14% done at 6491 kB/s, finished in 3:04
  DUMP: 58.12% done at 6470 kB/s, finished in 3:00
  DUMP: 59.53% done at 6497 kB/s, finished in 2:53
  DUMP: 60.21% done at 6444 kB/s, finished in 2:52
  DUMP: 61.77% done at 6487 kB/s, finished in 2:44
  DUMP: 62.71% done at 6464 kB/s, finished in 2:40
  DUMP: 64.20% done at 6497 kB/s, finished in 2:33
  DUMP: 64.73% done at 6434 kB/s, finished in 2:32
  DUMP: 65.41% done at 6388 kB/s, finished in 2:31
  DUMP: 66.40% done at 6372 kB/s, finished in 2:27
  DUMP: 67.23% done at 6343 kB/s, finished in 2:24
  DUMP: 68.12% done at 6320 kB/s, finished in 2:20
  DUMP: 68.72% done at 6272 kB/s, finished in 2:19
  DUMP: 69.26% done at 6219 kB/s, finished in 2:17
  DUMP: 69.92% done at 6179 kB/s, finished in 2:15
  DUMP: 70.86% done at 6164 kB/s, finished in 2:11
  DUMP: 72.62% done at 6220 kB/s, finished in 2:02
  DUMP: 73.15% done at 6171 kB/s, finished in 2:01
  DUMP: 73.76% done at 6129 kB/s, finished in 1:59
  DUMP: 74.43% done at 6095 kB/s, finished in 1:56
  DUMP: 75.10% done at 6061 kB/s, finished in 1:54
  DUMP: 76.09% done at 6052 kB/s, finished in 1:50
  DUMP: 76.83% done at 6026 kB/s, finished in 1:47
  DUMP: 77.63% done at 6004 kB/s, finished in 1:43
  DUMP: 78.76% done at 6008 kB/s, finished in 1:38
  DUMP: 79.91% done at 6013 kB/s, finished in 1:33
  DUMP: 80.72% done at 5993 kB/s, finished in 1:29
  DUMP: 81.31% done at 5958 kB/s, finished in 1:27
  DUMP: 81.89% done at 5923 kB/s, finished in 1:25
  DUMP: 82.87% done at 5917 kB/s, finished in 1:20
  DUMP: 83.80% done at 5907 kB/s, finished in 1:16
  DUMP: 84.56% done at 5887 kB/s, finished in 1:13
  DUMP: 85.40% done at 5871 kB/s, finished in 1:09
  DUMP: 86.66% done at 5886 kB/s, finished in 1:03
  DUMP: 88.36% done at 5929 kB/s, finished in 0:54
  DUMP: 89.59% done at 5940 kB/s, finished in 0:48
  DUMP: 90.92% done at 5957 kB/s, finished in 0:42
  DUMP: 92.68% done at 6002 kB/s, finished in 0:34
  DUMP: 93.94% done at 6014 kB/s, finished in 0:28
  DUMP: 95.53% done at 6046 kB/s, finished in 0:20
  DUMP: 96.74% done at 6054 kB/s, finished in 0:15
  DUMP: 97.29% done at 6021 kB/s, finished in 0:12
  DUMP: 98.09% done at 6004 kB/s, finished in 0:08
  DUMP: 98.94% done at 5991 kB/s, finished in 0:04
  DUMP: 99.52% done at 5961 kB/s, finished in 0:02
  DUMP: Closing /dev/nst0
  DUMP: Volume 1 completed at: Wed Jan 11 06:36:00 2012
  DUMP: Volume 1 166971392 blocks (163058.00MB)
  DUMP: Volume 1 took 7:47:05
  DUMP: Volume 1 transfer rate: 5957 kB/s
  DUMP: 166971392 blocks (163058.00MB) on 1 volume(s)
  DUMP: finished in 28015 seconds, throughput 5960 kBytes/sec
  DUMP: Date of this level 0 dump: Tue Jan 10 22:48:48 2012
  DUMP: Date this dump completed:  Wed Jan 11 06:36:00 2012
  DUMP: Average transfer rate: 5957 kB/s
  DUMP: DUMP IS DONE

All interfaces are SAS, I can do dd reads from tape at 150 MB/s from
both systems.

Trying to determine if this is kernel related (st module) or dump
related or ext3/4 related.

I thought initially it was issue with cfq shceduler after seeing bugs
like https://bugzilla.redhat.com/show_bug.cgi?id=456181, but switching
to deadline leads to similar results (still 10 times slower).

I was hoping someone on this list can shed some light, as I've received
no answers from IBM support forums.

Thanks,

-Bob

Re: [Dump-users] Dump 10 times slower on faster system

[Steve B. <fb7...@sn...>]

On Wed, Jan 11, 2012 at 11:04 AM, Bob Blanchard Jr.
blabj-at-dainty.ca|dump-users/gmail/sbonds|
<2n2...@sn...> wrote:
.... trimmed ...

> All interfaces are SAS, I can do dd reads from tape at 150 MB/s from both
> systems.
>
> Trying to determine if this is kernel related (st module) or dump related
> or ext3/4 related.
>

It looks like you're on the right track with your dd read tests to the tape
drive.  What about dd write tests to the tape drive and dd read tests from
the disk partition?  If these are slow, then dump will never get any faster.

I also recall some performance issues with older versions of dump-- try the
newest release (or even the CVS version) and see if the problem persists.
 You were using 0.4b41 (2006) and current is 0.4b44.

  -- Steve Bonds

Re: [Dump-users] Dump 10 times slower on faster system

[Bob B. Jr. <bl...@da...>]

On Wed, 2012-01-11 at 14:06 -0800, Steve Bonds wrote:
> On Wed, Jan 11, 2012 at 11:04 AM, Bob Blanchard Jr. blabj-at-dainty.ca
> |dump-users/gmail/sbonds| <2n2...@sn...> wrote:
> 
> ... trimmed ... 
>         All interfaces are SAS, I can do dd reads from tape at 150
>         MB/s from both systems.
>         
>         Trying to determine if this is kernel related (st module) or
>         dump related or ext3/4 related.
> 
> 
> It looks like you're on the right track with your dd read tests to the
> tape drive.  What about dd write tests to the tape drive and dd read
> tests from the disk partition?  If these are slow, then dump will
> never get any faster.

dd write tests to the tape are between 150 and 160 MB/s. dd reads from
disk around 150 - 180 MB/s

So with dump "out of the way", both systems are giving me at least 150
MB/s read/write speeds.

> I also recall some performance issues with older versions of dump--
> try the newest release (or even the CVS version) and see if the
> problem persists.  You were using 0.4b41 (2006) and current is 0.4b44.
> 


Surprisingly, the "older" 0.4b41 on ubuntu hardy is the blazingly fast
dump at 55 MB/s.  0.4b42 is slow.

I built 0.4b44 from source, and tried again on the ubuntu lucid machine
(where dumps are 10 times slower), and it is an improvement.. average
throughput is around 15 MB/s instead of 5MB/s.  But this is still
nowhere near the 55 MB/s I'm getting with dump 0.4b41.

Could it be slower due to ext4??  Unfortunately I don't have an ext3
partition on the lucid server to test 0.4b44.  I suppse I could try to
build 0.4b44 on hardy and try an ext3 dump.

-Bob

Re: [Dump-users] Dump 10 times slower on faster system

[Bob B. Jr. <bl...@da...>]

Well it seems to be all in the block size.  On both systems I was using
1024k block size, which we find is optimal for writing to tape.  dump
doesn't like this.  I started experimenting with different block sizes.

I found the sweet spot at 64k blocks.

Using 64k block size yields the fastest dump to tape throughput at about
50 MB/s  (still slower than older dump, but only marginally).

root@appserver-wn:~# dump 0uf /dev/st0 -b 64 /opt
  DUMP: Date of this level 0 dump: Thu Jan 12 15:57:58 2012
  DUMP: Dumping /dev/mapper/vg1-opt (/opt) to /dev/st0
  DUMP: Label: none
  DUMP: Writing 64 Kilobyte records
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 4999550 blocks.
  DUMP: Volume 1 started with block 1 at: Thu Jan 12 15:57:59 2012
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: Closing /dev/st0
  DUMP: Volume 1 completed at: Thu Jan 12 16:00:06 2012
  DUMP: Volume 1 4990336 blocks (4873.38MB)
  DUMP: Volume 1 took 0:02:07
  DUMP: Volume 1 transfer rate: 39293 kB/s
  DUMP: 4990336 blocks (4873.38MB) on 1 volume(s)
  DUMP: finished in 96 seconds, throughput 51982 kBytes/sec
  DUMP: Date of this level 0 dump: Thu Jan 12 15:57:58 2012
  DUMP: Date this dump completed:  Thu Jan 12 16:00:06 2012
  DUMP: Average transfer rate: 39293 kB/s
  DUMP: DUMP IS DONE