Unable to connect to the requested VDP Applicance VDP 6.1.4

[dustman86]

I am attempting to deploy a new VDP 6.1.4 appliance in our vCenter Server 6.5 environment. I am able to deploy and configure the appliance without issue, all services are running, and I am able to ssh to said appliance. When I attempt to connect to the appliance from vCenter I receive the following error:

Unable to connect to the requested VDP Appliance.

Would you like to be directed to the VDP Configuration utility to troubleshoot the issue?

I have deleted the appliance from disk and tried this a second time with the same results.

I have gone through the vCenter registration in the Configuration a few times, trying local accounts and SSO/AD accounts with the same results.

I have NTP servers configured in my ESXi hosts, set the time zone in the VDP appliance and verified that the date and time are correct.

Another thread led me to check the mcserver.out info as there is a known issue in an earlier version with vCenter Server 5.5. While there seems to be warnings and exceptions I am not sure I can make heads or tails as to what they are.

=== BEGIN === check.mcs (prestart)
check.mcs                        passed
=== PASS === check.mcs PASSED OVERALL (prestart)
Starting Administrator Server at: Tue Apr 18 07:33:44 MDT 2017
Starting Administrator Server...
Warning: org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser: Property 'http://www.oracle.com/xml/jaxp/properties/entityExpansionLimit' is not recognized.
Compiler warnings:
  WARNING:  'org.apache.xerces.jaxp.SAXParserImpl: Property 'http://javax.xml.XMLConstants/property/accessExternalDTD' is not recognized.'
Started
Clone started
Clone started
Clone started
Clone started
Initiated VC: /pic-vc01.corp.pingidentity.com. (Total time - 10421 ms)
VmwareService is ready. (Total time - 10422 ms)

2017-04-18 07:34:17.540:INFO::Logging to STDERR via org.mortbay.log.StdErrLog
2017-04-18 07:34:17.642:INFO::jetty-6.1.23
2017-04-18 07:34:17.669:INFO::Extract lib/mcsdk-axis2.war to /usr/local/avamar/var/mc/server_tmp/Jetty_0_0_0_0_9443_mcsdk.axis2.war____.xz4n3v/webapp
2017-04-18 07:34:25.927:INFO::Started TlsSocketConnector@0.0.0.0:9443
2017-04-18 07:34:26.146:INFO::jetty-6.1.23
2017-04-18 07:34:26.310:INFO::Extract lib/mcebms.war to /usr/local/avamar/var/mc/server_tmp/Jetty_0_0_0_0_9090_mcebms.war____i3qqxk/webapp
2017-04-18 07:34:27.075:INFO:/:Initializing Spring root WebApplicationContext
2017-04-18 07:34:28.219:INFO::Started TlsSocketConnector@0.0.0.0:9090
Administrator Server started.
Started
Ended VMWare
Ended VMWare
Started
Exception in thread "VmwareEventsMonitor for VC /pic-vc01.corp.xxxxxxxxxxx.com" java.lang.LinkageError: loader (instance of  sun/misc/Launcher$AppClassLoader): attempted  duplicate class definition for name: "org/apache/axis/message/SOAPFaultCodeBuilder"
        at java.lang.ClassLoader.defineClass1(Native Method)
        at java.lang.ClassLoader.defineClass(Unknown Source)
        at java.security.SecureClassLoader.defineClass(Unknown Source)
        at java.net.URLClassLoader.defineClass(Unknown Source)
        at java.net.URLClassLoader.access$100(Unknown Source)
        at java.net.URLClassLoader$1.run(Unknown Source)
        at java.net.URLClassLoader$1.run(Unknown Source)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(Unknown Source)
        at java.lang.ClassLoader.loadClass(Unknown Source)
        at sun.misc.Launcher$AppClassLoader.loadClass(Unknown Source)
        at java.lang.ClassLoader.loadClass(Unknown Source)
        at org.apache.axis.message.BodyBuilder.onStartChild(BodyBuilder.java:160)
        at org.apache.axis.encoding.DeserializationContext.startElement(DeserializationContext.java:1035)
        at org.apache.xerces.parsers.AbstractSAXParser.startElement(Unknown Source)
        at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
        at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
        at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)
        at org.apache.xerces.jaxp.SAXParserImpl.parse(Unknown Source)
        at org.apache.axis.encoding.DeserializationContext.parse(DeserializationContext.java:227)
        at org.apache.axis.SOAPPart.getAsSOAPEnvelope(SOAPPart.java:696)
        at org.apache.axis.Message.getSOAPEnvelope(Message.java:435)
        at org.apache.axis.handlers.soap.MustUnderstandChecker.invoke(MustUnderstandChecker.java:62)
        at org.apache.axis.client.AxisClient.invoke(AxisClient.java:206)
        at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
        at org.apache.axis.client.Call.invoke(Call.java:2767)
        at org.apache.axis.client.Call.invoke(Call.java:2443)
        at org.apache.axis.client.Call.invoke(Call.java:2366)
        at org.apache.axis.client.Call.invoke(Call.java:1812)
        at com.vmware.vim25.VimBindingStub.waitForUpdates(VimBindingStub.java:49497)
        at com.avamar.mc.vmware.VmwareEventsMonitor.run(VmwareEventsMonitor.java:334)
