EdgeRouterでSSHが切断される
TERATERM.INI の TTSSH セクションにある LogLevel を 100 にすると Tera Term のインストールディレクトリに TTSSH.LOG が作られるようになります。
この状態で現象を再現させて、その時の TTSSH.LOG をいただけないでしょうか?
doda への返信
> TERATERM.INI の TTSSH セクションにある LogLevel を 100 にすると Tera Term のインストールディレクトリに TTSSH.LOG が作られるようになります。 > > この状態で現象を再現させて、その時の TTSSH.LOG をいただけないでしょうか? 回答ありがとうございます。 LogLevel 100(VERBOSE モード)で取得した TTSSH.LOG を添付しました(※タイムスタンプが 9 時間遅れています。)。 素人目には突然切断されているように見えましたので、LogLevel 200(SSHDUMP モード)でも取得しました。 多量(4874 行、455 KB)ですが、個人情報が *** 含まれていなければ *** 添付可能です。 必要であれば、お知らせください。 なお、当方の設定は Zone-Based Firewall の Zone が 12 個(内 VPN Zone が 9 個)ありますが、 VPN Zone が 1 個増えるごとに約 1 分 commit-confirm の完了時間が増えます。 VPN Zone が 4 個で検証すると、commit-confirm の完了時間が 5 分 38 秒以下になるため、 Tera Term は正常に終了します(SSH は切断されない。)。 再現手順 1.SSH で EdgeRouter X にログイン(有線 LAN で接続してユーザー名及びパスワードを入力、マクロは未使用。)。 2.configure を入力。 3.08:27:00 から設定を貼り付け(Zone-Based Firewall 検証用の 177 行。)。 4.08:30:01 commit-confirm 15 を入力。 5.08:35:39 同コマンド実行中に、約 5 分 38 秒で切断される。 ※EdgeRouter X(EdgeOS)の CLI の基本操作は、下記の参考を参照。 ※一回で全文が投稿できないため、複数に分けました。
※前投稿の続き。 TTSSH.LOG LogLevel 100(VERBOSE モード) 2019-07-24 08:26:44.612Z [6628] SSH2_MSG_CHANNEL_SUCCESS was received(nego_status 2). 2019-07-24 08:26:44.612Z [6628] send_channel_request_gen: sending SSH2_MSG_CHANNEL_REQUEST. local: 0, remote: 0, request-type: shell, msg1=none, msg2=none 2019-07-24 08:26:44.628Z [6628] SSH2_MSG_CHANNEL_SUCCESS was received(nego_status 3). 2019-07-24 08:35:39.964Z [6628] Terminating SSH session... ※最後の 4 行を抜粋。
※前投稿の続き。 LogLevel 200(SSHDUMP モード) 2019-07-24 09:59:57.234Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:16, padlen:5, datalen:36, maclen:16, mode:EtM 2019-07-24 09:59:57.234Z [6600] SSH2_send_channel_data: sending SSH2_MSG_CHANNEL_DATA. local:0 remote:0 len:1 2019-07-24 09:59:57.249Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:2 2019-07-24 09:59:59.480Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:73 2019-07-24 09:59:59.480Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:14 2019-07-24 10:00:01.056Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:16, padlen:5, datalen:36, maclen:16, mode:EtM 2019-07-24 10:00:01.056Z [6600] SSH2_send_channel_data: sending SSH2_MSG_CHANNEL_DATA. local:0 remote:0 len:1 2019-07-24 10:00:01.087Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:5 2019-07-24 10:00:01.119Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:31 2019-07-24 10:00:28.180Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:95 2019-07-24 10:00:28.180Z [6600] SSH2_MSG_CHANNEL_DATA was received. local:0 remote:0 len:2
※前投稿の続き。 2019-07-24 10:01:02.016Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:32, padlen:13, datalen:52, maclen:16, mode:EtM 2019-07-24 10:01:02.016Z [6600] SSH2_MSG_IGNORE was sent at ssh_heartbeat_dlg_proc(). 2019-07-24 10:02:03.074Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:32, padlen:13, datalen:52, maclen:16, mode:EtM 2019-07-24 10:02:03.074Z [6600] SSH2_MSG_IGNORE was sent at ssh_heartbeat_dlg_proc(). 2019-07-24 10:03:04.024Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:32, padlen:13, datalen:52, maclen:16, mode:EtM 2019-07-24 10:03:04.024Z [6600] SSH2_MSG_IGNORE was sent at ssh_heartbeat_dlg_proc(). 2019-07-24 10:04:05.066Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:32, padlen:13, datalen:52, maclen:16, mode:EtM 2019-07-24 10:04:05.066Z [6600] SSH2_MSG_IGNORE was sent at ssh_heartbeat_dlg_proc(). 2019-07-24 10:05:06.016Z [6600] finish_send_packet_special: built packet info: aadlen:4, enclen:32, padlen:13, datalen:52, maclen:16, mode:EtM 2019-07-24 10:05:06.016Z [6600] SSH2_MSG_IGNORE was sent at ssh_heartbeat_dlg_proc(). 2019-07-24 10:05:37.871Z [6600] Terminating SSH session... ※最後の 22 行を抜粋。 ※10:00:00 に commit-confirm 15 を入力。
※前投稿の続き。 検証したバージョン teraterm-4.103.zip (SVN# 7769) 約 5 分 38 秒で切断される。 PuTTY-0.71-ranvis-20190320.win32.zip 約 9 分 12 秒で正常に終了する(SSH は切断されない。)。 ※念のため再検証しましたが、正常に終了します。 OS のバージョン Windows 7 Home Premium 64 bit 参考 コマンド > コマンド一覧 - EdgeOS 日本語Wiki [非公式] http://edge-os.net/wiki/view/コマンド_>_コマンド一覧 EdgeRouter - Zone-Based Firewall ― Ubiquiti Networks Support and Help Center https://help.ubnt.com/hc/en-us/articles/204952154-EdgeRouter-Zone-Based-Firewall
※前投稿の続き。
※リンクが認識されていないため、再投稿(内容は同一。)
参考
コマンド > コマンド一覧 - EdgeOS 日本語Wiki [非公式]
http://edge-os.net/wiki/view/コマンド_>_コマンド一覧
EdgeRouter - Zone-Based Firewall ― Ubiquiti Networks Support and Help Center
https://help.ubnt.com/hc/en-us/articles/204952154-EdgeRouter-Zone-Based-Firewall
ファイルを添付する方法が不明なため、TTSSH.LOG を無加工(そのまま)で投稿します。
※一回で全文が投稿できないため、複数に分けました。
TTSSH_verbose_20190724.LOG(※空行を含めて 74 行。)
2019-07-24 08:26:21.659Z [1981694380] Reading INI file 2019-07-24 08:26:26.245Z [6628] --------------------------------------------------------------------- 2019-07-24 08:26:26.245Z [6628] Initiating SSH session 2019-07-24 08:26:26.339Z [6628] Received server identification string: SSH-2.0-OpenSSH_6.6.1p1 Debian-4~bpo70+1 2019-07-24 08:26:26.339Z [6628] Sent client identification string: SSH-2.0-TTSSH/2.89 Win32 2019-07-24 08:26:27.400Z [6628] client proposal: KEX algorithm: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group18-sha512,diffie-hellman-group16-sha512,diffie-hellman-group14-sha256,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 2019-07-24 08:26:27.400Z [6628] client proposal: server host key algorithm: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,ssh-rsa,ssh-dss 2019-07-24 08:26:27.400Z [6628] client proposal: encryption algorithm client to server: aes256-gcm@openssh.com,aes128-gcm@openssh.com,camellia256-ctr,aes256-ctr,camellia256-cbc,aes256-cbc,camellia192-ctr,aes192-ctr,camellia192-cbc,aes192-cbc,camellia128-ctr,aes128-ctr,camellia128-cbc,aes128-cbc,3des-ctr,3des-cbc,blowfish-ctr,blowfish-cbc,cast128-ctr,cast128-cbc 2019-07-24 08:26:27.400Z [6628] client proposal: encryption algorithm server to client: aes256-gcm@openssh.com,aes128-gcm@openssh.com,camellia256-ctr,aes256-ctr,camellia256-cbc,aes256-cbc,camellia192-ctr,aes192-ctr,camellia192-cbc,aes192-cbc,camellia128-ctr,aes128-ctr,camellia128-cbc,aes128-cbc,3des-ctr,3des-cbc,blowfish-ctr,blowfish-cbc,cast128-ctr,cast128-cbc
※前投稿の続き(TTSSH_verbose_20190724.LOG)。
2019-07-24 08:26:27.400Z [6628] client proposal: MAC algorithm client to server: hmac-sha2-512-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-512,hmac-sha2-256,hmac-sha1,hmac-ripemd160-etm@openssh.com,hmac-ripemd160@openssh.com,hmac-md5-etm@openssh.com,hmac-md5 2019-07-24 08:26:27.400Z [6628] client proposal: MAC algorithm server to client: hmac-sha2-512-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-512,hmac-sha2-256,hmac-sha1,hmac-ripemd160-etm@openssh.com,hmac-ripemd160@openssh.com,hmac-md5-etm@openssh.com,hmac-md5 2019-07-24 08:26:27.400Z [6628] client proposal: compression algorithm client to server: none 2019-07-24 08:26:27.400Z [6628] client proposal: compression algorithm server to client: none 2019-07-24 08:26:27.400Z [6628] SSH2_MSG_KEXINIT was sent at SSH2_send_kexinit(). 2019-07-24 08:26:27.400Z [6628] SSH2_MSG_KEXINIT was received.
※前投稿の続き(TTSSH_verbose_20190724.LOG)。
2019-07-24 08:26:27.400Z [6628] server proposal: KEX algorithm: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 2019-07-24 08:26:27.400Z [6628] server proposal: server host key algorithm: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ssh-ed25519 2019-07-24 08:26:27.400Z [6628] server proposal: encryption algorithm client to server: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com 2019-07-24 08:26:27.400Z [6628] server proposal: encryption algorithm server to client: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com 2019-07-24 08:26:27.400Z [6628] server proposal: MAC algorithm client to server: hmac-md5-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-sha1,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96 2019-07-24 08:26:27.400Z [6628] AEAD cipher is selected, ignoring MAC algorithms. (client to server) 2019-07-24 08:26:27.400Z [6628] server proposal: MAC algorithm server to client: hmac-md5-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-sha1,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
※前投稿の続き(TTSSH_verbose_20190724.LOG)。
2019-07-24 08:26:27.400Z [6628] AEAD cipher is selected, ignoring MAC algorithms. (server to client) 2019-07-24 08:26:27.415Z [6628] server proposal: compression algorithm client to server: none,zlib@openssh.com 2019-07-24 08:26:27.415Z [6628] server proposal: compression algorithm server to client: none,zlib@openssh.com 2019-07-24 08:26:27.415Z [6628] server proposal: language client to server: 2019-07-24 08:26:27.415Z [6628] server proposal: language server to client: 2019-07-24 08:26:27.415Z [6628] KEX algorithm: ecdh-sha2-nistp256 2019-07-24 08:26:27.415Z [6628] server host key algorithm: ecdsa-sha2-nistp256 2019-07-24 08:26:27.415Z [6628] encryption algorithm client to server: aes256-gcm@openssh.com 2019-07-24 08:26:27.415Z [6628] encryption algorithm server to client: aes256-gcm@openssh.com 2019-07-24 08:26:27.415Z [6628] MAC algorithm client to server: <implicit> 2019-07-24 08:26:27.415Z [6628] MAC algorithm server to client: <implicit> 2019-07-24 08:26:27.415Z [6628] compression algorithm client to server: none 2019-07-24 08:26:27.415Z [6628] compression algorithm server to client: none 2019-07-24 08:26:27.415Z [6628] SSH2_MSG_KEX_ECDH_INIT was sent at SSH2_ecdh_kex_init(). 2019-07-24 08:26:27.478Z [6628] SSH2_MSG_KEX_ECDH_REPLY was received. 2019-07-24 08:26:27.493Z [6628] ssh2_kex_finish: SSH2_MSG_NEWKEYS was sent. 2019-07-24 08:26:27.493Z [6628] SSH2_MSG_NEWKEYS was received(DH key generation is completed). 2019-07-24 08:26:27.493Z [6628] Server reports supported authentication method mask = 65580 2019-07-24 08:26:27.493Z [6628] Entering secure mode 2019-07-24 08:26:44.285Z [6628] SSH2_MSG_SERVICE_REQUEST was sent at do_SSH2_userauth(). 2019-07-24 08:26:44.316Z [6628] SSH2_MSG_SERVICE_ACCEPT was received. service-name=ssh-userauth 2019-07-24 08:26:44.316Z [6628] SSH2_MSG_USERAUTH_REQUEST was sent do_SSH2_authrequest(). (method 3)
※前投稿の続き(TTSSH_verbose_20190724.LOG)。
2019-07-24 08:26:44.347Z [6628] SSH2_MSG_USERAUTH_BANNER was received. 2019-07-24 08:26:44.347Z [6628] Banner len: 262, Banner message: Welcome to EdgeOS By logging in, accessing, or using the Ubiquiti product, you acknowledge that you have read and understood the Ubiquiti License Agreement (available in the Web UI at, by default, http://192.168.1.1) and agree to be bound by its terms. . 2019-07-24 08:26:44.347Z [6628] Empty Language Tag 2019-07-24 08:26:44.347Z [6628] SSH2_MSG_USERAUTH_FAILURE was received. 2019-07-24 08:26:44.347Z [6628] Server reports supported authentication method mask = 65548 2019-07-24 08:26:44.347Z [6628] method list from server: publickey,password 2019-07-24 08:26:44.347Z [6628] SSH2_MSG_USERAUTH_REQUEST was sent do_SSH2_authrequest(). (method 3)
※前投稿の続き(TTSSH_verbose_20190724.LOG の最後)。
2019-07-24 08:26:44.581Z [6628] SSH2_MSG_USERAUTH_SUCCESS was received. 2019-07-24 08:26:44.581Z [6628] SSH2_MSG_CHANNEL_OPEN was sent at handle_SSH2_userauth_success(). 2019-07-24 08:26:44.597Z [6628] User authentication is successful and SSH heartbeat thread is starting. 2019-07-24 08:26:44.597Z [6628] SSH2_MSG_CHANNEL_OPEN_CONFIRMATION was received. 2019-07-24 08:26:44.597Z [6628] send_pty_request: sending SSH2_MSG_CHANNEL_REQUEST. local: 0, remote: 0, request-type: pty-req, term: xterm, cols: 320, rows: 38, x: 1381, y: 764, out-speed: 38400, in-speed: 38400, verase: ^h, onlcr: on 2019-07-24 08:26:44.612Z [6628] SSH2_MSG_CHANNEL_SUCCESS was received(nego_status 2). 2019-07-24 08:26:44.612Z [6628] send_channel_request_gen: sending SSH2_MSG_CHANNEL_REQUEST. local: 0, remote: 0, request-type: shell, msg1=none, msg2=none 2019-07-24 08:26:44.628Z [6628] SSH2_MSG_CHANNEL_SUCCESS was received(nego_status 3). 2019-07-24 08:35:39.964Z [6628] Terminating SSH session...
(※タイムスタンプが 9 時間遅れています。)。
時刻はUTCで記録されているので、正常な動作です。(最後のZがUTCを表す)
ファイルを添付する方法が不明なため、TTSSH.LOG を無加工(そのまま)で投稿します。
ファイルを添付するにはOSDNのユーザ登録が必要なようです。
可能でしたら一時的にでもユーザ登録を行ってファイルを添付してもらえないでしょうか?
2019-07-24 10:05:06.016Z [6600] SSH2_MSG_IGNORE was sent at ssh_heartbeat_dlg_proc(). 2019-07-24 10:05:37.871Z [6600] Terminating SSH session...
SSH として切断しているのではなく、TCP/IP のレベルでいきなり切断が起きているように見えますね。
PuTTY-0.71-ranvis-20190320.win32.zip
約 9 分 12 秒で正常に終了する(SSH は切断されない。)。
PuTTY の設定はデフォルトでしょうか? 特に "接続" にある "Keepalive の間隔" は 0 のままでしょうか?
もし 0 のままならば、Tera Term の [設定] - [SSH] にある "ハートビート (keep-alive)" を 0 にしてみてください。
Timeout. 再現環境が無い&返事が無いのでClose.
想定していた状況は、設定反映中にEdgeRouter XのI/Fが一時的に落ちる or 応答を返せない状態になり、ちょうどそのタイミングにTera TermがKeep-Aliveのパケットを投げて、応答が無いから切断されるという物。
PuTTYはデフォルトではKeep-Aliveのパケットを投げない為影響を受けない。
doda への返信
PuTTY の設定はデフォルトでしょうか? 特に "接続" にある "Keepalive の間隔" は 0 のままでしょうか?
もし 0 のままならば、Tera Term の [設定] - [SSH] にある "ハートビート (keep-alive)" を 0 にしてみてください。
doda への返信
想定していた状況は、設定反映中にEdgeRouter XのI/Fが一時的に落ちる or 応答を返せない状態になり、
ちょうどそのタイミングにTera TermがKeep-Aliveのパケットを投げて、応答が無いから切断されるという物。
PuTTYはデフォルトではKeep-Aliveのパケットを投げない為影響を受けない。
※返信が遅くなり、大変失礼しました。
"ハートビート (keep-alive)" を初期値の 60 → 0 に変更したら解決しました。
コマンド(commit-confirm)が実行中に 1 時間以上放置しても切断されないことを確認しました。
また、長期間返信が無いのに原因の解説までしていただき、とても感謝しています。
大変お世話になりました。
ありがとうございました。
EdgeRouter X を SSH で接続して設定を行っていますが、接続したままで長時間(30 分以上)放置しても SSH は切断されません。
しかし、設定を確定するコマンド(commit-confirm)を実行すると、同コマンドが実行中なのに約 5 分 38 秒経過すると SSH が切断されます。
PuTTYでも検証しましたが、同コマンドは正常に終了します(SSH は切断されません。)。
再現手順
1.SSH で EdgeRouter X にログイン(有線 LAN で接続。)。
2.configure を入力。
3.設定を入力。
4.commit-confirm 15 を入力(コマンド実行中に、約 5 分 38 秒で切断される。)。
※configure は、設定モードに移行するコマンド。
※commit-confirm N は、設定を確定するコマンド(N 分以内に confirm を入力する必要あり。)。
検証したバージョン
teraterm-4.94.zip
teraterm-4.103.zip
約 5 分 38 秒で切断される。
PuTTY-0.71-ranvis-20190320.win32.zip
約 9 分 12 秒で正常に終了する(SSH は切断されない。)。
OS のバージョン
Windows 7 Home Premium 64 bit
参考
Ubiquiti Networks - EdgeRouter X
https://www.ui.com/edgemax/edgerouter-x/
EdgeRouter X がすごい | yabe.jp
https://yabe.jp/gadgets/edgerouter-x/