11/14/2016 18:32:23 - requesting resource LCM_nbsrv01-hcart3-robot-tld-0
11/14/2016 18:32:23 - Info nbrb (pid=7612) Limit has been reached for the logical resource LCM_nbsrv01-hcart3-robot-tld-0
11/15/2016 15:26:07 - begin Duplicate
11/15/2016 15:26:07 - granted resource  LCM_nbsrv01-hcart3-robot-tld-0
11/15/2016 15:26:07 - started process RUNCMD (pid=17656)
11/15/2016 15:26:07 - ended process 0 (pid=17656)
11/15/2016 15:26:08 - requesting resource nbsrv01-hcart3-robot-tld-0
11/15/2016 15:26:08 - requesting resource @aaaac
11/15/2016 15:26:08 - reserving resource @aaaac
11/15/2016 15:26:08 - awaiting resource nbsrv01-hcart3-robot-tld-0. No drives are available.
11/16/2016 10:54:07 - resource @aaaac reserved
11/16/2016 10:54:07 - granted resource  1005L6
11/16/2016 10:54:07 - granted resource  IBM.ULT3580-HH6.001
11/16/2016 10:54:07 - granted resource  nbsrv01-hcart3-robot-tld-0
11/16/2016 10:54:07 - granted resource  MediaID=@aaaac;DiskVolume=G:\;DiskPool=DAS_G;Path=G:\;StorageServer=nbsrv01.domain.local;MediaServer=nbsrv01.domain.local
11/16/2016 10:54:08 - Info bpduplicate (pid=17656) window close behavior: Suspend
11/16/2016 10:54:08 - Info bptm (pid=16808) start
11/16/2016 10:54:08 - started process bptm (pid=16808)
11/16/2016 10:54:11 - Info bptm (pid=16808) start backup
11/16/2016 10:54:11 - Info bpdm (pid=17128) started
11/16/2016 10:54:11 - started process bpdm (pid=17128)
11/16/2016 10:54:11 - Info bpdm (pid=17128) reading backup image
11/16/2016 10:54:11 - Info bpdm (pid=17128) using 30 data buffers
11/16/2016 10:54:11 - Info bpdm (pid=17128) requesting nbjm for media
11/16/2016 10:54:12 - Info bptm (pid=16808) Waiting for mount of media id 1005L6 (copy 2) on server nbsrv01.domain.local.
11/16/2016 10:54:12 - started process bptm (pid=16808)
11/16/2016 10:54:12 - mounting 1005L6
11/16/2016 10:54:12 - Info bptm (pid=16808) INF - Waiting for mount of media id 1005L6 on server nbsrv01.domain.local for writing.
11/16/2016 10:54:12 - begin reading
11/16/2016 10:54:58 - Info bptm (pid=16808) media id 1005L6 mounted on drive index 1, drivepath {4,0,2,0}, drivename IBM.ULT3580-HH6.001, copy 2
11/16/2016 10:54:58 - Info bptm (pid=16808) INF - Waiting for positioning of media id 1005L6 on server nbsrv01.domain.local for writing.
11/16/2016 10:57:34 - end reading; read time: 0:03:22
11/16/2016 10:57:34 - begin reading
11/16/2016 10:59:08 - end reading; read time: 0:01:34
11/16/2016 10:59:08 - begin reading
11/16/2016 11:00:45 - end reading; read time: 0:01:37
11/16/2016 11:00:45 - begin reading
11/16/2016 11:02:28 - end reading; read time: 0:01:43
11/16/2016 11:02:28 - begin reading
11/16/2016 11:03:59 - Info bptm (pid=16808) waited for full buffer 20791 times, delayed 29192 times
11/16/2016 11:04:05 - end reading; read time: 0:01:37
11/16/2016 11:04:05 - Info bptm (pid=16808) setting receive network buffer to 263168 bytes
11/16/2016 11:04:05 - Info bpdm (pid=17128) completed reading backup image
11/16/2016 11:04:11 - Info bpdm (pid=17128) using 30 data buffers
11/16/2016 11:04:11 - begin reading
11/16/2016 11:05:39 - end reading; read time: 0:01:28
11/16/2016 11:05:39 - begin reading
11/16/2016 11:06:48 - end reading; read time: 0:01:09
11/16/2016 11:06:48 - begin reading
11/16/2016 11:07:57 - end reading; read time: 0:01:09
11/16/2016 11:07:57 - begin reading
11/16/2016 11:09:27 - end reading; read time: 0:01:30
11/16/2016 11:09:27 - begin reading
11/16/2016 11:10:58 - end reading; read time: 0:01:31
11/16/2016 11:10:58 - begin reading
11/16/2016 11:12:31 - end reading; read time: 0:01:33
11/16/2016 11:12:31 - begin reading
11/16/2016 11:13:41 - end reading; read time: 0:01:10
11/16/2016 11:13:41 - begin reading
11/16/2016 11:15:09 - end reading; read time: 0:01:28
11/16/2016 11:15:09 - begin reading
11/16/2016 11:16:40 - end reading; read time: 0:01:31
11/16/2016 11:16:40 - begin reading
11/16/2016 11:18:03 - end reading; read time: 0:01:23
11/16/2016 11:18:03 - begin reading
11/16/2016 11:19:13 - end reading; read time: 0:01:10
11/16/2016 11:19:13 - begin reading
11/16/2016 11:19:14 - Info bptm (pid=16808) waited for full buffer 26363 times, delayed 53064 times
11/16/2016 11:19:18 - end reading; read time: 0:00:05
11/16/2016 11:19:18 - Info bptm (pid=16808) setting receive network buffer to 263168 bytes
11/16/2016 11:19:19 - Info bpdm (pid=17128) completed reading backup image
11/16/2016 11:19:24 - Info bpdm (pid=17128) using 30 data buffers
11/16/2016 11:19:24 - begin reading
11/16/2016 11:20:42 - end reading; read time: 0:01:18
11/16/2016 11:20:42 - begin reading
11/16/2016 11:22:11 - end reading; read time: 0:01:29
11/16/2016 11:22:11 - begin reading
11/16/2016 11:23:02 - Info bptm (pid=16808) waited for full buffer 8636 times, delayed 12264 times
11/16/2016 11:23:05 - end reading; read time: 0:00:54
11/16/2016 11:23:05 - Info bptm (pid=16808) setting receive network buffer to 263168 bytes
11/16/2016 11:23:05 - Info bpdm (pid=17128) completed reading backup image
11/16/2016 11:23:10 - Info bpdm (pid=17128) using 30 data buffers
11/16/2016 11:23:10 - begin reading
11/16/2016 11:24:25 - end reading; read time: 0:01:15
11/16/2016 11:24:25 - begin reading
11/16/2016 11:25:54 - end reading; read time: 0:01:29
11/16/2016 11:25:54 - begin reading
11/16/2016 11:26:19 - Info bptm (pid=16808) waited for full buffer 7818 times, delayed 11294 times
11/16/2016 11:26:23 - end reading; read time: 0:00:29
11/16/2016 11:26:23 - Info bptm (pid=16808) setting receive network buffer to 263168 bytes
11/16/2016 11:26:24 - Info bpdm (pid=17128) completed reading backup image
11/16/2016 11:26:24 - Info bpdm (pid=17128) EXITING with status 0
11/16/2016 11:26:29 - Info bptm (pid=16808) EXITING with status 0 <----------
11/16/2016 11:26:29 - end Duplicate; elapsed time 20:00:22
the requested operation was successfully completed  (0)