Backup Client on different subnet is very slow

What version of NetBackup, what type of backup too?

Do you have the bptm log from the media server and the bpbkar log from the client? If you do please post this up. Also did you test copy FROM the client TO the media server (and not from the media to the client) ?

Hello

    I tested copy from/to media server from/to client.

I will post bptm and bpbkar

Thank you.

You need to test the copy from the client to the media server, that is the direction where the data is flowing.

A copy between source and destination, is that may small files like the backup or is it one single big file ?

The number of files and size do a diffrence in speed.

I tested the sam folder.

thank you.

one moe thing , it took several minutes before the actual transfer occured.

/3/2015 8:12:15 PM - Info nbjm(pid=3866964) starting backup job (jobid=12923) for client cofsvrt1, policy COFSVR_TEMP, schedule full 
8/3/2015 8:12:15 PM - Info nbjm(pid=3866964) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=12923, request id:{14D35C8C-39E1-11E5-812E-1E9930320000}) 
8/3/2015 8:12:15 PM - requesting resource backupsvr02-disk-z-DAILY_FILE
8/3/2015 8:12:15 PM - requesting resource backupsvr.NBU_CLIENT.MAXJOBS.cofsvrt1
8/3/2015 8:12:15 PM - requesting resource backupsvr.NBU_POLICY.MAXJOBS.COFSVR_TEMP
8/3/2015 8:12:15 PM - granted resource backupsvr.NBU_CLIENT.MAXJOBS.cofsvrt1
8/3/2015 8:12:15 PM - granted resource backupsvr.NBU_POLICY.MAXJOBS.COFSVR_TEMP
8/3/2015 8:12:15 PM - granted resource MediaID=@aaaag;Path=Z:\nbu_disk_stu\DAILY_FILE;MediaServer=backupsvr02
8/3/2015 8:12:15 PM - granted resource backupsvr02-disk-z-DAILY_FILE
8/3/2015 8:12:15 PM - started
8/3/2015 8:12:16 PM - estimated 31462863 Kbytes needed
8/3/2015 8:12:16 PM - Info nbjm(pid=3866964) started backup (backupid=cofsvrt1_1438607458) job for client cofsvrt1, policy COFSVR_TEMP, schedule full on storage unit backupsvr02-disk-z-DAILY_FILE
8/3/2015 8:12:17 PM - started process bpbrm (4460)
8/3/2015 8:12:18 PM - connecting
8/3/2015 8:12:19 PM - connected; connect time: 0:00:01
8/3/2015 8:12:25 PM - begin writing
8/3/2015 8:13:35 PM - Info bpbrm(pid=4460) cofsvrt1 is the host to backup data from    
8/3/2015 8:13:35 PM - Info bpbrm(pid=4460) reading file list for client       
8/3/2015 8:13:35 PM - Info bpbrm(pid=4460) starting bpbkar32 on client        
8/3/2015 8:13:36 PM - Info bpbkar32(pid=6196) Backup started          
8/3/2015 8:13:36 PM - Info bpbkar32(pid=6196) change time comparison:<disabled>         
8/3/2015 8:13:36 PM - Info bpbkar32(pid=6196) archive bit processing:<enabled>         
8/3/2015 8:13:36 PM - Info bpbkar32(pid=6196) not using change journal data for <C:\Users\sqlman\Desktop\software>: not enabled   
8/3/2015 8:13:36 PM - Info bptm(pid=1728) start           
8/3/2015 8:13:41 PM - Info bptm(pid=1728) using 262144 data buffer size       
8/3/2015 8:13:41 PM - Info bptm(pid=1728) setting receive network buffer to 1049600 bytes     
8/3/2015 8:13:41 PM - Info bptm(pid=1728) using 64 data buffers        
8/3/2015 8:13:41 PM - Info bptm(pid=1728) start backup          
8/3/2015 8:13:42 PM - Info bptm(pid=1728) backup child process is pid 5112.4996      
8/3/2015 8:13:42 PM - Info bptm(pid=5112) start           
8/3/2015 8:22:48 PM - end writing; write time: 0:10:23
8/3/2015 8:24:05 PM - Info bpbkar32(pid=6196) done. status: 150: termination requested by administrator     
termination requested by administrator (150)
8/3/2015 8:24:07 PM - Info bpbrm(pid=5444) Starting delete snapshot processing        
8/3/2015 8:25:04 PM - Info bpfis(pid=2428) Backup started          
8/3/2015 8:25:04 PM - Critical bpbrm(pid=5444) from client cofsvrt1: cannot open C:\Program Files\Veritas\NetBackup\online_util\fi_cntl\bpfis.fim.cofsvrt1_1438607458.1.0     
8/3/2015 8:25:04 PM - Info bpfis(pid=2428) done. status: 4207         
8/3/2015 8:25:04 PM - end operation
8/3/2015 8:25:04 PM - Info bpfis(pid=2428) done. status: 4207: Could not fetch snapshot metadata or state fil

