Bacula-users

[Bacula-users] Slow LTO4 write speed

2010-11-17 07:42:29
Subject: [Bacula-users] Slow LTO4 write speed
From: Lukas Kolbe <l-lists AT einfachkaffee DOT de>
To: bacula-users AT lists.sourceforge DOT net
Date: Wed, 17 Nov 2010 13:17:30 +0100
Hi!

We're seeing strange behaviour with Bacula 5.0.3 on Debian/Squeeze and
Kernels 2.6.36 and 2.6.32 (for a while, we've had CentOS 5 for testing,
but that didn't change a thing).

See the 'btape fill' results below, the write speed doesn't get above
50MB/s - the tape drive is an ULTRIUM-HH4 LTO4 drive in a Tandberg
StorageLoader. Tar is able to write with >120MB/s to the tapes.

I tried different block sizes (64K to 2M; the tape drive claims to
support up to 16M, but Linux doesn't let me), the relevant parts of
bacula-sd.conf are below. I'm quit out of ideas how I could speed up the
tape writes for bacula?

The system btw is a single Xeon E5420, 8GB Ram. The Storage Library/Tape
drives are SAS-connected via a LSI Logig MPTSAS 1068E and storage is a
24-disk Raid50 via Adaptec 52445.


16-Nov 17:02 btape JobId 0: 3304 Issuing autochanger "load slot 1, drive 0" 
command.
16-Nov 17:03 btape JobId 0: 3305 Autochanger "load slot 1, drive 0", status is 
OK.
Wrote Volume label for volume "TestVolume1".
Wrote Start of Session label.
17:03:23 Begin writing Bacula records to first tape ...
Wrote block=5000, file,blk=11,239 VolBytes=10,483,662,848 rate=47.01 MB/s
Wrote block=10000, file,blk=22,3 VolBytes=20,969,422,848 rate=40.87 MB/s
Wrote block=15000, file,blk=32,243 VolBytes=31,455,182,848 rate=42.68 MB/s
Wrote block=20000, file,blk=43,7 VolBytes=41,940,942,848 rate=45.93 MB/s
Wrote block=25000, file,blk=53,247 VolBytes=52,426,702,848 rate=46.27 MB/s
Wrote block=30000, file,blk=64,11 VolBytes=62,912,462,848 rate=47.87 MB/s
17:25:41 Flush block, write EOF
Wrote block=35000, file,blk=74,251 VolBytes=73,398,222,848 rate=48.03 MB/s
Wrote block=40000, file,blk=85,15 VolBytes=83,883,982,848 rate=49.02 MB/s
Wrote block=45000, file,blk=95,255 VolBytes=94,369,742,848 rate=49.15 MB/s
Wrote block=50000, file,blk=106,19 VolBytes=104,855,502,848 rate=49.74 MB/s
Wrote block=55000, file,blk=116,259 VolBytes=115,341,262,848 rate=49.82 MB/s
Wrote block=60000, file,blk=127,23 VolBytes=125,827,022,848 rate=50.13 MB/s
17:46:06 Flush block, write EOF
Wrote block=65000, file,blk=137,263 VolBytes=136,312,782,848 rate=50.29 MB/s
Wrote block=70000, file,blk=148,27 VolBytes=146,798,542,848 rate=50.29 MB/s
Wrote block=75000, file,blk=158,267 VolBytes=157,284,302,848 rate=50.52 MB/s
Wrote block=80000, file,blk=169,31 VolBytes=167,770,062,848 rate=50.50 MB/s
Wrote block=85000, file,blk=179,271 VolBytes=178,255,822,848 rate=50.81 MB/s
Wrote block=90000, file,blk=190,35 VolBytes=188,741,582,848 rate=49.16 MB/s
18:08:33 Flush block, write EOF
Wrote block=95000, file,blk=200,275 VolBytes=199,227,342,848 rate=49.50 MB/s
Wrote block=100000, file,blk=211,39 VolBytes=209,713,102,848 rate=49.43 MB/s
Wrote block=105000, file,blk=221,279 VolBytes=220,198,862,848 rate=49.79 MB/s
Wrote block=110000, file,blk=232,43 VolBytes=230,684,622,848 rate=49.65 MB/s
Wrote block=115000, file,blk=242,283 VolBytes=241,170,382,848 rate=50.05 MB/s
Wrote block=120000, file,blk=253,47 VolBytes=251,656,142,848 rate=49.89 MB/s
18:28:41 Flush block, write EOF
Wrote block=125000, file,blk=263,287 VolBytes=262,141,902,848 rate=50.23 MB/s
Wrote block=130000, file,blk=274,51 VolBytes=272,627,662,848 rate=50.07 MB/s
Wrote block=135000, file,blk=284,291 VolBytes=283,113,422,848 rate=50.25 MB/s
Wrote block=140000, file,blk=295,55 VolBytes=293,599,182,848 rate=50.15 MB/s
Wrote block=145000, file,blk=305,295 VolBytes=304,084,942,848 rate=50.34 MB/s
Wrote block=150000, file,blk=316,59 VolBytes=314,570,702,848 rate=50.31 MB/s
18:49:03 Flush block, write EOF
Wrote block=155000, file,blk=326,299 VolBytes=325,056,462,848 rate=50.45 MB/s
Wrote block=160000, file,blk=337,63 VolBytes=335,542,222,848 rate=50.45 MB/s
Wrote block=165000, file,blk=347,303 VolBytes=346,027,982,848 rate=49.58 MB/s
Wrote block=170000, file,blk=358,67 VolBytes=356,513,742,848 rate=49.61 MB/s
Wrote block=175000, file,blk=368,307 VolBytes=366,999,502,848 rate=49.52 MB/s
Wrote block=180000, file,blk=379,71 VolBytes=377,485,262,848 rate=49.64 MB/s
19:12:33 Flush block, write EOF
Wrote block=185000, file,blk=389,311 VolBytes=387,971,022,848 rate=49.47 MB/s
Wrote block=190000, file,blk=400,75 VolBytes=398,456,782,848 rate=49.56 MB/s
Wrote block=195000, file,blk=410,315 VolBytes=408,942,542,848 rate=49.47 MB/s
Wrote block=200000, file,blk=421,79 VolBytes=419,428,302,848 rate=49.36 MB/s
Wrote block=205000, file,blk=431,319 VolBytes=429,914,062,848 rate=49.37 MB/s
Wrote block=210000, file,blk=442,83 VolBytes=440,399,822,848 rate=49.26 MB/s
19:34:42 Flush block, write EOF
Wrote block=215000, file,blk=452,323 VolBytes=450,885,582,848 rate=49.34 MB/s
Wrote block=220000, file,blk=463,87 VolBytes=461,371,342,848 rate=49.23 MB/s
Wrote block=225000, file,blk=473,327 VolBytes=471,857,102,848 rate=49.26 MB/s
Wrote block=230000, file,blk=484,91 VolBytes=482,342,862,848 rate=49.24 MB/s
Wrote block=235000, file,blk=494,331 VolBytes=492,828,622,848 rate=49.20 MB/s
Wrote block=240000, file,blk=505,95 VolBytes=503,314,382,848 rate=49.26 MB/s
19:59:20 Flush block, write EOF
Wrote block=245000, file,blk=515,335 VolBytes=513,800,142,848 rate=48.50 MB/s
Wrote block=250000, file,blk=526,99 VolBytes=524,285,902,848 rate=48.70 MB/s
Wrote block=255000, file,blk=536,339 VolBytes=534,771,662,848 rate=48.65 MB/s
16-Nov 20:08 btape JobId 0: End of Volume "TestVolume1" at 543:330 on device 
"drv1" (/dev/nst1). Write of 2097152 bytes got -1.
16-Nov 20:08 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2702 Last block at: 543:329 this_dev_block_num=330
btape: btape.c:2737 End of tape 543:0. Volume Bytes=541,740,498,944. Write rate 
= 48.76 MB/s
16-Nov 20:08 btape JobId 0: End of medium on Volume "TestVolume1" 
Bytes=541,740,498,944 Blocks=258,322 at 16-Nov-2010 20:08.
16-Nov 20:08 btape JobId 0: 3307 Issuing autochanger "unload slot 1, drive 0" 
command.
16-Nov 20:10 btape JobId 0: 3301 Issuing autochanger "loaded? drive 0" command.
16-Nov 20:10 btape JobId 0: 3302 Autochanger "loaded? drive 0", result: nothing 
loaded.
16-Nov 20:10 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive 0" 
command.
16-Nov 20:10 btape JobId 0: 3305 Autochanger "load slot 2, drive 0", status is 
OK.
Wrote Volume label for volume "TestVolume2".
16-Nov 20:11 btape JobId 0: Wrote label to prelabeled Volume "TestVolume2" on 
device "drv1" (/dev/nst1)
16-Nov 20:11 btape JobId 0: New volume "TestVolume2" mounted on device "drv1" 
(/dev/nst1) at 16-Nov-2010 20:11.
btape: btape.c:2311 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
Wrote End of Session label.
btape: btape.c:2380 Wrote state file last_block_num1=329 last_block_num2=49
btape: btape.c:2398
20:11:55 Done filling tapes at 2:51. Now beginning re-read of first tape ...
btape: btape.c:2476 Enter do_unfill
16-Nov 20:11 btape JobId 0: 3307 Issuing autochanger "unload slot 2, drive 0" 
command.
16-Nov 20:13 btape JobId 0: 3304 Issuing autochanger "load slot 1, drive 0" 
command.
16-Nov 20:14 btape JobId 0: 3305 Autochanger "load slot 1, drive 0", status is 
OK.
16-Nov 20:14 btape JobId 0: Ready to read from volume "TestVolume1" on device 
"drv1" (/dev/nst1).
Rewinding.
Reading the first 10000 records from 0:0.
10000 records read now at 1:157
Reposition from 1:157 to 543:329
Reading block 329.
 
The last block of the first tape matches.
 
16-Nov 20:15 btape JobId 0: 3307 Issuing autochanger "unload slot 1, drive 0" 
command.
16-Nov 20:17 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive 0" 
command.
16-Nov 20:18 btape JobId 0: 3305 Autochanger "load slot 2, drive 0", status is 
OK.
16-Nov 20:18 btape JobId 0: Ready to read from volume "TestVolume2" on device 
"drv1" (/dev/nst1).
Reposition from 0:0 to 0:1
Reading block 1.
 
The first block on the second tape matches.
 
Reposition from 0:2 to 2:49
Reading block 49.
 
The last block on the second tape matches. Test succeeded.



#
# Tandberg StorageLibrary T80+ (stage 2)
#
Autochanger {
        Name                            = lib1
        Device                          = drv1
        Device                          = drv2
        Changer Command                 = "/etc/bacula/scripts/mtx-changer %c 
%o %S %a %d"
        Changer Device                  = /dev/backup/changer
}

Device {
        Name                            = drv1
        Drive Index                     = 0
        Media Type                      = LTO-4
        Device Type                     = Tape
        Archive Device                  = /dev/nst1
        AutomaticMount                  = yes
        AlwaysOpen                      = yes
        RemovableMedia                  = yes
        RandomAccess                    = no
        AutoChanger                     = yes
        Autoselect                      = yes
        Maximum block size              = 2097152
        Maximum Network Buffer Size     = 262144
        Alert Command                   = "sh -c 'tapeinfo -f /dev/nst1 | 
/bin/sed -n /TapeAlert/p'"
        Spool Directory                 = /var/bacula/spool/drv1
}

Device {
        Name                            = drv2
        Drive Index                     = 1
        Media Type                      = LTO-4
        Device Type                     = Tape
        Archive Device                  = /dev/nst0
        AutomaticMount                  = yes
        AlwaysOpen                      = yes
        RemovableMedia                  = yes
        RandomAccess                    = no
        AutoChanger                     = yes
        Autoselect                      = yes
        Maximum block size              = 2097152
        Maximum Network Buffer Size     = 262144
        Alert Command                   = "sh -c 'tapeinfo -f /dev/nst0 
|/bin/sed -n /TapeAlert/p'"
        Spool Directory                 = /var/bacula/spool/drv2
}

Regards,
Lukas



------------------------------------------------------------------------------
Beautiful is writing same markup. Internet Explorer 9 supports
standards for HTML5, CSS3, SVG 1.1,  ECMAScript5, and DOM L2 & L3.
Spend less time writing and  rewriting code and more time creating great
experiences on the web. Be a part of the beta today
http://p.sf.net/sfu/msIE9-sfdev2dev
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users

<Prev in Thread] Current Thread [Next in Thread>