Gentoo Linux の sshd を xinetd 化したのですが、リモートからのSSH接続に30秒かかる現象に遭遇しました。原因と対策が分かりましたので紹介します。
xinetd 接続時の現象
xinetd の設定はデフォルト値のまま、ssh用の設定をネットで拾ってきて以下の設定をしました。
/etc/xinetd.d/ssh service ssh { disable = no socket_type = stream wait = no user = root server = /usr/sbin/sshd server_args = -i log_on_success += DURATION USERID log_on_failure += USERID }
過去にtelnetやapacheなどで経験があったので簡単に終わる予定でした。
しかし、いざTeraTerm から接続するとなぜか遅い。しかも毎回30秒ピッタリ。
調査
ps afx で、xinetd からsshdをforkするタイミングをみてみると、30秒経過してからsshd が生まれているので、xinetd が原因なのは間違いありません。ネットを徘徊して調査をしましたが、それらしい記事は見つけられませんでした。
これ以上ネットを見ていても分からないので、いよいよ最後の手段のデバッグをすることにしました。Gentoo Linux は各パッケージのソースコードは /var/cache/distfiles 以下にあるので、そこから xinetd のアーカイブを展開します。
ソースを見ていると -d をつけるとコンソールにデバッグメッセージが表示されることが分かりました。デーモンでも通常のプログラムと変わらずにそのまま実行ができるのでコンパイルした xinetd を -d 付きで実行すると・・・
# configure # make # ./xinetd -d 22/5/30@23:52:09: DEBUG: 10139 {cnf_start_services} Started service: ssh 22/5/30@23:52:09: DEBUG: 10139 {cnf_start_services} pfds_last = 1, services_started = 1 22/5/30@23:52:09: NOTICE: 10139 {main} 2.3.15.4 started with loadavg options compiled in. 22/5/30@23:52:09: NOTICE: 10139 {main} Started working: 1 available service 22/5/30@23:52:09: DEBUG: 10139 {main_loop} active_services = 1 22/5/30@23:52:27: DEBUG: 10139 {main_loop} select returned 1 22/5/30@23:52:27: DEBUG: 10139 {server_start} Starting service ssh 22/5/30@23:52:27: DEBUG: 10139 {main_loop} active_services = 1 22/5/30@23:52:57: DEBUG: 10141 {exec_server} duping 7
最終行の exec_server で、30秒の隙間が空いています。ここまで分かれば後はソースの見ながら追加のメッセージを追加していけば原因が特定できます。
で、結局いきついたのは、ident.c の log_remote_user() の
if ( connect( sd, &sin_contact.sa, sizeof( sin_contact ) ) == -1 )
これでした。なんと、xinetdがコネクションを張りにいき30秒タイムアウトになっていたのです。コメントを見ていると気になる文がありました。
This function also logs the remote user id if appropriate
リモートユーザーの情報、つまりsshにコネクトをかけてきたクライアントの USERID を取得するために逆コネクションをしているようです。USER ID というキーワードでひらめいたのが、 /etc/xinetd.d/ssh の設定ファイルのこの行です。
log_on_success += DURATION USERID
ここの意味は知らなかったのですが、ログインが成功したときにリモートのUSER IDをロギングするという機能です。この USER ID指定があると、log_remote_user() がコールされる動きになっており、30秒遅延にはまり込んでいたのです。
このコネクションがなにかというと、ident (port 113)と呼ばれるサービスで接続してきたクライアントの情報を取得できるとのこと。Windows は ident には対応していないので、つながることはありません。
対策
最終的に USERID を取りのぞいた 以下の設定値にすることで、TeraTerm からの接続が一瞬で確立できるようになりました。
/etc/xinetd.d/ssh service ssh { disable = no socket_type = stream wait = no user = root server = /usr/sbin/sshd server_args = -i log_on_success += DURATION }
今回は調査に奥の手を使ってしまいましたが、マニュアルを見ると以下が書かれていました。
logs the user id of the remote user using the RFC 1413 identification protocol.
idnet を使っている事が書かれていますが、親切とはいえないです。。