10:57:33.022 [6800.6412] <2> bptm: INITIATING (VERBOSE = 0): -r -pid 7532 -c XXX-XXX -cl SQLServer_XXX-XXX-XXX -bt 1328895171 -b XXX-XXX-XXX -st 2 -mud 180 -dpath \\XXX-XXX\backup\SQL -hostname XXX-XXX -L /C/ProgramFilesx86/Veritas/NetBackup/Logs/user_ops/mssql/logs/0214112105714-11308-10136-000-000-prg -ru root -rclnt sek-sqltest2 -rclnthostname XXX-XXX -firstblk 0 -restoreid 153548.001 -lcmsg C -lctime C -no_callback -connect_options 0x01010100 -jobid 153548 -masterversion 710000 -flport 0 -flipc 54461 -S XXX-XXX 
10:57:33.022 [6800.6412] <2> vnet_pbxConnect: pbxConnectEx Succeeded
10:57:33.022 [6800.6412] <2> job_connect: SO_KEEPALIVE set on socket 720 for client sek-netbackup
10:57:33.022 [6800.6412] <2> logconnections: BPJOBD CONNECT FROM XXX.XXX.XXX.XXX.54473 TO XXX.XXX.XXX.XXX.1556 fd = 720
10:57:33.022 [6800.6412] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
10:57:33.022 [6800.6412] <2> job_connect: Connected to the host XXX-XXX contype 10 jobid <153548> socket <720>
10:57:33.022 [6800.6412] <2> job_connect: Connected on port 54473
10:57:33.022 [6800.6412] <2> vnet_same_host: ../../libvlibs/vnet_addrinfo.c.2926: 0: name2 is empty: 0 0x00000000
10:57:33.022 [6800.6412] <4> bptm: emmserver_name = XXX-XXX
10:57:33.022 [6800.6412] <4> bptm: emmserver_port = 1556
10:57:33.053 [6800.6412] <2> Orb::init: initializing ORB EMMlib_Orb with: dbstunitq -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:824)
10:57:33.053 [6800.6412] <2> Orb::init: caching EndpointSelectorFactory(../Orb.cpp:839)
10:57:33.069 [6800.6412] <4> report_client: VBRC 2 6800 0 XXX-XXX-XXX -1 SQLServer_XXX-XXX-XXX 2 *NULL* 0 1 1 
10:57:33.069 [6800.6412] <2> LOCAL CLASS_ATT_DEFS: Product ID = 6
10:57:33.084 [6800.6412] <2> ConnectionCache::connectAndCache: Acquiring new connection for host XXX-XXX, query type 81
10:57:33.084 [6800.6412] <2> vnet_pbxConnect: pbxConnectEx Succeeded
10:57:33.084 [6800.6412] <2> logconnections: BPDBM CONNECT FROM XXX.XXX.XXX.XXX.54477 TO XXX.XXX.XXX.XXX.1556 fd = 960
10:57:33.209 [6800.6412] <2> db_end: Need to collect reply
10:57:33.209 [6800.6412] <2> read_backup: path \\XXX-XXX\backup\SQL\XXX-XXX-XXX (242179104 Kbytes) being considered for restore
10:57:33.209 [6800.6412] <2> io_set_sendbuf: setting send network buffer to 525312 bytes
10:57:33.209 [6800.6412] <2> read_config_file: using 48 value from C:\Program Files\Veritas\NetBackup\db\config\NUMBER_DATA_BUFFERS
10:57:33.209 [6800.6412] <2> read_config_file: using 48 value from C:\Program Files\Veritas\NetBackup\db\config\NUMBER_DATA_BUFFERS_DISK
10:57:33.209 [6800.6412] <2> io_init: using 48 data buffers
10:57:33.209 [6800.6412] <2> io_init: buffer size for read is 262144
10:57:33.209 [6800.6412] <2> io_init: child delay = 10, parent delay = 15 (milliseconds)
10:57:33.225 [6800.6412] <2> create_shared_memory: Created "Global\NetBackup Media Manager SHM Path 331766920 6800" shared memory file.
10:57:33.225 [6800.6412] <2> create_shared_memory: shm_size = 12584128, buffer address = 0x0000000003300000, buf control = 0x0000000003F00000, ready ptr = 0x0000000003F00480, res_cntl = 0x0000000003F00488
10:57:33.225 [6800.6412] <2> read_backup: restore child process is pid 5876.2860
10:57:33.240 [6800.6412] <2> bp_sts_get_lsu: entry \\XXX-XXX\backup\SQL
10:57:33.365 [6800.6412] <2> construct_sts_isid: master_server XXX-XXX, client XXX-XXX, backup_time 1328895171, copy_number 1, stream_number 0, fragment_number 1, resume_number 0, spl_name NULL
10:57:33.427 [6800.6412] <2> io_open_disk: file XXX-XXX-XXX successfully opened
10:57:33.427 [6800.6412] <4> report_throughput: VBRT 1 6800 0 1 \\sek-dd01\backup\SQL *NULL* 0 1 0 0  0 (bptm.c.11652)
10:57:33.427 [6800.6412] <2> read_client: dname=., offline=0, online_at=0
10:57:33.427 [6800.6412] <2> read_client: dname=.., offline=0, online_at=0
10:57:33.427 [6800.6412] <2> read_client: dname=CO_0, offline=0, online_at=0
10:57:33.427 [6800.6412] <2> read_client: dname=host_info, offline=0, online_at=0
10:57:33.427 [6800.6412] <2> read_client: dname=OA_2147483647, offline=0, online_at=2147483647
10:57:33.427 [6800.6412] <2> db_freeEXDB_INFO: ?
10:57:33.443 [6800.6412] <2> vnet_pbxConnect: pbxConnectEx Succeeded
10:57:33.443 [6800.6412] <2> logconnections: BPCD CONNECT FROM XXX.XXX.XXX.XXX.54485 TO XXX.XXX.XXX.XXX.1556 fd = 1132
10:57:33.443 [6800.6412] <2> vnet_pbxConnect: pbxConnectEx Succeeded
10:57:33.474 [6800.6412] <2> do_pbx_service: ../../libvlibs/vnet_connect.c.1776: 0: via PBX: VNETD CONNECT FROM XXX.XXX.XXX.XXX.54486 TO XXX.XXX.XXX.XXX.1556 fd = 1140
10:57:33.474 [6800.6412] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.445: 0: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
10:57:33.661 [6800.6412] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.462: 0: ipc_string: 54657
10:57:35.065 [6800.6412] <2> signal_parent: set bpbrm media ready event (pid = 7532)
10:57:35.065 [6800.6412] <2> read_backup: copy 1, fragment 1 is the last fragment for restore
10:57:35.081 [6800.6412] <4> read_backup: begin reading backup id sek-sql-vs03_1328895171 (restore), copy 1, fragment 1, from media id  on drive  (index -1)
10:57:35.081 [6800.6412] <2> read_data: last_frag = 1, opt_bytes_left = 0, tape_Kbytes_left = 242179104, opt_remainder = 0
10:57:35.081 [6800.6412] <2> read_data: Total Kbytes transferred 0
11:17:39.885 [6800.6412] <4> report_throughput: VBRT 1 6800 0 1 \\XXX-XXX\backup\SQL *NULL* 0 1 0 17943296  17943552 (bptm.c.14435)
11:17:39.885 [6800.6412] <2> read_data: Total Kbytes transferred 17943552
11:37:40.383 [6800.6412] <4> report_throughput: VBRT 1 6800 0 1 \\XXX-XXX\backup\SQL *NULL* 0 1 0 24921600  24921600 (bptm.c.14435)
11:37:40.383 [6800.6412] <2> read_data: Total Kbytes transferred 42865152
11:57:40.117 [6800.6412] <4> report_throughput: VBRT 1 6800 0 1 \\XXX-XXX\backup\SQL *NULL* 0 1 0 24891392  24891392 (bptm.c.14435)
11:57:40.117 [6800.6412] <2> read_data: Total Kbytes transferred 67756544
12:17:50.709 [6800.6412] <4> report_throughput: VBRT 1 6800 0 1 \\XXX-XXX\backup\SQL *NULL* 0 1 0 13533184  13533184 (bptm.c.14435)
12:17:50.709 [6800.6412] <2> read_data: Total Kbytes transferred 81289728
12:38:00.536 [6800.6412] <4> report_throughput: VBRT 1 6800 0 1 \\XXX-XXX\backup\SQL *NULL* 0 1 0 23290368  23290368 (bptm.c.14435)
12:38:00.536 [6800.6412] <2> read_data: Total Kbytes transferred 104580096