2014年5月25日日曜日

バッファロー無線APのログについて




バッファロー無線APのログの見方

以下のログはWPA2-AESで設定された無線APのものです。クライアント認証はPEAPでやっています。

無線クライアントのMACアドレスはこの端末です。

7a:a5:37:xx:xx:xx



まずはクライアントが以下のように無線APへ接続してきます。

WIRELESS  wl0: 11g : Associated User - 7a:a5:37:xx:xx:xx



認証がOKで無線APへのアクセスが許可されれば、無線APでは以下のようにPMKを登録して、キャッシュしておきます。

AUTH  eth1(25891): Register PMK: id xxxxcfb28933d76818f17c3091aaxxxx (TTL 3599) - 7C:C5:37:xx:xx:xx AUTH  eth1(25891): Authenticated User - 7C:C5:37:xx:xx:xx

AUTH  eth1(25891): Register PMK: id xxxxcfb28933d76818f17c3091bbxxxx (TTL 3600) - 7C:C5:37:xx:xx:xx



IEEE802.1X認証にてローミングした際にPMKキャッシュを使用して暗号処理を早くします。

ちなみにPMKとは、Pairwise Master Key です。

データ通信の暗号鍵の元となるキーペアのことです。

そのキーをキャッシュしておくことで、クライアントがローミングにより戻ってきたりした場合に

このキャッシュキーを使用することで、暗号通信を開始する時間を短縮しています。




PMKキャッシュを使用して再通信する場合は以下のログが出るようですね。

無線クライアントがローミングしてきて、キャッシュを使用して無線APへはいってきています。

WIRELESS: wl0: 11a : ReAssociated User - 7C:C5:37:xx:xx:xx

AUTH: eth1(25891): Found PMK: id=xxxxxxxxfa61362f1943e43768ccxxxx, ea=7a:a5:37:xx:xx:xx  bbs=00:16:0x:xx:xx:xx

AUTH: eth1(25891): PMK Cache performed(RSN) for 7a:a5:37:xx:xx:xx

AUTH: eth1(25891): Authenticated User - 7a:a5:37:xx:xx:xx





最後に無線AP側でPMKを登録しています。

TTLの値は減っています。

AUTH: eth1(25891): Register PMK: id xxxxxxxxfa61362f1943e4376827xxxx (TTL 2300) - 7c:c5:37:xx:xx:xx





ローミングで移動しているので、元々接続していた無線APからは以下のログが出ています。

DisAssociate して無線APから外れています。



WIRELESS: wl0: 11a : Deleting roamed station - 7a:a5:37:xx:xx:xx

WIRELESS: wl0: 11a : DisAssociated (rcvd. station leaving..) User - 7a:a5:37:xx:xx:xx





PMKのキャッシュ時間は(TTL 3600)とあるように、3600秒で設定されています。



(無線APのRadius設定のSession-timeout値で変更可能)



この時間が経過すると、以下のように Session-timeout ログが表示されます。



そしてこの後、再認証の処理にはいっています。



再認証が成功すれば、引き続き無線LANへのアクセスが継続されます。



AUTH: eth1(25891): Session-Timeout expired - 7a:a5:37:xx:xx:xx

AUTH: eth1(25891): ReAuthenticating User - 7a:a5:37:xx:xx:xx

AUTH: eth1(25891): Discarded session, User - 7a:a5:37:xx:xx:xx

WIRELESS: wl0: 11a : DeAuthentication (dot11 auth. expired) User - 7a:a5:37:xx:xx:xx

WIRELESS: wl0: 11a : Associated User - 7a:a5:37:xx:xx:xx

AUTH: eth1(25891): Register PMK: id xxxxxxxxa54314f73de38517xxxxxxxx (TTL 3600) -7c:c5:37:xx:xx:xx

AUTH: eth1(25891): Authenticated User - 7a:a5:37:xx:xx:xx

AUTH: eth1(25891): Register PMK: id 83dcba3da54314f73de385176f0b5e06 (TTL 3600) - 7c:c5:37:xx:xx:xx





再認証の処理がうまくいかなかったりすると、以下のようなエラーが出たりします。

PMK作成あとのPTK作成処理のやりとりでエラーになったりします。

また、無線APからは絶えず無線クライアントへ信号を送信していますが、

知らない間に無線クライアントがどこかへいってしまった場合などは、

下にあるように無線クライアントへ問合せのリトライをかけたりします。

こういった認証処理は端末台数が多かったり、

ローミングが頻発するような環境では無線AP自身への負荷が高くなり、

こういった再認証処理に失敗するケースが見られます。

このため、再認証までの時間を長く設定したり、無線APを増やして1台への負荷を低減させるなどの処置が必要となってきます。





