Page 1 of 1

L2TP-VPNサーバに一旦接続しましたが翌日から接続しなくなってしまいました

Posted: Fri Mar 20, 2020 9:21 am
by kojima
数年前から SoftEther VPN を利用し順調に推移していました。
今年に入りルーターを AirMac から Buffaro WSR-2533DHP3 に替え V6 の利用を始めました。
SoftEther VPN はこのため接続できなくなり、回復に努めてきました。

VPN Server :
iMac : OS v10.15.3 Catalina
WiFi : フレッツ光り(自宅机上)

VPN Clients :
MacBook : OS v10.15.3 Catalina
WiFi : J:COM NET(自宅机上)

2020.03.10、接続設定に突如成功しました。

server_log
DHCP サーバーからの IP アドレスの取得に失敗しました。PPP の通信を受諾するためには DHCP サーバーが必要です。仮想 HUB の Ethernet セグメント上で DHCP サーバーが正しく動作しているかどうか確認してください。DHCP サーバーを用意することができない場合は、仮想 HUB の SecureNAT 機能を用いることもできます。

この server_log の「仮想 HUB の SecureNAT 機能を用いる」という指摘に着目し次のようにしました。

% vpncmd
VPN Server/DEFAULT>SecureNatEnable
SecureNatEnable コマンド - 仮想 NAT および DHCP サーバー機能 (SecureNAT 機能) の有効化
コマンドは正常に終了しました。

MacBook : VPN Clients : WiFi - J:COM NET
接続の試みが次の通り成功しました。

システム環境設定
ネットワーク - VPN(L2TP) - 接続 - 情況: 接続済み - IPアドレス: 192.168.30.10

server_log : vpn_202003010.log
セッション ポート 80 への接続に成功した部分の抜き書きは次の通りです。

2020-03-10 19:35:49.530 IPsec ESP セッション (IPsec SA) 1 (クライアント: 1) (114.198.194.43:62191 -> 192.168.1.60:4500): 新しい IPsec SA (方向: サーバー -> クライアント) を作成しました。SPI: 0pqrstuvC, DH グループ: (null), ハッシュアルゴリズム: SHA-1, 暗号化アルゴリズム: AES-CBC, 暗号鍵サイズ: 256 bits, 有効期限: 4294967295 kbytes または 3600 秒
2020-03-10 19:35:49.579 IPsec ESP セッション (IPsec SA) 1 (クライアント: 1) (114.198.194.43:62191 -> 192.168.1.60:4500): サーバー・クライアント間でこの IPsec SA が確立されました。
2020-03-10 19:35:49.579 IPsec クライアント 1 (114.198.194.43:62191 -> 192.168.1.60:4500): L2TP サーバーモジュールを開始しました。
2020-03-10 19:35:49.630 L2TP PPP セッション [114.198.194.43:1701]: 新しい PPP セッション (上位プロトコル: L2TP) が開始されました。PPP クライアント IP アドレス: 114.198.194.43 (ホスト名: "klmnopq.local"), PPP クライアント ポート番号: 1701, PPP サーバー IP アドレス: 192.168.1.60, PPP サーバー ポート番号:1701, クライアント ソフトウェア名: "L2TP VPN Client", IPv4 TCP MSS (Max Segment Size): 1314 bytes
2020-03-10 19:35:49.730 TCP リスナー (ポート 0) にクライアント (IP アドレス 114.198.194.43, ホスト名 "114-198-194-43.jcomnet.j-cnet.jp", ポート番号 1701) が接続しました。
2020-03-10 19:35:49.730 クライアント (IP アドレス 114.198.194.43, ホスト名 "114-198-194-43.jcomnet.j-cnet.jp", ポート番号 1701) に対応するコネクション "CID-1" が作成されました。
2020-03-10 19:35:49.730 コネクション "CID-1" に対する SSL 通信が開始されました。暗号化アルゴリズム名は "(null)" です。
2020-03-10 19:35:49.730 [HUB "DEFAULT"] コネクション "CID-1" (IP アドレス 114.198.194.43, ホスト名 114-198-194-43.jcomnet.j-cnet.jp, ポート番号 1701, クライアント名 "L2TP VPN Client", バージョン 4.32 ビルド 9731) が仮想 HUB への接続を試行しています。提示している認証方法は "外部サーバー認証" でユーザー名は "user" です。
2020-03-10 19:35:49.730 [HUB "DEFAULT"] コネクション "CID-1": ユーザー "user" として正しく認証されました。
2020-03-10 19:35:49.730 [HUB "DEFAULT"] コネクション "CID-1": 新しいセッション "SID-USER-[L2TP]-1" が作成されました。(IP アドレス 114.198.194.43, ポート番号 1701, 物理レイヤのプロトコル: "Legacy VPN - L2TP", プロトコル詳細: "InProc ")
2020-03-10 19:35:49.730 [HUB "DEFAULT"] セッション "SID-USER-[L2TP]-1": パラメータが設定されました。最大 TCP コネクション数 1, 暗号化の使用 はい, 圧縮の使用 いいえ, 半二重通信の使用 いいえ, タイムアウト 20 秒
2020-03-10 19:35:49.730 [HUB "DEFAULT"] セッション "SID-USER-[L2TP]-1": VPN Client の詳細: (クライアント製品名 "L2TP VPN Client", クライアントバージョン 432, クライアントビルド番号 9731, サーバー製品名 "SoftEther VPN Server (64 bit)", サーバーバージョン 432, サーバービルド番号 9731, クライアント OS 名 "L2TP VPN Client", クライアント OS バージョン "-", クライアントプロダクト ID "-", クライアントホスト名 "klmnopq.local", クライアント IP アドレス "114.198.194.43", クライアントポート番号 1701, サーバーホスト名 "192.168.1.60", サーバー IP アドレス "192.168.1.60", サーバーポート番号 1701, プロキシホスト名 "", プロキシ IP アドレス "0.0.0.0", プロキシポート番号 0, 仮想 HUB 名 "DEFAULT", クライアントユニーク ID "DefghijklmnopqrstD")

