Backup failing to 5020 appliance from regional office but successfull to tape

[Philip_Drew]

Hi All,

I'm having an issue with backing up regional servers to our head office.

We have a head office and 5 regional offices connected via WAN.

We are using NBU 7.1.0.4 and 5020 applianes (1.4.2) and LTO4 tape drives.

I have tested a backup from a regional server to the head office media server to tape and it runs fine ( if a little slow ) and it completes successfully.

When I run the same backup to the 5020 appliance the backup fails with the error:

10/09/2013 11:14:08 - Info nbjm(pid=7732) starting backup job (jobid=144785) for client ie-klkXXXXX, policy Weekly_Operational_System_Recovery_IE-DUBXXXX1_Regional_Servers, schedule Sunday 
10/09/2013 11:14:08 - Info nbjm(pid=7732) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=144785, request id:{443FCC92-FAA9-42DA-A3D2-559267D8A19D}) 
10/09/2013 11:14:08 - requesting resource SDK_XXX
10/09/2013 11:14:08 - requesting resource ie-dubXXXX.NBU_CLIENT.MAXJOBS.ie-klkXXXXX
10/09/2013 11:14:08 - requesting resource ie-dubXXXX.NBU_POLICY.MAXJOBS.Weekly_Operational_System_Recovery_IE-DUBXXXX_Regional_Servers
10/09/2013 11:14:08 - granted resource ie-dubXXXX.NBU_CLIENT.MAXJOBS.ie-klkXXXXX
10/09/2013 11:14:08 - granted resource ie-dubXXXX.NBU_POLICY.MAXJOBS.Weekly_Operational_System_Recovery_IE-DUBXXXX_Regional_Servers
10/09/2013 11:14:08 - granted resource MediaID=@aaaap;DiskVolume=PureDiskVolume;DiskPool=SDK_XXXX;Path=PureDiskVolume;StorageServer=XXXX;Me...
10/09/2013 11:14:08 - granted resource SDK_XXXX
10/09/2013 11:14:10 - estimated 0 Kbytes needed
10/09/2013 11:14:10 - Info nbjm(pid=7732) started backup job for client ie-klkXXXXX, policy Weekly_Operational_System_Recovery_IE-DUBXXXX_Regional_Servers, schedule Sunday on storage unit SDK_XXXXX
10/09/2013 11:14:16 - started process bpbrm (1620)
10/09/2013 11:14:34 - Info bpbrm(pid=1620) ie-klkuXXXXX is the host to backup data from    
10/09/2013 11:14:35 - Info bpbrm(pid=1620) reading file list from client       
10/09/2013 11:14:35 - connecting
10/09/2013 11:14:40 - Info bpbrm(pid=1620) starting bpbkar32 on client        
10/09/2013 11:14:40 - connected; connect time: 00:00:05
10/09/2013 11:14:41 - Info bpbkar32(pid=2220) Backup started          
10/09/2013 11:14:41 - Info bptm(pid=2260) start           
10/09/2013 11:14:43 - Info bptm(pid=2260) using 262144 data buffer size       
10/09/2013 11:14:43 - Info bptm(pid=2260) setting receive network buffer to 1049600 bytes     
10/09/2013 11:14:43 - Info bptm(pid=2260) using 128 data buffers        
10/09/2013 11:14:49 - Info ie-dubadm030(pid=2260) Using OpenStorage client direct to backup from client ie-klkXXXX to ie-dubXXXXX 
10/09/2013 11:15:21 - Critical bptm(pid=2260) sts_open_target_server failed: error 2060017 system call failed     
10/09/2013 11:15:23 - Critical bptm(pid=2260) failure to open proxy target server ie-dubnbupan011: plug-in reports error 2060017 system call failed
10/09/2013 11:15:35 - end writing
media open error(83)

(Note I have anonymised server and appliance names).

I have the advised firewall ports open and have even opened all TCP ports as a test but the backup still fails.

Local backups to the appliance from other servers in head office to the appliance all run with no issues.

Just hoping someone may have encountered this before, my COMMS guy is away this week so have to wait logging a call for a Webex with Symantec until he is back.

[Mark_Solutions]

When you use client side de-dupe with a 5020 appliance the data travels directly to the 5020 itself

You will need to make sure that you regional offices can resolve the host names of the 5020's and connect to them in order to use client side de-dupe

It sounds like a connection issue related to this

All other types of backups go via your media server so resolution is different

Hope this helps

[Philip_Drew]

I have carried out the following tests:

Ping appliance from client server - Successful

BPclntcmd -pn from client server - Successful

BPclintcmd -server APPLIANCE NAME from client server - Successful

Ping client server from appliance - Successful

Just to add the backup fails with the same error if I use the FQDN instead .

Have you any other suggestions on what to try ?

[Mark_Solutions]

On a client take a look under its ost-plugins - there should be a directly based on the appliance name

Have a look at the config and any logs in that directory to see if anything looks wrong

You could also rename that directory and try the backup again which sometimes helps

Other than that enable logging on the clients pd.conf as well as bpcd and bpbkar on the client to try and pin down where the issue lies

The messages file on the appliance may also give clues (or the spoold / storaged logs)

See what you can find and let us know

[Mark_Solutions]

Do the client have the appliances in its valid server list (like it has the other media servers)?

It may just be refusing to pass its data to the appliance once the job has been initiated by the media server.

[Philip_Drew]

When logging was initialised I got the following:
 

bpkar excerpt:

13:40:08.540: [2968.2036] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks
13:40:08.540: [2968.2036] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 40: network connection broken
13:40:08.540: [2968.2036] <16> dtcp_write: TCP - failure: send socket (412) (TCP 10054: Connection reset by peer)
13:40:08.540: [2968.2036] <16> dtcp_write: TCP - failure: attempted to send 48 bytes
13:40:08.540: [2968.2036] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'
13:40:08.540: [2968.2036] <16> tar_backup::SetExcludeFileList: **** DBG **** - alternate client fileter file is null
13:40:08.555: [2968.2036] <4> tar_backup_tfi::UpdateExcludeListWithVHD: INF - UpdateExludeListWithVHD begin
13:40:10.665: [2968.2036] <4> OVStopCmd: INF - EXIT - status = 0
13:40:10.665: [2968.2036] <16> dtcp_shutdown: TCP - failure: shutdown socket (276) (TCP 10054: Connection reset by peer)
13:40:10.665: [2968.2036] <2> tar_base::V_Close: closing...
13:40:13.962: [2968.2036] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): enter - InitFlags:0x00000001
13:40:13.962: [2968.2036] <16> dtcp_read: TCP - failure: recv socket (416) (TCP 10053: Software caused connection abort)
13:40:13.962: [2968.2036] <4> OVShutdown: INF - Finished process
13:40:13.977: [2968.2036] <4> WinMain: INF - Exiting C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe

I also have bpcd file which contains the following:

 

13:37:08.973 [3532.1328] <2> ReadKeyfile: keyfile C:\Program Files\Veritas\NetBackup\bin\keyfile.dat does not exist