Clone started
Clone started
Clone started
Clone started

[SavkoorSuhas]

Please give me this info:

# df -h

# dpnctl status

# status.dpn

# mccli server show-services

Along with this, try the connect operation one more time. Once it fails, give me the vdr-server.log file

Suhas

[dustman86]

root@vm-pic-den-ofc-vdp01:~/#: df -h

Filesystem      Size  Used Avail Use% Mounted on

/dev/sda2        32G  6.0G   24G  20% /

udev            1.9G  148K  1.9G   1% /dev

tmpfs           1.9G     0  1.9G   0% /dev/shm

/dev/sda1       128M   37M   85M  31% /boot

/dev/sda7       1.5G  144M  1.3G  11% /var

/dev/sda9       138G  3.7G  127G   3% /space

/dev/sdb1       512G  498M  512G   1% /data01

/dev/sdc1       512G   71M  512G   1% /data02

/dev/sdd1       512G   76M  512G   1% /data03

root@vm-pic-den-ofc-vdp01:~/#: dpnctl status

Identity added: /home/dpn/.ssh/dpnid (/home/dpn/.ssh/dpnid)

dpnctl: INFO: gsan status: up

dpnctl: INFO: MCS status: up.

dpnctl: INFO: emt status: up.

dpnctl: INFO: Backup scheduler status: up.

dpnctl: INFO: axionfs status: down.

dpnctl: INFO: Maintenance windows scheduler status: enabled.

dpnctl: INFO: Unattended startup status: enabled.

dpnctl: INFO: avinstaller status: up.

dpnctl: INFO: [see log file "/usr/local/avamar/var/log/dpnctl.log"]

root@vm-pic-den-ofc-vdp01:~/#: status.dpn
Wed Apr 19 07:00:55 MDT 2017  [VM-PIC-DEN-OFC-VDP01] Wed Apr 19 13:00:55 2017 UTC (Initialized Thu Apr 13 15:20:03 2017 UTC)
Node   IP Address     Version   State   Runlevel  Srvr+Root+User Dis Suspend Load UsedMB Errlen  %Full   Percent Full and Stripe Status by Disk
0.0  10.248.248.213 7.2.80-129  ONLINE fullaccess mhpu+0hpu+0hpu   1 false   0.28 3471   178580   0.0%   0%(onl:9  )  0%(onl:8  )  0%(onl:8  )
Srvr+Root+User Modes = migrate + hfswriteable + persistwriteable + useraccntwriteable

System ID: 1492096803@00:50:56:8B:9C:B2

All reported states=(ONLINE), runlevels=(fullaccess), modes=(mhpu+0hpu+0hpu)
System-Status: ok
Access-Status: full

Last checkpoint: cp.20170418150510 finished Tue Apr 18 09:05:38 2017 after 00m 28s (OK)
Last GC: finished Tue Apr 18 08:00:36 2017 after 00m 00s >> recovered 0.00 KB (OK)
Last hfscheck: finished Tue Apr 18 09:05:01 2017 after 02m 39s >> checked 24 of 24 stripes (OK)

Maintenance windows scheduler capacity profile is active.
  The backup window is currently running.
  Next backup window start time: Wed Apr 19 20:00:00 2017 MDT
  Next maintenance window start time: Wed Apr 19 08:00:00 2017 MDT

root@vm-pic-den-ofc-vdp01:~/#: mccli server show-services

0,23000,CLI command completed successfully.

Name                               Status

---------------------------------- ------------------------------------------

Hostname                           vm-pic-den-ofc-vdp01.corp.xxxxxxxxxxxxxx.com

IP Address                         10.248.248.213

Load Average                       0.32

Last Administrator Datastore Flush 2017-04-19 06:45:00 MDT

PostgreSQL database                Running

Web Services                       Error

Web Restore Disk Space Available   536,096,776K

Login Manager                      Running

snmp sub-agent                     Disabled

ConnectEMC                         Disabled

snmp daemon                        Disabled

ssh daemon                         Running

Data Domain SNMP Manager           Not Running