2020-03-10 20:07:12.336 [HUB "DEFAULT"] SecureNAT: DHCP エントリ 1 が作成されました。MAC アドレス: CA-43-B8-E6-72-DE, IP アドレス: 192.168.30.10, ホスト名: klmnopp.local, 有効期限: 7200 秒
2020-03-10 20:07:12.336 [HUB "DEFAULT"] セッション "SID-SECURENAT-2": このセッション上のホスト "5E-1E-9F-D8-D7-9A" (192.168.30.1) の DHCP サーバーは、別のセッション "SID-USER-[L2TP]-3" 上のホスト "CA-43-B8-E6-72-DE" に対して新しい IP アドレス 192.168.30.10 を割り当てました。
2020-03-10 20:07:12.336 L2TP PPP セッション [114.198.194.43:1701]: DHCP サーバーから IP アドレスを取得しました。クライアント IP アドレス: 192.168.30.10, サブネットマスク: 255.255.255.0, デフォルトゲートウェイ: 192.168.30.1, ドメイン名: "", DNS サーバー 1: 192.168.30.1, DNS サーバー 2: 0.0.0.0, WINS サーバー 1: 0.0.0.0, WINS サーバー 2: 0.0.0.0, DHCP サーバー IP アドレス: 192.168.30.1, リース時間: 7200 秒
2020-03-10 20:07:12.336 L2TP PPP セッション [114.198.194.43:1701]: クライアントの IP アドレスおよびその他の IP ネットワーク情報の設定が完了しました。クライアント IP アドレス: 192.168.30.10, サブネットマスク: 255.255.255.0, デフォルトゲートウェイ: 192.168.30.1, DNS サーバー 1: 192.168.30.1, DNS サーバー 2: 0.0.0.0, WINS サーバー 1: 0.0.0.0, WINS サーバー 2: 0.0.0.0
2020-03-10 20:07:17.637 [HUB "DEFAULT"] SecureNAT: UDP セッション 1 が作成されました。接続元 192.168.30.10:56762, 接続先 255.255.255.255:1900
2020-03-10 20:07:17.637 [HUB "DEFAULT"] SecureNAT: UDP セッション 2 が作成されました。接続元 192.168.30.10:61379, 接続先 192.168.30.1:53
2020-03-10 20:07:17.637 [HUB "DEFAULT"] SecureNAT: UDP セッション 3 が作成されました。接続元 192.168.30.10:64909, 接続先 192.168.30.1:53
2020-03-10 20:07:17.637 [HUB "DEFAULT"] SecureNAT: UDP セッション 4 が作成されました。接続元 192.168.30.10:65033, 接続先 192.168.30.1:53
2020-03-10 20:07:17.637 [HUB "DEFAULT"] SecureNAT: UDP セッション 5 が作成されました。接続元 192.168.30.10:56852, 接続先 192.168.30.1:53
2020-03-10 20:07:17.637 [HUB "DEFAULT"] SecureNAT: UDP セッション 6 が作成されました。接続元 192.168.30.10:57683, 接続先 192.168.30.1:53
2020-03-10 20:07:17.686 [HUB "DEFAULT"] SecureNAT: TCP セッション 7 が作成されました。接続元 192.168.30.10:58260, 接続先 153.145.66.230:443
2020-03-10 20:07:17.831 [HUB "DEFAULT"] SecureNAT: TCP セッション 7: ホスト "153.145.66.230 (153.145.66.230)", ポート 443 への接続に成功しました。
2020-03-10 20:07:17.879 [HUB "DEFAULT"] SecureNAT: UDP セッション 8 が作成されました。接続元 192.168.30.10:55828, 接続先 192.168.30.1:53
2020-03-10 20:07:17.879 [HUB "DEFAULT"] SecureNAT: UDP セッション 9 が作成されました。接続元 192.168.30.10:57035, 接続先 192.168.30.1:53
2020-03-10 20:07:17.879 [HUB "DEFAULT"] SecureNAT: UDP セッション 10 が作成されました。接続元 192.168.30.10:64786, 接続先 192.168.30.1:53
2020-03-10 20:07:17.879 [HUB "DEFAULT"] SecureNAT: UDP セッション 11 が作成されました。接続元 192.168.30.10:49519, 接続先 192.168.30.1:53
2020-03-10 20:07:17.879 [HUB "DEFAULT"] SecureNAT: UDP セッション 12 が作成されました。接続元 192.168.30.10:54739, 接続先 192.168.30.1:53
2020-03-10 20:07:17.879 [HUB "DEFAULT"] SecureNAT: UDP セッション 13 が作成されました。接続元 192.168.30.10:56654, 接続先 192.168.30.1:53
2020-03-10 20:07:17.976 [HUB "DEFAULT"] SecureNAT: UDP セッション 14 が作成されました。接続元 192.168.30.10:49307, 接続先 192.168.30.1:53
2020-03-10 20:07:17.976 [HUB "DEFAULT"] SecureNAT: UDP セッション 15 が作成されました。接続元 192.168.30.10:62889, 接続先 192.168.30.1:53
2020-03-10 20:07:18.070 [HUB "DEFAULT"] SecureNAT: TCP セッション 16 が作成されました。接続元 192.168.30.10:58261, 接続先 153.145.66.230:443
2020-03-10 20:07:18.070 [HUB "DEFAULT"] SecureNAT: TCP セッション 17 が作成されました。接続元 192.168.30.10:58262, 接続先 60.41.59.195:80
2020-03-10 20:07:18.070 [HUB "DEFAULT"] SecureNAT: TCP セッション 18 が作成されました。接続元 192.168.30.10:58263, 接続先 153.120.127.78:80
2020-03-10 20:07:18.070 [HUB "DEFAULT"] SecureNAT: TCP セッション 19 が作成されました。接続元 192.168.30.10:58264, 接続先 153.120.127.78:80
2020-03-10 20:07:18.170 [HUB "DEFAULT"] SecureNAT: TCP セッション 16: ホスト "153.145.66.230 (153.145.66.230)", ポート 443 への接続に成功しました。
2020-03-10 20:07:18.219 [HUB "DEFAULT"] SecureNAT: TCP セッション 18: ホスト "153.120.127.78 (153.120.127.78)", ポート 80 への接続に成功しました。
2020-03-10 20:07:18.219 [HUB "DEFAULT"] SecureNAT: TCP セッション 19: ホスト "153.120.127.78 (153.120.127.78)", ポート 80 への接続に成功しました。
2020-03-10 20:07:18.219 [HUB "DEFAULT"] SecureNAT: TCP セッション 20 が作成されました。接続元 192.168.30.10:58265, 接続先 153.120.127.78:80
2020-03-10 20:07:18.219 [HUB "DEFAULT"] SecureNAT: UDP セッション 21 が作成されました。接続元 192.168.30.10:60592, 接続先 192.168.30.1:53
2020-03-10 20:07:18.270 [HUB "DEFAULT"] SecureNAT: UDP セッション 22 が作成されました。接続元 192.168.30.10:54021, 接続先 192.168.30.1:53
2020-03-10 20:07:18.270 [HUB "DEFAULT"] SecureNAT: TCP セッション 23 が作成されました。接続元 192.168.30.10:58266, 接続先 153.120.127.78:80
2020-03-10 20:07:18.331 [HUB "DEFAULT"] SecureNAT: TCP セッション 20: ホスト "153.120.127.78 (153.120.127.78)", ポート 80 への接続に成功しました。
2020-03-10 20:07:18.331 [HUB "DEFAULT"] SecureNAT: TCP セッション 24 が作成されました。接続元 192.168.30.10:58267, 接続先 172.217.26.46:443
2020-03-10 20:07:18.381 [HUB "DEFAULT"] SecureNAT: TCP セッション 25 が作成されました。接続元 192.168.30.10:58268, 接続先 153.120.127.78:80
2020-03-10 20:07:18.381 [HUB "DEFAULT"] SecureNAT: TCP セッション 23: ホスト "153.120.127.78 (153.120.127.78)", ポート 80 への接続に成功しました。

