What is your NET_BUFFER_SZ set to?
If it's not set try this:
winnipeg:/opt/openv/netbackup>$ cat /opt/openv/netbackup/NET_BUFFER_SZ
262144
Previously i had it set to the default value(i think it's 32k). Apparently
this needs to be set high when doing a dupplication.
Karl-Frédéric Rössing
Technical Analyst
Federated Insurance Companies of Canada
http://www.federated.ca
"Donaldson, Mark" <Mark.Donaldson AT experianems DOT com>
Sent by: veritas-bu-admin AT mailman.eng.auburn DOT edu
04/02/2002 12:11 PM
To: "Veritasbu (E-mail)" <veritas-bu AT mailman.eng.auburn DOT edu>
cc:
Subject: [Veritas-bu] Duplication - 6 hours for one 230M
fragment!
I create offsite backups by duplicating a select set of backup images.
These images were laid down as multiplexed backups from a half dozen
servers in several different classes. I have only one master/media server
(v3.4.1 on Sol 2.6), the duplications therefore are taking place within
the library (DTL7000) that created them.
When I duplicate these images, I specifically don't use the -mpx option on
bpduplicate. It seemed to put more tape drives in service and I'm trying
to keep a some of them in reserve for other activities.
My problem, the duplication of 10 images (less than 350G) has been running
for 5 days now. Way too long - big time way too long. One image
duplication (~5Gig, 280000 files) took 17 hours to duplicate.
If you look at the bptm log snippet below, it's more than six hours from
start to finish for one fragment.
>From "read_backup: begin" to "read_backup: successfully read" is 371
minutes. The machine says the read-rate was 180 Kbytes/sec but some quick
math says 234496 KB in 371 minutes averages merely 6.4 KB/sec.
By the way, all the fragments for this image were arranged sequentially on
the same tape according to the logged positioning info so I don't think
it's a positioning/mechanical delay.
Most of the big time delays were flanked by this pair of notes:
02:58:20 [25598] <2> get_tape_position_for_read: absolute block position
prior to reading is 82012
09:07:54 [25598] <2> read_data: stopping mpx read because 234496 Kbytes of
234496 were read
I've been searching the support site and found technote 243197 about
NET_BUFFER_SZ and adjusted that yesterday to match my SIZE_DATA_BUFFERS
setting. I haven't seen a significant change from this but, frankly, it's
still early - the first bptm child since this change just started about 2
hours ago.
So - basically - does anybody know what's going on with this?
-Mark
Here's just one fragment from bptm log...
02:58:20 [25598] <2> read_backup: current media id is 000351, next media
id is 0
00351
02:58:20 [25598] <2> io_position_for_read: positioning 000351 to file
number 13
02:58:20 [25598] <2> io_read_back_header: drive index 3, reading backup
header
02:58:20 [25598] <2> io_read_back_header: drive index 3, reading backup
header
02:58:20 [25598] <2> io_read_back_header: drive index 3, reading backup
header
02:58:20 [25598] <2> io_read_back_header: drive index 3, reading backup
header
02:58:20 [25598] <2> io_position_for_read: successfully positioned 000351
to fil
e number 13, mpx_header = 1
02:58:20 [25598] <2> getsockconnected: host=backup00 service=bpdbm
address=192.1
68.1.30 protocol=tcp non-reserved port=13721
02:58:20 [25598] <4> read_backup: begin reading backup id
tools00.lodo_101727692
3 (duplicate), copy 1, fragment 11 from media id 000351 on drive index 3
02:58:20 [25598] <2> read_data: last_frag = 0, opt_bytes_left = 0,
tape_Kbytes_l
eft = 234496, opt_remainder = 0
02:58:20 [25598] <2> get_tape_position_for_read: absolute block position
prior t
o reading is 82012
09:07:54 [25598] <2> read_data: stopping mpx read because 234496 Kbytes of
23449
6 were read
09:07:54 [25598] <2> io_ioctl: command (1)MTFSF 1 from (bptm.c.9438) on
drive in
dex 3
09:09:14 [25598] <2> read_data: waited for empty buffer 0 times, delayed 0
times
09:09:14 [25598] <2> getsockconnected: host=backup00 service=bpdbm
address=192.1
68.1.30 protocol=tcp non-reserved port=13721
09:09:14 [25598] <4> read_backup: successfully read (duplicate) backup id
tools0
0.lodo.in.exactis.com_1017276923, copy 1, fragment 11, 234496 Kbytes at
180.137
Kbytes/sec
|