Trouble with Horizon Workspace 1.8 Desktop Clients

[BNO2006]

Hi everyone,

I've been working on a Workspace lab environment the past few weeks and currently everything seems to be working fine, except for the desktop clients.

I can login using the web client and iOS client, but when using the desktop clients I get a) different behavior and b) cannot access Workspace.

The log of the windows client shows the following:

2014-06-16 11:39:59 [INFO] [4388.5176] [wWinMain] ***** Horizon Workspace version 1.8.1-1751013 started *****

2014-06-16 11:39:59 [DEBUG] [4388.5176] [wWinMain] Cmd line: horizonapi://oauth2/?code=tdk5xA7Sfp3MgUHO8mMeY4xotiEHPdZ5&activation_code=eyJvdGEiOiI1Njo3QktpUzFqTzVEUHJOb1pEOVRCazRucGZnaDFqVmw2diIsInVybCI6Imh0dHBzOi8vZ2F0ZXdheS12YS5hZmZlY3QubG9jYWwvIn0=&state=ready&userstore=default

2014-06-16 11:39:59 [DEBUG] [4388.5176] PersistentConfig: New instance for PID 4388, isUser=true isClient=true

2014-06-16 11:39:59 [INFO] [4388.5176] PersistentConfigWin32Reg: using windows registry

2014-06-16 11:39:59 [INFO] [4388.5176] [wWinMain] Finishing registration in new helper process

2014-06-16 11:39:59 [INFO] [4388.5176] [HorizonClient::HorizonClient] HorizonClient Created

2014-06-16 11:39:59 [INFO] [4388.5176] [HorizonClient::HandleRegistrationResponse] HandleRegistrationResponse

2014-06-16 11:39:59 [INFO] [4388.5176] [HorizonClient::HandleRegistrationSuccess] HandleRegistrationSuccess

2014-06-16 11:39:59 [INFO] [4388.5176] [HorizonClient::ChangeProxySetting] No host proxy information for https://portal.company.tld.

2014-06-16 11:39:59 [ERROR] [4388.5176] [HorizonClient::HandleRegistrationSuccess] HZNActivateOAuth2Client failed. Try again without proxy.

2014-06-16 11:39:59 [ERROR] [4388.5176] [HorizonClient::HandleRegistrationSuccess] HZNActivateOAuth2Client failed: UNKNOWN (-206)

2014-06-16 11:39:59 [INFO] [4388.5176] [HorizonClient::HandleRegistrationResponse] Registration failed

2014-06-16 11:39:59 [INFO] [4388.5176] [HorizonClient::~HorizonClient] HorizonClient Deleted

2014-06-16 11:39:59 [INFO] [4388.5176] [wWinMain] Systray exiting winmain.

2014-06-16 11:39:59 [INFO] [6100.2996] [CloseBrowserWindowAndExit] User registration: received registration end event, closing browser window

2014-06-16 11:39:59 [ERROR] [3008.3032] [WaitForFinishRegistration] WaitForFinishRegistration ended with registration failure

2014-06-16 11:39:59 [INFO] [3008.3032] [ShowBalloon] Balloon error: Unable to connect to VMware Horizon..

2014-06-16 11:39:59 [INFO] [6100.1384] [wWinMain] Systray exiting winmain.

2014-06-16 11:39:59 [INFO] [6100.1384] [HorizonClient::~HorizonClient] HorizonClient Deleted

2014-06-16 11:39:59 [ERROR] [3008.3032] [WaitForFinishRegistration] User registration failed

2014-06-16 11:39:59 [INFO] [3008.3032] [WaitForFinishRegistration] WaitForFinishRegistration end

The Windows Client accepts the Horizon Url portal.company.tld and presents the login form, but fails to login. the HorizonWorkspace.log created by the diagnostics output shows the above error.

The Mac Client does not recognize the Url at all. It just says: Invalid Horizon Server address.

The corresponding log entries:

2014-Jun-16 10:34:34.890795 408363 INFO 1799 0x10400a530 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[AppController authenticateViaHorizonWithAlert:] - Starting horizon authentication process

2014-Jun-16 10:34:46.017229 11535169 INFO 47879 0x10421b050 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthController verifyHznServer:] - User provided Horizon URI: https://portal.company.tld

2014-Jun-16 10:34:46.635545 12153485 ERROR 47879 0x10421b050 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator performHorizonOperation:withName:] - HZNGetServiceInfofailed. Error code -260