2020.03.11

iMac をスリープ常態から起こしてみると VPN はいつもの通り未接続になっていました。
そこで、システム環境設定 - ネットワーク - VPN(L2TP) - 接続 - ボタンをクリックしました。
しかし、L2TP-VPNサーバが応答しませんでした、と警告ウインドウが表示されました。
以来、システム環境設定 - ネットワーク - VPN(L2TP) - 接続 - 情況: 接続済み に回復すべく幾多の試みをしてみましたが 未だその兆しが見えません。

server_log : vpn_202003011.log
セッション にポート 80 は全く現れなていません。
ポート 80 は全く現れなくなりました。

2020.03.17

システム環境設定 - ネットワーク - VPN(L2TP) - 接続 - ボタンをクリックしました。
相変わらず、L2TP-VPNサーバが応答しませんでした、と警告ウインドウが表示されました。
以来、システム環境設定 - ネットワーク - VPN(L2TP) - 接続 - 情況: 接続済み に回復すべく幾多の試みをしてみましたが 未だその兆しが見えません。

server_log : vpn_202003017.log
SecureNAT: TCP セッション は開始されていません。

2020-03-17 16:22:34.446 TCP リスナー (ポート 443) にクライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 53572) が接続しました。
2020-03-17 16:22:34.446 クライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 53572) に対応するコネクション "CID-1" が作成されました。
2020-03-17 16:22:34.545 コネクション "CID-1" に対する SSL 通信が開始されました。暗号化アルゴリズム名は "TuvwxyzM_SSU384" です。
2020-03-17 16:22:34.545 コネクション "CID-1" がサーバー管理モードで接続しました。
2020-03-17 16:22:34.545 コネクション "CID-1" は管理モードにログインできませんでした。アクセスが拒否されました。 (エラーコード 12)
2020-03-17 16:22:34.661 コネクション "CID-1" は理由 "エラーはありません。" (コード 0) で終了しました。
2020-03-17 16:22:34.661 コネクション "CID-1" が終了しました。
2020-03-17 16:22:34.661 クライアント (IP アドレス 127.0.0.1, ポート番号 53572) との間のコネクションは切断されました。
2020-03-17 16:22:41.097 TCP リスナー (ポート 443) にクライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 53573) が接続しました。
2020-03-17 16:22:41.097 クライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 53573) に対応するコネクション "CID-2" が作成されました。
2020-03-17 16:22:41.147 コネクション "CID-2" に対する SSL 通信が開始されました。暗号化アルゴリズム名は "TuvwxyzM_SSU384" です。
2020-03-17 16:22:41.147 コネクション "CID-2" がサーバー管理モードで接続しました。
2020-03-17 16:22:41.147 コネクション "CID-2" が管理モードでのログインに成功しました。
2020-03-17 16:22:41.147 コネクション "CID-2" は管理モードのための新しいリモートプロシージャコールセッション "RPC-64" を生成しました。
2020-03-17 16:45:20.250 管理モード [RPC-64]: TCP リスナー (ポート番号 443) を有効化しました。
2020-03-17 19:06:32.291 コネクション "CID-2" は理由 "エラーはありません。" (コード 0) で終了しました。
2020-03-17 19:06:32.291 コネクション "CID-2" が終了しました。
2020-03-17 19:06:32.291 クライアント (IP アドレス 127.0.0.1, ポート番号 53573) との間のコネクションは切断されました。
2020-03-17 19:06:45.714 TCP リスナー (ポート 443) にクライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 58084) が接続しました。
2020-03-17 19:06:45.714 クライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 58084) に対応するコネクション "CID-3" が作成されました。
2020-03-17 19:06:45.808 コネクション "CID-3" に対する SSL 通信が開始されました。暗号化アルゴリズム名は "TuvwxyzM_STU384" です。
2020-03-17 19:06:45.808 コネクション "CID-3" がサーバー管理モードで接続しました。
2020-03-17 19:06:45.808 コネクション "CID-3" は管理モードにログインできませんでした。アクセスが拒否されました。 (エラーコード 12)
2020-03-17 19:06:45.903 コネクション "CID-3" は理由 "エラーはありません。" (コード 0) で終了しました。
2020-03-17 19:06:45.903 コネクション "CID-3" が終了しました。
2020-03-17 19:06:45.903 クライアント (IP アドレス 127.0.0.1, ポート番号 58084) との間のコネクションは切断されました。
2020-03-17 19:06:53.593 TCP リスナー (ポート 443) にクライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 58085) が接続しました。
2020-03-17 19:06:53.593 クライアント (IP アドレス 127.0.0.1, ホスト名 "localhost", ポート番号 58085) に対応するコネクション "CID-4" が作成されました。
2020-03-17 19:06:53.643 コネクション "CID-4" に対する SSL 通信が開始されました。暗号化アルゴリズム名は "TuvwxyzM_STU384" です。
2020-03-17 19:06:53.643 コネクション "CID-4" がサーバー管理モードで接続しました。
2020-03-17 19:06:53.643 コネクション "CID-4" が管理モードでのログインに成功しました。
2020-03-17 19:06:53.643 コネクション "CID-4" は管理モードのための新しいリモートプロシージャコールセッション "RPC-64" を生成しました。

