2013年9月4日水曜日

iPadかつ某VPNでPCoIP接続するが、タイムアウトの巻


iPadかつ某VPNでConnectionServerに接続するが、60秒でタイムアウトしてしまう事象がありました。

■NGな環境
 ・iOS6
 ・CiscoVPN(iOS標準のIPSec)
 ・ViewClient2.1および2.1.1

■OKだった環境
 ・VPNがFirePass(SSL) もしくはVPNを使わない場合
 ・ViewClient2.0


別のゼロクラから接続中に行うとセッションを奪っているので
仮想マシン上のPCoIPサービスとの何らかのやりとりは認識されているようでした。



C:\ProgramData\VMware\VDM\logs\
に仮想デスクトップにて稼働するPCoIPAgentおよびPCoIPServerの稼働ログがあります。

その他色々と、気がついたものをメモしておきます。


~pcoip_agent~

■きちんと処理された場合

09/04/2013, 09:18:36.652> LVL:2 RC:   0           AGENT :pcoip_agent_connect_req
09/04/2013, 09:18:36.652> LVL:2 RC:   0           AGENT :Client address is 0.0.0.0:0 (host order)
(中略)
09/04/2013, 09:18:37.776> LVL:2 RC:   0           AGENT :Sending connection response ok.
09/04/2013, 09:18:37.776> LVL:2 RC:   0           AGENT :pcoip_agent_connect_req (end): connection_response, 0
(以下、あるべき動作)
09/04/2013, 09:18:38.529> LVL:2 RC:   0           AGENT :MBX_CON_COMPLETE
09/04/2013, 09:18:38.529> LVL:2 RC:   0           AGENT :monitor thread: connection_complete: SOFT - MBX_CON_COMPLETE
09/04/2013, 09:18:40.401> LVL:2 RC:   0           AGENT :mb_send_acknowledgement sending ack.
09/04/2013, 09:18:40.501> LVL:2 RC:   0           AGENT :mb_send_acknowledgement succeeded to 0000800e


■変な場合

09/04/2013, 17:07:48.868> LVL:2 RC:   0           AGENT :pcoip_agent_connect_req
09/04/2013, 17:07:48.868> LVL:2 RC:   0           AGENT :Client address is 0.0.0.0:0 (host order)
(中略)
09/04/2013, 17:07:49.985> LVL:2 RC:   0           AGENT :Sending connection response ok.
09/04/2013, 17:07:49.985> LVL:2 RC:   0           AGENT :pcoip_agent_connect_req (end): connection_response, 0
(音沙汰なし・・・・)


■セッションを強制で奪う時(これは正常)

09/04/2013, 09:18:35.285> LVL:2 RC:   0           AGENT :pcoip_agent_disconnect_extended
09/04/2013, 09:18:35.285> LVL:2 RC:   0           AGENT :tera_agent_disconnect: agent close code: 2, disconnect reason: 5
09/04/2013, 09:18:35.332> LVL:2 RC:   0           AGENT :MBX_CON_CLOSED
09/04/2013, 09:18:35.332> LVL:2 RC:   0           AGENT :tera_agent_disconnect: agent close code: 2, disconnect reason: 0
09/04/2013, 09:18:35.332> LVL:2 RC:   0           AGENT :tera_agent_disconnect could not find session.
09/04/2013, 09:18:35.332> LVL:2 RC:   0           AGENT :monitor thread: exiting
09/04/2013, 09:18:35.930> LVL:2 RC:   0           AGENT :tera_agent_disconnect: connection_closed 2


~pcoip_server~

■新しいPCoIPセッションが開始されるたびに、新しいファイルにログか書かれます。

09/04/2013, 17:07:48.921> LVL:2 RC:   0          COMMON :-- pcoip_server begins.
(中略)
09/04/2013, 17:07:50.097> LVL:2 RC:   0       MGMT_SSIG :Incoming session with: 10.xxx.yyy.zzz
09/04/2013, 17:07:50.097> LVL:2 RC:   0             PRI :Tera device family: SOFT_PCOIP_HOST
09/04/2013, 17:08:19.177> LVL:2 RC:   0            RTOS :tera_query_performance_frequency(): frequency is 14.316628MHz
09/04/2013, 17:08:49.658> LVL:2 RC:   0 MGMT_PCOIP_DATA :Tx thread info: bw limit = 0, plateau = 0.0, avg tx = 0.0, avg rx = 0.0 (KBytes/s)
09/04/2013, 17:08:49.658> LVL:1 RC:   0           VGMAC :Stat frms: R=000000/000000/000000  T=000000/000000/000000 (A/I/O) Loss=0.00%/0.00% (R/T)

09/04/2013, 17:08:50.027> LVL:2 RC:   0       MGMT_SSIG :Session timeout!
(ここで60秒タイムアウトが発動、iPad側にエラーを返す)
09/04/2013, 17:08:50.027> LVL:1 RC:-500          COMMON :poll_sockets failed to generate 1 callbacks!


■PCoIPのステータスなどもあります。

09/04/2013, 17:07:48.410> LVL:1 RC:   0           VGMAC :Session stats: Average TX=0.128387 average RX=0.0210645 (Mbps) Loss=0.00%/0.01% (R/T)


~wsnm_starts~

■VMware View Agentサービスを手動で上げ直した場合に記録されます。
ゴキゲンナナメの場合は、このサービスを再起動するとだいたい治ります。

2013-08-27T22:27:43.336+09:00 Stop  of PID=0x2168 EXE=C:\Program Files\VMware\VMware View\Agent\bin\wsnm.exe
2013-08-27T22:27:45.048+09:00 Start of PID=0x056C EXE=C:\Program Files\VMware\VMware View\Agent\bin\wsnm.exe

(どうやってリモートからつなぐかは別の機会に・・・)


~その他~

GPOで調整されたMTU値を認識している状況も確認できます。