Pages

Friday, December 21, 2018

VMware Horizon 7.6.0 agent unable to contact Connection Server with error: “com.vmware.vdi.messagesecurity.MessageSecurityException: Paired key does not exist”

Problem

You’ve noticed that some desktops are in Agent Unreachable state in the VMware Horizon 7 Administrator console and clicking on the elipsis displays the following detail:

Status:Agent unreachable

Pairing state:Paired and secured

Configured by:vcs.domain.com

Attempted theft by:

image

Reviewing the debug logs on the virtual desktop in the directory C:\programdata\VMware\VDM\Logs:

image

… displays the following entries:

2018-12-17T16:48:34.881-04:00 INFO  (0EAC-0D78) <Thread-4> [AgentJmsConfig] Attempting to securely pair agent for JMS communication
2018-12-17T16:48:34.881-04:00 DEBUG (0EAC-0D78) <Thread-4> [AgentJmsConfig] Using paired signing key
2018-12-17T16:48:34.881-04:00 DEBUG (0EAC-0D78) <Thread-4> [JmsManager] Unable to connect to JMS server conto-vcs.contoso.com com.vmware.vdi.logger.Logger.debug(Logger.java:44)
com.vmware.vdi.messagesecurity.MessageSecurityException: Paired key does not exist
     at com.vmware.vdi.agent.messageserver.AgentJmsConfig.pairOverJms(SourceFile:318)
     at com.vmware.vdi.agent.messageserver.JmsManager.connect(SourceFile:288)
     at com.vmware.vdi.agent.messageserver.Main.Start(SourceFile:1265)
2018-12-17T16:48:44.975-04:00 ERROR (0EAC-09C4) <Main Thread> [wsnm_jms] JavaBridge reader thread init: timed out
2018-12-17T16:48:44.975-04:00 DEBUG (0EAC-0400) <1024> [wsnm_jms] AddressCache::ThreadEntry: Stopping
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] SharedMem reader opt, reader 0x02EA21E8 for channel 0x00311280 detaching from thread 0x02E62168 handleCount 7
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] SharedMem reader opt, peer is dead - reader 0x02EA21E8 in thread 0x02E62168
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=EventLoggerService
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=JavaView-3756
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=JMSBridge
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=TimingProfilerService
2018-12-17T16:48:45.177-04:00 DEBUG (0644-0958) <SharedMemReaderThread> [MessageFrameWork] CORE::AuthChannelInt::~AuthChannelInt(): Closed incoming SharedMemory channel from machine conto-PLANET002.contoso.com, user contoso\conto-PLANET002$,  channel 00311280
2018-12-17T16:48:45.177-04:00 INFO  (0644-08F4) <JavaBridge> [wsnm_jmsbridge] wsnm_jms died, restarting in a minute

image

Further review of the logs displays the following entries:

2018-12-18T11:08:00.715-04:00 DEBUG (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] coregate 'KeyVault' locking

2018-12-18T11:08:00.715-04:00 DEBUG (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] coregate 'KeyVault' locked