2014-Jun-16 10:34:46.715755 12233695 ERROR 47879 0x10421b050 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator performHorizonOperation:withName:] - retry of HZNGetServiceInfo failed. Error code -260

Connecting using the iOS client from an iPad and an iPhone works without issues, same with the web client.

I've searched the web and this forum for hints regarding this issue, but till now I didn't find anything. I hope the community can help.

Update:

I was able to fix some issues related to the client issue, the Windows Client now can login, but after that it prompts "Invalid domain name". The only error I can see on the log right now is:

2014-06-18 10:44:07 [ERROR] [5516.5208] [HorizonClient::GetDomainName] Unable to get user name, error = 0x00000534

I am unable to find anyhting related to this error, Google gives me blank results.

[RaviChayanam]

The line "2014-06-18 10:44:07 [ERROR] [5516.5208] [HorizonClient::GetDomainName] Unable to get user name, error = 0x00000534" is indicating that the client is unable to determine the userdomain and username of the currently logged in user. Can you show the output of set command on this windows machine please?

[BNO2006]

Thank you for your reply.

I was able to resolve the issues for the Windows Clients. The Intermediate CA certificate was not provided through my Proxy, now it is and all Windows, iOS and Web Clients can login.

The behavior of the Mac Client changed as well. I now get to see the login form, but the login fails. The Clients log shows:

2014-Jun-23 11:35:24.809779 18928163 ERROR 40263 0x1043561c0 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator performHorizonOperation:withName:] - HZNActivateOAuth2Clientfailed. Error code -206

2014-Jun-23 11:35:29.885929 24004468 ERROR 40263 0x1043561c0 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator performHorizonOperation:withName:] - retry of HZNActivateOAuth2Client failed. Error code -206

horizon.log on service-va horizon.log shows this:

2014-06-23 13:35:10,048 WARN  (tomcat-http--7) [PORTAL;-;10.0.0.102] com.vmware.horizon.service.interceptor.ControllerInterceptor - No valid suite token

2014-06-23 13:35:10,479 WARN  (tomcat-http--11) [PORTAL;-;10.0.0.102] com.vmware.horizon.service.interceptor.ControllerInterceptor - No valid suite token

2014-06-23 13:35:12,079 ERROR (tomcat-http--12) [PORTAL;-;10.0.0.102] com.tricipher.tacsag.saml.AuthenticationUtilities - Saml exception occured :

com.vmware.horizon.common.api.exception.SamlAuthenticationException: saml.authentication.failed    Status code response is 401.

The above does not happen for the Windows Clients.

Update:

Okay, I disabled the Windows Authentication Feature in Connector-VA and the SAML exception is now gone.

The horizon.log now only shows 2 lines at each connection attempt from a Mac:

2014-06-23 18:12:43,729 WARN  (tomcat-http--28) [PORTAL;-;10.0.0.102] com.vmware.horizon.service.interceptor.ControllerInterceptor - No valid suite token

2014-06-23 18:12:44,166 WARN  (tomcat-http--36) [PORTAL;-;10.0.0.102] com.vmware.horizon.service.interceptor.ControllerInterceptor - No valid suite token

Here is the client log for one session:

2014-Jun-23 16:12:38.992595 156369 INFO 1799 0x103b11340 msync:daemonwrapper osx/DaemonWrapper.mm:415 Application finished launching, OS X version is 10.9.3.

2014-Jun-23 16:12:39.016154 179928 INFO 1799 0x103b11340 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator initializeHznApi] - Setting Horizon timeout to: 240

2014-Jun-23 16:12:39.016228 180003 INFO 1799 0x103b11340 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator initializeHznApi] - Setting Horizon connection timeout to: 120

2014-Jun-23 16:12:39.028478 192252 INFO 1799 0x103b11340 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[AppController authenticateViaHorizonWithAlert:] - Starting horizon authentication process

2014-Jun-23 16:12:45.162327 6326287 INFO 46855 0x103b55540 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthController verifyHznServer:] - User provided Horizon URI: https://portal.domain.tld

2014-Jun-23 16:12:45.760314 6924305 INFO 46855 0x103b55540 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator verifyHznServer:] - service info for 'https://portal.domain.tld' is build '1.8.1.1810 Build 1750976' time '2014-06-23 18:12:43 CEST'

