PAGE TOP

アトトックラボ

20180606

RubyのNet::HTTPのリトライについて調べてみた

rubyでサーバーと連携するAPIを開発していてサーバーからの応答が遅い場合に、
リクエストが2回送信される現象があったのでNet::HTTPのリトライについて気になったので調べてみました。

サーバー側はRailsで作成しクライアント側は
下記のようにget methodでリクエストを送信するテストプログラムで確認します。

test_http.rb

require 'net/http'

uri = URI.parse("http://localhost:3000/hoges.json")
req = Net::HTTP::Get.new(uri.path)
res = Net::HTTP.start(uri.host, uri.port) do |http|
  http.request(req)
end

これを実行すると下記のようにサーバーに1回だけGETでリクエストしています。

サーバー側のログ出力

Started GET "/hoges.json" for 127.0.0.1 at 2018-06-06 02:02:20 +0900
  ActiveRecord::SchemaMigration Load (0.3ms)  SELECT "schema_migrations".* FROM "schema_migrations"
Processing by HogesController#index as JSON
  Rendering hoges/index.json.jbuilder
  Hoge Load (0.2ms)  SELECT "hoges".* FROM "hoges"
  Rendered hoges/_hoge.json.jbuilder (1.8ms)
  Rendered hoges/_hoge.json.jbuilder (1.6ms)
  Rendered hoges/index.json.jbuilder (38.2ms)
Completed 200 OK in 96ms (Views: 71.0ms | ActiveRecord: 1.7ms)

サーバー側の応答を遅くしてみる

サーバー側ですぐに応答が返らないように90秒スリープさせてみます。

サーバー側の処理

def index
  @hoges = Hoge.all
  p "sleep start #{DateTime.now}"
  sleep(90)
  p "sleep end #{DateTime.now}"
end

リクエストがリトライされる

この状態でtest_http.rbを実行すると「GET "/hoges.json"」が2回リクエストきています。

Started GET "/hoges.json" for 127.0.0.1 at 2018-06-06 02:17:32 +0900
Processing by HogesController#index as JSON
"sleep start 2018-06-06T02:17:32+09:00"
Started GET "/hoges.json" for 127.0.0.1 at 2018-06-06 02:18:32 +0900
Processing by HogesController#index as JSON
"sleep start 2018-06-06T02:18:32+09:00"
"sleep end 2018-06-06T02:19:02+09:00"
  Rendering hoges/index.json.jbuilder
  Hoge Load (0.2ms)  SELECT "hoges".* FROM "hoges"
  Rendered hoges/_hoge.json.jbuilder (1.0ms)
  Rendered hoges/_hoge.json.jbuilder (0.5ms)
  Rendered hoges/index.json.jbuilder (6.6ms)
Completed 200 OK in 90028ms (Views: 19.7ms | ActiveRecord: 0.2ms)


"sleep end 2018-06-06T02:20:02+09:00"
  Rendering hoges/index.json.jbuilder
  Hoge Load (0.2ms)  SELECT "hoges".* FROM "hoges"
  Rendered hoges/_hoge.json.jbuilder (0.6ms)
  Rendered hoges/_hoge.json.jbuilder (0.4ms)
  Rendered hoges/index.json.jbuilder (5.2ms)
Completed 200 OK in 90027ms (Views: 19.2ms | ActiveRecord: 0.2ms)

Net::HTTP.startでリトライしているようです。

このときのrubyのバージョンは2.3.0

$ ruby -v
ruby 2.3.0p0 (2015-12-25 revision 53290) [x86_64-darwin15]

ruby 2.5.1のNet::HTTP

ruby 2.5.1のNet::HTTPにはmax_retriesが追加されています。
このへんの動きを確認してみます。

rbenvでruby 2.5.1に変更

$ rbenv local 2.5.1
$ ruby -v
ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-darwin16]

この状態でtest_http.rbを実行してみます。
ruby 2.5.1でもリクエストが2回あります。

Started GET "/hoges.json" for 127.0.0.1 at 2018-06-06 02:26:41 +0900
Processing by HogesController#index as JSON
"sleep start 2018-06-06T02:26:41+09:00"
Started GET "/hoges.json" for 127.0.0.1 at 2018-06-06 02:27:41 +0900
Processing by HogesController#index as JSON
"sleep start 2018-06-06T02:27:41+09:00"
"sleep end 2018-06-06T02:28:11+09:00"
  Rendering hoges/index.json.jbuilder
  Hoge Load (1.6ms)  SELECT "hoges".* FROM "hoges"
  Rendered hoges/_hoge.json.jbuilder (2.6ms)
  Rendered hoges/_hoge.json.jbuilder (0.6ms)
  Rendered hoges/index.json.jbuilder (15.9ms)
Completed 200 OK in 90047ms (Views: 33.1ms | ActiveRecord: 1.6ms)


"sleep end 2018-06-06T02:29:11+09:00"
  Rendering hoges/index.json.jbuilder
  Hoge Load (1.9ms)  SELECT "hoges".* FROM "hoges"
  Rendered hoges/_hoge.json.jbuilder (17.5ms)
  Rendered hoges/_hoge.json.jbuilder (1.3ms)
  Rendered hoges/index.json.jbuilder (81.6ms)
Completed 200 OK in 90152ms (Views: 121.6ms | ActiveRecord: 1.9ms)

test_http.rb

test_http.rbを修正し、max_retriesの値を確認してみます。

require 'net/http'

uri = URI.parse("http://localhost:3000/hoges.json")
req = Net::HTTP::Get.new(uri.path)
res = Net::HTTP.start(uri.host, uri.port) do |http|
  p "http.max_retries : #{http.max_retries}"
  http.request(req)
end

実行結果

$ ruby test_http.rb
"http.max_retries : 1"

max_retriesは1になっています。

max_retriesを0にして実行してみます。

require 'net/http'

uri = URI.parse("http://localhost:3000/hoges.json")
req = Net::HTTP::Get.new(uri.path)
res = Net::HTTP.start(uri.host, uri.port) do |http|
  http.max_retries = 0
  p "http.max_retries : #{http.max_retries}"
  http.request(req)
end

実行結果

Started GET "/hoges.json" for 127.0.0.1 at 2018-06-06 02:39:40 +0900
Processing by HogesController#index as JSON
"sleep start 2018-06-06T02:39:40+09:00"
"sleep end 2018-06-06T02:41:10+09:00"
  Rendering hoges/index.json.jbuilder
  Hoge Load (0.3ms)  SELECT "hoges".* FROM "hoges"
  Rendered hoges/_hoge.json.jbuilder (6.4ms)
  Rendered hoges/_hoge.json.jbuilder (7.8ms)
  Rendered hoges/index.json.jbuilder (24.4ms)
Completed 200 OK in 90055ms (Views: 43.5ms | ActiveRecord: 0.3ms)

max_retriesを0にするとリクエストは1回だけになりました。

お問い合わせはお問い合わせフォームかお電話でご連絡ください。
Btn mail
Btn tel

アトトックラボとは?

株式会社アトトック のメンバーが技術の話、デザインの話、キャラクターの話、ときどき脱線してガジェットの話やライフハックの話など好きなことを書いています。


最近の記事


タグ