2020.03.18

システム環境設定 - ネットワーク - VPN(L2TP) - 接続 - ボタンをクリックしました。
相変わらず、L2TP-VPNサーバが応答しませんでした、と警告ウインドウが表示されました。
以来、システム環境設定 - ネットワーク - VPN(L2TP) - 接続 - 情況: 接続済み に回復すべく幾多の試みをしてみたが 未だその兆しが見えません。

server_log : vpn_202003018.log
内容は ---------- から --------- までの繰り返しの表示だけです。

2020-03-18 19:47:50.558 ------------------------------------------------------
2020-03-18 19:49:04.338 ------------------------------------------------------
2020-03-18 19:49:04.338 SoftEther VPN Server Version 4.32 Build 9731 (Japanese)
2020-03-18 19:49:04.338 Compiled 2020/01/01 18:16:55 by buildsan at crosswin
2020-03-18 19:49:04.338 Log Messages are written with UTF-8 Encoding Format.
2020-03-18 19:49:04.338 SoftEther VPN Server エンジンを起動しました。
2020-03-18 19:49:04.338 IPsec モジュール: IPsec ver 2.0 (ISAKMP/IKEv1) 処理モジュールを起動しました。
2020-03-18 19:49:04.338 OpenVPN モジュール: OpenVPN サーバーモジュールを起動しました。
2020-03-18 19:49:04.338 設定ファイルの読み込みを行います。
2020-03-18 19:49:04.338 ディレクトリ "/usr/local/vpnserver" の監視を開始します。ディスクの空き容量が 100.00 MBytes 未満になった場合、このディレクトリのサブディレクトリ内に保存されているログファイルおよび設定のバックアップファイルを、古い順番に自動的に削除します。削除を開始するディスクの最小空き容量は、設定ファイルの "AutoDeleteCheckDiskFreeSpaceMin" 項目で変更することができます。
2020-03-18 19:49:04.338 仮想 HUB "DEFAULT" を開始しました。
2020-03-18 19:49:04.338 仮想 HUB "DEFAULT" の MAC アドレスは "00-AE-57-11-7D-A4" です。
2020-03-18 19:49:04.338 [HUB "DEFAULT"] SecureNAT が開始されました。SecureNAT セッション "SID-SECURENAT-1" を作成しました。
2020-03-18 19:49:04.338 [HUB "DEFAULT"] 仮想 HUB がオンラインになりました。
2020-03-18 19:49:04.338 TCP リスナー (ポート 443) を開始しています。
2020-03-18 19:49:04.338 TCP リスナー (ポート 992) を開始しています。
2020-03-18 19:49:04.338 TCP リスナー (ポート 443) が開始されました。クライアントからの接続を待機しています。
2020-03-18 19:49:04.338 TCP リスナー (ポート 992) が開始されました。クライアントからの接続を待機しています。
2020-03-18 19:49:04.338 TCP リスナー (ポート 1194) を開始しています。
2020-03-18 19:49:04.338 TCP リスナー (ポート 1194) が開始されました。クライアントからの接続を待機しています。
2020-03-18 19:49:04.338 設定ファイルの読み込みが完了しました。
2020-03-18 19:49:04.338 自動設定保存のためのバックグラウンドタスクを起動します。保存間隔は 300 秒です。なお、自動保存の間隔はコンフィグレーションファイルの AutoSaveConfigSpan パラメータで変更することができます。
2020-03-18 19:56:07.566 サーバー エンジンのシャットダウン処理を開始しています。
2020-03-18 19:56:07.566 すべての TCP リスナーを停止します。
2020-03-18 19:56:07.566 TCP リスナー (ポート 443) を停止しています。
2020-03-18 19:56:08.109 TCP リスナー (ポート 443) の停止が完了しました。
2020-03-18 19:56:08.109 TCP リスナー (ポート 992) を停止しています。
2020-03-18 19:56:08.601 TCP リスナー (ポート 992) の停止が完了しました。
2020-03-18 19:56:08.601 TCP リスナー (ポート 1194) を停止しています。
2020-03-18 19:56:09.093 TCP リスナー (ポート 1194) の停止が完了しました。
2020-03-18 19:56:09.093 すべての TCP リスナーの停止が完了しました。
2020-03-18 19:56:09.093 すべての仮想 HUB を停止しています。
2020-03-18 19:56:09.093 [HUB "DEFAULT"] 仮想 HUB がオフラインになりました。
2020-03-18 19:56:09.125 [HUB "DEFAULT"] SecureNAT が停止しました。
2020-03-18 19:56:09.660 仮想 HUB "DEFAULT" を停止しました。
2020-03-18 19:56:09.660 すべての仮想 HUB の停止が完了しました。
2020-03-18 19:56:09.698 IPsec モジュール: IPsec ver 2.0 (ISAKMP/IKEv1) 処理モジュールの終了処理を開始しています...
2020-03-18 19:56:09.698 IPsec モジュール: 終了時に残存していた IPsec SA の数は 0 個でした。
2020-03-18 19:56:09.698 IPsec モジュール: 終了時に残存していた IKE SA の数は 0 個でした。
2020-03-18 19:56:09.698 IPsec モジュール: 終了時に残存していた IPsec クライアントの数は 0 個でした。
2020-03-18 19:56:09.698 IPsec モジュール: IPsec ver 2.0 (ISAKMP/IKEv1) 処理モジュールを終了しました。
2020-03-18 19:56:09.698 OpenVPN モジュール: OpenVPN サーバーモジュールを停止しました。
2020-03-18 19:56:09.945 Cedar 通信モジュールをシャットダウンしています。
2020-03-18 19:56:09.945 Cedar 通信モジュールをシャットダウンしました。
2020-03-18 19:56:09.945 SoftEther VPN Server エンジンは正常にシャットダウンされました。
2020-03-18 19:56:09.945 ------------------------------------------------------
2020-03-18 23:57:29.631 ------------------------------------------------------

