PCoIP error

[sgangale]

Hi everybody,

we're having a strange issue.

VmWare View 5.3.3, 2 connection servers + 1 more CS paired with a security gateway, 16 pools and 96 clients (both full and linked).

I have an issue with only 1 user: everytime he tries to connect to his virtual client, he receives (in random order):

- connection timed out

- display protocol is currently not available

- the connection to the remote computer ended

At the fourth try he finally manages to connect.

In the View Manager the VM is always showed as Available.

I tried to analyze the issue and:

- everytime he tries to connect the VM shows a high cpu usage, which goes back to normal values as soon as the connection is successful

- i dig into logs and found:

CONNECTION SERVER LOG:

2015-03-04T20:29:37.688+01:00 INFO  (09B0-08D0) <TP-Processor10> [SessionLaunchContext] (SESSION:9238_***_1376) "domain\user", App = "pool": Session request failed.

  (SESSION:9238_***_1376:) ["domain\user", App = "pool"] (12ms): User has 1 possible sessions to analyze.

  (SESSION:9238_***_1376:) ["domain\user", App = "pool"] (12ms): Possible session match found on server cn=12560607-3a43-46a8-8904-432807e204fb,ou=servers,dc=vdi,dc=vmware,dc=int.

  (SESSION:9238_***_1376:) ["domain\user", App = "pool"] (12ms): No matching capids, selected session on server 12560607-3a43-46a8-8904-432807e204fb

  (SESSION:9238_***_1376:) ["domain\user", App = "pool"] (1396ms): Application launch failed, exception was: The display protocol for this desktop is currently not available. [NAME=PCOIP, ERROR-CODE=PROTOCOL_ERR_FAILURE]

VIEW AGENT LOG:

2015-03-04T20:29:36.261+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] commandhandler::startSession: Received windows credentials for SSO {SESSION:9238_***_1376}

2015-03-04T20:29:36.261+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] startSession found existing portal session for cn=s-1-5-21-3346229329-7196316-2077808190-1208,cn=foreignsecurityprincipals,dc=vdi,dc=vmware,dc=int {SESSION:9238_***_1376}

2015-03-04T20:29:36.261+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Starting protocol PCOIP... {SESSION:9238_***_1376}

2015-03-04T20:29:36.277+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Launch PCoIP server. {SESSION:9238_***_1376}

2015-03-04T20:29:36.277+01:00 WARN  (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Needed to disconnect existing PCoIP connection during requestConnection {SESSION:9238_***_1376}

2015-03-04T20:29:36.277+01:00 WARN  (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP requested disconnect while busy! {SESSION:9238_***_1376}

2015-03-04T20:29:36.277+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP disconnect handle: hndl 0xd {SESSION:9238_***_1376}

2015-03-04T20:29:36.277+01:00 DEBUG (01AC-1378) <NodeManagerWatcher> [pcoip_server_win32] ChannelCallbackEx: remoteName:"wsnm"  incoming:false  local:true  opened:false

2015-03-04T20:29:36.277+01:00 DEBUG (01AC-1378) <NodeManagerWatcher> [pcoip_server_win32] Closed outgoing SharedMemory channel to machine hostname.domain.local, user domain\hostname$

2015-03-04T20:29:36.277+01:00 DEBUG (0124-0FF8) <MessageChannel ReceiveThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=PCoIPVChan-SVR

2015-03-04T20:29:36.277+01:00 DEBUG (0124-0FF8) <MessageChannel ReceiveThread> [ws_vhub] USB channel callback: remoteName: PCoIP Virtual Channels incoming: true  local: true  opened: false

2015-03-04T20:29:36.277+01:00 DEBUG (0124-0FF8) <MessageChannel ReceiveThread> [MessageFrameWork] Closed incoming SharedMemory channel from machine hostname.domain.local, user domain\hostname$

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_server_win32] pcoip_vchan_plugin_server_exit(): unloaded

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [ViewMMDevRedir] pcoip_vchan_plugin_server_exit - Unloading Pcoip Server Plugin   Channel=MultimediaRedirChannel

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [ViewMMDevRedir] {MultimediaRedirChannel}: Closing channel

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] stop of virtual channel MultimediaRedirChannel

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [ViewMMDevRedir] {MultimediaRedirChannel}: Server side - After Channel Close notification

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [ViewMMDevRedir] DataMgrServer::NotifChannelState - [EnvReq: Channel] PMsgChannelClose

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [ViewMMDevRedir] DataMgrServer::Cleanup - Stopping Event processing thread

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1114) <4372> [ViewMMDevRedir] DataMgrServer::GetNextMsg - returning - PMsgChannelClose

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1114) <4372> [ViewMMDevRedir] DataMgrServer::ProcessEnvReq - Processing PMsgChannelClose - Closing A/V Device handles

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1114) <4372> [ViewMMDevRedir] States: Env=STChannelClose.  AIn=STOff.  WCam=STOff

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1114) <4372> [ViewMMDevRedir] DataMgrServer::ProcessEnvReq - Finished PMsgChannelClose

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1114) <4372> [ViewMMDevRedir] States: Env=STChannelClose.  AIn=STOff.  WCam=STOff

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1114) <4372> [ViewMMDevRedir] Thread exited. Name=DataMgrServer - EventProc. Id=4372

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-09A4) <2468> [ViewMMDevRedir] Thread exited. Name=DataMgrAgent(Reg). Id=2468

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [ViewMMDevRedir] {MultimediaRedirChannel}: Server side deleted

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-11C4) <4548> [ViewMMDevRedir] Thread exited. Name=VChanServiceThread - Server. Id=4548

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] remove of pcoip_mfw MultimediaRedirChannel

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] remove of pcoip_channel MultimediaRedirChannel

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] pcoip_mfw exit called

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] service: Stop