2018-12-18T11:08:00.715-04:00 INFO (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVaultCAPI upgrade rekey start for wsnm_jms

2018-12-18T11:08:00.716-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVaultCAPI encipher key 'local storage cipher key#1' MISSING, error:

2018-12-18T11:08:00.716-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'DataRef-9IQloB7D' from CAPI

2018-12-18T11:08:00.718-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.718-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.719-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'DataRef-AmH0fBxY' from CAPI

2018-12-18T11:08:00.719-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVaultCAPI encipher key 'local storage cipher key#1' MISSING, error:

2018-12-18T11:08:00.720-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'DataRef-hfBerq31' from CAPI

2018-12-18T11:08:00.720-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.720-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.721-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'DataRef-I4nSYR9Q' from CAPI

2018-12-18T11:08:00.721-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.722-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.722-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'DataRef-IYonrwPb' from CAPI

2018-12-18T11:08:00.722-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 87 (The parameter is incorrect.)

2018-12-18T11:08:00.722-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.722-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'local master encryption key' from CAPI

2018-12-18T11:08:00.723-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.723-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.723-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'local master encryption key' from CAPI

2018-12-18T11:08:00.724-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 87 (The parameter is incorrect.)

2018-12-18T11:08:00.724-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.724-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'local master encryption key' from CAPI

2018-12-18T11:08:00.725-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.725-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.725-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'local storage context' from CAPI

2018-12-18T11:08:00.726-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.726-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.726-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'local storage context' from CAPI

2018-12-18T11:08:00.766-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault cannot verify signature, error = 0x80090006 (Invalid Signature.)

2018-12-18T11:08:00.766-04:00 ERROR (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault registry data BAD SIGNATURE

2018-12-18T11:08:00.767-04:00 WARN (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVault failed to convert 'local storage context' from CAPI

2018-12-18T11:08:00.767-04:00 INFO (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] KeyVaultCAPI upgrade rekey completed for wsnm_jms

2018-12-18T11:08:00.767-04:00 DEBUG (12A0-0E88) <delayedRekeyCAPI> [MessageFrameWork] coregate 'KeyVault' un-locked

image

Solution

This issue had me stumped for a while as I could not find any results from the internet with the error messages above.  What ended up correcting the problem was a solution to another issue I had at another client that displayed a different error.  The solution can be found in my previous blog post here:

Troubleshooting VMware Horizon View 7.5.1 Virtual Desktop in “Agent unreachable” status
http://terenceluk.blogspot.com/2018/10/troubleshooting-vmware-horizon-view-751.html

Executing the vdmadmin command to reset the key pair resolved the issue:

vdmadmin -A -d desktop-pool-name -m name-of-machine-in-pool -resetkey

C:\Program Files\VMware\VMware View\Server\tools\bin>vdmadmin -A -d desktop-pool

-name -m planet002 -resetkey

Agent Public Key

================

MIHwMIGoBgcqhkjOOAQBMIGcAkEA/KaCzo4Syrom78z3EQ5SbbB4sF7ey80etKII864WF64B81uRpH5t

9jQTxeEu0ImbzRMqzVDZkVG9xD7nN1kuFwIVAJYu3cw2nLqOuyYO5rahJtk0bjjFAkBnhHGyepz0Tuka

ScUUfbGpqvJE8FpDTWSGkx0tFCcbnjUDC3H9c9oXkGmzLik1Yw4cIGI1TQ2iCmxBblC+eUykA0MAAkBA

lgbnFPWs2bOZJHQqyOtFVDf5IndS2riwKqaJTTUxCDutBJg4AsJqRVVa/Ktfc2Nq1joL+FF6AbAOxMtG

tyHT

C:\Program Files\VMware\VMware View\Server\tools\bin>

image

4 comments:

Matt Casper said...

Terence - The “-resetkey” only provides a temporary fix in what I’ve seen. Once the connection servers are rebooted, the agent unreachable status issues return. I currently have an open SR but VMware has been unable to provide a resolution to this point. Are you able to repro?

Michael said...

@Matt Casper & @Terence Luk
We have the same error. It could be work around with a manual Agent restart on the virtual Client.
But after some unspecific time the error comes back. Not always on the same client.
But after a reboot of the connection servers the problem reapears for sure on multiple clients.
Our SR is open since months and no hint from vmware was able toresolve this.
We have this problem 1st seen with 7.4, it stays with 7.5 & 7.5.1 and obviously with 7.6.

Matt Casper said...

@Michael & @Terence

VMware recommended an uninstall of the 7.5.1 agent, manually removing the HKLM/Software/VMware, Inc./Vmware VDM/KeyVault & KeyVaultCNG keys (which are ACL’d - Only SYSTEM has special perms so you need to replace inheritance), then reinstall the 7.5.1 agent. I have successfully tested this with the intention of automating and using to remediate in production. Could either one of you repro and let me know if it works for you also? Thanks

Alan W. said...

We are seeing this problem recently with the 7.4 agent. We have been on 7.4 for nearly 6 months and have only seen this issue in the last couple of weeks. Could have been since the last recompose but it's happening on multiple pools based on different images. Would be nice if VMware could fix this.