WIRELESS ?wl0: 11g : DeAuthentication (4-Way Handshake timeout) User - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : Attempt to Deauthentication not respond. Retrying remain(3)... - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : DeAuthentication (AP inactivity) User - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : Attempt to Deauthentication not respond. Retrying remain(2)... - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : DeAuthentication (AP inactivity) User - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : Attempt to Deauthentication not respond. Retrying remain(1)... - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : DeAuthentication (AP inactivity) User - 7a:a5:37:xx:xx:xx

WIRELESS ?wl0: 11g : Attempt to Deauthentication not respond. Abandoned. - 7a:a5:37:xx:xx:xx






以下、キー更新間隔設定についてのマニュアルからの抜粋

過負荷状態にある場合は、更新間隔を長くすることも対応策のひとつ


★★キー更新間隔

無線の暗号化にWEP(自動配信Key)を選択した場合、

Keyの自動更新を行う間隔を設定します。

TKIPまたはAESを更新した場合は、

この間隔でマルチキャスト・ブロードキャストに用いられる暗号鍵の更新を行います。

指定できる時間は、0~1440(分)です。



0に指定した場合、定期的なKey更新を行いません。 初期値は、60分です。

★★注意★★

指定時間を短くすると、キー更新による負荷が高くなり、

通信が不安定になる場合があります。


2014年5月17日土曜日

Chromeのエラー TUNNEL_CONNECTION_FAILED


Chromeで以下のエラーが表示されることがあります。

[ net::ERR_TUNNEL_CONNECTION_FAILED ]

最近のブラウザのセキュリティ仕様から、HTTPS通信内でのリダイレクト通信を認めていないそうです。

プロキシを経由した通信などでリダイレクト処理をしている場合、

リダイレクト処理された画面表示とならずに上記のエラーコードを出すことがあるようです。

プロキシでサイトをブロックしているときなんかに、「ブロックしました」というメッセージを出したりするんですが、そのメッセージはリダイレクト処理して表示しているので、そのメッセージすら表示できず、何がおきているのか不明のままになってしまうのです。

プロキシサーバのブロックログを見ればサイトへのアクセスをブロックしているログが残っていたりします。


TCP Zerowindowの調整


TCP Zerowindowによる通信切断が発生している状況をパケットキャプチャーしました。

以下では 192.168.1.55 がバックアップデータを受信する側、192.168.1.10 がバックアップデータを送信する側になっています。

Tivoli Storage Manager Server(192.168.1.55),Tivoli Storage Manager Client(192.168.1.10)間で発生していました。

以後、TSM Server,TSM Clientと表記します。

通信を開始してから、すぐにTCP ZeroWindowが192.168.1.55から出ています。

これは、受信側のバッファがいっぱいで受けられないという状況になっていることを示唆しています。

その後、192.168.1.10からTCP ZeroWindow Probeが出ています。

これは、送信側が受信側へバッファに余裕ができたかチェックをしています。

このチェックに対して、192.168.1.55からはTCP ZeroWindowAckを返答しています。

これは、受信側がまだ無理であると回答しているということです。

このやりとりが、送信側と受信側の間で繰り返されています。

1秒経過してから確認し、その後、2秒経過してから再び確認、今度は4秒経過してから、、というように2倍ずつ確認の間隔が延びていきます。

そして結果的に受信側に余裕ができることが無いままRSTパケット(リセットパケット)を発行し通信断で終了してしまっています。

この場合、バックアップデータを送信する側のTSMアプリケーション側でタイムアウト値を延ばすことで回避しています。

下図でいうところのRSTパケットを出しているのはアプリケーション側ということになるんですね。

だからタイムアウト値を延ばすことで、もうちょっとがんばって通信してくれるようになるんです。




NO Time Source Dest TCP 備考
6087 17:40:51 192.168.1.10 192.168.1.55 ACK 1460Byte
6088 17:40:50 192.168.1.55 192.168.1.10 TCP ZeroWindow
6089 17:40:51 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe
6090 17:40:51 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6091 17:40:52 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe 1秒後に確認
6092 17:40:52 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6093 17:40:54 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe 2.5秒後に確認
6094 17:40:54 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6095 17:40:59 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe 5秒後に確認
6096 17:40:59 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6097 17:41:09 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe 10秒後に確認
6098 17:41:09 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6099 17:41:28 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe 20秒後に確認
6100 17:41:28 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6107 17:42:06 192.168.1.10 192.168.1.55 TCP ZeroWindow Probe 40秒後に確認
6108 17:42:06 192.168.1.55 192.168.1.10 TCP ZeroWindowAck
6157 17:43:22 192.168.1.55 192.168.1.10 RST 76秒後にリセット

FortigateのTCPセッションタイムアウト値の変更

FortigateでTCPセッションのタイムアウト値、セッション保持時間を調整します。

DMZにいるWebサーバと、LANにいるデータベースサーバ間のセッションが切れてしまう、

なんてトラブルがあるときに、まずチェックする箇所になります。

以下の例では、25番ポートのセッションタイムアウト値を 3600 秒にしています。


config sys session-ttl

config port

edit 25

set timeout 3600

end