2015-03-04T20:29:36.308+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] Closed outgoing SharedMemory channel to machine hostname.domain.local, user domain\hostname$

2015-03-04T20:29:36.308+01:00 DEBUG (0124-11EC) <MessageChannel ReceiveThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=pcoip-mfw

2015-03-04T20:29:36.308+01:00 DEBUG (0124-11EC) <MessageChannel ReceiveThread> [ws_vhub] USB channel callback: remoteName: pcoip-mfw incoming: true  local: true  opened: false

2015-03-04T20:29:36.308+01:00 DEBUG (0124-11EC) <MessageChannel ReceiveThread> [MessageFrameWork] Closed incoming SharedMemory channel from machine hostname.domain.local, user domain\hostname$

2015-03-04T20:29:36.355+01:00 DEBUG (01AC-1024) <4132> [pcoip_mfw] DllMain - DLL_PROCESS_DETACH by "C:\Program Files\Common Files\VMware\Teradici PCoIP Server\pcoip_server_win32.exe"

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP connection closed: hndl 0xd code 2 {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Unknown handle: hndl 0xd {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Disconnected previous PCOIP connection (0xd) {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIPCnx::OnConnectionClosed {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIPCnx::OnConnectionClosed : Cleanup while no known session. {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 WARN  (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Incomplete login for session 2 {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] no partialLogon, login not initiated or interrupted {SESSION:9238_***_1376}

2015-03-04T20:29:36.495+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] util::SessionDisconnectPreLogin(): Do disconnect for session 2 {SESSION:9238_***_1376}

2015-03-04T20:29:36.526+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] enabling Display Settings in Control Panel {SESSION:9238_***_1376}

2015-03-04T20:29:36.526+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] My FQDN: hostname.domain.local {SESSION:9238_***_1376}

2015-03-04T20:29:36.542+01:00 DEBUG (0124-0158) <Main Thread> [wsnm_desktop] WTS_CONSOLE_DISCONNECT, session=2

2015-03-04T20:29:36.557+01:00 DEBUG (13D4-0CDC) <OfflineChannel> [LogonUI] OfflineChannel::OfflineChannel::ThreadEntry: thread exit event signaled.

2015-03-04T20:29:36.651+01:00 DEBUG (0124-0F54) <MessageChannel ReceiveThread> [MessageFrameWork] MessageFrameWork Worker Shutdown OnChannelDelete, Name=PCoIPVChan-APP(1620)

2015-03-04T20:29:36.651+01:00 DEBUG (0124-0F54) <MessageChannel ReceiveThread> [ws_vhub] USB channel callback: remoteName: PCoIP Virtual Channels incoming: true  local: true  opened: false

2015-03-04T20:29:36.651+01:00 DEBUG (0124-0F54) <MessageChannel ReceiveThread> [MessageFrameWork] Closed incoming SharedMemory channel from machine hostname.domain.local, user domain\hostname$

2015-03-04T20:29:36.760+01:00 INFO  (133C-0DB4) <3508> [LogonUI] Program 'LogonUI - Windows Logon User Interface Host' started, version=6.1.7601.17514 (win7sp1_rtm.101119-1850), pid=0x133C, buildtype=release, usethread=0, closeafterwrite=0

2015-03-04T20:29:36.807+01:00 DEBUG (0124-0158) <Main Thread> [wsnm_desktop] WTS_CONSOLE_CONNECT, session=1

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIPCnx::OnConnectionResponse {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP connection response: CODEC UNAVAILABLE {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP connection complete: hndl 0xffffffff code 2 {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIPCnx::OnConnectionComplete Begin {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIPCnx::OnConnectionComplete ERROR = DEVICE {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 WARN  (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP connection request failed: 14 {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] PCoIP connection request failed! (handle=0xe) {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (0124-1334) <MessageFrameWorkDispatch> [wsnm_desktop] Requested protocol for session is not available, user domain\username {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (06E8-0278) <Thread-1162> [ComponentResponse] Reponse directed to:ID:/127.0.0.1/-6932673291715716769/156636/0 {SESSION:9238_***_1376}

2015-03-04T20:29:37.556+01:00 DEBUG (06E8-0278) <Thread-1162> [ComponentResponse] Message is <?xml version="1.0"?>

Can you please help?

Thanks

[the1whynotq]

i take it this is a full clone vm?

so the question would be "whats different for this user?"

networking, vm resources, access device? if he slects rdp or uses blast is it connecting first time?

[sgangale]

hi, yes this is a full clone.

in RDP he can connect with no issues.

There's nothing different between this VM and the other full clones of its pool, the only thing that comes into my mind is that this user connects from very different network because he travels a lot, and the other users usually connect from the office, from home or from 3g networks using mobile devices.

[sgangale]

up

please please help, I'm stuck in here

[JackMac4]

Have you tried uninstalling and reinstalling the VIew Agent on his desktop? That would be the first thing I would do.