質問::
L2TP-VPNサーバが一旦応答したにもかかわらず応答しなくなった原因を探す方法のヒントを得るにはどうしたらよいでしょうか。

Re: L2TP-VPNサーバに一旦接続しましたが翌日から接続しなくなってしまいました

Posted: Tue Mar 24, 2020 10:37 am
by cedar
L2TP/IPsec ではポート 80 ではなく、UDP の 500 と 4500 番のポートを使用します。
NAT ルーターでこれらのポートは解放されているでしょうか。

Re: L2TP-VPNサーバに一旦接続しましたが翌日から接続しなくなってしまいました

Posted: Wed Mar 25, 2020 1:00 pm
by kojima
早速のお返事ありがとうございます。

セッション ポート 80 への接続に成功した部分は、VPNトンネルが成立した後に画面共有も成立した部分として考えていました。
2020-03-10 20:07:18.993 SecureNAT: UDP セッション 36 が作成されました。接続元 192.168.30.10:55278, 接続先 192.168.30.1:53
2020-03-10 20:07:19.040 SecureNAT: TCP セッション 37 が作成されました。接続元 192.168.30.10:58277, 接続先 153.145.67.120:443
2020-03-10 20:07:19.088 SecureNAT: UDP セッション 38 が作成されました。接続元 192.168.30.10:59144, 接続先 192.168.30.1:53
2020-03-10 20:07:19.136 SecureNAT: TCP セッション 39 が作成されました。接続元 192.168.30.10:58278, 接続先 219.118.68.181:80
2020-03-10 20:07:19.136 SecureNAT: TCP セッション 40 が作成されました。接続元 192.168.30.10:58279, 接続先 219.118.68.181:80

