Ruby の Enumerator を dis る

バックエンド

こんにちは、masm11 です。

Ruby には Enumerator というクラスがあります。

Rails で、

self.response_body = Enumerator.new { ... }

とすると、response body をその場で生成するのでなく、 あとで Enumerator のブロックが呼び出され、そこで生成させてくれます。

便利そうですね。………そうですか？

今回は、そんな (Rails +) Enumerator を dis りたいと思います。

サンプルコード

今回使用する test_controller.rb です。

class TestController < ApplicationController
  def index
    headers['Cache-Control'] ||= 'no-cache'
    headers['Content-Type'] = 'application/octet-stream'
    headers['Content-Disposition'] = 'attachment; filename="test.csv"'
    headers['Last-Modified'] = Time.zone.now.httpdate
    response.status = 200
    self.response_body = generate_csv
  end

  def generate_csv
    Enumerator.new do |y|
      100.times do |i|
        sleep 0.05         # 時間のかかる処理
        y << "test#{i}\n"
      end
    end
  end
end

http://localhost:3000/test 等にアクセスすると、 test.csv がゆっくりダウンロードされます。

ファイル名は test.csv 固定です。

generate_csv は Enumerator を返します。 この Enumerator は、ブロックの中で時間のかかる処理をやりつつ、 CSV を生成しつつ、y << でクライアントに送信する想定です。

curl でアクセスしてみましょう。

luna:chunked % curl --raw http://localhost:3000/test --verbose
*   Trying 127.0.0.1:3000...
* Connected to localhost (127.0.0.1) port 3000 (#0)
> GET /test HTTP/1.1
> Host: localhost:3000
> User-Agent: curl/7.85.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Date: Sat, 01 Oct 2022 15:25:47 GMT
< Connection: close
< X-Frame-Options: SAMEORIGIN
< X-XSS-Protection: 0
< X-Content-Type-Options: nosniff
< X-Download-Options: noopen
< X-Permitted-Cross-Domain-Policies: none
< Referrer-Policy: strict-origin-when-cross-origin
< Cache-Control: no-cache
< Content-Type: application/octet-stream
< Content-Disposition: attachment; filename="test.csv"
< Last-Modified: Sat, 01 Oct 2022 15:25:47 GMT
< X-Request-Id: 67ffe14c-a2e1-4ede-9ac8-ca8c1747d5f6
< X-Runtime: 0.072237
< Server-Timing: start_processing.action_controller;dur=0.20, process_action.action_controller;dur=0.67
< Transfer-Encoding: chunked
< 
6
test0

6
test1

6
test2

6
test3

6
test4

6
test5
...(中略)
7
test98

7
test99

0

* Closing connection 0
luna:chunked %

Transfer-Encoding: chunked が付いて、 chunk-size と chunk-data が交互に来て、 最後は 0 バイトの chunk ですね。 この受信データが、全体がまとめて表示されるのでなく、 受信できたものから表示されています。

いい感じのコードになっていると思います。

今回使用したのは、

  • Rails 7.0.4
  • Unicorn 6.1.0

です。unicorn/config.rb は以下の通りです。

# :tcp_nopush This prevents partial TCP frames from being sent out
# :tcp_nodelay Disables Nagle’s algorithm on TCP sockets if true.
listen 3000, tcp_nopush: false, tcp_nodelay: true

なお、最近の Rack では、

    headers['Last-Modified'] = Time.zone.now.httpdate

の行が必要だそうです。これがないと、chunked にはなるものの、 body 全体がまとめて送られてしまいました。 このページに感謝です。stackoverflow のコードにも書いてありますがスルーしてしまってました。

時間計測

では、処理にかかっている時間を計測してみましょう。

  def index
    b = Time.zone.now
    headers['Cache-Control'] ||= 'no-cache'
    headers['Content-Type'] = 'application/octet-stream'
    headers['Content-Disposition'] = 'attachment; filename="test.csv"'
    headers['Last-Modified'] = Time.zone.now.httpdate
    response.status = 200
    self.response_body = generate_csv
    e = Time.zone.now
    Rails.logger.info "duration=#{e - b}"
  end

メソッドの最初と最後で時刻を取得して、かかった時間をログに出力しています。 ログには以下のように出力されていました。

duration=0.000133403

あれれ。0.1ミリ秒程度ですか？？ 5秒はかかっているはずですが。

それもそのはず、Enumerator のブロックは後で実行されるのです。 generate_csv メソッドでは、ブロックを引数にして Enumerator.new しているだけで、ブロックは実行していないのです。

そりゃ速いですね。

でも、だからと言って、サーバで処理がかかってないわけではありません。 見えてないだけで、確実に5秒はかかっているのです。

サーバが処理であっぷあっぷしてても、 これでは改修対象にすべき箇所一覧から外れてしまうかもしれません。

例外捕捉

raise を追加しました。 CSV を途中まで生成したところで、エラーが発生してしまった想定です。

  def generate_csv
    Enumerator.new do |y|
      100.times do |i|
        sleep 0.05         # 時間のかかる処理
        y << "test#{i}\n"
        raise 'test exception !!' if i == 90
      end
    end
  end

curl でアクセスしてみます。

7
test89

7
test90

HTTP/1.1 500 Internal Server Error

* Illegal or missing hexadecimal sequence in chunked-encoding
* Closing connection 0
curl: (56) Illegal or missing hexadecimal sequence in chunked-encoding
luna:chunked %

chunk-size があるはずの場所に HTTP/1.1 500 Internal Server Error が 出力されてしまいました。curl はこれを処理できていません。まぁそりゃそうでしょう。

ブラウザからアクセスしてみると、ファイルをダウンロードしますが、 「失敗しました」表示となりました。文字がちっちゃくて、 成功の場合とよく似ています。

ユーザはこれにちゃんと気づいてくれるのでしょうか？ ユーザが気づかないといけない、というのは最終手段ではないでしょうか？ CSV のダウンロードごときで頼って良いものではないと思います。 気づかないといけないのなら、もっと目立つように表示するべきです。

ダウンロードする内容を代わりに画面に表示するように変更してみます。

  def index
    headers['Cache-Control'] ||= 'no-cache'
    # headers['Content-Type'] = 'application/octet-stream'
    # headers['Content-Disposition'] = 'attachment; filename="test.csv"'
    headers['Content-Type'] = 'text/plain'
    headers['Last-Modified'] = Time.zone.now.httpdate
    response.status = 200
    self.response_body = generate_csv
  end

画面に表示はされましたが、もちろん test90 までで、 例外処理ができていません。 通常、development 環境では、例外が発生すると、backtrace などが画面に表示されますよね？ あれが表示されません。

また、ステータスが 200 と表示されていますね。 これが JavaScript からアクセスする API だとすると、 この中途半端なデータのまま、 エラーに気づかれることなく処理が進んでしまうのでしょうか？

処理の流れ

先程の例外が発生した時、ログには以下のように出力されていました。

127.0.0.1 - - [02/Oct/2022:00:47:21 +0900] "GET /test HTTP/1.1" 200 - 4.5946
E, [2022-10-02T00:47:21.370387 #45803] ERROR -- : app error: test exception !! (RuntimeError)
E, [2022-10-02T00:47:21.370523 #45803] ERROR -- : /home/masm/src/chunked/app/controllers/test_controller.rb:17:in `block (2 levels) in generate_csv'
E, [2022-10-02T00:47:21.370546 #45803] ERROR -- : /home/masm/src/chunked/app/controllers/test_controller.rb:14:in `times'
E, [2022-10-02T00:47:21.370565 #45803] ERROR -- : /home/masm/src/chunked/app/controllers/test_controller.rb:14:in `block in generate_csv'
E, [2022-10-02T00:47:21.370585 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/actionpack-7.0.4/lib/action_dispatch/http/response.rb:145:in `each'
E, [2022-10-02T00:47:21.370605 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/actionpack-7.0.4/lib/action_dispatch/http/response.rb:145:in `each'
E, [2022-10-02T00:47:21.370624 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/actionpack-7.0.4/lib/action_dispatch/http/response.rb:145:in `each_chunk'
E, [2022-10-02T00:47:21.370644 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/actionpack-7.0.4/lib/action_dispatch/http/response.rb:127:in `each'
E, [2022-10-02T00:47:21.370664 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/actionpack-7.0.4/lib/action_dispatch/http/response.rb:75:in `each'
E, [2022-10-02T00:47:21.370682 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/actionpack-7.0.4/lib/action_dispatch/http/response.rb:480:in `each'
E, [2022-10-02T00:47:21.370702 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.370748 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.370778 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.370938 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.371022 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.371048 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.371069 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/lint.rb:754:in `each'
E, [2022-10-02T00:47:21.371088 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/body_proxy.rb:41:in `method_missing'
E, [2022-10-02T00:47:21.371107 #45803] ERROR -- : /home/masm/src/chunked/vendor/bundle/ruby/3.0.0/gems/rack-2.2.4/lib/rack/chunked.rb:38:in `each'
...

test_controller.rb:17 の上が test_controller.rb:14 でその上が test_controller.rb:14。 その上は………… actionpack? そんなところから呼ばれるわけがないですね。

処理の流れがわかりにくいです。 一番上に GET /test とあるので、これを手がかりに処理の流れを思い出し (知らなければコードを見て勉強し)、 …なんてことをする必要があります。

まとめ

これだけのデメリットがある機能を使う理由って何ですか？

「流行だから」？

「ダウンロード開始までの時間が短くできる」？

やめましょうよ…

頭痛の種を増やしてまでやることとは私には思えません。

所感

以上、最近何度か私から見て最悪だと思ったので dis りました。

私はエンジニア歴40年近い老害ですが、 「最近の若者」は、これでも問題なくやっていけるんですかね？ よく解りません…