はじめにまとめ

AWS SDK for Rubyでタグが大量に付与されているリソースを大量に取得する処理は、タグが無いリソースに比べて大幅に時間がかかることがある（今回はEBSとEBSスナップショットで確認）
原因はSDK内で、AWSのAPIレスポンスのXMLをRubyのオブジェクトにパースするときの変換処理

背景

AWS SDK for Rubyである程度数の多いリソースの取得に非常に時間がかかったことがあり、原因を追求するとタグが大量に付与されたリソースの場合にそのような事象が発生する場合があることが分かったので、検証したメモ。

前提（検証環境）

クライアント
- 東京リージョンのLightStail
- Ubuntu 18.04
- Ruby 2.6.3
- AWS SDK for Ruby 関連Versionは以下

    aws-sdk-core (3.89.1)
      aws-eventstream (~> 1.0, >= 1.0.2)
      aws-partitions (~> 1, >= 1.239.0)
      aws-sigv4 (~> 1.1)
      jmespath (~> 1.0)
    aws-sdk-ec2 (1.137.0)
      aws-sdk-core (~> 3, >= 3.71.0)
      aws-sigv4 (~> 1.1)
    aws-sigv4 (1.1.0)
      aws-eventstream (~> 1.0, >= 1.0.2)

速度測定検証

事前準備

東京リージョンにEBSを300個ずつ、タグを20個/0個付与したそれぞれのケースを作成し、以下のように describe_volumes が完了するまでの時間を計測する ¹

require 'aws-sdk-ec2'

start_time = Time.now
ec2_client = Aws::EC2::Client.new(region: "ap-northeast-1")
ec2_client.describe_volumes
p "時間 #{Time.now - start_time}s"

結果

結果は以下の通り。リソースの絶対数はそれほどパフォーマンスに影響はしないが、タグの数によって大幅にパフォーマンスに影響が出る。

なぜ？AWS SDK for Ruby の処理の内容を覗いてみる

さて、何が原因で上記のような結果になるのか確認するため、ライブラリの処理の中でどこの部分で時間がかかっているのか確認してみました。

AWS SDK for Ruby の処理の流れ概要

Aws::EC2::Client.describe_volumes が実行されると以下の流れで処理が流れます。

Aws::EC2::Client.describe_volumes ->
  Seahorse::Client::Request.send_request ->
    @handlers.to_stack.call(@context)->

ここの @handlers.to_stack を展開すると呼び出しているのは以下のクラスですが、

Seahorse::Client::Plugins::ResponseTarget::Handler.call

このオブジェクトの中身をさらに展開すると、以下のように Seahorse::Client::Handler を継承したクラスが @handler 変数に格納され、それらが入れ子になって管理されていると分かります。
つまり、 @handler.call メソッドが上から順番に呼び出され、 call メソッドは一番下のオブジェクトから順番に実行完了していき、その実行結果が一つ上のオブジェクトの call メソッドで順繰りに使用されていきます。

<Seahorse::Client::Plugins::ResponseTarget::Handler @handler=
<Aws::Plugins::ResponsePaging::Handler @handler=
<Aws::Plugins::ParamConverter::Handler @handler=
<Aws::Plugins::IdempotencyToken::Handler @handler=
<Aws::Plugins::JsonvalueConverter::Handler @handler=
<Seahorse::Client::Plugins::RaiseResponseErrors::Handler @handler=
<Aws::Plugins::ParamValidator::Handler @handler=
<Seahorse::Client::Plugins::Endpoint::Handler @handler=
<Aws::Plugins::EndpointDiscovery::Handler @handler=
<Aws::Plugins::EndpointPattern::Handler @handler=
<Aws::Plugins::UserAgent::Handler @handler=
<Aws::Plugins::Protocols::EC2::Handler @handler=
<Aws::Plugins::RetryErrors::Handler @handler=
<Aws::Plugins::HelpfulSocketErrors::Handler @handler=
<Aws::Plugins::TransferEncoding::Handler @handler=
<Aws::Plugins::SignatureV4::Handler @handler=
<Aws::Xml::ErrorHandler @handler=
<Seahorse::Client::Plugins::ContentLength::Handler @handler=
<Seahorse::Client::NetHttp::Handler @handler=nil>>>>>>>>>>>>>>>>>

例えば、 Seahorse::Client::Plugins::RaiseResponseErrors::Handle の中身を見てみると、以下のようになっていますが、 Aws::Plugins::ParamValidator::Handler の実行結果を用いて処理を行い、それを上のオブジェクト（ Aws::Plugins::JsonvalueConverter::Handler ）に渡します。

raise_response_errors.rb

class Handler < Client::Handler
  def call(context)
    response = @handler.call(context)
    raise response.error if response.error
    response
  end
end

どこの処理で時間がかかっているか？

上記のHandlerの中でどのオブジェクトで時間がかかっているかをPrintデバッグを仕込んで確認してみました。結果は、 Aws::Plugins::Protocols::EC2::Handler で時間がかかっていると分かりました。
さらに、この中でどこで時間がかかっているか掘っていくと、以下★の部分でした。
ここの引数の xml はAWS APIのレスポンスのXMLが格納されているようです。
この★の処理は REXML::StreamListener が include されているこのクラス内でXMLが tag_start や tag_end にしたがって、SDKのレスポンスの構造（Rubyのオブジェクト）にパースされていきます。

rexml.rb

def parse(xml)
  begin
    source = REXML::Source.new(xml)
    REXML::Parsers::StreamParser.new(source, self).parse # ★
  rescue REXML::ParseException => error
    @stack.error(error.message)
  end
end

この部分の処理が完了すると、このクラスの @stack インスタンス変数にパース結果が格納され、 @stack.result を確認するとその結果が確認できます（つまり出来上がった struct Aws::EC2::Types::Volume オブジェクトが確認できます）。

さて、タグが付与されている場合は、以下のような構造のオブジェクトが出来上がるわけですが、タグは数が不定で、それぞれが1つの構造体オブジェクトになっています。このあたりの変換処理に数が多いと、時間がかかるということのようです。

[#<struct Aws::EC2::Types::Volume
  attachments=[],
  availability_zone="ap-northeast-1a",
  create_time=2020-02-02 15:36:41 UTC,
  encrypted=false,
  kms_key_id=nil,
  outpost_arn=nil,
  size=1,
  snapshot_id="",
  state="available",
  volume_id="vol-xxxxxxxx",
  iops=100,
  tags=
   [#<struct Aws::EC2::Types::Tag key="TEST2", value="test">,
    #<struct Aws::EC2::Types::Tag key="TEST3", value="test">,
    #<struct Aws::EC2::Types::Tag key="TEST1", value="test">],
  volume_type="gp2",
  fast_restored=nil>,

おわりに/その他気になること等

さて、AWS SDK for Rubyでタグが大量にあるリソースの取得処理は非常に時間がかかることがあること、その理由はSDK内の変換処理であることが分かりました。
実は、同じ環境でAWS CLIで実行すると、タグが大量付与されている場合でも1秒程度で取得が完了します。AWS CLIも内部的にはXMLで取得したものをJSONに変換していると思うのですが、プログラム上で扱うオブジェクトに変換するわけではないから、これほど高速に処理が完了するのでしょうか？ 🤔
また、Ruby以外のSDKで実行したときにどのような結果になるかも気になるところです。

AWS SDK for Ruby には Client 的なクラスではなく、 Aws::Resource 的なクラスも用意されているが、パフォーマンス的にはどちらも同じであった。というか後者のメソッドは前者のメソッドを内部的に呼んでいるようだったので、基本的には大きくパフォーマンスが良いみたいなことは無いように思う。参考: AWS SDK for Ruby V3のAws::S3::ClientとAws::S3::Resourceの違いに正面から向き合う - Qiita https://qiita.com/Kta-M/items/c1245ae6bf12f686e827 ↩

【AWS SDK for Ruby】タグが大量にあるリソースの取得処理は非常に時間がかかることがある話