Tera Term岩本様
公開鍵認証でログインできました！！
原因は、サーバ側の「authorized_keys」のファイル名が
微妙に間違っていたことで、sshdが公開鍵を見つけられなく
鍵を弾いていたことでした。
TeraTerm側には何も問題はありませんでした。
（強いて上げるのであれば、エラーメッセージの
文字コードくらいでしょうか…？）
大変お騒がせしました。申し訳ありません。
┌───────────────────────┐
市村 光康
mitsu****@jg8ni*****（メイン）
jg8ni****@gmail*****（Gmail）
jg8ni****@kuh*****（メーリングリスト）
└───────────────────────┘
On Mon, 16 Dec 2019 19:08:04 +0900
Mitsuyasu Ichimura <jg8ni****@kuh*****> wrote:
> 岩本様
>
> 市村です。お世話になっております。公開鍵認証方式と、
> キーボードインタラクティブ方式の両方でログインを試み
> たときのログを採取しました。
>
>
> 公開鍵認証時
>
> 2019-12-16 09:54:12.751Z [11896] SSH2_MSG_NEWKEYS was received(DH key generation is completed).
> 2019-12-16 09:54:12.766Z [11896] Server reports supported authentication method mask = 65580
> 2019-12-16 09:54:12.766Z [11896] Entering secure mode
> 2019-12-16 09:54:12.766Z [11896] User authentication will be shown by 0 method.
> 2019-12-16 09:54:12.972Z [11896] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:12.972Z [11896] SSH2_MSG_SERVICE_REQUEST was sent at do_SSH2_userauth().
> 2019-12-16 09:54:12.988Z [11896] SSH2_MSG_SERVICE_ACCEPT was received. service-name=ssh-userauth
> 2019-12-16 09:54:12.988Z [11896] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:12.988Z [11896] SSH2_MSG_USERAUTH_REQUEST was sent do_SSH2_authrequest(). (method 2)
> 2019-12-16 09:54:12.988Z [11896] SSH2_MSG_USERAUTH_FAILURE was received.
> 2019-12-16 09:54:12.988Z [11896] Server reports supported authentication method mask = 65572
> 2019-12-16 09:54:12.988Z [11896] method list from server: publickey,keyboard-interactive
> 2019-12-16 09:54:13.003Z [11896] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:13.003Z [11896] SSH2_MSG_USERAUTH_REQUEST was sent do_SSH2_authrequest(). (method 2)
> 2019-12-16 09:54:13.003Z [11896] SSH2_MSG_USERAUTH_FAILURE was received.
> 2019-12-16 09:54:13.003Z [11896] SSH2自動ログインエラー: ユーザー認証が失敗しました.
> 2019-12-16 09:54:13.003Z [11896] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:13.003Z [11896] SSH2_MSG_DISCONNECT was sent at SSH_notify_disconnecting().
> 2019-12-16 09:54:13.019Z [11896] Terminating SSH session...
>
>
> キーボードインタラクティブ方式時
>
> 2019-12-16 09:54:19.091Z [8664] SSH2_MSG_NEWKEYS was received(DH key generation is completed).
> 2019-12-16 09:54:19.107Z [8664] Server reports supported authentication method mask = 65580
> 2019-12-16 09:54:19.107Z [8664] Entering secure mode
> 2019-12-16 09:54:19.107Z [8664] User authentication will be shown by 0 method.
> 2019-12-16 09:54:19.154Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.170Z [8664] SSH2_MSG_SERVICE_REQUEST was sent at do_SSH2_userauth().
> 2019-12-16 09:54:19.201Z [8664] SSH2_MSG_SERVICE_ACCEPT was received. service-name=ssh-userauth
> 2019-12-16 09:54:19.201Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.216Z [8664] SSH2_MSG_USERAUTH_REQUEST was sent do_SSH2_authrequest(). (method 5)
> 2019-12-16 09:54:19.216Z [8664] SSH2_MSG_USERAUTH_FAILURE was received.
> 2019-12-16 09:54:19.232Z [8664] Server reports supported authentication method mask = 65572
> 2019-12-16 09:54:19.232Z [8664] method list from server: publickey,keyboard-interactive
> 2019-12-16 09:54:19.232Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.232Z [8664] SSH2_MSG_USERAUTH_REQUEST was sent do_SSH2_authrequest(). (method 5)
> 2019-12-16 09:54:19.232Z [8664] SSH2_MSG_USERAUTH_INFO_REQUEST was received.
> 2019-12-16 09:54:19.248Z [8664] handle_SSH2_userauth_inforeq: user=, inst=, lang=
> 2019-12-16 09:54:19.248Z [8664] handle_SSH2_userauth_inforeq: prompts=1
> 2019-12-16 09:54:19.248Z [8664] handle_SSH2_userauth_inforeq: prompt[0]="Password for mitsu****@ameth*****:", echo=40, pass-state=0
> 2019-12-16 09:54:19.248Z [8664] User authentication will be shown by 5 method.
> 2019-12-16 09:54:19.299Z [8664] SSH2_MSG_USERAUTH_INFO_REQUEST was received.
> 2019-12-16 09:54:19.300Z [8664] handle_SSH2_userauth_inforeq: user=, inst=, lang=
> 2019-12-16 09:54:19.302Z [8664] handle_SSH2_userauth_inforeq: prompts=1
> 2019-12-16 09:54:19.303Z [8664] handle_SSH2_userauth_inforeq: prompt[0]="Password for mitsu****@ameth*****:", echo=40, pass-state=1
> 2019-12-16 09:54:19.304Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.306Z [8664] handle_SSH2_userauth_inforeq: sending SSH2_MSG_USERAUTH_INFO_RESPONSE.
> 2019-12-16 09:54:19.313Z [8664] SSH2_MSG_USERAUTH_INFO_REQUEST was received.
> 2019-12-16 09:54:19.313Z [8664] handle_SSH2_userauth_inforeq: user=, inst=, lang=
> 2019-12-16 09:54:19.313Z [8664] handle_SSH2_userauth_inforeq: prompts=0
> 2019-12-16 09:54:19.313Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.313Z [8664] handle_SSH2_userauth_inforeq: sending SSH2_MSG_USERAUTH_INFO_RESPONSE.
> 2019-12-16 09:54:19.313Z [8664] SSH2_MSG_USERAUTH_SUCCESS was received.
> 2019-12-16 09:54:19.313Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.329Z [8664] SSH2_MSG_CHANNEL_OPEN was sent at handle_SSH2_userauth_success().
> 2019-12-16 09:54:19.329Z [8664] User authentication is successful and SSH heartbeat thread is starting.
> 2019-12-16 09:54:19.329Z [8664] SSH2_MSG_GLOBAL_REQUEST was received.
> 2019-12-16 09:54:19.329Z [8664] Hostkey was not updated because ts.UpdateHostkeys is disabled.
> 2019-12-16 09:54:19.375Z [8664] SSH2_MSG_CHANNEL_OPEN_CONFIRMATION was received.
> 2019-12-16 09:54:19.375Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.375Z [8664] send_pty_request: sending SSH2_MSG_CHANNEL_REQUEST. local: 0, remote: 0, request-type: pty-req, term: xterm, cols: 80, rows: 24, x: 597, y: 447, out-speed: 38400, in-speed: 38400, verase: ^h, onlcr: on
> 2019-12-16 09:54:19.375Z [8664] SSH2_MSG_CHANNEL_SUCCESS was received(nego_status 2).
> 2019-12-16 09:54:19.375Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:19.375Z [8664] send_channel_request_gen: sending SSH2_MSG_CHANNEL_REQUEST. local: 0, remote: 0, request-type: shell, msg1=none, msg2=none
> 2019-12-16 09:54:19.375Z [8664] SSH2_MSG_CHANNEL_SUCCESS was received(nego_status 3).
> 2019-12-16 09:54:34.223Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:34.238Z [8664] SSH2_MSG_CHANNEL_EOF was received. local:0 remote:0
> 2019-12-16 09:54:34.238Z [8664] SSH2_MSG_CHANNEL_REQUEST was received.
> 2019-12-16 09:54:34.238Z [8664] handle_SSH2_channel_request: local=0, remote=0, request=exit-status, want_reply=0
> 2019-12-16 09:54:34.238Z [8664] handle_SSH2_channel_request: exit-status=0
> 2019-12-16 09:54:34.254Z [8664] SSH2_MSG_CHANNEL_CLOSE was received. local:0 remote:0
> 2019-12-16 09:54:34.254Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:34.254Z [8664] SSH2_MSG_CHANNEL_CLOSE was sent at ssh2_channel_send_close(). local:0 remote:0
> 2019-12-16 09:54:34.254Z [8664] CRYPT_set_random_data: RAND_bytes call
> 2019-12-16 09:54:34.269Z [8664] SSH2_MSG_DISCONNECT was sent at SSH_notify_disconnecting().
> 2019-12-16 09:54:34.285Z [8664] Terminating SSH session...
>
>
> 以上となります。宜しくお願いします。
>
>
> ┌───────────────────────┐
> 市村 光康
> mitsu****@jg8ni*****（メイン）
> jg8ni****@gmail*****（Gmail）
> jg8ni****@kuh*****（メーリングリスト）
> └───────────────────────┘
>
> On Mon, 16 Dec 2019 13:22:37 +0900
> IWAMOTO Kouichi <sue****@iwmt*****> wrote:
>
> > 岩本です。
> >
> > On Sun, 15 Dec 2019 10:11:56 +0900
> > Mitsuyasu Ichimura <jg8ni****@kuh*****> wrote:
> >
> > > auth.logを確認してみると、下記の通りのエラーが出ています。
> > >
> > > Dec 15 10:04:36 amethyst sshd[39709]: user mitsu login class [preauth]
> > > Dec 15 10:04:36 amethyst syslogd: last message repeated 1 times
> > > Dec 15 10:04:36 amethyst sshd[39709]: Received disconnect from 192.168.1.15 port 60490:11: SSH2\\216\\251\\223\\256\\203\\215\\203O\\203C\\203\\223\\203G\\203\\211\\201[:\\203\\206\\201[\\203U\\201[\\224F\\217\\330\\202\\252\\216\\270\\224s\\202\\265\\202\\334\\202\\265\\202\\275. [preauth]
> >
> > Disconnect メッセージに日本語(CP932)の文字列を含めちゃってますね。日本語を
> > 含めるならばUTF-8にする必要が有るので、これは修正が必要だなあ。
> >
> > メッセージは「SSH2自動ログインエラー:ユーザー認証が失敗しました.」なので、
> > これからは何等かの理由で認証が失敗した事しかわからないですね。
> >
> > 1. TERATERM.INI の LogLevel を 100 にする
> > 2. サーバに接続して、公開鍵認証で認証を行う
> > 3. 2 が失敗した後にキーボードインタラクティブ認証で認証を行う
> >
> > を実施して、Tera Termのインストールディレクトリに出来た TTSSH.LOG のうち、
> > "SSH2_MSG_NEWKEYS was received(DH key generation is completed)." より後の
> > ログを見せてもらえますか?
> > 現状ではログ出力が貧弱なので、見せてもらったログを元にログ出力を強化した
> > バージョンで試してもらう事になると思います。
> >
> > > 鍵は、サーバ上で
> > > ssh-keygen -b 2048
> > > で生成しています。そのうえで、公開鍵をサーバのautorized_keyに
> > > 登録してあります。パーミッションも「600」に設定しております。
> >
> > パーミッションの問題だったら、キーボードインタラクティブ認証でログイン時に
> >
> > 2019-12-16 03:18:57.668Z [19216] DEBUG message from server: Ignored authorized keys: bad ownership or modes for directory /home/sue
> >
> > というように問題の有るファイル/ディレクトリの情報が TTSSH.LOG に出てくる
> > はずです。ただ、FreeBSD -> FreeBSD で問題が無いとの事なので、これの可能性は
> > 低いと思います。
> >
> > --
> > IWAMOTO Kouichi <sue****@iwmt*****>
> >
> > _______________________________________________
> > Ttssh2-users mailing list
> > Ttssh****@lists*****
> > https://lists.osdn.me/mailman/listinfo/ttssh2-users
>
> _______________________________________________
> Ttssh2-users mailing list
> Ttssh****@lists*****
> https://lists.osdn.me/mailman/listinfo/ttssh2-users