2014-Jun-23 16:12:45.761263 6925255 INFO 46855 0x103b55540 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator startAuthenticationUsingUri:] - Starting auth with server 'https://portal.domain.tld'.

2014-Jun-23 16:12:45.762115 6926107 INFO 46855 0x103b55540 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthController authenticateWithServerUri:] - Opening browser window for: https://portal.domain.tld/SAAS/API/1.0/GET/user/devices/register?user_device=%7B%22deviceId%22%3A%22BC423008-4C02-4308-B410-EF2437E71C21%22%2C%22machineName%22%3A%22Bastian%E2%80%99s%20MacBook%20Pro%22%2C%22osName%22%3A%22Mac%20OS%20X%22%2C%22osVersion%22%3A%2210.9.3%22%2C%22osFamily%22%3A%22desktop%22%7D&app_product_id=VMware-HorizonDesktopAgent-1.5&response_type=code&redirect_uri=horizonapi://oauth2&state=&device_name=Bastian%E2%80%99s%20MacBook%20Pro

2014-Jun-23 16:12:53.241483 14405691 ERROR 1799 0x103b11340 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthController webView:didFailProvisionalLoadWithError:forFrame:] - Error loading login page: Error Domain=WebKitErrorDomain Code=102 "Frame load interrupted" UserInfo=0x61000026fc00 {NSErrorFailingURLStringKey=horizonapi://oauth2?code=Oaa0iLe27wmbH87wLwMOGARI0OhfWZgU&activation_code=eyJvdGEiOiIxNjY6aWczVHlpZHlQOG9raG5reXpPM2FRdmZRdU9BdUpMd3oiLCJ1cmwiOiJodHRwczovL2dhdGV3YXktdmEuYWZmZWN0LmxvY2FsLyJ9&userstore=default, NSLocalizedDescription=Frame load interrupted, NSErrorFailingURLKey=horizonapi://oauth2?code=Oaa0iLe27wmbH87wLwMOGARI0OhfWZgU&activation_code=eyJvdGEiOiIxNjY6aWczVHlpZHlQOG9raG5reXpPM2FRdmZRdU9BdUpMd3oiLCJ1cmwiOiJodHRwczovL2dhdGV3YXktdmEuYWZmZWN0LmxvY2FsLyJ9&userstore=default}

2014-Jun-23 16:12:53.244303 14408511 INFO 41251 0x103b58a40 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator parseRedirectUri:] - client info not in keychain.

2014-Jun-23 16:12:58.293406 19457769 ERROR 41251 0x103b58a40 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator performHorizonOperation:withName:] - HZNActivateOAuth2Clientfailed. Error code -206

2014-Jun-23 16:13:03.365836 24530354 ERROR 41251 0x103b58a40 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator performHorizonOperation:withName:] - retry of HZNActivateOAuth2Client failed. Error code -206

2014-Jun-23 16:13:03.365946 24530465 INFO 41251 0x103b58a40 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[HorizonAuthenticator getSecretAndIdWithAct:andAuth:] - call to HZNActivateOAuth2Client returned code (-206)

2014-Jun-23 16:13:03.376947 24541465 INFO 41251 0x103b58a40 msync:daemonwrapper osx/DaemonWrapper.mm:415 -[AppController authenticateViaHorizonWithAlert:] - Starting horizon authentication process

2014-Jun-23 16:13:11.241136 32405902 INFO 1799 0x103b11340 msync:daemonwrapper osx/DaemonWrapper.mm:415 Stopping daemon...

What strikes me is the time difference of both logs. It seems like the client has a UTC+0 clock while the server has the correct UTC+2. The clock on all Macs is configured correctly and the system shows the correct time and time zone.

[RaviChayanam]

Do you see a login screen on your Mac client? The login screen should ask for username, password (or securid if you have that configured)

Can we get two more logs please

1. /opt/vmware/nginx/logs/access.log from gateway-va

2. /opt/vmware/c2/c2instance/logs/connector.log from connector-va. This should show all auth attempts.

[BNO2006]

Yes, I see the login screen and I am able to enter credentials.

Please find the logs attached.

[RaviChayanam]

Thanks for the logs, it shows that the user is authenticated but a later call fails. What do you see as error on the UI? Do you still see "Invalid Horizon Server address" or do you see something else? Have you tried restarting the app and did it make any difference?

[BNO2006]

This is the message I am getting: