NetBackup for Microsoft Exchange Server restore fails with Status Code 59 when there is a hardware Network Load Balancer

Problem

NetBackup for Microsoft Exchange Server restore fails with Status Code 59 when there is a hardware Network Load Balancer
 

Error Message

6/17/2011 9:39:02 AM - begin Restore
6/17/2011 9:39:09 AM - restoring image ExchangeCAS_1308320111
6/17/2011 9:39:19 AM - Error bpbrm(pid=1446) bpcd on CAS-Client exited with status 59: access to the client was not allowed
6/17/2011 9:39:19 AM - Info bpbrm(pid=1446) CAS-Client is the host to restore data      
6/17/2011 9:39:24 AM - Info tar32(pid=0) done. status: 59: access to the client was not allowed   
6/17/2011 9:39:24 AM - Error bpbrm(pid=1446) client restore EXIT STATUS 59: access to the client was not allowed 
6/17/2011 9:55:16 AM - restored image ExchangeCAS_1308320111 - (cannot connect on socket(25)); restore time 00:16:07
6/17/2011 9:55:21 AM - end Restore; elapsed time: 00:16:19
MS-Exchange-Server policy restore error(2810)
 

Troubleshooting

Enable the bpcd log on the CAS nodes
On the NetBackup for Exchange Client: 
1. Open the "Backup Archive and Restore" GUI 
2. Go To File > NetBackup Client Properties > Troubleshooting Tab 
3. Set General to 2, Verbose to 5 and Database to 9. 
4. Create the following directories in "install_path\netbackup\logs\": bpcd

Execute the Restore and review the log for the following:

09:35:40.247 [7792.6732] <2> setup_debug_log: switched debug log file for bpcd
09:35:40.247 [7792.6732] <2> bpcd main: VERBOSE = 5
09:35:40.247 [7792.6732] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\bpcd.exe -standalone
09:35:40.247 [7792.6732] <2> ReadKeyfile: keyfile C:\Program Files\Veritas\NetBackup\bin\keyfile.dat does not exist
09:35:40.247 [7792.6732] <2> process_requests: offset to GMT 21600
09:35:40.263 [7792.6732] <2> logconnections: BPCD ACCEPT FROM 100.101.99.102.53690 TO 100.101.99.103.1556 fd = 420
09:35:40.263 [7792.6732] <2> process_requests: setup_sockopts complete
09:35:40.263 [7792.6732] <2> vnet_pcache_init_table: ../../libvlibs/vnet_private.c.232: 0: starting cache size: 200 0x000000c8
09:35:45.075 [7792.6732] <2> retry_getnameinfo: ../../libvlibs/vnet_addrinfo.c.1099: 0: getnameinfo() failed: 11001 0x00002af9
09:35:45.075 [7792.6732] <2> vnet_cached_getnameinfo: ../../libvlibs/vnet_addrinfo.c.1830: 0: retry_getnameinfo() milliseconds: 4812 0x000012cc
09:35:45.075 [7792.6732] <2> vnet_cached_getnameinfo: ../../libvlibs/vnet_addrinfo.c.1833: 0: retry_getnameinfo() failed: 11001 0x00002af9
09:35:45.075 [7792.6732] <2> vnet_cached_getnameinfo: ../../libvlibs/vnet_addrinfo.c.1834: 0: retry_getnameinfo() failed ipstr: 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_cached_getnameinfo: ../../libvlibs/vnet_addrinfo.c.1835: 0: retry_getnameinfo() failed port: 53690 0x0000d1ba
09:35:45.075 [7792.6732] <2> bpcd peer_hostname: vnet_cached_getnameinfo() failed: 6 11001
09:35:45.075 [7792.6732] <2> bpcd peer_hostname: Connection from host 100.101.99.102 (100.101.99.102) port 53690
09:35:45.075 [7792.6732] <2> bpcd valid_server: comparing Master-Server and 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_pcache_init_table: ../../libvlibs/vnet_private.c.232: 0: starting cache size: 200 0x000000c8
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: Master-Server
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: NULL
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1572: 0: found via getaddrinfo name: 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1574: 0: found via getaddrinfo service: NULL
09:35:45.075 [7792.6732] <2> bpcd valid_server: comparing Media-Server and 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: Media-Server
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: NULL
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
09:35:45.075 [7792.6732] <4> bpcd valid_server: 100.101.99.102 is not a master server
09:35:45.075 [7792.6732] <16> bpcd valid_server: 100.101.99.102 is not a media server either
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: 100.101.99.102
09:35:45.075 [7792.6732] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
09:35:45.075 [7792.6732] <16> process_requests: read failed: The operation completed successfully.

Solution

When using 3rd party Network Load Balancers, such as an F5 BIG-IP, add the IP address of the Network Load Balancer to the CAS nodes SERVER keys.

Open regedit on the CAS nodes and browse to:

HKLM\SOFTWARE\VERITAS\NETBACKUP\CURRENTVERSION\CONFIG\SERVER

Add the IP address from the bpcd log to the bottom of the list. Retry the restore operation.