NBU master /media/client  7.6.1

on the client, we install SFHA on windows 2012 R2 server.

we backup normal file.

How about the firewall on the client ? we seen initiations when netbackup has to switch from pbx on 1556 to the legacy vnetd on 13724 because the client firewall blocked the pbx 1556 connections. Easy to see with bptestbpcd from master and media servers

bpbkar  on the client

20:23:28.198 [6576.6008] <4> ov_log::OVInit: INF - Starting log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\080315.log

20:23:28.198 [6576.6008] <4> ov_log::OVInit: GENERAL Log Level (Effective): 0
20:23:28.198 [6576.6008] <4> ov_log::OVInit: TCP Log Level (Effective): 0
20:23:28.198 [6576.6008] <8> OVLog: BPBKAR  NetBackup Backup/Archive  7.6GA  [Oct 27 2014]

20:23:28.198 [6576.6008] <8> OVLog: Copyright c 1993 - 2014 Symantec Corporation, All Rights Reserved.
All Rights Reserved.

20:23:28.198 [6576.6008] <2> WinMain: BPBKAR_VERBOSE Debug log level: Actual=0, Effective=0
20:23:28.198 [6576.6008] <2> WinMain: DAT - _pgmptr = 'C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe'
20:23:28.198 [6576.6008] <2> WinMain: DAT - lpCmdLine = '-r 604800 -ru root -dt 0 -to 0 -bpstart_time 1438608417 -clnt cofsvrt1 -class COFSVR_TEMP -sched full -st FULL -bpstart_to 300 -bpend_to 300 -read_to 300 -blks_per_buffer 512 -use_otm -fso -b cofsvrt1_1438608116 -kl 150 -WOFB_enabled -WOFB_fim 0 -WOFB_usage 0 -WOFB_error 0 -ct 13 -use_ofb '
20:23:28.198 [6576.6008] <2> date_debug: DAT - timezone: SE Asia Standard Time, offset=-25200, dst: NONE
20:23:28.198 [6576.6008] <2> date_debug: DAT - current time: 1438608208, 8/3/2015 8:23:28 PM
20:23:28.198 [6576.6008] <2> date_debug: DAT - 01/01/94 UCT:  757382400, 1/1/1994 7:00:00 AM
20:23:28.198 [6576.6008] <2> date_debug: DAT - 07/01/94 UCT:  773020800, 7/1/1994 7:00:00 AM
20:23:28.198 [6576.6008] <2> WinMain: DAT - standard input handle = 732
20:23:28.213 [6576.6008] <2> WinMain: DAT - standard input handle is NOT resilient socket.
20:23:28.213 [6576.6008] <2> WinMain: DAT - standard output handle = 380
20:23:28.213 [6576.6008] <2> WinMain: DAT - standard output handle is NOT resilient socket.
20:23:28.213 [6576.6008] <2> WinMain: DAT - standard error handle = 500
20:23:28.213 [6576.6008] <2> WinMain: DAT - standard error handle is NOT resilient socket.
20:23:28.213 [6576.6008] <4> tar_backup::V_SetupJobData: INF - dwJobData: ffffffff
20:23:28.213 [6576.6008] <4> tar_backup::V_SetupJobData: INF -     dwJob: ffffffff
20:23:28.213 [6576.6008] <4> dos_backup::V_PreProcessing: INF - backup privileges enabled, previous = 0
20:23:28.229 [6576.6008] <4> dos_backup::V_PreProcessing: INF - restore privileges enabled, previous = 0
20:23:28.229 [6576.6008] <4> dos_backup::V_PreProcessing: INF - security privileges enabled, previous = 0
20:23:28.229 [6576.6008] <4> dos_backup::V_PreProcessing: INF - tcb privileges enabled, previous = 0
20:23:28.229 [6576.6008] <4> dos_backup::V_PreProcessing: INF - create token privileges enabled, previous = 0
20:23:28.229 [6576.6008] <4> dos_backup::V_PreProcessing: INF - user name: root
20:23:28.229 [6576.6008] <4> dos_backup::V_PreProcessing: INF - no access token: scheduled backup
20:23:28.229 [6576.6008] <2> ov_log::V_GlobalLog: WRN - ubsVerifyMIS():Microsoft Exchange Information Store is not installed.
20:23:28.229 [6576.6008] <2> ov_log::V_GlobalLog: INF - BEDS_Init() Enter InitFlags:0x0
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: C:
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: D:
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: EFI>System>Partition
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Terminal Services
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Windows Network
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: NFS Network
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: COFSVRT1\Microsoft SQL Server Instances
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpChildDleInfo() Child DLE Device Name: COFSVRT1\MSSQLSERVER
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: System?State
20:23:28.354 [6576.6008] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Active Directory Application Mode
20:23:28.448 [6576.6008] <2> tar_base::V_vTarMsgW: INF - BACKUP START 6576
20:23:28.448 [6576.6008] <2> tar_base::V_vTarMsgW: JBD - change time comparison:<disabled>
20:23:28.448 [6576.6008] <2> tar_base::V_vTarMsgW: JBD - archive bit processing:<enabled>
20:23:28.448 [6576.6008] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received
20:23:28.448 [6576.6008] <2> tar_base::V_vTarMsgW: INF - CONTINUE BACKUP message received
20:23:28.463 [6576.6008] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = C:\Users\sqlman\Desktop\software
20:23:28.463 [6576.7576] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds
20:23:28.479 [6576.6008] <2> tar_backup_vxbsa::add: INF - called with 'C:\Users\sqlman\Desktop\software'
20:23:28.479 [6576.6008] <2> _expand_root: INF - checking for root expansion:<C:\Users\sqlman\Desktop\software>
20:23:28.479 [6576.6008] <2> _fix_registry: INF - checking for registry expansion:<C:\Users\sqlman\Desktop\software>
20:23:28.479 [6576.6008] <4> dos_backup::V_VerifyFileSystem: INF - corrected name:<C:\Users\sqlman\Desktop\software>
20:23:28.479 [6576.6008] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'C:\Users\sqlman\Desktop\software' --> 10020002
20:23:28.479 [6576.6008] <2> VxCJUtilGetParams: INF - GetVolumePathName for <C:\Users\sqlman\Desktop\software> returned <C:\>
20:23:28.479 [6576.6008] <2> VxCJUtilGetParams: INF - GetVolumeNameForVolumeMountPoint for <C:\> returned <\\?\Volume{5ecb4c02-7841-4f95-89f1-77f4547d1e7f}\>
20:23:28.479 [6576.6008] <2> tar_base::V_vTarMsgW: JBD - not using change journal data for <C:\Users\sqlman\Desktop\software>: not enabled
20:23:28.479 [6576.6008] <4> dos_backup::V_Initialize: INF - did not create change journal collection, not needed
20:27:16.528 [6576.6008] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'
20:27:16.528 [6576.6008] <4> tar_backup_tfi::UpdateExcludeListWithVHD: INF - UpdateExludeListWithVHD begin
20:27:16.559 [6576.6008] <4> tar_backup_tfi::backup_arg_state: INF - remember start error count: 0
20:27:16.559 [6576.6008] <4> tar_backup_tfi::backup_arg_state: INF - remember start fatal count: 0
20:27:16.559 [6576.6008] <4> dos_backup::tfs_scanstart: INF - starting scan for file directive:<C:\Users\sqlman\Desktop\software>
20:27:16.559 [6576.6008] <4> dos_backup::tfs_scanstart: INF - starting scan using name:<C:\Users\sqlman\Desktop\software>
20:27:16.559 [6576.6008] <4> dos_backup::tfs_scanstart: INF - in 'backup' mode
20:27:16.559 [6576.6008] <2> tar_base::V_vTarMsgW: INF - Enabling volume snapshots for (C:\Users\sqlman\Desktop\software), please wait...
20:27:16.559 [6576.6008] <4> V_DetermineMountInfo: INF - Checking Volume \\?\Volume{5ecb4c02-7841-4f95-89f1-77f4547d1e7f}\ for '\Users\sqlman\Desktop\software'
20:27:16.559 [6576.6008] <4> V_DetermineMountInfo: INF -   Adding NTFS Volume C:\ ==> \\?\Volume{5ecb4c02-7841-4f95-89f1-77f4547d1e7f}\
20:27:16.559 [6576.6008] <4> V_Snapshot::V_Snapshot_CreateSnapshot: INF - ======================================================================
20:27:16.559 [6576.6008] <4> V_Snapshot::V_Snapshot_CreateSnapshot: INF - Attempting to create snapshots for 'C:\Users\sqlman\Desktop\software'
20:27:16.559 [6576.6008] <4> V_Snapshot::V_Snapshot_CreateSnapshot: INF - CREATE request: "C:\Program Files\Veritas\NetBackup\bin\bpfis.exe" create -owner NBU -fso -WOFB -fim VSS:prov_type=1,snap_attr=0,max_snapshots=1 -id cofsvrt1_1438608116 -nbu_version 123797504 "C:\Users\sqlman\Desktop\software"
20:31:25.097 [6576.6008] <4> V_Snapshot::V_Snapshot_AddMappings: INF - input parameters:
 source path:<C:\Users\sqlman\Desktop\software>
   snap path:<\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy15\Users\sqlman\Desktop\software>
  mount path:<(null)>
