Ruby の Net::HTTP のタイムアウトにハマって、結局 Timeout について調べることになった件

外部API を実行するために、Net::HTTP で POST してたんだけど、
何故かタイムアウト値を設定しても適用されなかったので調べた時のメモ

下記が当初作ったコードで、ネットワークを接続しない状態で実行したところ、
何故か 20 秒たってやっとタイムアウトの例外 ( `Net::OpenTimeout: execution expired` ) が発生
`open_timeout` の 5 秒で例外が発生するんじゃないの？？

### サンプル1

```rb
def post(url, request_body)
  uri = URI.parse(url)
  response = Net::HTTP.start(uri.host, uri.port, use_ssl: uri.scheme == 'https') {|http|
    http.open_timeout = 5
    http.read_timeout = 125
    http.post(uri.request_uri, request_body)
  }
end
```

調べたら、`start()` でこけてるのにその後ろで指定してもだめらしい。
http://moriq.tdiary.net/20080805.html  

なるほど確かにと思い、下記のように `new` して `start` 前に設定するよう修正してみた

### サンプル2

```rb
def post(url, request_body)
  uri = URI.parse(url)
  http = Net::HTTP.new(uri.host, uri.port)
  http.use_ssl = uri.scheme == 'https'
  http.open_timeout = 5
  http.read_timeout = 125
  response = http.start do
    http.post(uri.request_uri, request_body)
  end
end
```

これでやっと実現できるだろう思い、再度実行してみたが…
相変わらず、20 秒たっての例外発生。

これはソース読むしか無いと、net/http の接続する部分 ( 879行目 ) を読んでみた。

ソースの抜粋

```rb:net/http.rb
def connect
  # 省略
  # 省略
  # 省略
  s = Timeout.timeout(@open_timeout, Net::OpenTimeout) {
    TCPSocket.open(conn_address, conn_port, @local_host, @local_port)
  }
  # 省略
  # 省略
  # 省略
end
```

これ見る限り、タイムアウトの処理がちゃんと記載されている…
試しにコンソールで実行してみたところ、何故かタイムアウト値が効かない
なぜッッ！？！？！？！？！？

```rb
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s = TCPSocket.open('www.example.com', 80) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
  s.close if s.class == TCPSocket # Socket を閉じるため
}
2015-02-12 16:22:16 +0900
2015-02-12 16:22:56 +0900
Timeout::Error:execution expired
```

`sleep` で試してみた。

```rb
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  sleep(10)
  puts Time.zone.now.to_s
} rescue puts "#{Time.zone.now.to_s} #{$!.class.to_s}:#{$!.message}"
2015-02-12 16:25:16 +0900
2015-02-12 16:25:21 +0900 Timeout::Error:execution expired
```

ちゃんと 5 秒でタイムアウトした
何かのバグなのかと色々調べてみた結果、Timeout の説明に下記のような文言があった

http://docs.ruby-lang.org/ja/2.1.0/class/Timeout.html

>timeout による割り込みは Thread によって実現されています。 C 言語レベルで実装され、 Ruby のスレッドが割り込めない処理に対して timeout は無力です。 そのようなものは実用レベルでは少ないのですが、 Socket などは DNSの名前解決に時間がかかった場合割り込めません (resolv-replace を使用する必要があります)。 その処理を Ruby で実装しなおすか C 側で Ruby のスレッドを意識してあげる必要があります。

今回、ネットワークにつながず試したので、名前解決に時間がかかり、その処理中に `timeout` が割り込めなかったようだ

以下、実際にネットワークにつなげてみて `timeout` の動きを試してみた

接続できる場合

```
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s = TCPSocket.open('www.google.jp', 80) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
  s.close if s.class == TCPSocket # Socket を閉じるため
}
2015-02-12 17:15:46 +0900
2015-02-12 17:15:46 +0900
```
これは特に問題なし

存在しないサブドメインの場合

```
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s = TCPSocket.open('hogehoge.google.jp', 80) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
  s.close if s.class == TCPSocket # Socket を閉じるため
}
2015-02-12 17:14:59 +0900
2015-02-12 17:14:59 +0900
SocketError:getaddrinfo: 名前またはサービスが不明です
```
ソッコー返ってきた。名前解決がすぐ出来たため ( 出来たと言っても、存在しないドメインだから名前解決が出来ず `SocketError` が発生 )、即例外が発生している

存在しないドメインでやってみた

```
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s = TCPSocket.open('www.google.jpp', 80) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
  s.close if s.class == TCPSocket # Socket を閉じるため
}
2015-02-12 17:14:34 +0900
2015-02-12 17:14:34 +0900
SocketError:getaddrinfo: 名前またはサービスが不明です
```
上と同じ理由で、ソッコー返ってきた。

次は、接続できないポートでやってみた

```
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s = TCPSocket.open('www.google.jp', 500) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
  s.close if s.class == TCPSocket # Socket を閉じるため
}
2015-02-12 17:19:58 +0900
2015-02-12 17:20:03 +0900
Timeout::Error:execution expired
```

`timeout` がきいた
ただし、`TCPSocket.open` 実行中 ( 名前解決は成功 ) に 5 秒立って `Timeout::Error` が割り込んで、その後ろの `rescue` でを拾ってるみたい
確かに割り込んでる
`sleep` 使ってそれを試してみた

```
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s = sleep(20) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
}
2015-02-12 17:36:43 +0900
2015-02-12 17:36:48 +0900
Timeout::Error:execution expired
```

`sleep(20)` 実行中に `Timeout::Error` が発生し、ちゃんと `rescue` できた。

今度は、`sleep(20)` ではなく、 `sleep(2)` を挟んでそれぞれで `rescue` してみる

```
Timeout.timeout(5, Timeout::Error) {
  puts Time.zone.now.to_s
  s1 = sleep(2) rescue "#{$!.class.to_s}:#{$!.message}"
  s2 = sleep(20)
  s3 = sleep(2) rescue "#{$!.class.to_s}:#{$!.message}"
  puts Time.zone.now.to_s
  puts s if s.class == String #　エラーメッセージ表示用
}
2015-02-12 17:55:43 +0900
Timeout::Error: execution expired
from (pry):211:in `sleep'
```

`rescue` できなかった。
`timeout` の動きとしては、やはり `Timeout` 内の実行中のメソッドで、`Timeout::Error` が発生した動きになってるみたい。

## 結論
`net/http` の `open_timeout` は 接続できないポートにアクセスした時や、相手方サーバーの負荷により、connection が張れない時などには有効で、そもそもサーバーが障害等でネットワークがつながってない状態では、DNS の名前解決により、`timeout` が割り込めず、タイムアウト値を設定しても、その秒数で処理を終了させることが出来ない。

後、 post の処理は、サンプル 2 を採用することにした