ルーター変更前のログデータを見ると、 TCP セッション:443、 UDP セッション:53 の方が遥かに多いことに気が付きました。
2020-01-20 10:40:23.184 [HUB "DEFAULT"] SecureNAT: UDP セッション 517 が作成されました。接続元 192.168.30.10:52750, 接続先 192.168.30.1:53
2020-01-20 10:40:23.184 [HUB "DEFAULT"] SecureNAT: TCP セッション 518 が作成されました。接続元 192.168.30.10:57068, 接続先 153.145.66.230:443
2020-01-20 10:40:23.233 [HUB "DEFAULT"] SecureNAT: TCP セッション 519 が作成されました。接続元 192.168.30.10:57069, 接続先 219.118.79.176:80
2020-01-20 10:40:23.332 [HUB "DEFAULT"] SecureNAT: TCP セッション 520 が作成されました。接続元 192.168.30.10:57071, 接続先 153.145.66.230:443
2020-01-20 10:40:23.332 [HUB "DEFAULT"] SecureNAT: TCP セッション 521 が作成されました。接続元 192.168.30.10:57072, 接続先 219.118.79.176:80
2020-01-20 10:40:24.035 [HUB "DEFAULT"] SecureNAT: UDP セッション 522 が作成されました。接続元 192.168.30.10:55310, 接続先 192.168.30.1:53