20:31:25.097 [6576.6008] <4> V_Snapshot::V_GetSourceVolume: INF - input parameters:
   source:<C:\Users\sqlman\Desktop\software>
 snapshot:<\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy15\Users\sqlman\Desktop\software>
20:31:25.129 [6576.6008] <4> V_Snapshot::V_Snapshot_AddMappings: INF - Volume Snapshot Mapping: \\?\Volume{5ecb4c02-7841-4f95-89f1-77f4547d1e7f}\ --> GLOBALROOT\Device\HarddiskVolumeShadowCopy15
20:31:25.129 [6576.6008] <4> V_Snapshot::V_Snapshot_ParseBpfisOutput: INF - Snapshot creation, FIS_ID: cofsvrt1_1438608116
20:31:25.129 [6576.6008] <4> V_Snapshot::V_Snapshot_CreateSnapshot: INF - Snapshot creation was successful
20:31:25.129 [6576.6008] <4> V_Snapshot::V_Snapshot_CreateSnapshot: INF - Snapshot provider: VSS
20:31:25.129 [6576.6008] <4> V_Snapshot::V_Snapshot_CreateSnapshot: INF - ======================================================================
20:31:25.129 [6576.6008] <2> tar_base::V_vTarMsgW: INF - Volume snapshots enabled
20:33:01.894 [6576.6008] <4> dos_backup::tfs_scannext: INF - no more path list entries
20:33:01.894 [6576.6008] <4> tar_backup::backup_endarg_state: INF - finish error count: 0
20:33:01.894 [6576.6008] <4> tar_backup::backup_endarg_state: INF - finish fatal count: 0
20:33:01.894 [6576.6008] <4> V_Snapshot::V_Snapshot_Destroy: INF - Attempting to destroy volume snapshots: bpfis delete -id cofsvrt1_1438608116 -copy 1 -WOFB
20:37:09.604 [6576.6008] <4> V_Snapshot::V_Snapshot_Destroy: INF - Snapshot Destroy EXIT STATUS 0: the requested operation was successfully completed

20:37:09.604 [6576.6008] <2> tar_base::backup_finish: TAR - backup:                     221 files
20:37:09.604 [6576.6008] <2> tar_base::backup_finish: TAR - backup:          file data:  306854409 bytes  5 gigabytes
20:37:09.604 [6576.6008] <2> tar_base::backup_finish: TAR - backup:         image data:  307590144 bytes  5 gigabytes
20:37:09.604 [6576.6008] <2> tar_base::backup_finish: TAR - backup:       elapsed time:        593 secs      9572174 bps
20:37:09.604 [6576.6008] <4> tar_backup::backup_done_state: INF - number of file directives not found: 0
20:37:09.604 [6576.6008] <4> tar_backup::backup_done_state: INF -     number of file directives found: 1
20:37:09.604 [6576.7576] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0)
20:37:09.604 [6576.6008] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0)
20:37:09.604 [6576.6008] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 0: the requested operation was successfully completed
20:37:12.651 [6576.6008] <4> dos_backup::ClearDFSRArchiveBits: INF - no DFSR file list was created, No bits cleared.
20:37:12.651 [6576.6008] <4> dos_backup::tfs_reset: INF - Snapshot deletion start
20:37:12.651 [6576.6008] <4> OVStopCmd: INF - EXIT - status = 0
20:37:12.651 [6576.6008] <2> tar_base::V_Close: closing...
20:37:12.651 [6576.6008] <4> dos_backup::tfs_reset: INF - Snapshot deletion start
20:37:12.651 [6576.6008] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): enter - InitFlags:0x00000101
20:37:12.651 [6576.6008] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): ubs specifics: 0x001d0000
20:37:12.667 [6576.6008] <4> OVShutdown: INF - Finished process
20:37:12.667 [6576.6008] <4> WinMain: INF - Exiting C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe