VMware Horizon Community
Kushmaro
Contributor
Contributor
‎09-27-2011 01:15 AM

Random Disconnects from view sessions

Hi,

I'm experiancing a problem with users being disconnected with a "session timeout" box poping up,

session expiry time was set to 180 minuts (I increased it now to 600 - the default)

but when looking at the log file, I saw some messages that alaremed me yet I'm not sure what they mean:

This is a first part of the log I thought was suspicious from the "pcoip server" log at

c:\programdata\VMware View\logs\pcoip_server

09/26/2011, 12:04:01.272> LVL:0 RC:-500    IMG_FRONTEND :cSW_HOST_FRONTEND::open_display - Error attaching to SVGADevTap, error 1: Failed 


09/26/2011, 12:04:01.272> LVL:1 RC:-500    IMG_FRONTEND :reconfigure_displays: Error 1 in svga_get_display_modes call!


09/26/2011, 12:04:01.272> LVL:2 RC:   0        MGMT_IMG :Resetting encoder (reset_type=1)


09/26/2011, 12:04:01.288> LVL:0 RC:-500    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() unexpected return value, retcode = 4294967295, GetLastError() =  6, m_event_count = 3, m_event_timeout_ms = 33, m_state = 1.


09/26/2011, 12:04:01.288> LVL:0 RC:   0    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() m_events[0] = 6a4


09/26/2011, 12:04:01.288> LVL:0 RC:   0    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() m_events[1] = 6a8


09/26/2011, 12:04:01.288> LVL:0 RC:   0    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() m_events[2] = e78


09/26/2011, 12:04:01.631> LVL:1 RC:   0          SERVER :InputDevTap_GetKeyboardState @ timer: LEDs = 0x02 ==> 0x00


09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server mailbox: MBX_SHUTDOWN with agent disconnect reason code (0x1)


09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server mailbox: Stopping mailbox message loop


09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server main: exiting


09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server cleanup: tearing down pcoip with agent disconnect reason code(1) and waiting


09/26/2011, 12:04:01.678> LVL:1 RC:   0          SERVER :map_agent_to_tera: DISCONNECT_EXPIRED -> TERA_DISCONNECT_CAUSE_HOST_BROKER_SESSION_EXPIRY_TIMEOUT


09/26/2011, 12:04:01.678> LVL:2 RC:10038            PERF :tera_perf_monitor_send: Failure during message write (header).


09/26/2011, 12:04:01.678> LVL:1 RC:-500            PERF :tera_perf_unregister: Sending remove_instance failed.


09/26/2011, 12:04:01.678> LVL:0 RC:   0       MGMT_SESS :Tearing down the session


09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Request to reset session (PRI: 0)


09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Session closed locally (172.20.165.107, 00-0F-01-01-01-00, PRI: 0)


09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Sending to peer: BYE disconnect reason cause (0x102)


09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Session closure reason cause (host:broker: session expiry timeout)


09/26/2011, 12:04:01.678> LVL:2 RC:   0      MGMT_VCHAN :app_reset: Session has been dropped. Forcing all channels to close!


09/26/2011, 12:04:01.678> LVL:2 RC:   0 MGMT_PCOIP_DATA :mgmt_pcoip_data_set_media_activation: URBoIP is not used


09/26/2011, 12:04:01.678> LVL:1 RC:   0        MGMT_DDC :mgmt_ddc_fcc_callback: queuing TERA_MGMT_FCC_EVENT_RESET [pri=0]


09/26/2011, 12:04:01.678> LVL:1 RC:-500           VGMAC :tera_sock_recv() failed - Interrupted system call (10004)!

can anyone interpert this part of the log?

why is the session being forcly disconnected by VMware Client/View?

thanks a lot

Omer.

Please reward this comment if you find it useful
0 Kudos
6 Replies
admin
Immortal
Immortal
‎09-27-2011 01:33 AM

It might be worth checking out http://kb.vmware.com/kb/2001443

0 Kudos
Kushmaro
Contributor
Contributor
‎09-27-2011 01:37 AM

Thnks for the tip,

unfortunatly the network here is a LAN network, latency of approximatly 2ms ...

definetly a fast connection and not a WAN network ..

Please reward this comment if you find it useful
0 Kudos
Kushmaro
Contributor
Contributor
‎09-27-2011 01:47 AM

as I further examined the log file I noticed that msot of the log is of properly working pcoip session

and then happens somthing weird.

09/26/2011, 12:03:33.238> LVL:2 RC:   0        MGMT_IMG :log:  enc bits/pixel - 0.67, enc bits/sec - 255265.34, enc MPix/sec - 0.38, decode rate est (MBit/sec) - 10.50
09/26/2011, 12:03:33.551> LVL:2 RC:   0 MGMT_PCOIP_DATA :Tx thread info: round trip time (ms) = 0, variance = 0, rto = 100
09/26/2011, 12:03:59.022> LVL:2 RC:   0 MGMT_PCOIP_DATA :Tx thread info: round trip time (ms) = 0, variance = 0, rto = 100
09/26/2011, 12:04:01.241> LVL:0 RC:   0    IMG_FRONTEND :flip_frame_buffer: Resolution change for display 0 [0, 1004]
09/26/2011, 12:04:01.241> LVL:0 RC:-500    IMG_FRONTEND :reattach_devtap(): Attempting recovery from devtap error with Detach/Attach.
09/26/2011, 12:04:01.272> LVL:0 RC:-500    IMG_FRONTEND :cSW_HOST_FRONTEND::open_display - Error attaching to SVGADevTap, error 1: Failed
09/26/2011, 12:04:01.272> LVL:1 RC:-500    IMG_FRONTEND :reconfigure_displays: Error 1 in svga_get_display_modes call!
09/26/2011, 12:04:01.272> LVL:2 RC:   0        MGMT_IMG :Resetting encoder (reset_type=1)
09/26/2011, 12:04:01.288> LVL:0 RC:-500    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() unexpected return value, retcode = 4294967295, GetLastError() =  6, m_event_count = 3, m_event_timeout_ms = 33, m_state = 1.
09/26/2011, 12:04:01.288> LVL:0 RC:   0    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() m_events[0] = 6a4
09/26/2011, 12:04:01.288> LVL:0 RC:   0    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() m_events[1] = 6a8
09/26/2011, 12:04:01.288> LVL:0 RC:   0    IMG_FRONTEND :cSW_HOST_FRONTEND_SVGA_RX_THREAD::run() m_events[2] = e78
09/26/2011, 12:04:01.631> LVL:1 RC:   0          SERVER :InputDevTap_GetKeyboardState @ timer: LEDs = 0x02 ==> 0x00
09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server mailbox: MBX_SHUTDOWN with agent disconnect reason code (0x1)
09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server mailbox: Stopping mailbox message loop
09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server main: exiting
09/26/2011, 12:04:01.678> LVL:2 RC:   0          SERVER :server cleanup: tearing down pcoip with agent disconnect reason code(1) and waiting
09/26/2011, 12:04:01.678> LVL:1 RC:   0          SERVER :map_agent_to_tera: DISCONNECT_EXPIRED -> TERA_DISCONNECT_CAUSE_HOST_BROKER_SESSION_EXPIRY_TIMEOUT
09/26/2011, 12:04:01.678> LVL:2 RC:10038            PERF :tera_perf_monitor_send: Failure during message write (header).
09/26/2011, 12:04:01.678> LVL:1 RC:-500            PERF :tera_perf_unregister: Sending remove_instance failed.
09/26/2011, 12:04:01.678> LVL:0 RC:   0       MGMT_SESS :Tearing down the session
09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Request to reset session (PRI: 0)
09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Session closed locally (172.20.165.107, 00-0F-01-01-01-00, PRI: 0)
09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Sending to peer: BYE disconnect reason cause (0x102)
09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Session closure reason cause (host:broker: session expiry timeout)
09/26/2011, 12:04:01.678> LVL:2 RC:   0      MGMT_VCHAN :app_reset: Session has been dropped. Forcing all channels to close!
09/26/2011, 12:04:01.678> LVL:2 RC:   0 MGMT_PCOIP_DATA :mgmt_pcoip_data_set_media_activation: URBoIP is not used
09/26/2011, 12:04:01.678> LVL:1 RC:   0        MGMT_DDC :mgmt_ddc_fcc_callback: queuing TERA_MGMT_FCC_EVENT_RESET [pri=0]
09/26/2011, 12:04:01.678> LVL:1 RC:-500           VGMAC :tera_sock_recv() failed - Interrupted system call (10004)!
09/26/2011, 12:04:01.678> LVL:2 RC:   0           VGMAC :PCoIP UDP RX thread exiting
09/26/2011, 12:04:01.678> LVL:1 RC:-500 MGMT_PCOIP_DATA :INIT: Peer has reset our PCoIP connection.  Aborting session ...
09/26/2011, 12:04:02.272> LVL:0 RC:-500    IMG_FRONTEND :close_displays: Error resetting SVGADevTap, error 1.

the bolded underlined lines shows that theres a resolution change at the VM, and after that it seems that theres an error with re-attaching "devtap" which leads eventually to the closure of the session...

does anyone here know whats the background procedures that are being done?

can this be the cause for the session disconnect?

thanks a lot,

omer

Please reward this comment if you find it useful
0 Kudos
mpryor
Commander
Commander
‎09-27-2011 06:46 AM

The root cause of the issue is the disconnect request, as you said.

09/26/2011, 12:04:01.678> LVL:2 RC:   0       MGMT_SSIG :Session closure reason cause (host:broker: session expiry timeout)

The devtap error you're seeing above is likely due to the Windows user session being detached from the console during the disconnect process - in this particular case I think it's safe to ignore them.

0 Kudos
Kushmaro
Contributor
Contributor
‎09-27-2011 06:50 AM

can you estimate why this disconnect request occurs?

I've opened a support request, yet a quick answer is always appreciated Smiley Happy

Please reward this comment if you find it useful
0 Kudos
mpryor
Commander
Commander
‎09-27-2011 01:36 PM

It's as you mentioned in your initial comment:

"I'm experiancing a problem with users being disconnected with a "session timeout" box poping up,

session expiry time was set to 180 minuts (I increased it now to 600 - the default) "

The user's broker session has timed out 180 minutes after the user authenticated, and all connections are requested to be closed at that time. In the connect server's logs you will see the logout occur there that triggers the disconnect command.

0 Kudos