Client VPNがタイムアウトを繰り返す場合に確認すること
はじめに
こんにちは！コンサル部のぐっさんです。
こんなログメッセージを見つけたら解決の糸口になるかもしれません。
「Server poll timeout, restarting」
先に結論
クライアント端末にインストールされているセキュリティ系のソフトウェアでファイアウォール機能の設定を確認してみてください。
どこかにアクセスをブロックする設定が潜んでいるかもしれません。
背景
Client VPNを構築する機会があり、構築自体は完了したがクライアント端末から接続を行うとアクセスができないという事象が発生しました。その際の対応記録です。
前提
Client VPNの設定情報などの前提です。同じような設定でうまくいかない場合は参考になるかもしれません。
| 項目 | 値 |
|---|---|
| プロトコル | UDP |
| ポート番号 | 443 |
| 認証 | オンプレミスAD認証(AD Connectorを使用) |
| DNS | カスタムDNSを設定(ADサーバーのDNS) |
| 証明書 | サーバ証明書のみ |
| 接続元のクライアントOS | Windows OS |
| VPNクライアントアプリ | AWS Client VPNクライアント(Windows用) |
確認手順
その1 公式ドキュメントのトラブルシューティングとログ確認
はじめに、公式のトラブルシューティングのドキュメントを確認します。
状況としてはこのページの「クライアントが再接続状態でスタックしている」の症状が最も近いものでした。
プロファイルの追加は正常に完了し、ADユーザーによる認証も通る状態です。
最後にいざVPN接続をしようとすると、ずっと「再接続中」となってしまう事象です。
ドキュメントより、まずインターネットに接続されていることは確認。
次に設定ファイルのVPNエンドポイントが正常に名前解決できているか確認するため、クライアントアプリケーションのログを確認します。
Windowsの場合は、デフォルトで以下の場所にアプリケーションのログが格納されます。
※「User」は実際のユーザー名
C:\Users\User\AppData\Roaming\AWSVPNClient\logs
「ovpn_aws_vpn_client_yyyymmdd.log」の中身を見てみると以下のようなログがありました。
※IPなどの情報は一部マスクしております。
2025-09-25 11:45:51.495 +09:00 [DBG][TI=24][ClientVPN] >LOG:1758768351,D,MANAGEMENT: CMD 'echo on'
2025-09-25 11:45:51.511 +09:00 [DBG][TI=24][ClientVPN] >LOG:1758768351,D,MANAGEMENT: CMD 'hold off'
2025-09-25 11:45:51.511 +09:00 [DBG][TI=24][ClientVPN] >LOG:1758768351,D,MANAGEMENT: CMD 'hold release'
2025-09-25 11:46:07.269 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,D,MANAGEMENT: CMD 'username "Auth" **************'
2025-09-25 11:46:07.274 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,D,MANAGEMENT: CMD 'password [...]'
2025-09-25 11:46:07.630 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,,MANAGEMENT: >STATE:1758768367,RESOLVE,,,,,,
2025-09-25 11:46:07.633 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,I,TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:443
2025-09-25 11:46:07.633 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,,Socket Buffers: R=[65536->65536] S=[65536->65536]
2025-09-25 11:46:07.633 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,I,UDPv4 link local: (not bound)
2025-09-25 11:46:07.633 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,I,UDPv4 link remote: [AF_INET]xx.xx.xx.xx:443
2025-09-25 11:46:07.634 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768367,,MANAGEMENT: >STATE:1758768367,WAIT,,,,,,
2025-09-25 11:46:12.845 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,I,Server poll timeout, restarting
2025-09-25 11:46:12.846 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,I,SIGUSR1[soft,server_poll] received, process restarting
2025-09-25 11:46:12.847 +09:00 [DBG][TI=7][ClientVPN] >LOG:1758768372,,MANAGEMENT: >STATE:1758768372,RECONNECTING,server_poll,,,,,
2025-09-25 11:46:12.865 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,I,TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:443
2025-09-25 11:46:12.865 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,,Socket Buffers: R=[65536->65536] S=[65536->65536]
2025-09-25 11:46:12.865 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,I,UDPv4 link local: (not bound)
2025-09-25 11:46:12.866 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,I,UDPv4 link remote: [AF_INET]xx.xx.xx.xx:443
2025-09-25 11:46:12.866 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768372,,MANAGEMENT: >STATE:1758768372,WAIT,,,,,,
2025-09-25 11:46:17.077 +09:00 [DBG][TI=14][ClientVPN] >LOG:1758768377,I,Server poll timeout, restarting
「WAIT,,,,,,」と「Server poll timeout, restarting」が続けて出ています。
UDP443ポートで接続試行をしているが、それがうまくいかずにループしてしまっているのかと思いました。
とても怪しいです。
ただ、名前解決に関してはAWSの管理するIPアドレス帯との通信を確立しようとしているため、これについては問題ないことを確認しました。
その2 クライアント端末のファイアウォール設定
クライアント端末(Windows)のファイアウォール設定でUDP443を許可いただくようにしました。
ただ、この時点でも同じ症状で接続NGです。
その3 他のネットワーク環境・端末で試す
とにかくネットワークの設定が怪しいと考え、接続予定のクライアント端末とは全く別のネットワーク環境で、他端末から同じVPNへ接続を試しました。
すると最初はMac端末からアクセスし、接続成功。
そのときのログが以下のような出力でした。
2025-09-25 10:17:43.092 +09:00 [DBG][TI=91797][ClientVPN] >LOG:1758763063,D,MANAGEMENT: CMD 'echo on'
2025-09-25 10:17:43.102 +09:00 [DBG][TI=91797][ClientVPN] >LOG:1758763063,D,MANAGEMENT: CMD 'hold off'
2025-09-25 10:17:43.102 +09:00 [DBG][TI=91797][ClientVPN] >LOG:1758763063,D,MANAGEMENT: CMD 'hold release'
2025-09-25 10:18:02.056 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,D,MANAGEMENT: CMD 'username "Auth" **************'
2025-09-25 10:18:02.061 +09:00 [DBG][TI=91796][ClientVPN] >LOG:1758763082,D,MANAGEMENT: CMD 'password [...]'
2025-09-25 10:18:02.236 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,W,NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2025-09-25 10:18:02.237 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,,MANAGEMENT: >STATE:1758763082,RESOLVE,,,,,,
2025-09-25 10:18:02.239 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,I,TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:443
2025-09-25 10:18:02.239 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,,Socket Buffers: R=[786896->786896] S=[9216->9216]
2025-09-25 10:18:02.239 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,I,UDPv4 link local: (not bound)
2025-09-25 10:18:02.240 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,I,UDPv4 link remote: [AF_INET]xx.xx.xx.xx:443
2025-09-25 10:18:02.240 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,,MANAGEMENT: >STATE:1758763082,WAIT,,,,,,
2025-09-25 10:18:02.254 +09:00 [DBG][TI=91768][ClientVPN] >LOG:1758763082,,MANAGEMENT: >STATE:1758763082,AUTH,,,,,,
2025-09-25 10:18:02.255 +09:00 [DBG][TI=91768][ClientVPN] >LOG:1758763082,,TLS: Initial packet from [AF_INET]xx.xx.xx.xx:443, sid=f7f7aa86 158b6137
2025-09-25 10:18:02.256 +09:00 [DBG][TI=91768][ClientVPN] >LOG:1758763082,W,WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
2025-09-25 10:18:02.294 +09:00 [DBG][TI=91780][ClientVPN] >LOG:1758763082,,VERIFY OK: depth=1, CN=xxxxx
2025-09-25 10:18:02.294 +09:00 [DBG][TI=91780][ClientVPN] >LOG:1758763082,,VERIFY KU OK
2025-09-25 10:18:02.295 +09:00 [DBG][TI=91780][ClientVPN] >LOG:1758763082,,Validating certificate extended key usage
2025-09-25 10:18:02.296 +09:00 [DBG][TI=91780][ClientVPN] >LOG:1758763082,,++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
以下の部分で、「WAIT,,,,,,」から「AUTH,,,,,,」に遷移しています。
その後、初期TLSパケット(Initial packet)がサーバから到着しており後続の暗号化通信が確立できています！
2025-09-25 10:18:02.240 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,I,UDPv4 link remote: [AF_INET]xx.xx.xx.xx:443
2025-09-25 10:18:02.240 +09:00 [DBG][TI=91792][ClientVPN] >LOG:1758763082,,MANAGEMENT: >STATE:1758763082,WAIT,,,,,,
2025-09-25 10:18:02.254 +09:00 [DBG][TI=91768][ClientVPN] >LOG:1758763082,,MANAGEMENT: >STATE:1758763082,AUTH,,,,,,
2025-09-25 10:18:02.255 +09:00 [DBG][TI=91768][ClientVPN] >LOG:1758763082,,TLS: Initial packet from [AF_INET]xx.xx.xx.xx:443, sid=f7f7aa86 158b6137
おそらく、失敗している環境ではVPNサーバーにリクエストはしたもののパケットが戻ってくる際に何らかの原因でブロックされてしまっているものと推測できます。
DTLSハンドシェイク(UDP上のTLSハンドシェイク)の通信の中で、以下のようなイメージです。
今回はサーバー証明書のみ作成のため、クライアント証明書の検証フェーズはありません。
（通信の流れはざっくり書いています）
その後、クライアントアプリケーション(OS)起因かどうかの切り分けのため対象のクライアント端末と同じWindows OSの端末でも接続を試したところ成功しました。
ここまでである程度、クライアント端末のネットワーク環境に何かブロックしている原因となるものが存在すると見当がつきました。
その4 クライアント端末のセキュリティソフトウェアを確認
接続元の端末にOSのファイアウォール以外でセキュリティソフト等の導入がないか確認しました。
すると、どうやらその起因となりそうなソフトウェアがあることが判明！
ソフトウェアで設定されていたファイアウォールの設定を見直すことで無事VPNの疎通ができるようになりました。
今回の場合は設定について様々な試行錯誤をいただいたのち、実行ファイル「acvc-openvpn.exe」のパスを許可ルールに指定いただいたことにより解決しました！
クライアントアプリケーションが内部的に使用しているプロセスのようです。
この設定により、該当プロセスが使用するUDP通信（サーバからのレスポンス受信を含む）が許可され、VPN接続が確立できるようになりました。
実際の環境に合わせて適切な設定が必要となります。
最後に
まずはログと向き合ってみると、色々なものが見えてくると思います。
最近は多くの企業ネットワークでゼロトラストの考え方をベースにしたセキュリティ強化を行っていることがよくあると思います。もちろんセキュリティに気を使うことは大切なのですが、業務に必要なシステムの導入やネットワーク周りの疎通で案外これらのツールによって阻まれていることがありそうです。
VPNやその他ネットワーク関連で想定通りに接続できないことがある場合は、真っ先に原因の一つとして確認をとってみても良いかと思います。
最後までお読みいただきありがとうございました。
この記事が誰かの助けになったら幸いです！
