0

状況

環境は下記です。今回はあまり関係ないと思いますがフロントはreact nativeでスマホアプリです。

ruby: 3.0.3
rails: 6.1.4.4
carrierwave: 2.2.3

参考までにサーバーはさくらインターネットのVPSです。OSは標準のCentOS Stream 8 x86_64を利用してます。

carrierwaveの設定は下記の様な感じ。

  config.fog_provider = 'fog/aws'
  config.fog_credentials = {
    provider: 'AWS',
    aws_access_key_id: Rails.application.credentials.dig(:aws, :access_key_id),
    aws_secret_access_key: Rails.application.credentials.dig(:aws, :secret_access_key),
    region: 'ap-northeast-1',
  }
  config.storage = :fog

  if Rails.env.production?
    config.fog_directory = "prod-profit-#{ProFitName.normalize_to('-')}"
  else
    config.fog_directory = "dev-profit-#{ProFitName.normalize_to('-')}"
  end

エラーログは下記の様な感じです。

I, [2023-01-22T05:23:31.521083 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486] Started PUT "/api/v1/jobs/2/" for 202.241.150.66 at 2023-01-22 05:23:31 +0900
I, [2023-01-22T05:23:31.544738 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486] Processing by API::V1::JobsController#update as HTML
I, [2023-01-22T05:23:31.544879 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Parameters: {"userId"=>"1", "secureCode"=>"****", "job"=>{"mainImage"=>#<ActionDispatch::Http::UploadedFile:0x0000000005a99a98 @tempfile=#<Tempfile:/tmp/RackMultipart20230122-7888-h3q0hr.jpg>, @original_filename="124B68E9-A2E7-4195-9CAD-8046C11AAF5B.jpg", @content_type="image/jpeg", @headers="content-disposition: form-data; name=\"job[mainImage]\"; filename=\"124B68E9-A2E7-4195-9CAD-8046C11AAF5B.jpg\"\r\ncontent-type: image/jpeg\r\n">}, "id"=>"2"}
D, [2023-01-22T05:23:31.546758 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   User Load (0.3ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` = 1 LIMIT 1
D, [2023-01-22T05:23:31.549101 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   UserSecurity Load (0.2ms)  SELECT `user_securities`.* FROM `user_securities` WHERE `user_securities`.`user_id` = 1 AND `user_securities`.`code` = '****' LIMIT 1
D, [2023-01-22T05:23:31.550264 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Job Load (0.2ms)  SELECT `jobs`.* FROM `jobs` WHERE `jobs`.`id` = 2 LIMIT 1
D, [2023-01-22T05:23:31.551645 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   JobUser Exists? (0.2ms)  SELECT 1 AS one FROM `job_users` WHERE `job_users`.`job_id` = 2 AND `job_users`.`user_id` = 1 AND `job_users`.`role` = 1 LIMIT 1
D, [2023-01-22T05:23:32.126445 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   TRANSACTION (0.3ms)  BEGIN
D, [2023-01-22T05:23:32.127519 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Job Update (0.9ms)  UPDATE `jobs` SET `jobs`.`main_image` = '1728a43022.jpg', `jobs`.`updated_at` = '2023-01-22 05:23:32.123767' WHERE `jobs`.`id` = 2
D, [2023-01-22T05:23:32.130675 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   TRANSACTION (1.8ms)  COMMIT
I, [2023-01-22T05:24:52.209200 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486] Completed 500 Internal Server Error in 80664ms (ActiveRecord: 3.9ms | Allocations: 9861)
F, [2023-01-22T05:24:52.211158 #7888] FATAL -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]
[db679c33-cf22-4dc9-9ecf-4ced05a50486] Excon::Error::Socket (no address for dev-profit-beauty.s3.ap-northeast-1.amazonaws.com (Resolv::ResolvError)):
[db679c33-cf22-4dc9-9ecf-4ced05a50486]
[db679c33-cf22-4dc9-9ecf-4ced05a50486] app/controllers/api/v1/jobs_controller.rb:531:in `upadte_job'
[db679c33-cf22-4dc9-9ecf-4ced05a50486] app/controllers/api/v1/jobs_controller.rb:83:in `update'
I, [2023-01-22T05:24:52.213130 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486] Processing by ErrorsController#show as HTML
I, [2023-01-22T05:24:52.213361 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Parameters: {"userId"=>"1", "secureCode"=>"****", "job"=>{"mainImage"=>#<ActionDispatch::Http::UploadedFile:0x0000000005a99a98 @tempfile=#<Tempfile:/tmp/RackMultipart20230122-7888-h3q0hr.jpg>, @original_filename="124B68E9-A2E7-4195-9CAD-8046C11AAF5B.jpg", @content_type="image/jpeg", @headers="content-disposition: form-data; name=\"job[mainImage]\"; filename=\"124B68E9-A2E7-4195-9CAD-8046C11AAF5B.jpg\"\r\ncontent-type: image/jpeg\r\n">}, "id"=>"2"}
I, [2023-01-22T05:24:52.214088 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486] no address for dev-profit-beauty.s3.ap-northeast-1.amazonaws.com (Resolv::ResolvError)
D, [2023-01-22T05:24:52.222160 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Rendering layout layouts/application.html.erb
D, [2023-01-22T05:24:52.222370 #7888] DEBUG -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Rendering errors/internal_server_error.html.erb within layouts/application
I, [2023-01-22T05:24:52.224244 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Rendered errors/internal_server_error.html.erb within layouts/application (Duration: 1.7ms | Allocations: 239)
I, [2023-01-22T05:24:52.234582 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486]   Rendered layout layouts/application.html.erb (Duration: 12.3ms | Allocations: 1224)
I, [2023-01-22T05:24:52.234983 #7888]  INFO -- : [db679c33-cf22-4dc9-9ecf-4ced05a50486] Completed 500 Internal Server Error in 22ms (Views: 19.9ms | ActiveRecord: 0.0ms | Allocations: 2517)

ローカルサーバーでは問題なくアップロードできますが、サーバーにデプロイしたらできなくなりました。ログのJob Update (0.9ms) UPDATE jobs SET jobs.main_image = '1728a43022.jpg', のところでDBへのファイル名の登録が成功しているのですがファイルはaws上にアップされていません。その後60秒後くらいにExcon::Error::Socketが発生します。

不思議なことに必ずこのエラーが起きるわけではありません。状況は3種類あります。

  • このエラーが発生し画像がアップされていない。
  • 画像はアップされているがこのエラーが発生しレスポンスが返ってこない。
  • 正常にアップロードされ、レスポンスも返ってくる。

ただし、レスポンスが返る場合でも1分以上かかります(一度だけ瞬時に正しいレスポンスが返る時もありました)。

試したこと

  • aws command-lineツールを使って対象のバケットにサーバーからアップロードしてみた。これはうまくできました。時間も一瞬です。
  • サーバー側で保存(awsのアップロード)が走る前に画像を別の場所にコピーして、サーバまで画像が来ているか確認した。これはアップロードに失敗する時もちゃんとサーバーまでは来ていますね。
  • DNSのエラーの様なのでサーバーからエラーログにあるs3のドメインをdigしてみたらちゃんと引けました。

最後に

何か思い当たることはありますでしょうか?あるいは他に試した方がいいことがあったらアドバイスお願いします。

これ書くのに色々調べてて一点気になったのはCentOS Stream 8な点ですね。バージョンが微妙に異なるのですがほぼ同じ構成で問題なくアップロードできるアプリケーションがあるのですが、そちらはCentOS Linux 8.2.2004なんですよね。同じCentOS8かと思ってあまり考えずに入れたんですけど、調べたら本家より先にパッチの入るOSみたいですね。他のOSをインストールし直して1から構築した方が手っ取り早そうな気もしてきましたが・・・

2023/01/25追加情報

StreamはCentOSの代替えにはならないということなので、AlmaLinux8をインストールしやり直してみましたが改善しませんでした。

検索しているエラー文をno address for s3.ap-northeast-1.amazonaws.com (Resolv::ResolvError)に変えて検索してみたら同じようなエラーを見つけました。

https://gitlab.com/gitlab-org/charts/gitlab/-/issues/3303

ここで試してるようにRailsコンソールを開いて下記を実行すると・・・

Resolv.each_address('dev-profit-beauty.s3.ap-northeast-1.amazonaws.com'){|ip| puts ip }

下記の様にIPがサクッと取れる時もあるけど、60秒くらい待たされて配列のレスポンスが変える時があります。

irb(main):008:0> Resolv.each_address('dev-profit-beauty.s3.ap-northeast-1.amazonaws.com'){|ip| puts ip }
52.219.16.151
52.219.4.63
52.219.137.50
52.219.196.74
52.219.0.243
52.219.136.91
52.219.16.7
52.219.137.6
=> nil
irb(main):009:0> Resolv.each_address('dev-profit-beauty.s3.ap-northeast-1.amazonaws.com'){|ip| puts ip }
=>
[#<Resolv::Hosts:0x0000000003c42e28
  @addr2name={"127.0.0.1"=>["localhost", "localhost.localdomain", "localhost4", "localhost4.localdomain4"]},
  @filename="/etc/hosts",
  @initialized=true,
  @mutex=#<Thread::Mutex:0x0000000003c42d60>,
  @name2addr={"localhost"=>["127.0.0.1"], "localhost.localdomain"=>["127.0.0.1"], "localhost4"=>["127.0.0.1"], "localhost4.localdomain4"=>["127.0.0.1"]}>,
 #<Resolv::DNS:0x0000000003c42ce8
  @config=
   #<Resolv::DNS::Config:0x0000000003c42bf8
    @config_info=nil,
    @initialized=true,
    @mutex=#<Thread::Mutex:0x0000000003c42b80>,
    @nameserver_port=[["210.188.224.10", 53], ["210.188.224.11", 53]],
    @ndots=1,
    @search=[[#<Resolv::DNS::Label::Str app>]],
    @timeouts=nil>,
  @initialized=true,
  @mutex=#<Thread::Mutex:0x0000000003c42c70>>]
irb(main):010:0>

2023/01/26追加情報

追加で試したことを追記します。

carrierwaveのバージョンを下げた

同じSakuraのサーバーからアップロードできている他のアプリと同じバージョンにしてみました。

carrierwave (1.2.3)
fog-aws (3.0.0)
fog-core (2.1.0)

これを動かすのにrubyのダウングレードが必要で2.7.7下げました。

これもダメでした。

URLをパス形式に変更した

@sayuri さんの提案で試してみました。

  config.fog_provider = 'fog/aws'
  config.fog_credentials = {
    provider: 'AWS',
    aws_access_key_id: Rails.application.credentials.dig(:aws, :access_key_id),
    aws_secret_access_key: Rails.application.credentials.dig(:aws, :secret_access_key),
    region: 'ap-northeast-1',
    path_style: true # これを追加
  }
  config.storage = :fog

  if Rails.env.production?
    config.fog_directory = "prod-profit-#{ProFitName.normalize_to('-')}"
  else
    config.fog_directory = "dev-profit-#{ProFitName.normalize_to('-')}"
  end

これもダメでした。

エラー文が下記の様に変わったのでちゃんとパス形式になってると思います。

Excon::Error::Socket (no address for s3.ap-northeast-1.amazonaws.com (Resolv::ResolvError))

sdkでアップロードしてみた

下記の純正SDKです。
https://docs.aws.amazon.com/sdk-for-ruby/v3/api/Aws/S3/Client.html

テストなので静的なローカルファイルをアップロードしてみました。

  def aws_s3(name)
    bucket_name = "prod-profit-#{ProFitName.normalize_to('-')}"
    key = "test/#{name}.jpg"
    region = 'ap-northeast-1'

    s3_client = Aws::S3::Client.new(
      region: region,
      access_key_id: Rails.application.credentials.dig(:aws, :access_key_id),
      secret_access_key: Rails.application.credentials.dig(:aws, :secret_access_key)
    )
    file = File.open('./data/images/main.jpg')
    s3_client.put_object(
      acl: 'public-read',
      bucket: bucket_name,
      key: key,
      body: file,
      content_type: MIME::Types.type_for(file.path)[0].to_s
    )
  end

10回ほどアップロードしてみましたが、全部瞬時にアップロードできました。SDKだと問題ない様です。

2 件の回答 2

1

何もわかっていませんが…

S3のURLは次の2種類があります。

  • 仮想ホスティング形式
    https://bucket-name.s3.region-code.amazonaws.com/key-name
  • パス形式
    https://s3.region-code.amazonaws.com/bucket-name/key-name

今回dev-profit-beauty.s3.ap-northeast-1.amazonaws.comということで仮想ホスティング形式を使われているようです。仮想ホスティング形式は命名規則からわかる通り、s3.region-code.amazonaws.comゾーンにS3バケット名が一覧される形になっていますが、言われるまでもなくS3バケットは膨大に存在するためDNSとして負荷が高いです。

仮想ホスティング形式でDNSエラーになるのであれば、より負荷の低いパス形式に変更することで改善されるかもしれません。

1

一応アップロードできる様になったので自己解答です。

https://stackoverflow.com/questions/25029663/carrierwave-exconerrorssocketerror

こちらの質問がきっかけですが曰く

This is possibly because of an implementation with fog, perhaps try switching your gem to carrierwave-aws and see if it fixes your problems :)

https://github.com/sorentwo/carrierwave-aws

fogの問題だからcarrierwave-awsに変えれば動くんじゃないか?って話ですね。変えた結果うまくいきました。

ただ、fogをいろんなバージョンで試しましたが動かなかったので、もっと大騒ぎになってますよね。サーバーの設定との相性なのかもしれません。ただ、さくらのVPSでfog使ってる人も割といると思うので、エラー文で引っかかっても良さそうな気がしました。

原因を特定できてないのでちょっと釈然としませんが案件の締め切りが近いので先に進みます。

引き続き情報ありましたら教えていただけると嬉しいです。

2
  • ちょっと細かく調べる時間がないのでコメント残しておきますが、FirewallでDNSの問い合わせのランダムで選ばれるポートが閉じてるせいじゃないかと思いました。その範囲がサーバーのFirewallとResolvの設定が合ってないからなのかも。だから、空いてるポートが選ばれた時はアップされるけどダメな時はダメとか?ただ、時間がかかってアップされる時もあるのが説明つかないかな。余裕ができたら調べてみます。 1月28日 9:12
  • github.com/ruby/ruby/blob/… ここですね。さくらのパケットフィルタを使ってるのですがそれを外して試してみたいです。ただ、わずかな時間でも外すのは怖いので、firewalldで自前の設定を用意してやらないといけないのでちょっと時間がないです。あと、さくらのパケットフィルタ使っていてアップロードできるサーバーもあるので違うかなあ。 1月28日 9:16

この質問に回答するには、ログインする必要があります。

求めていた回答ではありませんか? のタグが付いた他の質問を参照する。