UDP の 500 と 4500 番のポート開放の部分は次の通りでした。
Last login: Tue Feb 25 09:31:38 on ttys000
^_^ ~ (gh-pages) <U>
% sudo lsof -i:500,4500 -P
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
vpnserver 411 root 51u IPv4 0x54260 0t0 UDP localhost:500
vpnserver 411 root 52u IPv4 0x54260 0t0 UDP localhost:4500
vpnserver 411 root 54u IPv4 0x54260 0t0 UDP *:500
vpnserver 411 root 55u IPv4 0x54260 0t0 UDP *:4500
vpnserver 411 root 56u IPv6 0x54260 0t0 UDP imac.local:500
vpnserver 411 root 57u IPv6 0x54260 0t0 UDP imac.local:4500
vpnserver 411 root 59u IPv6 0x54260 0t0 UDP localhost:500
vpnserver 411 root 60u IPv6 0x54260 0t0 UDP localhost:4500
------------------------------------------------------------------------------
^_^ ~ (gh-pages) <U>

しかし現在のポート開放の状況は次の通り何も表示されていないことに気が付きました。
^_^ ~ (gh-pages) <U>
% sudo lsof -i:500,4500 -P
Password:
X_X ~ (gh-pages) <U>

ルータでの設定は当初から変わりないことを確認しました。
ルーター:BUFFALO WSR-2533DHP3 Version 1.21
ポート変換登録情報
Group01 PPPoE1:plalaのInternet側IPアドレス UDPポート:500
192.168.1.60 UDPポート:500
Group02 PPPoE1:plalaのInternet側IPアドレス UDPポート:4500
192.168.1.60 UDPポート:4500
Group04 PPPoE1:plalaのInternet側IPアドレス TCPポート:80
192.168.1.60 TCPポート:80

