LWP::UserAgentのタイムアウトがうまく効かなかった事象の調査 (序章)

皆様, メリークリスマス! この記事は, ｢Perl Advent Calendar 2020｣の25日目の記事です.

qiita.com

昨日は, id:hitode909 さんの｢Perlアプリケーションの依存モジュールの更新についてWEB+DB PRESS vol.120のPerl Hackers Hubに寄稿しました｣でした.

blog.sushi.money

---

さて, 本題です. Perlにおいて, HTTPリクエストを送る時のデファクトスタンダードと言えばLWP::UserAgentではないでしょうか.

metacpan.org

LWP::UserAgentには, timeoutというオプションがあります. 2020年12月25日現在の最新版は6.50ですが, このバージョンではtimeoutのデフォルトは180秒となっていて, この場合HTTPリクエストを送って180秒経過するとその通信を打ち切ってくれます(リクエスト先のサーバーで処理に時間がかかり, 180秒で返せなかった場合など).

先日, ある特定の状況下でこのタイムアウトが効かず, しばらく処理が続いてしまうという事象に遭遇しました. LWP::UserAgentのログを手がかりに調査した様子を紹介することで, ｢Perl Advent Calendar 2020｣の25日目の記事としようと思います.

...ただ先に述べておくと, 今回は時間の制約上｢こうかな...?｣という仮説を立てる所で力尽きてしまいました. なので, どちらかというと, ｢ログを参考にして実装を追う｣時の一例, として見てもらった方が良いかもしれません.

LWP::UserAgent

該当のリクエストにおいて, LWP::UserAgentは以下のようなリクエストを出力していました:

500 Can't connect to example.com:80

これを手がかりに, まずはLWP::UserAgentでCan't connect toといったログを出力している場所を探してみました. ちなみにこういう時は,

• metacpanでGitHubのLWP::UserAgentの実装があるリポジトリを探す
• 見つけたリポジトリを, ghqで手元にclone
• kazuhoさんのブログで紹介されていた｢peco改｣で探し, エディタで開く

... という流れが多いです.

github.com

blog.kazuhooku.com

さて, そうすると, LWP::Protocol::http に次のようなコードがあることがわかりました. LWP::Protocol::http は, その名の通りHTTPプロトコルによる通信を司るモジュールなので, ここを調べていくと良さそうです.

github.com

   # IO::Socket::INET leaves additional error messages in $@
    my $status = "Can't connect to $host:$port";

前後のコードを追いかけていきましょう. すると, この直前で $self->socket_class->new() を使って, $sock という変数を定義していることがわかります.

github.com

    my $sock = $self->socket_class->new(PeerAddr => $host,
                    PeerPort => $port,
                    LocalAddr => $self->{ua}{local_address},
                    Proto    => 'tcp',
                    Timeout  => $timeout,
                    KeepAlive => !!$self->{ua}{conn_cache},
                    SendTE    => $self->{ua}{send_te},
                    $self->_extra_sock_opts($host, $port),
                       );

LWP::Protocol::http における socket_class の実装は以下のとおりです.

github.com

sub socket_class
{
    my $self = shift;
    (ref($self) || $self) . "::Socket";
}

この場合, $self は LWP::Protocol::http のオブジェクト, もしくはLWP::Protocol::httpという文字列になるので, つまり $self->socket_class は LWP::Protocol::http::Socket を返します.

続いて, LWP::Protocol::http::Socket を探します. するとLWP::Protocol::httpと同じファイルの下に, 以下のように定義されていました.

github.com

package # hide from PAUSE
    LWP::Protocol::http::Socket;

use parent -norequire, qw(LWP::Protocol::http::SocketMethods Net::HTTP);

余談ですが, hide from PAUSEについて. これは id:Songmu さんの以下のエントリにある説明を読むとよいでしょう.

songmu.jp

...話を戻します. ここまでをまとめると, $self->socket_class->new は実際には LWP::Protocol::http::Socket->new が実行されることがわかりました. そして, LWP::Protocol::http::Socket は, LWP::Protocol::http::SocketMethodsとNet::HTTPを継承したものということもわかりました.

つまり, $self->socket_class->new を呼び出した時に実行されるnew メソッドは, LWP::Protocol::http::SocketMethodsとNet::HTTPのいずれかに定義されているはずです. 結論から言うと(名前からも察せると思いますが), LWP::Protocol::http::SocketMethodsにはnewメソッドがなく, Net::HTTPのnewメソッドが呼び出されていることがわかります.

github.com

package # hide from PAUSE
    LWP::Protocol::http::SocketMethods;

sub ping {
    my $self = shift;
    !$self->can_read(0);
}

sub increment_response_count {
    my $self = shift;
    return ++${*$self}{'myhttp_response_count'};
}

Net::HTTP

続いて, Net::HTTPを調べていきます. 対象は, 2020年12月25日現在の最新版, 6.19です.

metacpan.org

our @ISA = ($SOCKET_CLASS, 'Net::HTTP::Methods');
 
sub new {
    my $class = shift;
    Carp::croak("No Host option provided") unless @_;
    $class->SUPER::new(@_);
}