13:37:09.801 [3532.1328] <2> vnet_cached_getaddrinfo: ../../libvlibs/vnet_addrinfo.c.1225: 0: vnet_cached_getaddrinfo_and_update() failed: 6 0x00000006
13:37:09.801 [3532.1328] <2> vnet_cached_get_service_port: ../../libvlibs/vnet_addrinfo.c.2498: 0: vnet_cached_getaddrinfo failed: 6 0x00000006
13:37:09.801 [3532.1328] <2> vnet_cached_get_service_port: ../../libvlibs/vnet_addrinfo.c.2499: 0: vnet_cached_getaddrinfo failed ret: 10109 0x0000277d
13:37:09.801 [3532.1328] <2> vnet_cached_get_service_port: ../../libvlibs/vnet_addrinfo.c.2500: 0: vnet_cached_getaddrinfo failed service: testdaemon
13:37:09.801 [3532.1328] <2> is_pbxable_server: ../../libvlibs/vnet_connect.c.1827: 0: vnet_cached_get_service_port() failed: 6 0x00000006
13:37:09.801 [3532.1328] <2> is_pbxable_server: ../../libvlibs/vnet_connect.c.1828: 0: service: 51041
13:37:09.801 [3532.1328] <2> file_to_addrinfo: ../../libvlibs/vnet_addrinfo.c.6702: 0: fopen() failed: 2 0x00000002
13:37:09.801 [3532.1328] <2> file_to_addrinfo: ../../libvlibs/vnet_addrinfo.c.6703: 0: fopen() failed: C:\Program Files\Veritas\NetBackup\var\host_cache\14f\6cf9fd4f+51041,1,0,2,1,0+127.0.0.1.txt
13:37:09.801 [3532.1328] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1574: 0: found via getaddrinfo name: 127.0.0.1
13:37:09.801 [3532.1328] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1576: 0: found via getaddrinfo service: 51041
13:37:09.801 [3532.1328] <2> vnet_sortaddrs: ../../libvlibs/vnet_addrinfo.c.4067: 0: sorted addrs:: 1 0x00000001
13:37:09.801 [3532.1328] <2> get_pref_netconnection: ../../libvlibs/vnet_addrinfo.c.4899: 0: Local [strong] check, using interface : ANY
13:37:09.801 [3532.1328] <2> vnet_async_connect: ../../libvlibs/vnet_connect.c.1200: 0: connect in progress: 1 0x00000001

Also PDplugin.log wasn't created even though configured in config files - backup didn't get that far.

Do I need to set credentials for this client server for the appliances like I have for the media servers ?

Thanks again.

[Philip_Drew]

They are 5020 appliances - they don't have the media server built in.

I haven't had to do that for any of the local servers.

I've had added the appliance names to the additional servers list on the client setting on the master server - but that didn't work - new error now:

10/09/2013 14:31:16 - Error bpbrm(pid=7004) [ERROR][proxy_get_server_prop_byname_v8]STSException is caught in proxy_get_server_prop_byname_v8:.sts errno: 2060018.error message: fail to call sts_get_server_prop_byname
10/09/2013 14:31:18 - Error bpbrm(pid=7004) sts_get_server_prop_byname failed: error 2060018 - retrying      
10/09/2013 14:31:22 - Error bpbrm(pid=7004) [ERROR][proxy_get_server_prop_byname_v8]STSException is caught in proxy_get_server_prop_byname_v8:.sts errno: 2060018.error message: fail to call sts_get_server_prop_byname
10/09/2013 14:31:24 - Error bpbrm(pid=7004) sts_get_server_prop_byname failed: error 2060018 - retrying      
10/09/2013 14:31:28 - Error bpbrm(pid=7004) [ERROR][proxy_get_server_prop_byname_v8]STSException is caught in proxy_get_server_prop_byname_v8:.sts errno: 2060018.error message: fail to call sts_get_server_prop_byname
10/09/2013 14:31:29 - Error bpbrm(pid=7004) sts_get_server_prop_byname failed: error 2060018 - retrying      
10/09/2013 14:31:34 - Error bpbrm(pid=7004) [ERROR][proxy_get_server_prop_byname_v8]STSException is caught in proxy_get_server_prop_byname_v8:.sts errno: 2060018.error message: fail to call sts_get_server_prop_byname
10/09/2013 14:31:35 - Error bpbrm(pid=7004) sts_get_server_prop_byname failed: error 2060018 - retrying      
10/09/2013 14:31:40 - Error bpbrm(pid=7004) [ERROR][proxy_get_server_prop_byname_v8]STSException is caught in proxy_get_server_prop_byname_v8:.sts errno: 2060018.error message: fail to call sts_get_server_prop_byname
10/09/2013 14:31:42 - Error bpbrm(pid=7004) sts_get_server_prop_byname failed: error 2060018        
10/09/2013 14:31:44 - Critical bpbrm(pid=7004) Client Direct plugin not available (2060018)      
10/09/2013 14:31:48 - end writing
media open error(83)

[Mark_Solutions]

Interesting that adding the names now causes a new error!

I had meant that the client being backed up may need the appliance names adding to its server list as the client will be talking directly to the appliance to do its backup.

Short and FQDN also makes a difference here.

Is the client also on 7.1.0.4? There were a few fixes prior to that for client side de-dupe.

[Philip_Drew]

I've tested with short and FQDN names and both resolve from client to appliance via ping and bpclntcmd.

All servers (master, media and clients) are on 7.1.0.4

[Mark_Solutions]

Just another check - can the appliance ping the client using short and FQDN?

I think you need to get the ost logging working to get more information

[D_Flood]

What OS is the client?  That error looks a lot like the error that occurs when a non-Windows client tries to use Client Side Dedup.

[Philip_Drew]

OS is Windows 2008 R2 X64 on both sides.

Appliance is able to ping client via short and FQDN with no issues and same in revers

[Philip_Drew]

The inital backup policy which is failing was set to use client side de-dupe.

I have changed the client settings to use the media server de-dupe (not ideal but just a test) and that works so it looks to me like it might be a routing / comms issue.

[Mark_Solutions]

Also worth a look on the web gui of the 5020 as it does log errors on there that can be handy sometimes (as well as its messages file)

[Philip_Drew]

Is there a restriction between a client server using client side dedupe and the master server and / or appliance if they are on different VLANs ?

[Mark_Solutions]

VLANS are not supported with appliances - but as long as they can communicate via tcpip successfully they should be OK - depends how you have the appliance setup

[Philip_Drew]

Logged in to the WebGUI now and no logs re failing jobs.

Finally got the PDPlugin.log working - here are the contents:


09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE NAME)
09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE NAME)
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE NAME) (0000000000000000)
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.cfg
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:23:06 [3272] [2872] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE NAME, flags 0x31f)
09/16/13 14:23:06 [3272] [2872] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT NAME)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT NAME)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE NAME) (0000000000000000)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.cfg
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE NAME, flags 0x31f)
09/16/13 14:23:34 [3272] [888] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:23:36 [3272] [892] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE NAME)
09/16/13 14:23:36 [3272] [892] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:36 [3272] [892] [DEBUG] pi_open_server_v7 entry
09/16/13 14:23:36 [3272] [892] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE NAME root 26)
09/16/13 14:23:36 [3272] [892] [DEBUG] impl_open_server session id sd_id = 145981:bptm:7464:ie-dubXXXX
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE NAME) (0000000000000000)
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.cfg
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server enter PureDisk:APPLIANCE NAME
09/16/13 14:23:36 [3272] [892] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE NAME 0000000000000000
09/16/13 14:23:36 [3272] [892] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:23:36 [3272] [892] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:23:36 [3272] [892] [DEBUG] new_svh enter PureDisk:APPLIANCE NAME
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server new node <PureDisk:APPLIANCE NAME> (n=0000000004BF7720 root=0000000000000000) 0
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:23:36 [3272] [892] [DEBUG] Going through normal path
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server about to mount APPLIANCE NAME
09/16/13 14:23:36 [3272] [892] [DEBUG] pd_mount entry (00000000024B5470) (0000000000000000) <APPLIANCE NAME> <> prop=0
09/16/13 14:23:36 [3272] [892] [DEBUG] pd_mount storage server APPLIANCE NAME (0000000000000000)
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE NAME) (0000000000000000)
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.cfg
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:36 [3272] [892] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.reset>
09/16/13 14:23:36 [3272] [892] [DEBUG] add_mount enter 0000000004C03940 (APPLIANCE NAME)
09/16/13 14:23:36 [3272] [892] [DEBUG] add_mount PdvfsMount (APPLIANCE NAME#2) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.cfg)
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path enter <00000000024B5470> (/APPLIANCE NAME#2) ()
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE NAME#2/2/
09/16/13 14:23:41 [3272] [892] [DEBUG] pd_get_dsid_path check directory /APPLIANCE NAME#2/2/
09/16/13 14:23:41 [3272] [892] [DEBUG] tag_nbu_dsid enter </APPLIANCE NAME#2/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004233990) <APPLIANCE NAME>
09/16/13 14:24:02 [3272] [892] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:24:02 [3272] [892] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE NAME#2/2//NBU_PD_SERVER
09/16/13 14:24:02 [3272] [892] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_umount entry APPLIANCE NAME#2 (1)
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE NAME 00000000024B5470
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE NAME
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_ll exit: svh_ll=0000000004BF7720
09/16/13 14:24:02 [3272] [892] [DEBUG] free_svh enter: 00000000024B5470 PureDisk:APPLIANCE NAME 1
09/16/13 14:24:02 [3272] [892] [DEBUG] free_svh searching for 00000000024B5470 found 00000000024B5470 opencount=1 nhandle=1
09/16/13 14:24:02 [3272] [892] [DEBUG] free_svh removing 00000000024B5470 from list (0)
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_remove_ref_ll enter: 00000000024B5470
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:24:02 [3272] [892] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:24:02 [3272] [892] [DEBUG] impl_open_server exit (2060017:system call failed) 00000000023FFE10
09/16/13 14:24:02 [3272] [892] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0

[Mark_Solutions]

Does the C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE NAME.cfg actually look OK?

Anything in it that does not look right? It is usually this file that causes the issues

I know you have edited the log file but is APPLIANCE NAME#2 actually its name#2 or is it a different name?

[Philip_Drew]

Updated PDPlugin.log

Note - APPLIANCE_NAME has replaced all instances of the appliance name & CLIENT_NAME has replaced all instances of the client server name due to security requirements (for the post)

09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:06 [3272] [2872] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:23:06 [3272] [2872] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:23:06 [3272] [2872] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:23:06 [3272] [2872] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:23:34 [3272] [892] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:23:34 [3272] [2872] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:23:34 [3272] [888] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:23:34 [3272] [888] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:34 [3272] [888] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:23:34 [3272] [888] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:23:34 [3272] [888] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:23:36 [3272] [892] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:23:36 [3272] [892] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:23:36 [3272] [892] [DEBUG] pi_open_server_v7 entry
09/16/13 14:23:36 [3272] [892] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:23:36 [3272] [892] [DEBUG] impl_open_server session id sd_id = 145981:bptm:7464:ie-dubadm030
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:23:36 [3272] [892] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:23:36 [3272] [892] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:23:36 [3272] [892] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:23:36 [3272] [892] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=0000000004BF7720 root=0000000000000000) 0
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:23:36 [3272] [892] [DEBUG] Going through normal path
09/16/13 14:23:36 [3272] [892] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:23:36 [3272] [892] [DEBUG] pd_mount entry (00000000024B5470) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:23:36 [3272] [892] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:23:36 [3272] [892] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:23:36 [3272] [892] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:23:36 [3272] [892] [DEBUG] add_mount enter 0000000004C03940 (APPLIANCE_NAME)
09/16/13 14:23:36 [3272] [892] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#2) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path enter <00000000024B5470> (/APPLIANCE_NAME#2) ()
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:23:40 [3272] [892] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#2/2/
09/16/13 14:23:41 [3272] [892] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#2/2/
09/16/13 14:23:41 [3272] [892] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#2/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004233990) <APPLIANCE_NAME>
09/16/13 14:24:02 [3272] [892] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:24:02 [3272] [892] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#2/2//NBU_PD_SERVER
09/16/13 14:24:02 [3272] [892] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_umount entry APPLIANCE_NAME#2 (1)
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:24:02 [3272] [892] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 00000000024B5470
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_ll exit: svh_ll=0000000004BF7720
09/16/13 14:24:02 [3272] [892] [DEBUG] free_svh enter: 00000000024B5470 PureDisk:APPLIANCE_NAME 1
09/16/13 14:24:02 [3272] [892] [DEBUG] free_svh searching for 00000000024B5470 found 00000000024B5470 opencount=1 nhandle=1
09/16/13 14:24:02 [3272] [892] [DEBUG] free_svh removing 00000000024B5470 from list (0)
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_remove_ref_ll enter: 00000000024B5470
09/16/13 14:24:02 [3272] [892] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:24:02 [3272] [892] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:24:02 [3272] [892] [DEBUG] impl_open_server exit (2060017:system call failed) 00000000023FFE10
09/16/13 14:24:02 [3272] [892] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
09/16/13 14:29:35 [3272] [888] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:29:35 [3272] [888] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:29:35 [3272] [888] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:29:35 [3272] [888] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:04 [2876] [3668] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:35:04 [2876] [3668] [DEBUG] session_init exit
09/16/13 14:35:04 [2876] [3668] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:35:04 [2876] [3668] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:04 [2876] [3668] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:35:04 [2876] [3668] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:04 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:35:04 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:35:04 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:35:04 [2876] [3668] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:35:04 [2876] [3668] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:35:04 [2876] [3668] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:35:04 [2876] [3668] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:35:04 [2876] [3668] [DEBUG] pi_terminate_v7 entry (1)
09/16/13 14:35:04 [2876] [3668] [DEBUG] session_exit entry
09/16/13 14:35:04 [2876] [3668] [DEBUG] session_exit exit err=OK
09/16/13 14:35:04 [2876] [3668] [DEBUG] pi_terminate_v7 exit (0) 1
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:35:30 [2876] [2668] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:35:30 [2876] [2668] [DEBUG] session_init exit
09/16/13 14:35:30 [2876] [2668] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:35:30 [2876] [2668] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:35:30 [2876] [2668] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:35:30 [2876] [2668] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:35:30 [2876] [2668] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:35:32 [2876] [3668] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:35:32 [2876] [3668] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:35:32 [2876] [3668] [DEBUG] pi_open_server_v7 entry
09/16/13 14:35:32 [2876] [3668] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:35:32 [2876] [3668] [DEBUG] impl_open_server session id sd_id = 145982:bptm:2704:ie-dubadm030
09/16/13 14:35:32 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:35:32 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:35:32 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:35:32 [2876] [3668] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:35:32 [2876] [3668] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:35:32 [2876] [3668] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:35:32 [2876] [3668] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:35:32 [2876] [3668] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:35:32 [2876] [3668] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=000000000229B8A0 root=0000000000000000) 0
09/16/13 14:35:32 [2876] [3668] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:35:32 [2876] [3668] [DEBUG] Going through normal path
09/16/13 14:35:32 [2876] [3668] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:35:32 [2876] [3668] [DEBUG] pd_mount entry (0000000002369FA0) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:35:32 [2876] [3668] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:35:32 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:35:32 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:35:32 [2876] [3668] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:35:32 [2876] [3668] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:35:32 [2876] [3668] [DEBUG] add_mount enter 00000000022C7F00 (APPLIANCE_NAME)
09/16/13 14:35:32 [2876] [3668] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#1) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_get_dsid_path enter <0000000002369FA0> (/APPLIANCE_NAME#1) ()
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:35:36 [2876] [3668] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#1/2/
09/16/13 14:35:37 [2876] [3668] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#1/2/
09/16/13 14:35:37 [2876] [3668] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#1/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004203990) <APPLIANCE_NAME>
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: NetConnectByAddr: Failed to connect to host: Unknown error (10060)
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not establish a connection to APPLIANCE_NAME.ie.ema.ad.pwcinternal.com:10082: connect failed (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. )
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send get operations for DOs: connection timed out
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send all DO get operations via CR_CURRENT route table: connection timed out
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:35:58 [2876] [3668] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#1/2//NBU_PD_SERVER
09/16/13 14:35:58 [2876] [3668] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:35:58 [2876] [3668] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:35:58 [2876] [3668] [DEBUG] pd_umount entry APPLIANCE_NAME#1 (1)
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not receive binary message: expected 4 bytes got -1 bytes. Cause: not a socket
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not get reply for DO 0: not a socket
09/16/13 14:35:58 [2876] [3668] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not discard DO get operation batch: not a socket
09/16/13 14:35:58 [2876] [3668] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:35:58 [2876] [3668] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:35:58 [2876] [3668] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000002369FA0
09/16/13 14:35:58 [2876] [3668] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:35:58 [2876] [3668] [DEBUG] find_svh_ll exit: svh_ll=000000000229B8A0
09/16/13 14:35:58 [2876] [3668] [DEBUG] free_svh enter: 0000000002369FA0 PureDisk:APPLIANCE_NAME 1
09/16/13 14:35:58 [2876] [3668] [DEBUG] free_svh searching for 0000000002369FA0 found 0000000002369FA0 opencount=1 nhandle=1
09/16/13 14:35:58 [2876] [3668] [DEBUG] free_svh removing 0000000002369FA0 from list (0)
09/16/13 14:35:58 [2876] [3668] [DEBUG] find_svh_remove_ref_ll enter: 0000000002369FA0
09/16/13 14:35:58 [2876] [3668] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:35:58 [2876] [3668] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:35:58 [2876] [3668] [DEBUG] impl_open_server exit (2060017:system call failed) 00000000023681A0
09/16/13 14:35:58 [2876] [3668] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
09/16/13 14:36:51 [2876] [772] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:36:51 [2876] [772] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:36:51 [2876] [772] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:36:51 [2876] [772] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:36:51 [2876] [772] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:36:51 [2876] [772] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:36:51 [2876] [772] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:36:51 [2876] [772] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:36:51 [2876] [772] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:36:51 [2876] [772] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:37:28 [2536] [3644] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:37:28 [2536] [3644] [DEBUG] session_init exit
09/16/13 14:37:28 [2536] [3644] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:37:28 [2536] [3644] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:37:28 [2536] [3644] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:37:28 [2536] [3644] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:37:28 [2536] [3644] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:37:28 [2536] [3644] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:37:28 [2536] [3644] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:37:28 [2536] [3644] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:37:28 [2536] [3644] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:37:28 [2536] [3644] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:37:28 [2536] [3644] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:37:28 [2536] [3644] [DEBUG] pi_terminate_v7 entry (1)
09/16/13 14:37:28 [2536] [3644] [DEBUG] session_exit entry
09/16/13 14:37:28 [2536] [3644] [DEBUG] session_exit exit err=OK
09/16/13 14:37:28 [2536] [3644] [DEBUG] pi_terminate_v7 exit (0) 1
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:38:01 [2536] [4064] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:38:01 [2536] [4064] [DEBUG] session_init exit
09/16/13 14:38:01 [2536] [4064] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:38:01 [2536] [4064] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:38:01 [2536] [4064] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:38:01 [2536] [4064] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:38:01 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:38:02 [2536] [2512] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:38:02 [2536] [2512] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:38:02 [2536] [2512] [DEBUG] pi_open_server_v7 entry
09/16/13 14:38:02 [2536] [2512] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:38:02 [2536] [2512] [DEBUG] impl_open_server session id sd_id = 145983:bptm:7512:ie-dubadm030
09/16/13 14:38:02 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:38:02 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:38:02 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:38:02 [2536] [2512] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:38:02 [2536] [2512] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:38:02 [2536] [2512] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:38:02 [2536] [2512] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:38:02 [2536] [2512] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:38:03 [2536] [2512] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=00000000023CB840 root=0000000000000000) 0
09/16/13 14:38:03 [2536] [2512] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:38:03 [2536] [2512] [DEBUG] Going through normal path
09/16/13 14:38:03 [2536] [2512] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:38:03 [2536] [2512] [DEBUG] pd_mount entry (0000000002499D90) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:38:03 [2536] [2512] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:38:03 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:38:03 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:38:03 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:38:03 [2536] [2512] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:38:03 [2536] [2512] [DEBUG] add_mount enter 00000000023F49A0 (APPLIANCE_NAME)
09/16/13 14:38:03 [2536] [2512] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#1) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:38:09 [2536] [2512] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:38:09 [2536] [2512] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:38:10 [2536] [2512] [DEBUG] pd_get_dsid_path enter <0000000002499D90> (/APPLIANCE_NAME#1) ()
09/16/13 14:38:10 [2536] [2512] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:38:10 [2536] [2512] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:38:10 [2536] [2512] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:38:10 [2536] [2512] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:38:10 [2536] [2512] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#1/2/
09/16/13 14:38:11 [2536] [2512] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#1/2/
09/16/13 14:38:11 [2536] [2512] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#1/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004233990) <APPLIANCE_NAME>
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: NetConnectByAddr: Failed to connect to host: Unknown error (10060)
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not establish a connection to APPLIANCE_NAME.ie.ema.ad.pwcinternal.com:10082: connect failed (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. )
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send get operations for DOs: connection timed out
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send all DO get operations via CR_CURRENT route table: connection timed out
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:38:32 [2536] [2512] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#1/2//NBU_PD_SERVER
09/16/13 14:38:32 [2536] [2512] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:38:32 [2536] [2512] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:38:32 [2536] [2512] [DEBUG] pd_umount entry APPLIANCE_NAME#1 (1)
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not receive binary message: expected 4 bytes got -1 bytes. Cause: not a socket
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not get reply for DO 0: not a socket
09/16/13 14:38:32 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not discard DO get operation batch: not a socket
09/16/13 14:38:32 [2536] [2512] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:38:32 [2536] [2512] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:38:32 [2536] [2512] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000002499D90
09/16/13 14:38:32 [2536] [2512] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:38:32 [2536] [2512] [DEBUG] find_svh_ll exit: svh_ll=00000000023CB840
09/16/13 14:38:32 [2536] [2512] [DEBUG] free_svh enter: 0000000002499D90 PureDisk:APPLIANCE_NAME 1
09/16/13 14:38:32 [2536] [2512] [DEBUG] free_svh searching for 0000000002499D90 found 0000000002499D90 opencount=1 nhandle=1
09/16/13 14:38:32 [2536] [2512] [DEBUG] free_svh removing 0000000002499D90 from list (0)
09/16/13 14:38:32 [2536] [2512] [DEBUG] find_svh_remove_ref_ll enter: 0000000002499D90
09/16/13 14:38:32 [2536] [2512] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:38:32 [2536] [2512] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:38:32 [2536] [2512] [DEBUG] impl_open_server exit (2060017:system call failed) 0000000002498150
09/16/13 14:38:32 [2536] [2512] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
09/16/13 14:39:19 [2536] [2512] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:19 [2536] [2512] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:39:19 [2536] [2512] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:19 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:39:19 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:39:19 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:39:19 [2536] [2512] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:39:19 [2536] [2512] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:39:19 [2536] [2512] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:39:19 [2536] [2512] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:39:45 [2536] [4064] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:39:45 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:45 [2536] [4064] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:39:45 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [2512] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:39:46 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [2512] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:39:46 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:39:46 [2536] [4064] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:39:46 [2536] [4064] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:39:46 [2536] [4064] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:39:46 [2536] [4064] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:39:47 [2536] [2512] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:39:47 [2536] [2512] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:39:47 [2536] [2512] [DEBUG] pi_open_server_v7 entry
09/16/13 14:39:47 [2536] [2512] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:39:47 [2536] [2512] [DEBUG] impl_open_server session id sd_id = 145983:bptm:3352:ie-dubadm030
09/16/13 14:39:47 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:39:47 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:39:47 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:39:47 [2536] [2512] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:39:47 [2536] [2512] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:39:47 [2536] [2512] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:39:47 [2536] [2512] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:39:47 [2536] [2512] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:39:48 [2536] [2512] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=0000000005036610 root=0000000000000000) 0
09/16/13 14:39:48 [2536] [2512] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:39:48 [2536] [2512] [DEBUG] Going through normal path
09/16/13 14:39:48 [2536] [2512] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:39:48 [2536] [2512] [DEBUG] pd_mount entry (0000000002499400) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:39:48 [2536] [2512] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:39:48 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:39:48 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:39:48 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:39:48 [2536] [2512] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:39:48 [2536] [2512] [DEBUG] add_mount enter 00000000023F5D00 (APPLIANCE_NAME)
09/16/13 14:39:48 [2536] [2512] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#2) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_get_dsid_path enter <0000000002499400> (/APPLIANCE_NAME#2) ()
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:39:53 [2536] [2512] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#2/2/
09/16/13 14:39:54 [2536] [2512] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#2/2/
09/16/13 14:39:54 [2536] [2512] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#2/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004233990) <APPLIANCE_NAME>
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: NetConnectByAddr: Failed to connect to host: Unknown error (10060)
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not establish a connection to APPLIANCE_NAME.ie.ema.ad.pwcinternal.com:10082: connect failed (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. )
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send get operations for DOs: connection timed out
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send all DO get operations via CR_CURRENT route table: connection timed out
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:40:15 [2536] [2512] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#2/2//NBU_PD_SERVER
09/16/13 14:40:15 [2536] [2512] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:40:15 [2536] [2512] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:40:15 [2536] [2512] [DEBUG] pd_umount entry APPLIANCE_NAME#2 (1)
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not receive binary message: expected 4 bytes got -1 bytes. Cause: not a socket
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not get reply for DO 0: not a socket
09/16/13 14:40:15 [2536] [2512] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not discard DO get operation batch: not a socket
09/16/13 14:40:15 [2536] [2512] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:40:15 [2536] [2512] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:40:15 [2536] [2512] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000002499400
09/16/13 14:40:15 [2536] [2512] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:40:15 [2536] [2512] [DEBUG] find_svh_ll exit: svh_ll=0000000005036610
09/16/13 14:40:15 [2536] [2512] [DEBUG] free_svh enter: 0000000002499400 PureDisk:APPLIANCE_NAME 1
09/16/13 14:40:15 [2536] [2512] [DEBUG] free_svh searching for 0000000002499400 found 0000000002499400 opencount=1 nhandle=1
09/16/13 14:40:15 [2536] [2512] [DEBUG] free_svh removing 0000000002499400 from list (0)
09/16/13 14:40:15 [2536] [2512] [DEBUG] find_svh_remove_ref_ll enter: 0000000002499400
09/16/13 14:40:15 [2536] [2512] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:40:15 [2536] [2512] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:40:15 [2536] [2512] [DEBUG] impl_open_server exit (2060017:system call failed) 0000000002498150
09/16/13 14:40:15 [2536] [2512] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
09/16/13 14:41:02 [2876] [772] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:41:02 [2876] [772] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:41:02 [2876] [2668] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:41:02 [2876] [2668] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:41:55 [2536] [3484] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:41:55 [2536] [3484] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:41:55 [2536] [3484] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:41:55 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:41:55 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:41:55 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:41:55 [2536] [3484] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:41:55 [2536] [3484] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:41:55 [2536] [3484] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:41:55 [2536] [3484] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [3484] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:42:27 [2536] [3484] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [3484] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:42:27 [2536] [3484] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 entry (ClientDirectCE:ShMem:CLIENT_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:42:27 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:42:27 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:42:27 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:42:27 [2536] [2512] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:42:27 [2536] [2512] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:42:27 [2536] [2512] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:42:27 [2536] [2512] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:42:28 [2536] [2512] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:42:28 [2536] [2512] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:42:28 [2536] [2512] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:42:28 [2536] [2512] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:42:28 [2536] [2512] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:42:28 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:42:28 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:42:28 [2536] [2512] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:42:28 [2536] [2512] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:42:28 [2536] [2512] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:42:28 [2536] [2512] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:42:28 [2536] [2512] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:42:29 [2536] [3484] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:42:29 [2536] [3484] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:42:29 [2536] [3484] [DEBUG] pi_open_server_v7 entry
09/16/13 14:42:29 [2536] [3484] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:42:29 [2536] [3484] [DEBUG] impl_open_server session id sd_id = 145983:bptm:7888:ie-dubadm030
09/16/13 14:42:29 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:42:29 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:42:29 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:42:29 [2536] [3484] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:42:29 [2536] [3484] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:42:29 [2536] [3484] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:42:29 [2536] [3484] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:42:29 [2536] [3484] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:42:30 [2536] [3484] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=00000000024B4950 root=0000000000000000) 0
09/16/13 14:42:30 [2536] [3484] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:42:30 [2536] [3484] [DEBUG] Going through normal path
09/16/13 14:42:30 [2536] [3484] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:42:30 [2536] [3484] [DEBUG] pd_mount entry (0000000002499400) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:42:30 [2536] [3484] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:42:30 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:42:30 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:42:30 [2536] [3484] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:42:30 [2536] [3484] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:42:30 [2536] [3484] [DEBUG] add_mount enter 000000000503F420 (APPLIANCE_NAME)
09/16/13 14:42:30 [2536] [3484] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#3) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_get_dsid_path enter <0000000002499400> (/APPLIANCE_NAME#3) ()
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:42:34 [2536] [3484] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#3/2/
09/16/13 14:42:38 [2536] [3484] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#3/2/
09/16/13 14:42:38 [2536] [3484] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#3/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004233990) <APPLIANCE_NAME>
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: NetConnectByAddr: Failed to connect to host: Unknown error (10060)
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not establish a connection to APPLIANCE_NAME.ie.ema.ad.pwcinternal.com:10082: connect failed (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. )
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send get operations for DOs: connection timed out
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send all DO get operations via CR_CURRENT route table: connection timed out
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:43:00 [2536] [3484] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#3/2//NBU_PD_SERVER
09/16/13 14:43:00 [2536] [3484] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:43:00 [2536] [3484] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:43:00 [2536] [3484] [DEBUG] pd_umount entry APPLIANCE_NAME#3 (1)
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not receive binary message: expected 4 bytes got -1 bytes. Cause: not a socket
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not get reply for DO 0: not a socket
09/16/13 14:43:00 [2536] [3484] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not discard DO get operation batch: not a socket
09/16/13 14:43:00 [2536] [3484] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:43:00 [2536] [3484] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:43:00 [2536] [3484] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000002499400
09/16/13 14:43:00 [2536] [3484] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:43:00 [2536] [3484] [DEBUG] find_svh_ll exit: svh_ll=00000000024B4950
09/16/13 14:43:00 [2536] [3484] [DEBUG] free_svh enter: 0000000002499400 PureDisk:APPLIANCE_NAME 1
09/16/13 14:43:00 [2536] [3484] [DEBUG] free_svh searching for 0000000002499400 found 0000000002499400 opencount=1 nhandle=1
09/16/13 14:43:00 [2536] [3484] [DEBUG] free_svh removing 0000000002499400 from list (0)
09/16/13 14:43:00 [2536] [3484] [DEBUG] find_svh_remove_ref_ll enter: 0000000002499400
09/16/13 14:43:00 [2536] [3484] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:43:00 [2536] [3484] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:43:00 [2536] [3484] [DEBUG] impl_open_server exit (2060017:system call failed) 0000000002498150
09/16/13 14:43:00 [2536] [3484] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:44:54 [4376] [4448] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:44:54 [4376] [4448] [DEBUG] session_init exit
09/16/13 14:44:54 [4376] [4448] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:44:54 [4376] [4448] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:44:54 [4376] [4448] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:44:54 [4376] [4448] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:44:54 [4376] [4448] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:44:54 [4376] [4448] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:44:54 [4376] [4448] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:44:54 [4376] [4448] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:44:54 [4376] [4448] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:44:54 [4376] [4448] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:44:54 [4376] [4448] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:44:54 [4376] [4448] [DEBUG] pi_terminate_v7 entry (1)
09/16/13 14:44:54 [4376] [4448] [DEBUG] session_exit entry
09/16/13 14:44:54 [4376] [4448] [DEBUG] session_exit exit err=OK
09/16/13 14:44:54 [4376] [4448] [DEBUG] pi_terminate_v7 exit (0) 1
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:45:22 [4376] [4640] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:45:22 [4376] [4640] [DEBUG] session_init exit
09/16/13 14:45:22 [4376] [4640] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:45:22 [4376] [4640] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:45:22 [4376] [4640] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:45:22 [4376] [4640] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:45:22 [4376] [4640] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:45:23 [4376] [4816] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:45:23 [4376] [4816] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:45:23 [4376] [4816] [DEBUG] pi_open_server_v7 entry
09/16/13 14:45:23 [4376] [4816] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:45:23 [4376] [4816] [DEBUG] impl_open_server session id sd_id = 145984:bptm:1980:ie-dubadm030
09/16/13 14:45:23 [4376] [4816] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:45:23 [4376] [4816] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:45:23 [4376] [4816] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:45:23 [4376] [4816] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:45:23 [4376] [4816] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:45:23 [4376] [4816] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:45:23 [4376] [4816] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:45:23 [4376] [4816] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:45:24 [4376] [4816] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=000000000222BF90 root=0000000000000000) 0
09/16/13 14:45:24 [4376] [4816] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:45:24 [4376] [4816] [DEBUG] Going through normal path
09/16/13 14:45:24 [4376] [4816] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:45:24 [4376] [4816] [DEBUG] pd_mount entry (00000000022F9FB0) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:45:24 [4376] [4816] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:45:24 [4376] [4816] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:45:24 [4376] [4816] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:45:24 [4376] [4816] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:45:24 [4376] [4816] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:45:24 [4376] [4816] [DEBUG] add_mount enter 00000000022574E0 (APPLIANCE_NAME)
09/16/13 14:45:24 [4376] [4816] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#1) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_get_dsid_path enter <00000000022F9FB0> (/APPLIANCE_NAME#1) ()
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:45:28 [4376] [4816] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#1/2/
09/16/13 14:45:29 [4376] [4816] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#1/2/
09/16/13 14:45:29 [4376] [4816] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#1/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004293990) <APPLIANCE_NAME>
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: NetConnectByAddr: Failed to connect to host: Unknown error (10060)
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not establish a connection to APPLIANCE_NAME.ie.ema.ad.pwcinternal.com:10082: connect failed (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. )
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send get operations for DOs: connection timed out
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send all DO get operations via CR_CURRENT route table: connection timed out
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:45:50 [4376] [4816] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#1/2//NBU_PD_SERVER
09/16/13 14:45:50 [4376] [4816] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:45:50 [4376] [4816] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:45:50 [4376] [4816] [DEBUG] pd_umount entry APPLIANCE_NAME#1 (1)
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not receive binary message: expected 4 bytes got -1 bytes. Cause: not a socket
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not get reply for DO 0: not a socket
09/16/13 14:45:50 [4376] [4816] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not discard DO get operation batch: not a socket
09/16/13 14:45:50 [4376] [4816] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:45:50 [4376] [4816] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:45:50 [4376] [4816] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 00000000022F9FB0
09/16/13 14:45:50 [4376] [4816] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:45:50 [4376] [4816] [DEBUG] find_svh_ll exit: svh_ll=000000000222BF90
09/16/13 14:45:50 [4376] [4816] [DEBUG] free_svh enter: 00000000022F9FB0 PureDisk:APPLIANCE_NAME 1
09/16/13 14:45:50 [4376] [4816] [DEBUG] free_svh searching for 00000000022F9FB0 found 00000000022F9FB0 opencount=1 nhandle=1
09/16/13 14:45:50 [4376] [4816] [DEBUG] free_svh removing 00000000022F9FB0 from list (0)
09/16/13 14:45:50 [4376] [4816] [DEBUG] find_svh_remove_ref_ll enter: 00000000022F9FB0
09/16/13 14:45:50 [4376] [4816] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:45:50 [4376] [4816] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:45:50 [4376] [4816] [DEBUG] impl_open_server exit (2060017:system call failed) 00000000022F8150
09/16/13 14:45:50 [4376] [4816] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
09/16/13 14:46:28 [2536] [3484] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:46:28 [2536] [3484] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:46:28 [2536] [3484] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:46:28 [2536] [3484] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:50:53 [4376] [4640] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:50:53 [4376] [4640] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:50:53 [4376] [4640] [DEBUG] pi_claim_v7 entry (ShMem:CLIENT_NAME)
09/16/13 14:50:53 [4376] [4640] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:10 [3488] [340] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:58:10 [3488] [340] [DEBUG] session_init exit
09/16/13 14:58:10 [3488] [340] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:58:10 [3488] [340] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:10 [3488] [340] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:58:10 [3488] [340] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:10 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:58:10 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:58:10 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:58:10 [3488] [340] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:58:10 [3488] [340] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:58:10 [3488] [340] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:58:10 [3488] [340] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:58:10 [3488] [340] [DEBUG] pi_terminate_v7 entry (1)
09/16/13 14:58:10 [3488] [340] [DEBUG] session_exit entry
09/16/13 14:58:10 [3488] [340] [DEBUG] session_exit exit err=OK
09/16/13 14:58:10 [3488] [340] [DEBUG] pi_terminate_v7 exit (0) 1
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Debug Log File Max Size (MB)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <MAX_LOG_MBSIZE = 500
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Determines if server-side settings from storage unit should be used
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# 0 - Server settings can override local pd.conf settings
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# 1 - Local pd.conf settings will always be used; server settings are ignored
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <LOCAL_SETTINGS = 0
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Compression (0=Disabled, 1=Enabled)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <COMPRESSION = 1
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Encryption (0=Disabled, 1=Enabled)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <ENCRYPTION = 0
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Optimized-duplication timeout (minutes)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <OPTDUP_TIMEOUT = 720
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Optimized-duplication max bandwidth (KB/s, 0=No Limit)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <OPTDUP_BANDWIDTH = 0
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Optimized-duplication compression (0=Off, 1=On)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <OPTDUP_COMPRESSION = 1
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Optimized-duplication encryption (0=Off, 1=On)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <OPTDUP_ENCRYPTION = 0
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Segment size (KB)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <SEGKSIZE = 128
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Don't segment files with these suffixes
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# DONT_SEGMENT_TYPES = mpeg,jpg,mp3
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Max bandwidth backup/restore (KB/s, 0=No Limit)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <BANDWIDTH_LIMIT = 0
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Max image fragment size allowed (MB)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <MAX_IMG_MBSIZE = 51200
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Specify the local NIC for backup/restore
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# BACKUPRESTORERANGE = 192.168.1.1/32
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# PDDO web service retry count
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <WS_RETRYCOUNT = 3
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# PDDO web service call timeout (seconds)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <WS_TIMEOUT = 120
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <###############################################################################
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Agent side decryption and decompression on restore (0=off, 1=on
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <RESTORE_DECRYPT_LOCAL = 0
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Buffer size to use when prefetching data for restore operations (B)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <PREFETCH_SIZE = 33554432
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Segment size for meta data streams (KB)
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <# Size must be a multiple of 32 and fall in the range 32-16384
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <META_SEGKSIZE = 4096
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile parsing: <#
>
09/16/13 14:58:35 [3488] [2872] [DEBUG] parse_configfile : pdvfs_conf_disable_stg_loc 0
09/16/13 14:58:35 [3488] [2872] [DEBUG] session_init exit
09/16/13 14:58:35 [3488] [2872] [DEBUG] stspi_init exit 6.5.0.0 10:12:34 Mar 16 2012
09/16/13 14:58:35 [3488] [2872] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:35 [3488] [2872] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:58:35 [3488] [2872] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:35 [3488] [2872] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:58:35 [3488] [2872] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:58:35 [3488] [2872] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:58:35 [3488] [2872] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:58:35 [3488] [2872] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:58:35 [3488] [2872] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:58:35 [3488] [2872] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:58:36 [3488] [2872] [DEBUG] pi_claim_v7 entry (ClientDirectCE:PureDisk:APPLIANCE_NAME)
09/16/13 14:58:36 [3488] [2872] [DEBUG] pi_claim_v7 exit (2060009:object not claimed by a plug-in)
09/16/13 14:58:36 [3488] [2872] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:36 [3488] [2872] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:58:36 [3488] [2872] [DEBUG] pi_get_server_prop_byname_v8 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:36 [3488] [2872] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:58:36 [3488] [2872] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:58:36 [3488] [2872] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:58:36 [3488] [2872] [DEBUG] get_server_info exit: (0: OK)
09/16/13 14:58:36 [3488] [2872] [DEBUG] impl_get_server_prop_byname info (server PureDisk:APPLIANCE_NAME, flags 0x31f)
09/16/13 14:58:36 [3488] [2872] [DEBUG] impl_get_server_prop_byname exit (0:OK)
09/16/13 14:58:36 [3488] [2872] [DEBUG] pi_get_server_prop_byname_v8 exit (0:OK)
09/16/13 14:58:37 [3488] [340] [DEBUG] pi_claim_v7 entry (PureDisk:APPLIANCE_NAME)
09/16/13 14:58:37 [3488] [340] [DEBUG] pi_claim_v7 exit (0:OK)
09/16/13 14:58:37 [3488] [340] [DEBUG] pi_open_server_v7 entry
09/16/13 14:58:37 [3488] [340] [DEBUG] impl_open_server entry (PureDisk:APPLIANCE_NAME root 26)
09/16/13 14:58:37 [3488] [340] [DEBUG] impl_open_server session id sd_id = 145985:bptm:1060:ie-dubadm030
09/16/13 14:58:37 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:58:37 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:58:37 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:58:37 [3488] [340] [DEBUG] open_server enter PureDisk:APPLIANCE_NAME
09/16/13 14:58:37 [3488] [340] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000000000000
09/16/13 14:58:37 [3488] [340] [DEBUG] find_svh_ll Couldn't match against name and pointer, finding available connections
09/16/13 14:58:37 [3488] [340] [DEBUG] find_svh_ll exit: svh_ll=0000000000000000
09/16/13 14:58:37 [3488] [340] [DEBUG] new_svh enter PureDisk:APPLIANCE_NAME
09/16/13 14:58:37 [3488] [340] [DEBUG] open_server new node <PureDisk:APPLIANCE_NAME> (n=00000000023ABB70 root=0000000000000000) 0
09/16/13 14:58:37 [3488] [340] [DEBUG] open_server nhandle=1 opencount=1 mntp=0000000000000000
09/16/13 14:58:37 [3488] [340] [DEBUG] Going through normal path
09/16/13 14:58:37 [3488] [340] [DEBUG] open_server about to mount APPLIANCE_NAME
09/16/13 14:58:37 [3488] [340] [DEBUG] pd_mount entry (0000000002479FB0) (0000000000000000) <APPLIANCE_NAME> <> prop=0
09/16/13 14:58:37 [3488] [340] [DEBUG] pd_mount storage server APPLIANCE_NAME (0000000000000000)
09/16/13 14:58:37 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount entry (APPLIANCE_NAME) (0000000000000000)
09/16/13 14:58:37 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount using PureDisk agent configuration file C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg
09/16/13 14:58:37 [3488] [340] [DEBUG] get_agent_cfg_file_path_for_mount exit (0)
09/16/13 14:58:37 [3488] [340] [DEBUG] pd_mount checking for <C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.reset>
09/16/13 14:58:37 [3488] [340] [DEBUG] add_mount enter 00000000023D74E0 (APPLIANCE_NAME)
09/16/13 14:58:37 [3488] [340] [DEBUG] add_mount PdvfsMount (APPLIANCE_NAME#1) config=(C:\Program Files\Veritas\NetBackup\bin\\ost-plugins\APPLIANCE_NAME.cfg)
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_mount rollbackmode:0
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_mount default segsize 131072, minfile_size 0
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_get_dsid_path enter <0000000002479FB0> (/APPLIANCE_NAME#1) ()
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_get_dsid_path processing entry .
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_get_dsid_path processing entry ..
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_get_dsid_path processing entry 2
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_get_dsid_path adding dsid (2)
09/16/13 14:58:41 [3488] [340] [DEBUG] pd_get_dsid_path opening directory /APPLIANCE_NAME#1/2/
09/16/13 14:58:42 [3488] [340] [DEBUG] pd_get_dsid_path check directory /APPLIANCE_NAME#1/2/
09/16/13 14:58:42 [3488] [340] [DEBUG] tag_nbu_dsid enter </APPLIANCE_NAME#1/2//NBU_PD_SERVER> PD_TAG_MODE_READ (0000000004213990) <APPLIANCE_NAME>
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: NetConnectByAddr: Failed to connect to host: Unknown error (10060)
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not establish a connection to APPLIANCE_NAME.ie.ema.ad.pwcinternal.com:10082: connect failed (A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. )
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send get operations for DOs: connection timed out
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not send all DO get operations via CR_CURRENT route table: connection timed out
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_pread: CRDOReaderRead for NBU_PD_SERVER failed: 15 (connection timed out)
09/16/13 14:59:03 [3488] [340] [ERROR] tag_nbu_dsid error (5 Input/output error) reading /APPLIANCE_NAME#1/2//NBU_PD_SERVER
09/16/13 14:59:03 [3488] [340] [DEBUG] tag_nbu_dsid exit match=0 (2060017:system call failed)
09/16/13 14:59:03 [3488] [340] [DEBUG] pd_get_dsid_path exit (2060017:system call failed) () ()
09/16/13 14:59:03 [3488] [340] [DEBUG] pd_umount entry APPLIANCE_NAME#1 (1)
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not receive binary message: expected 4 bytes got -1 bytes. Cause: not a socket
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not get reply for DO 0: not a socket
09/16/13 14:59:03 [3488] [340] [ERROR] PDVFS: [1] pdvfs_lib_log: Could not discard DO get operation batch: not a socket
09/16/13 14:59:03 [3488] [340] [DEBUG] pd_umount exit (0:OK) 0
09/16/13 14:59:03 [3488] [340] [DEBUG] pd_mount exit (2060017:system call failed)
09/16/13 14:59:03 [3488] [340] [DEBUG] find_svh_ll enter: PureDisk:APPLIANCE_NAME 0000000002479FB0
09/16/13 14:59:03 [3488] [340] [DEBUG] find_svh_ll walking open_server_ll_t: PureDisk:APPLIANCE_NAME (nhandle=1 open=1) ? PureDisk:APPLIANCE_NAME
09/16/13 14:59:03 [3488] [340] [DEBUG] find_svh_ll exit: svh_ll=00000000023ABB70
09/16/13 14:59:03 [3488] [340] [DEBUG] free_svh enter: 0000000002479FB0 PureDisk:APPLIANCE_NAME 1
09/16/13 14:59:03 [3488] [340] [DEBUG] free_svh searching for 0000000002479FB0 found 0000000002479FB0 opencount=1 nhandle=1
09/16/13 14:59:03 [3488] [340] [DEBUG] free_svh removing 0000000002479FB0 from list (0)
09/16/13 14:59:03 [3488] [340] [DEBUG] find_svh_remove_ref_ll enter: 0000000002479FB0
09/16/13 14:59:03 [3488] [340] [DEBUG] find_svh_remove_ref_ll exit
09/16/13 14:59:03 [3488] [340] [DEBUG] open_server exit (2060017:system call failed) svh=0000000000000000
09/16/13 14:59:03 [3488] [340] [DEBUG] impl_open_server exit (2060017:system call failed) 0000000002478150
09/16/13 14:59:03 [3488] [340] [DEBUG] pi_open_server_v7 exit (2060017:system call failed) 0
 

[Philip_Drew]

The PDPlugin config file looks fine. I've also deleted it and re-run the job to recreate the config file.