Remote Backup Manager Service      Running

RabbitMQ                           Not Running

Replication cron job               Not Running

/pic-vc01.corp.xxxxxxxxxx.com    All vCenter connections OK.

vdr-server.log excerpt

2017-04-19 07:00:03,311 INFO  [Timer_vc]-db.EntityDisplayPathDAO: EntityDisplayPathDAO.pruneDuplicateUuidRows found 0 occurrences of duplicate instance_uuid values

2017-04-19 07:00:51,598 INFO  [pool-1-thread-1]-vi.ViJavaServiceInstanceMonitorImpl: Size of Service Instance Set : [1]

2017-04-19 07:02:33,233 INFO  [Timer_cache]-proxy.CommonBaseProxy:  (S T A R T) Reload cache....

2017-04-19 07:02:33,233 INFO  [Timer_cache]-services.ClientManagementServiceWS: Getting:VirtualMachine clients from Cache

2017-04-19 07:02:33,233 INFO  [Timer_cache]-services.ClientManagementServiceWS: Completed : Fetched Clients from Cache, size: 0

2017-04-19 07:02:33,233 INFO  [Timer_cache]-services.ClientManagementServiceWS: Getting:Normal clients from Cache

2017-04-19 07:02:33,234 INFO  [Timer_cache]-services.ClientManagementServiceWS: Completed : Fetched Clients from Cache, size: 0

2017-04-19 07:02:33,257 WARN  [Timer_cache]-server.VDPMcSdkUtil:  Replication domain not present.

2017-04-19 07:02:33,273 INFO  [Timer_cache]-proxy.CommonBaseProxy:  (E N D) Reload cache completed

2017-04-19 07:02:37,986 INFO  [Timer_ServiceHealthValidator]-schedule.ServiceHealthValidatorTimerTask: Starting Service Health Check on Wed Apr 19 07:02:37 MDT 2017

2017-04-19 07:02:38,003 INFO  [Timer_ServiceHealthValidator]-schedule.ServiceHealthValidatorTimerTask: Internal proxy configured?true

2017-04-19 07:02:38,003 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: GsanCLI: Updating service state.

2017-04-19 07:02:38,337 INFO  [GsanCLI-update]-services.BaseCLI$4: GsanCLI-update: State update complete. New state: running

2017-04-19 07:02:38,338 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: McsCLI: Updating service state.

2017-04-19 07:02:38,342 INFO  [McsCLI-update]-service.AdapterUtils: MCS Web Services URL: https://vm-pic-den-ofc-vdp01.corp.xxxxxxxxxxx.com:9443/services/mcService  MCUserId="MCUser"

2017-04-19 07:02:38,375 INFO  [McsCLI-update]-connection.Mcsdk10StubManager: ServiceInstanceMoref desc=Service Id: urn:uuid:FF7DB1A5B8F3719AA81492607192590 name=urn:uuid:FF7DB1A5B8F3719AA81492607192590 value=SERVICE

2017-04-19 07:02:38,377 INFO  [McsCLI-update]-connection.McAccessManager: Creating new mcsdk stub handler for connection key: [609063526, Service Id: urn:uuid:FF7DB1A5B8F3719AA81492607192590] on Thread: [McsCLI-update]

2017-04-19 07:02:38,383 INFO  [McsCLI-update]-services.McsCLI: MC Connection with Key: [McConnectionKey URI: https://vm-pic-den-ofc-vdp01.corp.xxxxxxxxxx.com:9443/services/mcsdk10 Username: MCUser Locale: en_US mcDomain: / trustAllSSLCerts: true productName: VDP] isConnected: [true]

2017-04-19 07:02:38,383 INFO  [McsCLI-update]-services.McsCLI: Starting check to see if mcs can be restored.

2017-04-19 07:02:40,524 INFO  [McsCLI-update]-services.McsCLI: MCS is running

2017-04-19 07:02:40,524 INFO  [McsCLI-update]-services.BaseCLI$4: McsCLI-update: State update complete. New state: running

2017-04-19 07:02:40,524 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: VmwareFlrCLI: Updating service state.

2017-04-19 07:02:40,556 INFO  [VmwareFlrCLI-update]-services.BaseCLI$4: VmwareFlrCLI-update: State update complete. New state: running

2017-04-19 07:02:40,556 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: MaintCLI: Updating service state.

2017-04-19 07:02:40,607 INFO  [MaintCLI-update]-services.BaseCLI$4: MaintCLI-update: State update complete. New state: running

2017-04-19 07:02:40,608 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: SchedCLI: Updating service state.

2017-04-19 07:02:42,514 INFO  [SchedCLI-update]-services.BaseCLI$4: SchedCLI-update: State update complete. New state: running

2017-04-19 07:02:42,514 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: AvagentCLI: Updating service state.

2017-04-19 07:02:42,577 INFO  [AvagentCLI-update]-services.BaseCLI$4: AvagentCLI-update: State update complete. New state: running

2017-04-19 07:02:42,577 INFO  [Timer_ServiceHealthValidator]-services.BaseCLI: AvagentReplicateCLI: Updating service state.

2017-04-19 07:02:42,608 INFO  [AvagentReplicateCLI-update]-services.BaseCLI$4: AvagentReplicateCLI-update: State update complete. New state: running

2017-04-19 07:02:42,609 INFO  [Timer_ServiceHealthValidator]-schedule.ServiceHealthValidatorTimerTask: Ending Service Health Check on Wed Apr 19 07:02:42 MDT 2017 Elapsed time(ms)=4623

2017-04-19 07:02:42,675 INFO  [Timer_ServiceHealthValidator]-schedule.ServiceHealthValidatorTimerTask: Waiting to start ?false

2017-04-19 07:02:51,598 INFO  [pool-1-thread-1]-vi.ViJavaServiceInstanceMonitorImpl: Size of Service Instance Set : [1]

2017-04-19 07:04:51,598 INFO  [pool-1-thread-1]-vi.ViJavaServiceInstanceMonitorImpl: Size of Service Instance Set : [1]

Thanks for the response and let me know if you need any further info. I only provided a bit of the log as it is a large file, but should be the info you requested.

[SavkoorSuhas]

I would need the complete vdr-server.log

Try the connect one more time and attach that file to the reply.

Also,

1. Perform nslookup of vCenter IP and FQDN from the VDP appliance and verify it is giving the right name resolution

Make sure no unnecessary IPv6 is being populated.

2. Telnet (telnet) from VDP to vCenter over 80 and 443

3. Verify the time on VC and VDP is in sync

4. nslookup VDP from VC and verify this works good too without unnecessary IPv6

Suhas

[dustman86]

Thanks for responding. Please let me know if there are any other questions.

1. root@vm-pic-den-ofc-vdp01:~/#: nslookup pic-vc01.corp.xxxxxxxxxxxx.com
Server:         10.248.248.54
Address:        10.248.248.54#53

Name:   pic-vc01.corp.xxxxxxxxxx.com
Address: 10.248.248.59

root@vm-pic-den-ofc-vdp01:~/#: nslookup 10.248.248.59
Server:         10.248.248.54
Address:        10.248.248.54#53

59.248.248.10.in-addr.arpa      name = pic-vc01.corp.xxxxxxxxxx.com.

2. The date and time match. NTP servers have been added to my ESXi hosts prior.

3. root@vm-pic-den-ofc-vdp01:~/#: telnet pic-vc01.corp.xxxxxxxxxxxx.com 80
Trying 10.248.248.59...
Connected to pic-vc01.corp.xxxxxxxxxxxxxxx.com.
Escape character is '^]'.

root@vm-pic-den-ofc-vdp01:~/#: telnet pic-vc01.corp.xxxxxxxxxxxx.com 443
Trying 10.248.248.59...
Connected to pic-vc01.corp.xxxxxxxxxxxxxx.com.
Escape character is '^]'.

[SavkoorSuhas]

Output of this please:

mcserver.sh --status | tail -15

# Suhas

[dustman86]

Here is the info you requested.

admin@vm-pic-den-ofc-vdp01:~/>: mcserver.sh --status | tail -15
Backup UserInfo polling interval (min): 60
Next Backup UserInfo polling: Fri Apr 21 13:34:16 MDT 2017
===============
===============
SERVICE STATUS: com.avamar.mc.rpt.ReportService
Life cycle state: started
Active Report Requests: 0

===============
===============
SERVICE STATUS: com.avamar.mc.pdm.ProxyDeploymentManagerService
Life cycle state: started

===============
Administrator Server status check complete.

[SavkoorSuhas]

Could you:

# mcserver.sh --restart --verbose >> /tmp/logs.txt

and provide me with this file?

Post this:

# emwebapp.sh --restart

Then try reconnecting?

# Suhas

[dustman86]

Thanks for the response. In an interesting turn of events this VDP appliance as well as two others are working as intended.

What changed? We had our monthly patching cycle on Friday night, which rebooted the vCenter server as well as other servers such as Domain Controllers.

*Note this had been done before with no change in behavior.

After the patching completed I tested the connectivity and was able to access the appliances via the vCenter server plugin.

I am willing to provide additional logging or details if you so desire.

Thanks again for the assistance.