[Veritas-bu] SIZE/NUMBER_DATA_BUFFERS and slow duplications

We have 10 x 9840 FC tapes drives attached to Brocade Silkworm
switches. We're running NBU DataCentre 3.4 under NT 4.

I'm not so worried about our backup times, however, we are getting
really slow duplication times, and I mean really slow!

Our backups are multiplexed and we're using BPVault to do
our duplication, with multiplexing set to 1.

Here is part of the BPTM log from one of the Media Servers

10:57:07 [346.387] <2> write_backup: write_data() returned, exit_status = 0,
CINDEX = 1, backup_status = -6
10:57:07 [346.387] <2> io_ioctl: command (0)MTWEOF 1 from (../bptm.c.12584)
on drive index 3
10:57:07 [346.387] <2> write_backup: maximum fragment size written ---
Fragmenting
10:57:07 [346.387] <2> process_brm_msg: no pending message from bpbrm
10:57:07 [346.387] <2> write_data: absolute block position prior to writing
backup header(s) is 125010
10:57:07 [346.387] <2> io_write_back_header: drive index 3,
kwdpra01b_0997301578, file num = 5, mpx_headers = 1
10:57:07 [346.387] <2> write_data: completed writing backup header, start
writing data when first buffer is available
10:57:07 [346.387] <2> write_data: received first buffer (65536 bytes),
begin writing data
10:57:39 [244.376] <2> mpx_read_data: ReadFile returned FALSE, A tape access
reached a filemark. (1101);bytes = 0
10:57:39 [244.376] <2> mpx_read_data: ReadFile detected EOM or EOF, bytes =
0
10:57:39 [244.376] <2> mpx_read_data: waited for empty buffer 17844 times,
delayed 34819 times
10:57:39 [244.376] <2> mpx_advance_frags: advancing CINDEX 1 to fragment 35,
filenum 3, media id N00105
10:57:39 [244.376] <2> io_position_for_read: positioning N00105 to file
number 3
10:57:39 [244.376] <2> io_read_back_header: drive index 6, reading backup
header
10:57:39 [244.376] <2> io_position_for_read: successfully positioned N00105
to file number 3, mpx_header = 1
10:57:39 [244.376] <2> send_brm_msg: CURRENT POSITION N00105 3
10:57:39 [244.376] <2> process_brm_msg: no pending message from bpbrm
10:57:40 [244.376] <2> read_brm_msg: CONTINUE RESTORE
10:57:40 [244.376] <2> mpx_read_data: begin reading data from media id
N00105, file num 3
10:57:40 [244.376] <2> get_tape_position_for_read: absolute block position
prior to reading is 62507
11:01:24 [381.326] <2> bptm: INITIATING: -count -cmd -rt 1 -rn 6 -stunit
kwdbak40 -den 6 -mt 2 -masterversion 340000
11:01:24 [381.326] <2> bptm: EXITING with status 0 <----------
11:01:27 [159.113] <2> bptm: INITIATING: -delete_expired
11:01:27 [159.113] <2> bptm: EXITING with status 0 <----------
11:11:24 [385.300] <2> bptm: INITIATING: -count -cmd -rt 1 -rn 6 -stunit
kwdbak40 -den 6 -mt 2 -masterversion 340000
11:11:24 [385.300] <2> bptm: EXITING with status 0 <----------
11:11:25 [359.364] <2> bptm: INITIATING: -delete_expired
11:11:25 [359.364] <2> bptm: EXITING with status 0 <----------


My questions are:

1.      Are other people getting slow throughput when duplicating?

2.      Has anyone tried turning off multiplexing for the duplicates to see
        if this improves times?

3.      Does the entry in BPTM 10:57:39 [244.376] <2> mpx_read_data:
        waited for empty buffer 17844 times, delayed 34819 times indicate
        that I need to try tuning the size/number of data buffers.

        If so has anyone tried doing this in an environment with NT 4 NBU 
servers,
        Brocade Silkworm SAN switches and FC attached 9840s?


Thanks,

Andy Skates
Legal & General Assurance PLC

andyskates AT iname DOT com