このコードを見ると, Net::HTTPもまた何かのモジュール($SOCKET_CLASS)を継承しており, $class->SUPER::new(@_);でそのモジュールのnewメソッドを呼び出していることがわかります.

$SOCKET_CLASSを宣言している部分はと言うと, 次のような実装になっています:

metacpan.org

use vars qw($SOCKET_CLASS);
unless ($SOCKET_CLASS) {
    # Try several, in order of capability and preference
    if (eval { require IO::Socket::IP }) {
       $SOCKET_CLASS = "IO::Socket::IP";    # IPv4+IPv6
    } elsif (eval { require IO::Socket::INET6 }) {
       $SOCKET_CLASS = "IO::Socket::INET6"; # IPv4+IPv6
    } elsif (eval { require IO::Socket::INET }) {
       $SOCKET_CLASS = "IO::Socket::INET";  # IPv4 only
    } else {
       require IO::Socket;
       $SOCKET_CLASS = "IO::Socket::INET";
    }
}

つまり, Net::HTTPは,

• IO::Socket::IPが利用可能なら, IO::Socket::IP を
• IO::Socket::INET6が利用可能なら, IO::Socekt::INET6 を
• いずれも利用できないなら, IO::Socket::INET を

...継承し, 利用するようになっています.

$ corelist IO::Socket::IP
Data for 2020-06-01
IO::Socket::IP was first released with perl v5.19.8

corelistコマンドによれば, IO::Socket::IPは, 5.19.8でコアモジュールとなっているので, 最近のPerlであればこれが使われる... と考えて良いでしょう. ということで, 次はIO::Socket::IPを調べていきます.

IO::Socket::IP

※この辺りから, だいぶ自信がなくなってきています. 間違ったことを書いていたら, 指摘頂けると幸いです...

IO::Socket::IPは, Family-neutral IP socket supporting both IPv4 and IPv6つまりIPv4とIPv6の両方に対応したソケット通信を提供するモジュールのようです. 今回は, 2020年12月25日現在の最新版である, 0.41を参照しました.

IO::Socket::IPのドキュメントを見ると, こちらにもまたタイムアウトのオプションがありそうです(Timeout). が...

If defined, gives a maximum time in seconds to block per connect() call when in blocking mode. If missing, no timeout is applied other than that provided by the underlying operating system. When in non-blocking mode this parameter is ignored.

• connect()を呼び出すごとにブロックする最大時間をTimeoutで定義できる
• 非ブロッキングモードの場合, このパラメータは無視される

This behviour is copied inspired by IO::Socket::INET; for more fine grained control over connection timeouts, consider performing a nonblocking connect directly.

• もしタイムアウトを細かく制御したければ, 非ブロッキングモードで実行することを検討せよ

...といったことが書かれている, ように見えます. ちなみに"ブロッキングモード"は, Blockingというパラメータで制御できるらしく, 説明を読むと...

If defined but false, the socket will be set to non-blocking mode.

...つまり, デフォルトはブロッキングモードが有効で, 偽値を指定すると無効(= 非ブロッキングモード)になる... ようです.

ちょっと複雑なので説明を端折りますが, LWP::Protocol::httpで$self->socket_class->new()すると, 最終的にはIO::Socket::IPのconnectメソッドが呼ばれます.

metacpan.org

ここで, Perlのconnect()関数が呼ばれているようなのですが, ここにTimeoutが渡っていない(渡せない)です.

というわけで, 万が一, 例えばリクエスト先のサーバが不調などの原因で, このconnect()関数の呼び出しに時間がかかってしまった場合, LWP::UserAgentに渡したtimeoutオプションを無視して待ち続ける... ということが起こりうるのでは...? という仮説を立てるところまで至りました.

ソケット周りの知識, 大学で学んだはずなのですが大昔すぎて忘れてしまったりということもあり, ちょっと中途半端ではありますが, 今回はこの辺りで一旦終了としようと思います... が, 流石に不完全燃焼なので, 本当にconnect()関数の呼び出しの部分に原因があるのか? であったり, IO::Socket::IPの非ブロッキングモードで回避する方法はあるか? といった所について, 改めて調べてみたいと思います.

...中途半端なオチですいません.

---

さて, このエントリで｢Perl Advent Calendar 2020｣も無事終了です!!! 最終日まで, だれ1人欠けることなく, 珠玉の25記事が集まりました.

qiita.com

2020年といえば, 開催を予定していたYAPC::Kyotoが新型コロナウイルスの影響で中止となってしまいました. しかしながら, 2021年に向けてオンライン形式でのイベント, ｢Japan.pm｣の計画が進みつつあります.

おまたせしました！オンラインPerlカンファレンス、https://t.co/zuK0JlFovB の開催が決定しました！2/18(木) 2/19(金)で開催する予定です。詳細につきましては続報をお待ち下さい！ #yapcjapan #perl

— yapcjapan (@yapcjapan) 2020年12月2日

2021年が, Perl Mongerの皆様にとって実りの多い1年になることを祈りつつ, ｢Perl Advent Calendar 2020｣の25日目の記事を終えたいと思います.