Net::HTTPでNet::OpenTimeout (execution expired)が発生

Question

前提

いつも拝見させていただいております。
ありがとうございます。

現在Ruby on Railsを用いてGoogle Books ApiにGETリクエストを送りresponseを加工してNuxt.jsにJsonデータを返却する機能を作っています。

Railsの中で以下のmodelに定義したメソッドを使用してGoogle Books ApiにGETリクエストを送る機能を作りました。
ローカル環境では正常に作動しているのですが、
aws(ecs、EC2)にデプロイしたところ表題の通りエラーが発生しました。

数日詰まっているため、皆様の知恵を貸していただきたくて質問しました。

https://ja.stackoverflow.com/questions/90909/nethttp%e3%81%a7netopentimeout-execution-expired%e3%81%ab%e5%af%be%e5%87%a6%e3%81%97%e3%81%9f%e3%81%84
追記
こちらのサイトでも同様の質問を行っております。
解決した場合は双方のサイトにご報告し、私と同様の問題を抱える方の助けになるよう解決策をシェアいたします。

※９月４日追記
教えていただいた事及び調査結果から、現状は「RailsのEc2コンテナからGoogleApiに対しgetリクエストが届かない」事が判明しています。
下記の「Net::HTTPでGoogle Books ApiにGETリクエストを送り、レスポンスを得たい」という目的を達成するまで補足情報に調査経過を記載します。
情報に誤りがあった場合はご指摘いただけると幸いです。

※９月５日補足情報に(私なりの)解決策を提示しました。

実現したいこと

●何が起きているか知りたい。
●Net::HTTPでGoogle Books ApiにGETリクエストを送り、レスポンスを得たい。

発生している問題・エラーログ

●aws環境のログ

Started GET "/api/v1/books/search/?keyword=%E3%83%86%E3%82%B9%E3%83%88" for 000.000.00.000 at 2022-09-03 16:11:58 +0900
Processing by Api::V1::BooksController#search as HTML
Parameters: {"keyword"=>"........."}
https://www.googleapis.com/books/v1/volumes?q=.........&country=JP
https://www.googleapis.com/books/v1/volumes?q=%E3%83%86%E3%82%B9%E3%83%88&country=JP
https://www.googleapis.com/books/v1/volumes?q=%E3%83%86%E3%82%B9%E3%83%88&country=JP
#<Net::HTTP:0x00007f7e4c5fd008>
#<Net::HTTP::Get:0x00007f7e4c5fcdb0>
Completed 500 Internal Server Error in 60002ms (ActiveRecord: 0.0ms | Allocations: 2006)
↓関係していそうなlogデータ
Net::OpenTimeout (execution expired):
/usr/local/lib/ruby/3.0.0/net/http.rb:987:in `initialize'
/usr/local/lib/ruby/3.0.0/net/http.rb:987:in `open'
/usr/local/lib/ruby/3.0.0/net/http.rb:987:in `block in connect'
/usr/local/lib/ruby/3.0.0/timeout.rb:107:in `timeout'
/usr/local/lib/ruby/3.0.0/net/http.rb:985:in `connect'
/usr/local/lib/ruby/3.0.0/net/http.rb:970:in `do_start'
 /usr/local/lib/ruby/3.0.0/net/http.rb:959:in `start'
/usr/local/lib/ruby/3.0.0/net/http.rb:1512:in `request'
↑関係していそうなlogデータ
/app/models/google_book.rb:61:in `search'

●ローカル環境のログ

Started GET "/api/v1/books/search/?keyword=%E3%83%86%E3%82%B9%E3%83%88" for 000.00.0.0 at 2022-09-03 16:03:24 +0900
Processing by Api::V1::BooksController#search as HTML
  Parameters: {"keyword"=>"........."}
https://www.googleapis.com/books/v1/volumes?q=.........&country=JP
https://www.googleapis.com/books/v1/volumes?q=%E3%83%86%E3%82%B9%E3%83%88&country=JP
https://www.googleapis.com/books/v1/volumes?q=%E3%83%86%E3%82%B9%E3%83%88&country=JP
#<Net::HTTP:0x00007fd7a0119e58>
#<Net::HTTP::Get:0x00007fd7a0119930>
#<Net::HTTPOK:0x00007fd7a0125550>
200
OK
Completed 200 OK in 692ms (Views: 0.7ms | ActiveRecord: 0.0ms | Allocations: 4250)

該当のソースコード

require 'google_books_api'

class GoogleBook
  include ActiveModel::Model
  include ActiveModel::Attributes
  include ActiveModel::Validations
  
  attribute :google_books_api_id, :string
  attribute :authors
  attribute :image, :string
  attribute :published_at, :date
  attribute :title, :string
  attribute :publisher, :string
  
  
  validates :google_books_api_id, presence: true
  validates :title, presence: true
  
  class << self
  #lib以下に作成したモジュールを使用する
  include GoogleBooksApi
  
    def new_from_item(item)
      @item = item
      @volume_info = @item['volumeInfo']
      new(
        google_books_api_id: @item['id'],
        authors: @volume_info['authors'],
        image: image_url,
        published_at: @volume_info['publishedDate'],
        title: @volume_info['title'],
        publisher: @volume_info['publisher'],
      )
    end
  
    def new_from_id(google_books_api_id)
      url = url_of_creating_from_id(google_books_api_id)
      item = get_json_from_url(url)
      new_from_item(item)
    end
 

#エラー発生個所↓
#以下のメソッドをコントローラーで使用します。
#フロントエンドからパラメーターとして送られてくる「keyword」を
#引数に取っています。

    def search(keyword)
      #フロントエンドからのリクエストをuriに変換
      #url_of_searching_from_keywordメソッドは以下のmoduleで定義
      url = url_of_searching_from_keyword(keyword)
      #ログに書き込み
      Rails.logger.debug(url)

      #urlをエンコード
      enc = Addressable::URI.encode(url)
      #ログに書き込み
      Rails.logger.debug(enc)

      #uriに変換
      uri = URI.parse(enc)
      #ログに書き込み
      Rails.logger.debug(uri)
      
      #hostとポート番号をターミナルに出力
      #puts uri.host => www.googleapis.com
      #puts uri.port => 443

      require 'net/https'
      http = Net::HTTP.new(uri.host, uri.port)
      Rails.logger.debug(http)
      http.use_ssl = true
      http.verify_mode = OpenSSL::SSL::VERIFY_NONE

　　
      request = Net::HTTP::Get.new(uri.request_uri)
      ×#getリクエストが為されているかをlogに書き込む
　　訂正#getリクエストするための objectが作られているかをlogに書き込む
      Rails.logger.debug(request)
　　
　　#↓ここがおかしい(レスポンスが返ってこない)
      response = http.request(request)
　　#↑ここまでの処理を機能させたい

module GoogleBooksApi
  
  def url_of_searching_from_keyword(keyword)
    "https://www.googleapis.com/books/v1/volumes?q=#{keyword}&country=JP"
  end

試したこと

①httpからhttps通信に
当初
response ＝ Net::HTTP.get(uri)
というコードを使用していましたが、これを上記modelの通りssl化しました。

②Rails.logger.debugによるデバッグで問題発生箇所を特定

コードを分解し、Rails.logger.debugでどこまで処理が実行されているか確認
したところ
Production.logのlogで
Net::HTTP::Get:0x00007f7e4af86658
というログを発見したため、RailsからGoogle Books Apiへのgetリクエスト自体は送られていると思われます。

補足情報（FW/ツールのバージョンなど）

現在もエラーの原因を調査中ですが、他の方の知恵や対処法(デバック方法)を知りたくて質問させていただきました(以前ご指摘いただいてビックリしたのですが丸投げする意図は全っっっっくありません)。
どうか、皆様の力を貸してください。
足りない情報やご意見がありましたら、コメントを頂けると助かります！

Ruby 3.0.2
Rails 6.1.6

調査経過
９月４日
Rails
models/google_books.rb

      ###疎通確認用##################################################
      require 'net/ping'

      ## Pingの宛て先はuri.host(www.googleapis.com)

      pinger = Net::Ping::External.new(uri.host)

      ## Pingが通るかどうかテストします
      Rails.logger.debug(pinger.ping?)
      ローカル環境 => logへの記録はtrue
      aws環境 => logへの記録無し
      ##############################################################

NuxtとRailsが入っているクラスター内でping

[ec2-user@ip-00-00-0-000 ~]$ ping www.googleapis.com
--- www.googleapis.com ping statistics ---
56 packets transmitted, 56 received, 0% packet loss, time 55082ms
rtt min/avg/max/mdev = 1.332/1.408/2.085/0.143 ms

docker execでRailsが入っているコンテナに侵入しping

/ # ping www.googleapis.com
--- www.googleapis.com ping statistics ---
55 packets transmitted, 0 packets received, 100% packet loss

現状は「RailsのEc2コンテナからGoogleApiに対しgetリクエストが届かない」
現在awsのセキュリティグループ、ネットワークALC、Route53を調査中

9月５日
公式の設定例に従ってRails側のネットワークモードを「awsvpc」にしておりましたが、
https://docs.aws.amazon.com/ja_jp/AmazonECS/latest/bestpracticesguide/networking-outbound.html
↑の記事によればawsvpcはインターネットゲートウェイが使えない事が分かりました。

その為、Rails側のタスク定義でネットワークモードを以下のとおり「bridge」で作り直しました。

結果としてはawsのコンソールにおいて「portが重複しているため、サービスを作成できない」旨のエラーメッセージが発生しサービスを作成できませんでした。
いくつか記事を見たところ
https://aws.amazon.com/jp/premiumsupport/knowledge-center/dynamic-port-mapping-ecs/
を発見し、動的ポートマッピングというものを行えば良いのではないか？と気づきました。

そして、記事に則りネットワーク周り等を作り直しました。
作り直したものは
●アプリケーションロードバランサー(バックエンド用)
●ターゲットグループ(バックエンド用)
●Rails側のタスク定義
●Rails側のサービス
です。
そして、ロードバランサーを作り直したため、Route53を再設定しました(Aレコード)。
その後、以下によればRails側のセキュリティグループで上記ロードバランサーをインバウンドルールに追加する必要がある事が分かり、以下に沿ってRails側のセキュリティグループのインバウンドルールを編集しました。

セキュリティを全てを見せる事は出来ないので、抜粋しますが以下の様になります。

以上の作業を行い、
Rails側の本番用のurlをブラウザに入力し、アクセスしたところ、head200を返すだけのヘルスチェック用アクションにブラウザからアクセスできるようになりました(真白な画面が表示されます)。
また、クラスターにssh接続をした後、Rails側のコンテナにdocker exec で侵入し、外部（GoogleApi）に向けてpingとcurlコマンドを打ったところ、無事レスポンスが返ってくる事を確認しました。
しかし、次は以前ネットワークモードをawsvpcにした状態で正常に作動していたRdsとの接続において、別のエラーが発生し、NuxtとRailsの疎通が不可能になりました。
幾つか記事を読んだところ、以下の記事を発見し、
https://qiita.com/fkana/items/a4b3c4d5d8ca27cd20ec
https://zatoima.github.io/aws-ec2-psql-install.html
Rails側のセキュリティが怪しい、と気づきました。
その後、Rails側のセキュリティグループに以下のインバウンドルールを設定しました。

その結果、表題の
「Net::HTTPでGoogle Books ApiにGETリクエストを送り、レスポンスを得たい」
という目的が達成されました。
ただし、私自身awsの設定やセキュリティの知見はありません。
上記の画像はアクセスの許容範囲が広い設定であるため、セキュリティの問題を孕んでおり、あくまで暫定的な処置になると思われます(アクセスの範囲を絞る必要がある？)。

以上で表題の問題は一旦解決となりますが、何かご意見やご指摘のある方は是非、コメントを頂けると大変助かります。
コメントや回答を下さった皆様(特に辛抱強く何度もコメントを下さったwinterboumさん)、本当にありがとうございました。

Comments

[winterboum]

エラーログ読めないです。
私には力不足の可能性があるので回答は期待しないでほしいですが、力ある人もこれだと読む気起きないかもなので。

[take-hull]

winterboumさん
>エラーログ読めないです。
>私には力不足の可能性があるので回答は期待しないでほしいですが、力ある人もこれだと読>む気起きないかもなので

先日はありがとうございました。
基本的な部分が抜け落ちていました。

表題のエラーが発生した際にベテランの方がどういった点に着目するのか、どこが重要な場所なのかが分かりませんし、不足しているよりかは、と思いlogを全文掲載しました。

読む気が起きなくなるという点についてはおっしゃる通りだと思います。

しかし、現状はできる事をやるしかないので、誰かの目につけば良い、という程度の考えで過度な期待はせず、可能な限り自力で解決できるよう調査を進めております。

不備がありましたら今後もご指摘いただければ幸いです。

[otn]

プログラムを動かす前に環境の確認はしてないのでしょうか？
例えば、pingが通るかとか、wgetかcurコマンドlでHTTPアクセスしてみるとか。

[take-hull]

otnさん

>プログラムを動かす前に環境の確認はしてないのでしょうか？
コメントありがとうございます。
最初にインフラ構築を行い、webサーバーとapiサーバーで最低限の疎通確認を行ったのみでした・・・。
手探りで作っていたというのが正直な所でして、他の方であれば当たり前にやる事を怠っていたり、基礎的な知識が欠落している事を日々痛感しています。
不快に思われたならばお詫びいたします。申し訳ありません。

[otn]

よくあることなので、別に不快では無いです。不快ならコメントしませんし。
うまく行くことに根拠のある確信がある場合は、一か八か、最終結果だけ確認しても良いですが、
確信が無い場合とか、確信があったのにエラーになるなど意図通りの結果にならなかった場合は、
最初から一歩ずつ順番に確認して、どこで間違えたのかを調べます。

[take-hull]

otnさん

コメントありがとうございます。

>よくあることなので、別に不快では無いです。不快ならコメントしませんし。

確かにwgetやcurl等、ネットワーク回りのヒントを頂いてますね・・・失礼しました。

>確信が無い場合とか、確信があったのにエラーになるなど意図通りの結果にならなかった場合は、
>最初から一歩ずつ順番に確認して、どこで間違えたのかを調べます。

肝に銘じます。ありがとうございます！

Answer 1

Net::OpenTimeout ですから、コネクションできていません。
request = Net::HTTP::Get.new(uri.request_uri) は リクエストするための object が作られるだけで、アクセスはしていません。
ので 「#getリクエストが為されているかをlogに書き込む」とありますが、このlogがあってもリクエストはまだしていません。
response = http.request(request) で初めてアクセスに行きます。

可能性としては、 EC2のセキュリティ設定で

1. www.googleapis.com へのアクセスができるようになっていない
2. www.googleapis.com への https プロトコルが通るようになっていない

あたりかな、

Comments

[take-hull]

winterboumさん

解答していただいてありがとうございます。
セキュリティグループの設定を見直し、結果を確認してから返信しようとしていたため、返信が遅れてしまいました。申し訳ありません。

>Net::OpenTimeout ですから、コネクションできていません。
net-pingを用いてuri.host(www.googleapis.com)との疎通確認を行った所、production.logにlogが記録されていないため、おっしゃる通りwww.googleapis.com へのアクセスができるようになっていないのだと思います。

Rails側のセキュリティグループでhttpsを許可しているのですが、十分な知識が無く、設定に不備がある可能性があるため、調査を継続し、(時間がかかるかもしれませんが・・・)問題点や解決策が分かり次第他サイトを含め皆様と情報共有致します。

なお、問題自体は未解決の状態ですが、以前の質問を含め質問のマナー、logの参照、デバッグ、セキュリティの確認等手取り足取り教えていただいたおかげで
「何が起きているか分からず手が付けられない」
状態から
×「RailsがGoogleApiに対してgetリクエストを送れていない」
９月４日訂正「RailsがGoogleApiに対してgetリクエストが届かない」
という所まで把握出来ましたので、頂いた回答をベストアンサーとさせて頂きます。

[winterboum]

getリクエストを送れていない
ではないですよ
getリクエストが届かない
です

[take-hull]

winterboumさん

>getリクエストが届かない
>です

重ね重ね申し訳ありません。
コメントや回答を頂けて本当に助かっています。
「Net::HTTPでGoogle Books ApiにGETリクエストを送り、レスポンスを得る」
という目的を達成するまで途中経過を補足情報に記載しますが、誤った情報をシェアするのはユーザーの不利益なりますので、もし今後見かける機会がありましたら指摘していただけると大変助かります・・・。