これらのことから、ご指摘頂いた通り現在「UDP の 500 と 4500 番のポートを使用」していないことがトラブルの原因の一つだということが解りました。
3月10日には次の通り 4500 が使われていましたのでトンネルが作成されていたものと思われます。
2020-03-10 19:35:49.579 IPsec ESP セッション (IPsec SA) 1 (クライアント: 1) (114.198.194.43:62191 -> 192.168.1.60:4500): サーバー・クライアント間でこの IPsec SA が確立されました。
2020-03-10 19:35:49.579 IPsec クライアント 1 (114.198.194.43:62191 -> 192.168.1.60:4500): L2TP サーバーモジュールを開始しました。

ヒントを頂きありがとうございました。

このとき、次の最新ビルドに気が付きましたので VPN Server の更新に着手しました。
SoftEther VPN Server (Ver 4.34, Build 9744, beta)
softether-vpnserver-v4.34-9744-beta-2020.03.20-macos-x64-64bit.tar.gz (6.62 MB)
[Non-SSL (HTTP) Download Link] Try this if the above link fails because your HTTP client doesn't support TLS 1.2.

その結果を報告する予定です。

Re: L2TP-VPNサーバに一旦接続しましたが翌日から接続しなくなってしまいました

Posted: Thu Mar 26, 2020 10:10 am
by cedar
「SecureNAT: ***セッション xx が作成されました」のログはVPN接続のログではなく、SecureNATを通してVPNクライアントが通信を行っているログです。
VPN 接続自体のトラブルの際には、このログはあまり関係ないので参照の必要はありません。