Solved: thanks for the quick reply. I

ApieBe · ‎09-07-2012

After weeks of trying to find a solution, reading numereous articles, manuals,... I decided to post my problem ;).
I installed a sharepoint agent and sql agent on the servers.
I try to add a sharepoint farm to backup exec. This is the setup:

Backup server, Sharepoint 2010 SP1 server and SQL 2008 R2 server are installed on separated servers.
I activated debug logging, but I cannot figure out what is going wrong.

BEREMOTE01.LOG (Sharepoint server)

[2812] 09/07/12 11:36:29 [ndmp\ndmpcomm]      - ndmpRun: Control connection accepted : connection established between end-points 172.17.11.16:11000 and 172.17.1.99:49527
[4368] 09/07/12 11:36:29 [ndmp\ndmpsrvr]      - sslOpen() : Opening SSL for: 00000000DF8E9C2F
[4368] 09/07/12 11:36:29 [ndmp\ndmpsrvr]      - sslOpen(): certinfo = 00000000DF92808F ; sslConn = 00000000DF8BD15F
[4368] 09/07/12 11:36:29 [ndmp\ndmpcomm]      - GetCertificateDataFolderPath: Not checking for cluster.
[4368] 09/07/12 11:36:29                      - SSL connection using version TLSv1
[4368] 09/07/12 11:36:29                      - SSL connection using cipher AES256-SHA
[4368] 09/07/12 11:36:32 [ndmp\ndmpsrvr]      - Username for Logon: SPHV\gbesrvbuexechv
[4368] 09/07/12 11:36:32                      - BELogonUser: beclass::IsThisMe() returned error: 87
[4368] 09/07/12 11:36:32                      - LogonType set = [LOGON32_LOGON_BATCH][0x4]
[4368] 09/07/12 11:36:34                      - LogonUser failed: Logon failure: unknown user name or bad password.
[4368] 09/07/12 11:36:34 [ndmp\ndmpsrvr]      - LogonuserError: 1326
[4368] 09/07/12 11:36:34 [ndmp\ndmpsrvr]      - LogonUser failed for user: SPHV\gbesrvbuexechv
[4368] 09/07/12 11:36:34 [ndmp\ndmpsrvr]      - In ndmpdGetLastError:: Callback to get last NDMP Error.
[4368] 09/07/12 11:36:34 [ndmp\ndmpsrvr]      - sslClose() : Closing SSL for: 00000000DF8E9C2F
[4368] 09/07/12 11:36:34                      - SSL Shutdown clean
[4368] 09/07/12 11:36:34 [BESocket]           - @@@@@@@MyCloseSocket called with sockfd = 1076(0x434) retval = 0
[4368] 09/07/12 11:36:34 [ndmp\tpfmt]         - FreeFormatEnv( cur_fmt=0 )
[4368] 09/07/12 11:36:34 [ndmp\tpfmt]         - FreeFormatEnv( cur_fmt=0 )
[4368] 09/07/12 11:36:34 [ndmp\ndmpsrvr]      - sslClose() : Closing SSL for: 00000000DF8E9C2F
[4368] 09/07/12 11:36:34 [ndmp\ndmpsrvr]      - sslClose() : certinfo = 0 ; sslConn = 0
[2812] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - ndmpRun: Control connection accepted : connection established between end-points 172.17.11.16:11000 and 172.17.1.99:49535
[4168] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - sslOpen() : Opening SSL for: 00000000DF8E9C2F
[4168] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - sslOpen(): certinfo = 00000000DF8E94DF ; sslConn = 00000000DF8BD15F
[4168] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - GetCertificateDataFolderPath: Not checking for cluster.
[4168] 09/07/12 11:36:40                      - SSL connection using version TLSv1
[4168] 09/07/12 11:36:40                      - SSL connection using cipher AES256-SHA
[4168] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - Username for Logon: SP\gbesrvbuexec
[4168] 09/07/12 11:36:40                      - BELogonUser: beclass::IsThisMe() returned error: 87
[4168] 09/07/12 11:36:40                      - LogonType set = [LOGON32_LOGON_BATCH][0x4]
[4168] 09/07/12 11:36:40                      - LogonUser(LOGON32_LOGON_BATCH-0x4) success
[4168] 09/07/12 11:36:40                      - Successfully impersonated SP\gbesrvbuexec
[4168] 09/07/12 11:36:40                      - WhoAmI( ) reports: SP\gbesrvbuexec
[4168] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - LogonuserError: 0
[4168] 09/07/12 11:36:40 [ndmp\dsss]          - DS_OpenSelectionService
[4168] 09/07/12 11:36:40 [engidrapi]          - GetVirtualHardDisksNumbers() - Enter
[4168] 09/07/12 11:36:40 [engidrapi]          - GetVirtualHardDisksNumbers() - Exit
[4168] 09/07/12 11:36:40 [fsys\ntfs]          - GetServerType for local machine
[4168] 09/07/12 11:36:40 [engidrapi]          - GetVirtualHardDisksNumbers() - Enter
[4168] 09/07/12 11:36:40 [engidrapi]          - GetVirtualHardDisksNumbers() - Exit
[4168] 09/07/12 11:36:40 [fsys\ntfs]          - GetServerType for local machine
[4168] 09/07/12 11:36:40 [fsys\ntfs\mnet]     - Finding MNET entries using PunchDownWithWNetCalls()
[4168] 09/07/12 11:36:40 [fsys\notes2]        - Notes Agent:FindDrives
[4168] 09/07/12 11:36:40 [fsys\oracle]        - RMAN_FindDrives - Oracle RMAN Agent not authorized.
[4168] 09/07/12 11:36:40 [fsys\ntfs]          - GetServerType for local machine
[4168] 09/07/12 11:36:40 [fsys\shadow]        - Device Shadow?Copy?Components Dle platform 2 major version 6 minor version 1 build 7601
[4168] 09/07/12 11:36:40 [fsys\upfs]          - No utility partitions found on any of the disks
[4168] 09/07/12 11:36:40 [fsys\ra]            - NRDS_RA_FindDrives entered
[4168] 09/07/12 11:36:40 [fsys\ra]            - NRDS_RA_FindDrives completed immediately because we aren't browsing locally
[4168] 09/07/12 11:36:40 [fsys\protsrvs\cps] - Informational: Cps root device creation using default Cps library mechanism when creating device 'Cont?Prot?Srv' in CPS::DetermineRootCpsComponent:692
[4168] 09/07/12 11:36:40 [fsys\protsrvs\cps] - Informational: Cps library not available. Not creating Cps root device 'Cont?Prot?Srv' in CPS::DetermineRootCpsComponent:696
[4168] 09/07/12 11:36:40 [fsys\db2]           - Function called: DB2_FindDrives
[4168] 09/07/12 11:36:40 [fsys\db2]           - DB2_FindDrives - DB2 Agent not autherized.
[4168] 09/07/12 11:36:40 [fsys\systemstate]   -   AD:DeviceName "System?State" in SystemState::CreateDLEs:373
[4168] 09/07/12 11:36:40 [fsys\systemstate]   -   AD:Full Device Path "System?State" in SystemState::CreateDLEs:378
[4168] 09/07/12 11:36:40 [fsys\systemstate]   -   AD:ADRO Agent is authorized for System?State.
[4168] 09/07/12 11:36:40 [fsys\systemstate]   -   AD:Found 0 instances of Active Directory Applcation Mode in SystemState::GetADAMInstanceCount:1415
[4168] 09/07/12 11:36:40 [fsys\ev]            - EVM_FindDrives: Function called
[4168] 09/07/12 11:36:40 [fsys\ev]            - EVM_FindDrives - EV Agent not authorized.
[4168] 09/07/12 11:36:40 [fsys\sql2]          - SQL2_FindDrives - the default SQL Service is not running on SPSERVER.
[4168] 09/07/12 11:36:40 [fsys\ese]           - [FSYS:ESE07]   FindDrives ... This is not an Exchange Server (0)
[4168] 09/07/12 11:36:40 [fsys\spsv2]         - ERROR: Could not connect to server SPSERVER
[4168] 09/07/12 11:36:40 [fsys\spsv3]         - checking for SPS evidence on SPSERVER, in SPSERVER
[4168] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - Successfully resolved the "ndmp" service to port: 11000 (host order)
[4168] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - ndmpConnectEx: 'SPSERVER' resolves to the local machine itself. So, we will try and connect to a loopback address ...
[4168] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:50471 and [::1]:11000.
[2812] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - ndmpRun: Control connection accepted : connection established between end-points [::1]:11000 and [::1]:50471
[4168] 09/07/12 11:36:40 [ndmp\ndmpclient]    - NDMP version 3 connection CONNECTED
[0584] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - sslOpen() : Opening SSL for: 00000000DF96632F
[0584] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - sslOpen(): certinfo = 00000000DF940DFF ; sslConn = 00000000DF92999F
[4168] 09/07/12 11:36:40 [ndmp\ndmpcomm]      - GetCertificateDataFolderPath: Not checking for cluster.
[4168] 09/07/12 11:36:40 [ndmp\ndmpclient]    - connectClientAuth(): agent is on local loopback, skipping SSL connection...
[0584] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - ndmpdConnectClientAuth(): agent is on local loopback, skipping SSL connection...
[0584] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - Username for Logon: SP\gbesrvbuexec
[0584] 09/07/12 11:36:40                      - BELogonUser: beclass::IsThisMe() returned error: 87
[0584] 09/07/12 11:36:40                      - LogonType set = [LOGON32_LOGON_BATCH][0x4]
[0584] 09/07/12 11:36:40                      - LogonUser(LOGON32_LOGON_BATCH-0x4) success
[0584] 09/07/12 11:36:40                      - Successfully impersonated SP\gbesrvbuexec
[0584] 09/07/12 11:36:40                      - WhoAmI( ) reports: SP\gbesrvbuexec
[0584] 09/07/12 11:36:40 [ndmp\ndmpsrvr]      - LogonuserError: 0
[4168] 09/07/12 11:36:40 [fsys\spsv3]         - NDMPEngine::SetupNDMPConnection(): Using proxy authentication as requested
[0584] 09/07/12 11:36:40 [fsys\spsv3]         - process ready?
[0584] 09/07/12 11:37:10 [fsys\spsv3]         - process NOT ready!
[4168] 09/07/12 11:37:16 [fsys\spsv3]         - GetTopology returned be0, from server SPSERVER, as user SP\gbesrvbuexec
[4168] 09/07/12 11:37:16 [BESocket]           - @@@@@@@MyCloseSocket called with sockfd = 1268(0x4f4) retval = 0
[4168] 09/07/12 11:37:16 [beutil]             - Input Error (       0) for Type: (43)
[4168] 09/07/12 11:37:16 [fsys\shared]        - FS_ResolveDevName: [SP_Portal (SPSERVER)]
[4168] 09/07/12 11:37:16 [fsys\mb2]           - MB2-Resolve returned 1
[4168] 09/07/12 11:37:16 [fsys\notes2]        - Notes Agent:CLNFileSystem::ResolveDeviceName
[0584] 09/07/12 11:37:16 [ndmp\ndmpsrvr]      - sslClose() : Closing SSL for: 00000000DF96632F
[0584] 09/07/12 11:37:16 [BESocket]           - @@@@@@@MyCloseSocket called with sockfd = 1272(0x4f8) retval = 0
[0584] 09/07/12 11:37:16 [ndmp\tpfmt]         - FreeFormatEnv( cur_fmt=0 )
[0584] 09/07/12 11:37:16 [ndmp\tpfmt]         - FreeFormatEnv( cur_fmt=0 )
[0584] 09/07/12 11:37:16 [ndmp\ndmpsrvr]      - sslClose() : Closing SSL for: 00000000DF96632F
[0584] 09/07/12 11:37:16 [ndmp\ndmpsrvr]      - sslClose() : certinfo = 0 ; sslConn = 0
[4168] 09/07/12 11:37:16 [beutil]             - ApplyRegExp(): Invalid input (SP_Portal (SPSERVER)). Parsing Failed.
[4168] 09/07/12 11:37:16 [beutil]             - GoodEvName(): Invalid EV device (SP_Portal (SPSERVER)).
[4168] 09/07/12 11:37:16 [beutil]             - ApplyRegExp(): Invalid input (SP_Portal (SPSERVER)). Parsing Failed.
[4168] 09/07/12 11:37:16 [beutil]             - GoodEvName(): Invalid EV device (SP_Portal (SPSERVER)).
[4168] 09/07/12 11:37:16 [beutil]             - Input Error (e000fe23) for Type: (43)
[4168] 09/07/12 11:37:16 [fsys\ev]            - EVM_ResolveDeviceName: Function Enter
[4168] 09/07/12 11:37:16 [beutil]             - ApplyRegExp(): Invalid input (SP_Portal (SPSERVER)). Parsing Failed.
[4168] 09/07/12 11:37:16 [fsys\ev]            - EVM_ResolveDeviceName: Invalid device name (SP_Portal (SPSERVER)). Parsing Failed.
[4168] 09/07/12 11:37:16 [fsys\ev]            - EVM_ResolveDeviceName: Function Exit
[4168] 09/07/12 11:37:16 [fsys\ntfs]          - Not valid device name : SP_Portal (SPSERVER)
[4168] 09/07/12 11:37:16 [fsys\shared]        - FS_BlowOutMachine: entered -->SP_Portal (SPSERVER)<--
[4168] 09/07/12 11:37:16 [fsys\shared]        - FS_BlowOutMachine: device already in DLE list
[4168] 09/07/12 11:37:16 [ndmp\ndmpcomm]      - Successfully resolved the "ndmp" service to port: 11000 (host order)
[4168] 09/07/12 11:37:16 [ndmp\ndmpcomm]      - ndmpConnectEx: 'SPSERVER' resolves to the local machine itself. So, we will try and connect to a loopback address ...
[4168] 09/07/12 11:37:16 [ndmp\ndmpcomm]      - ndmpConnectEx : Control Connection information: A connection was established between end-points [::1]:50493 and [::1]:11000.
[2812] 09/07/12 11:37:17 [ndmp\ndmpcomm]      - ndmpRun: Control connection accepted : connection established between end-points [::1]:11000 and [::1]:50493
[4168] 09/07/12 11:37:17 [ndmp\ndmpclient]    - NDMP version 3 connection CONNECTED
[4180] 09/07/12 11:37:17 [ndmp\ndmpsrvr]      - sslOpen() : Opening SSL for: 00000000DF96BBAF
[4180] 09/07/12 11:37:17 [ndmp\ndmpsrvr]      - sslOpen(): certinfo = 00000000DF940DFF ; sslConn = 00000000DF9299EF
[4168] 09/07/12 11:37:17 [ndmp\ndmpcomm]      - GetCertificateDataFolderPath: Not checking for cluster.
[4168] 09/07/12 11:37:17 [ndmp\ndmpclient]    - connectClientAuth(): agent is on local loopback, skipping SSL connection...
[4180] 09/07/12 11:37:17 [ndmp\ndmpsrvr]      - ndmpdConnectClientAuth(): agent is on local loopback, skipping SSL connection...
[4180] 09/07/12 11:37:17 [ndmp\ndmpsrvr]      - Username for Logon: SP\gbesrvbuexec
[4180] 09/07/12 11:37:17                      - BELogonUser: beclass::IsThisMe() returned error: 87
[4180] 09/07/12 11:37:17                      - LogonType set = [LOGON32_LOGON_BATCH][0x4]
[4180] 09/07/12 11:37:17                      - LogonUser(LOGON32_LOGON_BATCH-0x4) success
[4180] 09/07/12 11:37:17                      - Successfully impersonated SP\gbesrvbuexec
[4180] 09/07/12 11:37:17                      - WhoAmI( ) reports: SP\gbesrvbuexec
[4180] 09/07/12 11:37:17 [ndmp\ndmpsrvr]      - LogonuserError: 0
[4168] 09/07/12 11:37:17 [fsys\spsv3]         - NDMPEngine::SetupNDMPConnection(): Using proxy authentication as requested
[4180] 09/07/12 11:37:17 [fsys\spsv3]         - process ready?
[4180] 09/07/12 11:37:47 [fsys\spsv3]         - process NOT ready!
[4168] 09/07/12 11:37:52 [fsys\spsv3]         - GetTopology returned be0, from server SPSERVER, as user SP\gbesrvbuexec
[4180] 09/07/12 11:37:52 [ndmp\ndmpsrvr]      - sslClose() : Closing SSL for: 00000000DF96BBAF
[4180] 09/07/12 11:37:52 [BESocket]           - @@@@@@@MyCloseSocket called with sockfd = 1304(0x518) retval = 0
[4180] 09/07/12 11:37:52 [ndmp\tpfmt]         - FreeFormatEnv( cur_fmt=0 )
[4168] 09/07/12 11:37:52 [BESocket]           - @@@@@@@MyCloseSocket called with sockfd = 1220(0x4c4) retval = 0
[4180] 09/07/12 11:37:52 [ndmp\tpfmt]         - FreeFormatEnv( cur_fmt=0 )
[4180] 09/07/12 11:37:52 [ndmp\ndmpsrvr]      - sslClose() : Closing SSL for: 00000000DF96BBAF
[4180] 09/07/12 11:37:52 [ndmp\ndmpsrvr]      - sslClose() : certinfo = 0 ; sslConn = 0
[4168] 09/07/12 11:37:52 [fsys\shared]        - FS_CreateTempDLE
[4168] 09/07/12 11:37:52 [fsys\spsv3]         - This is an SPS server, but we failed to get the topology
[4168] 09/07/12 11:37:52 [fsys\spsv2]         - ERROR: Could not connect to server SPSERVER
[4168] 09/07/12 11:37:52 [fsys\spsv2]         - This server is NOT an SPS webserver
[4168] 09/07/12 11:37:52 [ndmp\ndmpsrvr]      - DSEnumerator failed with -536805633: The specified machine is not a SharePoint Server.

SPSWrapper.log (Sharepoint server)

[130c] 09/07/12 11:37:15 *************************************************************************
[130c] 09/07/12 11:37:15 * VERITAS Backup Exec SharePoint Portal Server v3 Agent Debug Log       *
[130c] 09/07/12 11:37:15 *    Date-Time:        Fri Sep 07 11:37:15 2012                         *
[130c] 09/07/12 11:37:15 *************************************************************************
[130c] 09/07/12 11:37:15   Security initialized for multithread.
[0864] 09/07/12 11:37:42 *************************************************************************
[0864] 09/07/12 11:37:42 * VERITAS Backup Exec SharePoint Portal Server v3 Agent Debug Log       *
[0864] 09/07/12 11:37:42 *    Date-Time:        Fri Sep 07 11:37:42 2012                         *
[0864] 09/07/12 11:37:42 *************************************************************************
[0864] 09/07/12 11:37:42   Security initialized for multithread.
[0864] 09/07/12 11:37:52 Establishing FarmType ..
[0864] 09/07/12 11:37:52 This installation is identified as a Sharepoint Server 2010
[0864] 09/07/12 11:37:52 Inside Clear Pause
[0864] 09/07/12 11:37:52 Nothing to UnPause Returning