Hello all,
I have Netbackup accelerator backups of Windows 2008 file server which fails when performing full schedules. Master server is 7.5, MSDP is 7.5.0.7, client server was 7.5.0.4, I installed 7.5.0.7 client patch but it did not resolve the issue. I have change journal enabled on client.
The problem is that I can perform the first full backup (I tried to completely uninstall Netbackup client), I can then perform incremental ones with accelerator, but next full backups with accelerator and with accelerator forced rescan fail.
These backups are either pending after the buffer size limit is reached and I`m forced to kill bpbrm on media server to cancel the job or they fail with errors that you can see in the log below (please do not look at E: drive, actually it was a redundant selection, I only backup D:)
9/13/2015 12:00:00 AM - Info nbjm(pid=6812) starting backup job (jobid=1238597) for client CLIENT, policy PROD_CLIENT_FS_FP_CLIENT, schedule CLIENT_FS_FP_Full
9/13/2015 12:00:00 AM - Info nbjm(pid=6812) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=1238597, request id:{7F248B57-36A5-4F4E-BAE2-88536A2B3C4A})
9/13/2015 12:00:00 AM - requesting resource PD_msdp_1
9/13/2015 12:00:00 AM - requesting resource master.NBU_CLIENT.MAXJOBS.CLIENT
9/13/2015 12:00:00 AM - requesting resource master.NBU_POLICY.MAXJOBS.PROD_CLIENT_FS_FP_CLIENT
9/13/2015 12:00:02 AM - granted resource master.NBU_CLIENT.MAXJOBS.CLIENT
9/13/2015 12:00:02 AM - granted resource master.NBU_POLICY.MAXJOBS.PROD_CLIENT_FS_FP_CLIENT
9/13/2015 12:00:02 AM - granted resource MediaID=@aaaeJ;DiskVolume=PureDiskVolume;DiskPool=PD_msdp;Path=PureDiskVolume;StorageServer=msdp.ad1.domain.com;MediaServer=msdp.ad1.domain.com
9/13/2015 12:00:02 AM - granted resource PD_msdp_1
9/13/2015 12:00:26 AM - estimated 2205836350 Kbytes needed
9/13/2015 12:00:26 AM - Info nbjm(pid=6812) started backup (backupid=CLIENT_1442095226) job for client CLIENT, policy PROD_CLIENT_FS_FP_CLIENT, schedule CLIENT_FS_FP_Full on storage unit PD_msdp_1
9/13/2015 12:00:26 AM - started
9/13/2015 12:00:28 AM - started process bpbrm (3128)
9/13/2015 12:00:31 AM - using resilient connections
9/13/2015 12:00:38 AM - Info bpbrm(pid=3128) CLIENT is the host to backup data from
9/13/2015 12:00:38 AM - Info bpbrm(pid=3128) reading file list from client
9/13/2015 12:00:39 AM - Info bpbrm(pid=3128) accelerator enabled
9/13/2015 12:00:49 AM - connecting
9/13/2015 12:00:51 AM - Info bpbrm(pid=3128) starting bpbkar32 on client
9/13/2015 12:00:51 AM - connected; connect time: 00:00:02
9/13/2015 12:00:54 AM - Info bpbkar32(pid=2412) Backup started
9/13/2015 12:00:54 AM - Info bpbkar32(pid=2412) change time comparison:<enabled>
9/13/2015 12:00:54 AM - Info bpbkar32(pid=2412) accelerator enabled backup, archive bit processing:<disabled>
9/13/2015 12:00:54 AM - Info bpbkar32(pid=2412) will attempt to use change journal data for <D:\Data>
9/13/2015 12:00:54 AM - Info bpbkar32(pid=2412) not using change journal data for <E:\Data>: not supported for non-local volumes / file systems
9/13/2015 12:00:54 AM - Info bptm(pid=3892) start
9/13/2015 12:00:55 AM - Info bptm(pid=3892) using 1048576 data buffer size
9/13/2015 12:00:55 AM - Info bptm(pid=3892) setting receive network buffer to 4195328 bytes
9/13/2015 12:00:55 AM - Info bptm(pid=3892) using 512 data buffers
9/13/2015 12:00:55 AM - Info msdp.ad1.domain.com(pid=3892) Using OpenStorage client direct to backup from client CLIENT to msdp.ad1.domain.com
9/13/2015 12:00:59 AM - begin writing
9/13/2015 12:01:35 AM - Info bpbkar32(pid=2412) not using change journal data for <D:\Data>: not configured for use
9/13/2015 12:01:35 AM - Info bpbkar32(pid=2412) not using change journal data for enumeration for <D:\Data> but will use it for change detection
9/13/2015 1:28:03 AM - Info bpbrm(pid=3128) from client CLIENT: TRV - object not found for file system backup: E:\Data
9/13/2015 1:28:23 AM - Info bpbkar32(pid=2412) accelerator sent 6542848 bytes out of 1891403958272 bytes to server, optimization 100.0%
9/13/2015 1:28:23 AM - Info bpbkar32(pid=2412) bpbkar waited 0 times for empty buffer, delayed 0 times.
9/13/2015 3:04:15 AM - Error bptm(pid=3892) Could not get bytes copied on client 2060057, by sts_ioctl,will use default value.
9/13/2015 3:04:15 AM - Error bptm(pid=3892) image copy failed: error 2060057: OpenStorage Proxy Plugin Error
9/13/2015 3:04:15 AM - Error bptm(pid=3892) cannot set media state 2: retval = 2060057
9/13/2015 5:04:17 AM - Critical bptm(pid=3892) sts_get_image_prop failed: error 2060057: OpenStorage Proxy Plugin Error
9/13/2015 5:04:17 AM - Critical bptm(pid=3892) sts_close_handle failed: 2060057 OpenStorage Proxy Plugin Error
9/13/2015 5:04:17 AM - Error bptm(pid=3892) Could not set last backup info to client 2060057
9/13/2015 5:04:17 AM - Critical bptm(pid=3892) sts_get_image_prop failed: error 2060057: OpenStorage Proxy Plugin Error
9/13/2015 5:04:17 AM - Critical bptm(pid=3892) sts_close_handle failed: 2060057 OpenStorage Proxy Plugin Error
9/13/2015 5:04:17 AM - Critical bptm(pid=3892) cannot write image to disk, media close failed with status 2060057 OpenStorage Proxy Plugin Error
9/13/2015 5:04:17 AM - Critical bptm(pid=3892) sts_get_server_prop failed: error 2060057 OpenStorage Proxy Plugin Error
9/13/2015 5:04:18 AM - Critical bptm(pid=3892) sts_get_server_prop failed: error 2060057 OpenStorage Proxy Plugin Error
9/13/2015 7:04:39 AM - Error bpbrm(pid=3128) [ERROR][proxy_open_server_v7]CORBA::SystemException is caught in proxy_open_server_v7, minor = 1330446338, status = 1, info = system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'.OMG minor code (2), described as '*unknown description*', completed = NO
9/13/2015 7:04:39 AM - Error bpbrm(pid=3128) libsts opensvh() 15/09/13 07:04:39: v11_open_server failed in plugin C:\Program Files\Veritas\NetBackup\bin\\libstspinbostpxy.dll err 2060057
9/13/2015 7:04:39 AM - Error bpbrm(pid=3128) sts_open_server failed: error 2060057
Today I tried once again to completely uninstall the client and I ensured the Install:\Veritas folder and VxCJDelete.dat. VxCJInfo.dat and VxCJMon.dat files are removed. I removed the client from policy and added it again. I have just started the full backup but I can see that activity monitor is still able to calculate the estimated backup size --> how is it possible if no track file exist? In the past removing track files resolved my accelerator issues but in this case I`m afraid it will not work...
This is really strange, after complete client uninstall my first backup is behaving as if it were still using the journal files....One more detail, the legacy settings were True Image Restore with Move detection and accelerator, when the issue appeared I disabled TIR, as I understand it is not recommended to have both TIR and accelerator. I have Keep TIR restore info set for 14 days on master server. Is it possible that this is still causing the problem?Is it the reason why estimated backup size is displayed in activity monitor?
I ensured that McAffee settings on client follow meticulously the Symantec recommended (journal file excluded from scan etc.) Also in the past applying these AV settings solved my acclerator issues but not this time.
9/16/2015 12:52:23 PM - Info nbjm(pid=6812) starting backup job (jobid=1240316) for client client, policy PROD_CLIENT_FS_FP_client, schedule CLIENT_FS_FP_Full
9/16/2015 12:52:23 PM - Info nbjm(pid=6812) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=1240316, request id:{50F63D7A-E0E6-4253-81C1-2EEE7254031F})
9/16/2015 12:52:23 PM - requesting resource PD_MSDP_1
9/16/2015 12:52:23 PM - requesting resource master.NBU_CLIENT.MAXJOBS.client
9/16/2015 12:52:23 PM - requesting resource master.NBU_POLICY.MAXJOBS.PROD_CLIENT_FS_FP_client
9/16/2015 12:52:23 PM - granted resource master.NBU_CLIENT.MAXJOBS.client
9/16/2015 12:52:23 PM - granted resource master.NBU_POLICY.MAXJOBS.PROD_CLIENT_FS_FP_client
9/16/2015 12:52:23 PM - granted resource MediaID=@aaaeJ;DiskVolume=PureDiskVolume;DiskPool=PD_MSDP;Path=PureDiskVolume;StorageServer=MSDP.ad1.domain.com;MediaServer=MSDP.ad1.domain.com
9/16/2015 12:52:23 PM - granted resource PD_MSDP_1
9/16/2015 12:52:23 PM - estimated 2216488894 Kbytes needed
9/16/2015 12:52:23 PM - Info nbjm(pid=6812) started backup (backupid=client_1442400743) job for client client, policy PROD_CLIENT_FS_FP_client, schedule CLIENT_FS_FP_Full on storage unit PD_MSDP_1
9/16/2015 12:52:23 PM - started
9/16/2015 12:52:25 PM - started process bpbrm (732)
9/16/2015 12:52:27 PM - using resilient connections
9/16/2015 12:52:32 PM - Info bpbrm(pid=732) client is the host to backup data from
9/16/2015 12:52:32 PM - Info bpbrm(pid=732) reading file list from client
9/16/2015 12:52:32 PM - Info bpbrm(pid=732) accelerator enabled
9/16/2015 12:52:34 PM - Info bpbrm(pid=732) There is no complete backup image match with track journal, a regular full backup will be performed.
9/16/2015 12:52:35 PM - connecting
9/16/2015 12:52:37 PM - Info bpbrm(pid=732) starting bpbkar32 on client
9/16/2015 12:52:37 PM - connected; connect time: 00:00:02
9/16/2015 12:52:39 PM - Info bpbkar32(pid=2456) Backup started
9/16/2015 12:52:39 PM - Info bpbkar32(pid=2456) change time comparison:<enabled>
9/16/2015 12:52:39 PM - Info bpbkar32(pid=2456) accelerator enabled backup, archive bit processing:<disabled>
9/16/2015 12:52:39 PM - Info bptm(pid=8584) start
9/16/2015 12:52:39 PM - Info bpbkar32(pid=2456) will attempt to use change journal data for <D:\Data>
9/16/2015 12:52:40 PM - Info bptm(pid=8584) using 1048576 data buffer size
9/16/2015 12:52:40 PM - Info bptm(pid=8584) setting receive network buffer to 4195328 bytes
9/16/2015 12:52:40 PM - Info bptm(pid=8584) using 512 data buffers
9/16/2015 12:52:40 PM - Info MSDP.ad1.domain.com(pid=8584) Using OpenStorage client direct to backup from client client to MSDP.ad1.domain.com
9/16/2015 12:52:48 PM - begin writing
9/16/2015 12:53:20 PM - Info bpbkar32(pid=2456) not using change
