Skip to content

ngx_mruby v2.7.6

Latest

Choose a tag to compare

@matsumotory matsumotory released this 12 Nov 06:53
a8ef5ec

Behavior changes: read before upgrading

Output from an HTTP log handler

Security advisory: GHSA-r6wq-r8rh-6rc3.

  • Before: a log handler could append the text of Nginx.rputs or Nginx.echo after the response body.
  • Now: the calls convert their argument as usual and write no bytes. The script continues after a successful call.
  • Why it changed:
    • The defect: the shared handler finalizer could flush an output chain while nginx was freeing the request.
    • Why the old behavior could not be kept: extra bytes could be read as another response on the connection.
    • What the documentation promised: the log directives run at the end of request processing for logging.
  • Affected: HTTP file and inline log handlers, including calls from their helper methods.
  • What to do: log messages with Nginx.log. Write response bodies in a content handler.
  • Not changed by this release: argument conversion errors and output from ordinary content handlers.

Output of an mruby content handler or body filter in an SSI subrequest

Security advisory: GHSA-79vp-37cx-547v.

  • Before: the output of a subrequest's mruby content handler (Nginx.rputs, Nginx.echo, Nginx.send_header) or mruby body filter could end the parent response at the subrequest's output. Over HTTP/1.1 the chunked filter emitted the response-terminator chunk mid-stream, so a length-delimited reader saw two responses where there was one; over HTTP/1.0 or when the parent used Content-Length, the parent response was cut short at the subrequest's bytes and the connection closed; and a static file read through the mruby body filter of a subrequest held the main request until send_timeout.
  • Now: a subrequest marks its last buffer with last_in_chain (and sync for an empty buffer), as nginx's own handlers do. The parent response goes on until the main request's own last buffer. The static file case no longer stops the main request.
  • Why it changed:
    • The defect: ngx_mruby's response finalization set last_buf on every chain, which is correct only for the main request. Nginx's chunked filter, Content-Length framing and body-end detection act on last_buf.
    • Why the old behavior could not be kept: a subrequest's last_buf ended the parent response early (a split chunked response, a truncated Content-Length or HTTP/1.0 response, read as another response on a shared connection), and the body-filter path held the main request until send_timeout closed the connection.
    • What the documentation promised: Nginx.rputs and Nginx::Filter in 2.7.5 said nothing about how a subrequest's output interacts with the parent response.
  • Affected: locations whose mruby content handler calls Nginx.rputs, Nginx.echo or Nginx.send_header, or whose mruby body filter produces a body, when another location includes them with SSI <!--# include virtual=... --> or by another form of subrequest.
  • What to do: nothing. The subrequest output is framed correctly as part of the parent response.

A value of mruby_set or Nginx::Var whose to_s is missing, raises or does not return a String no longer ends the worker (#768)

  • Before: ngx_mruby converted a value that is not a String with its to_s and used the result as a String without checking its type. For the value that the code of mruby_set or mruby_set_code returned, it called to_s where mruby does not raise an exception of to_s but returns it. A to_s that returns something other than a String ended the worker process with a segmentation fault, before and after Nginx::Async.sleep. A value without to_s (a BasicObject) or whose to_s raises was read as a String although it was the exception, and the exception stayed in the mruby state of the worker: the request got 500 or no response, and the next mruby handler that the worker ran, in the same request or a later one, could fail with that exception and answer 500. The setter of Nginx::Var (Nginx::Var#<name>=) and Nginx::Var#set ended the worker process when they got a value, or Nginx::Var#set a name, whose to_s returns something other than a String. A to_s that is missing or raises made these two methods raise its exception, as it does now.
  • Now: a value of mruby_set and mruby_set_code that cannot be converted counts as an exception of the code. Before the code waits in Nginx::Async.sleep, ngx_mruby logs the exception, the variable is set to an empty string, and the request goes on. After the sleep, ngx_mruby logs the exception and the request gets 500. The exception is TypeError (... cannot be converted to String) for a to_s that returns something other than a String, NoMethodError for a value without to_s, and the exception of to_s otherwise. The setter of Nginx::Var and Nginx::Var#set raise TypeError when to_s returns something other than a String, and the variable keeps its value. No exception stays for a later handler.
  • Why it changed:
    • The defect: ngx_mruby read the result of to_s as a String without checking its type, and at the end of an mruby_set handler it called to_s outside Ruby code, where mruby returns the exception of a to_s that is missing or raises instead of raising it. The review of #735, which fixed the same conversion on next, found it.
    • Why the old behavior could not be kept: the old behavior ended the worker process, with the other requests of that worker, or made a later handler fail with an exception that was not its own. The variable needs a String, and such a value gives none, so the fix handles the value as the exception that ngx_mruby already handles for this code.
    • What the documentation promised: mruby_set and mruby_set_code and Nginx::Var in 2.7.5 said nothing about values that are not Strings. The documentation of mruby_set described how the variable and the request go on after an exception of the code, which this release applies to these values.
  • Affected: mruby_set and mruby_set_code whose code returns a value whose to_s is missing, raises or does not return a String; calls of the setter of Nginx::Var and of Nginx::Var#set with a value, or a name, whose to_s does not return a String.
  • What to do: return a String, nil or a value whose to_s returns a String from the code of mruby_set, and pass such values to Nginx::Var. Code that returned or passed the other values did not work on 2.7.5 either: it ended the worker or made a handler fail.
  • Not changed by this release: a String, nil, an Integer and any other value whose to_s returns a String give the variable the same value as before, and a to_s that is missing or raises in a call of Nginx::Var raises the same exception as before.

Nginx.rputs, Nginx.echo, Nginx.redirect and Nginx::Filter#body= raise TypeError when to_s of the argument does not return a String (#775)

  • Before: Nginx.rputs, Nginx.echo, Nginx.redirect, Nginx::Filter#body= and Nginx::Filter#output converted an argument that is not a String with its to_s and used the result as a String without checking its type. A to_s that returns an Integer ended the worker process with a segmentation fault, with the other requests of that worker. A to_s that returns another object that is not a String made the method read the memory of that object as a String. A to_s that is missing or raises made these methods raise its exception, as it does now.
  • Now: these methods raise TypeError (... cannot be converted to String) when to_s of the argument returns something other than a String, as the setter of Nginx::Var does since #768. The exception ends the handler like any other exception of the script: a rescue in the script catches it, and otherwise ngx_mruby logs it and the request gets 500. Nothing is written, no redirect is made, and the body of the filter stays as it was.
  • Why it changed:
    • The defect: these methods read the result of to_s as a String without checking its type. #768 fixed the same reading for mruby_set and Nginx::Var, and the tests of that change found it in these methods.
    • Why the old behavior could not be kept: the old behavior ended the worker process, with the other requests of that worker, or read memory that was not a String. These methods need a String, and such a value gives none, so they raise the exception that the setter of Nginx::Var raises for the same value.
    • What the documentation promised: Nginx.rputs in 2.7.5 said that an argument that is not a String is converted with to_s, and said nothing about a to_s that does not return a String. The documentation of Nginx.echo, Nginx.redirect and Nginx::Filter#body= said nothing about arguments that are not Strings.
  • Affected: calls of Nginx.rputs, Nginx.echo, Nginx.redirect, Nginx::Filter#body= and Nginx::Filter#output with an argument whose to_s does not return a String.
  • What to do: pass a String, nil or a value whose to_s returns a String to these methods. Code that passed other values did not work on 2.7.5 either: it ended the worker or read memory that was not a String.
  • Not changed by this release: a String, nil and any other value whose to_s returns a String give the same output as before, and a to_s that is missing or raises makes these methods raise the same exception as before.

An mruby body filter, with or without an mruby header filter, runs once on a proxied response that needs more than one write after an earlier Nginx.rputs (#786)

  • Before: in a location with mruby_output_body_filter (or mruby_output_body_filter_code), with or without mruby_output_header_filter (or mruby_output_header_filter_code), when an earlier handler of the request had written with Nginx.rputs and let the request go on (for example a rewrite handler that returns Nginx::DECLINED), the response came from proxy_pass, and nginx could not send it in one write (for example with sendfile_max_chunk or limit_rate), the code of the body filter ran twice: once on the body of the upstream response, and once more on an empty body when the upstream response ended. The client got the body of the first run with its Content-Length, but $sent_http_content_length gave 0 in log_format.
  • Now: the code of the body filter runs once for such a response, and $sent_http_content_length gives the length of the body that the client got. A response that nginx sends in one write is not changed by this release: there the code of the body filter still runs a second time on an empty body.
  • Why it changed:
    • The defect: when an earlier handler's Nginx.rputs output is still in the state of the request after the body filter has run, ngx_mruby drops that state, so that a later handler does not send the output after the response. The dropped state also held the flag that makes the body filter pass the rest of the same response on to the next filter, and the body filter then waited for a new body. A response from a static file stopped after its first write until send_timeout closed the connection (see "Fixes"). A proxied response went on only because the end of the upstream response made the body filter run once more, on an empty body. The review of #785 found it.
    • Why the old behavior could not be kept: the stop and the second run have the same cause, and the fix gives the request a new state with that flag whenever nginx still holds a part of the response. Keeping the second run for proxied responses would mean leaving the flag out for them alone, and the code of their body filter would still run on an empty body after it has made the response. The new behavior is the one that the same location already has without the earlier Nginx.rputs: there the code of the body filter runs once and $sent_http_content_length gives the length of the body, whether nginx sends the response in one write or in more.
    • What the documentation promised: mruby_output_body_filter and Nginx::Filter in 2.7.5 said nothing about how many times the code of a body filter runs for one response.
  • Affected: the code of mruby_output_body_filter and mruby_output_body_filter_code that counts its runs or acts on an empty body, and log_format with $sent_http_content_length, for responses from proxy_pass (or another upstream) after an earlier Nginx.rputs in a location with an mruby body filter, with or without an mruby header filter, which nginx sends in more than one write.
  • What to do: nothing for a body filter that only transforms the body, because the body that the client gets is the same. A body filter whose code relied on its second run on an empty body, for example to count responses or to act at the end of one, has to do that in the first run, which now is the only one for such a response.

更新前に確認する挙動の変更

HTTP のログハンドラからの出力

アドバイザリ:GHSA-r6wq-r8rh-6rc3

  • 変更前:ログハンドラが Nginx.rputs や Nginx.echo に渡した文字列が、応答本文の後に送信されることがありました。
  • 変更後:両メソッドは従来どおり引数を変換し、応答には何も書き込みません。呼び出しに成功するとスクリプトは次の処理に進みます。
  • 変更の理由:
    • 不具合:共通のハンドラ終了処理が、nginx がリクエストを解放する段階で出力チェーンを送信することがありました。
    • 以前の挙動を維持できない理由:同じ接続で余分なバイトが次の応答として読まれることがありました。
    • 文書が示していた挙動:ログディレクティブは、リクエスト処理の最後にログを記録するために実行されます。
  • 影響の範囲:ファイル形式とインライン形式の HTTP ログハンドラ、およびそこから呼ぶメソッド内での出力です。
  • 必要な対応:ログの記録には Nginx.log を使い、応答本文はコンテンツハンドラで書き込んでください。
  • このリリースで変わらない挙動:引数の変換時に起きる例外と、通常のコンテンツハンドラからの出力です。

SSIサブリクエストでのmrubyのcontentハンドラやボディフィルタの出力

アドバイザリ:GHSA-79vp-37cx-547v

  • 変更前:サブリクエストでmrubyのcontentハンドラ(Nginx.rputs、Nginx.echo、Nginx.send_header)やmrubyのボディフィルタが出力する内容が、親リクエストの応答をサブリクエストの出力で終わらせることがありました。HTTP/1.1では、chunkedフィルタが応答の終端を示す0チャンクを応答の途中で出してしまい、長さで応答を区切って読むリーダーは1つの応答を2つとして読んでいました。HTTP/1.0のときや、親がContent-Lengthを使うときは、親の応答がサブリクエストのバイトで途中で切れ、接続が閉じました。mrubyのボディフィルタを持つサブリクエストが静的ファイルを読むときは、親リクエストがsend_timeoutまで止まりました。
  • 変更後:サブリクエストは、nginx自身のハンドラと同じに、最後のバッファをlast_in_chainで(空のバッファではsyncも)閉じます。親の応答は、親リクエスト自身の最後のバッファで終わります。静的ファイルの経路でも、親リクエストは止まりません。
  • 変更の理由:
    • 不具合:ngx_mrubyの応答の確定処理は、どのチェーンでもlast_bufを立てていました。last_bufは親リクエストでのみ正しく、サブリクエストでは誤りです。nginxのchunkedフィルタ、Content-Lengthのフレーミング、ボディ終端の検出は、last_bufで動きます。
    • 前の挙動を残せなかった理由:サブリクエストのlast_bufが親の応答を早く終わらせていました(chunkedの分割、Content-LengthやHTTP/1.0の応答の途中での切断で、共有している接続では別の応答として読まれます)。ボディフィルタの経路では、親リクエストがsend_timeoutが切れて接続が閉じるまで止まっていました。
    • ドキュメントが示していた挙動:2.7.5のNginx.rputsとNginx::Filterは、サブリクエストの出力が親の応答とどう連動するかについて、何も書いていませんでした。
  • 影響の範囲:mrubyのcontentハンドラがNginx.rputs、Nginx.echo、Nginx.send_headerを呼ぶか、mrubyのボディフィルタが本体を作るlocationで、別のlocationがSSIの<!--# include virtual=... -->やほかのサブリクエストで取り込む構成です。
  • 必要な対応:ありません。サブリクエストの出力は、親の応答の一部として正しく並ぶようになりました。

to_sが無いか、例外を出すか、String以外を返す値をmruby_setやNginx::Varに渡しても、ワーカーが終わらなくなります(#768)

  • 変更前:ngx_mrubyは、Stringでない値をto_sで変換し、その結果を型を確かめずにStringとして使っていました。mruby_setかmruby_set_codeのコードが返した値については、mrubyがto_sの例外を出さずに返す場所でto_sを呼んでいました。to_sがString以外を返すと、Nginx::Async.sleepの前でも後でも、ワーカープロセスがセグメンテーション違反で終わりました。BasicObjectのようにto_sの無い値と、to_sが例外を出す値では、ngx_mrubyは例外のオブジェクトをStringとして読み、例外はワーカーのmrb_stateに残りました。そのリクエストは500になるか応答が無く、ワーカーが次に動かすmrubyのハンドラは、同じリクエストでも後のリクエストでも、その例外で失敗して500を返すことがありました。Nginx::VarのセッターであるNginx::Var#<name>=と、Nginx::Var#setは、to_sがString以外を返す値を受け取ると、ワーカープロセスを終わらせました。Nginx::Var#setに名前として同じ値を渡した場合も同じでした。to_sが無いか例外を出す場合は、この2つのメソッドはその例外を出していました。この挙動は変わりません。
  • 変更後:mruby_setとmruby_set_codeの値を変換できないとき、ngx_mrubyはコードが例外を出した場合と同じに扱います。コードがNginx::Async.sleepで待つ前なら、ngx_mrubyは例外をログに書き、変数を空の文字列にして、リクエストを続けます。sleepの後なら、ngx_mrubyは例外をログに書き、リクエストは500になります。to_sがString以外を返すとき、ログに書く例外はTypeErrorで、メッセージは... cannot be converted to Stringです。to_sが無いときはNoMethodErrorを書き、to_sが例外を出すときはその例外を書きます。Nginx::VarのセッターとNginx::Var#setは、to_sがString以外を返すとTypeErrorを出し、変数の値を変えません。後のハンドラに例外は残りません。
  • 変更の理由:
    • 不具合:ngx_mrubyはto_sの結果を、型を確かめずにStringとして読んでいました。さらにmruby_setのハンドラの終わりでは、Rubyのコードの外でto_sを呼んでいました。そこでは、to_sが無いか例外を出しても、mrubyは例外を出さずに例外のオブジェクトを返します。同じ変換をnextで直した#735のレビューで、この不具合が見つかりました。
    • 前の挙動を残せなかった理由:前の挙動では、ワーカープロセスが同じワーカーのほかのリクエストと一緒に終わるか、後のハンドラが自分のものでない例外で失敗しました。変数にはStringが要り、このような値からはStringを作れません。そこで、このコードの例外としてngx_mrubyが既に扱っている方法で、この値を扱うことにしました。
    • ドキュメントが示していた挙動:2.7.5のmruby_set and mruby_set_codeとNginx::Varは、Stringでない値について何も書いていませんでした。mruby_setの説明は、コードが例外を出した後に変数とリクエストがどうなるかを書いていました。このリリースは、その扱いをこれらの値に当てます。
  • 影響の範囲:to_sが無いか、例外を出すか、String以外を返す値を返すコードを持つmruby_setとmruby_set_codeです。to_sがString以外を返す値か名前を、Nginx::VarのセッターやNginx::Var#setに渡す呼び出しも含みます。
  • 必要な対応:mruby_setのコードからは、String、nil、to_sがStringを返す値のどれかを返してください。Nginx::Varにも同じ値を渡してください。ほかの値を返すか渡すコードは、2.7.5でも動いていませんでした。ワーカーが終わるか、ハンドラが失敗していました。
  • このリリースで変わらない挙動:String、nil、Integer、to_sがStringを返すほかの値から変数に入る値は、前と同じです。Nginx::Varの呼び出しでto_sが無いか例外を出したときに出る例外も、前と同じです。

引数のto_sがString以外を返すと、Nginx.rputs、Nginx.echo、Nginx.redirect、Nginx::Filter#body=がTypeErrorを出します(#775)

  • 変更前:Nginx.rputs、Nginx.echo、Nginx.redirect、Nginx::Filter#body=、Nginx::Filter#outputは、Stringでない引数をto_sで変換していました。その結果を、型を確かめずにStringとして使っていました。to_sがIntegerを返すと、ワーカープロセスがセグメンテーション違反で終わりました。同じワーカーのほかのリクエストも、一緒に止まりました。to_sがString以外のオブジェクトを返すと、これらのメソッドはそのオブジェクトのメモリをStringとして読みました。to_sが無いか例外を出す場合は、これらのメソッドはその例外を出していました。この挙動は変わりません。
  • 変更後:引数のto_sがString以外を返すと、これらのメソッドはTypeErrorを出します。メッセージは... cannot be converted to Stringです。#768以降のNginx::Varのセッターと同じ例外です。スクリプトのほかの例外と同じに、この例外でもハンドラは終わります。スクリプトはrescueでこの例外を捕まえられます。捕まえなければ、ngx_mrubyは例外をログに書き、リクエストは500になります。どの場合も、メソッドは何も書き出さず、リダイレクトもしません。フィルタのボディも変わりません。
  • 変更の理由:
    • 不具合:これらのメソッドは、to_sの結果を型を確かめずにStringとして読んでいました。#768はmruby_setとNginx::Varで同じ読み方を直しました。そのテストを書いたときに、これらのメソッドにも同じ読み方が見つかりました。
    • 前の挙動を残せなかった理由:前の挙動では、ワーカープロセスが同じワーカーのほかのリクエストと一緒に終わるか、Stringでないメモリを読みました。これらのメソッドにはStringが要り、このような値からはStringを作れません。そこで、同じ値にNginx::Varのセッターが出す例外を、これらのメソッドも出すことにしました。
    • ドキュメントが示していた挙動:2.7.5のNginx.rputsは、Stringでない引数をto_sで変換すると書いていました。to_sがString以外を返す場合は、何も書いていませんでした。Nginx.echo、Nginx.redirect、Nginx::Filter#body=のドキュメントは、Stringでない引数について何も書いていませんでした。
  • 影響の範囲:to_sがString以外を返す引数を渡す、Nginx.rputs、Nginx.echo、Nginx.redirect、Nginx::Filter#body=、Nginx::Filter#outputの呼び出しです。
  • 必要な対応:これらのメソッドには、String、nil、to_sがStringを返す値のどれかを渡してください。ほかの値を渡すコードは、2.7.5でも動いていませんでした。ワーカーが終わるか、Stringでないメモリを読んでいました。
  • このリリースで変わらない挙動:String、nil、to_sがStringを返すほかの値を渡したときの出力は、前と同じです。to_sが無いか例外を出したときにこれらのメソッドが出す例外も、前と同じです。

mrubyのヘッダフィルタの有無にかかわらず、前のハンドラがNginx.rputsで書いた後、1回の書き込みで送れないproxyの応答で、mrubyのボディフィルタが1回だけ動くようになります(#786)

  • 変更前:mruby_output_body_filterかmruby_output_body_filter_codeのあるlocationで、mruby_output_header_filterかmruby_output_header_filter_codeの有無にかかわらず、次の3つがそろうと、ボディフィルタのコードが2回動きました。1つ目は、リクエストの前のハンドラがNginx.rputsで書いてからリクエストを続けたことです。たとえば、Nginx::DECLINEDを返すrewriteハンドラがこれに当たります。2つ目は、応答がproxy_passから来ることです。3つ目は、nginxがその応答を1回の書き込みで送れないことです。たとえば、sendfile_max_chunkかlimit_rateがあるときがこれに当たります。1回目はupstreamの応答のボディに対して動き、2回目はupstreamの応答が終わったときに空のボディに対して動きました。クライアントは1回目のボディを、そのContent-Lengthとともに受け取りました。一方、log_formatの$sent_http_content_lengthは0になりました。
  • 変更後:このような応答では、ボディフィルタのコードは1回だけ動きます。$sent_http_content_lengthは、クライアントが受け取ったボディの長さになります。nginxが1回の書き込みで送る応答は、このリリースでも変わりません。その場合は、ボディフィルタのコードが空のボディに対してもう一度動きます。
  • 変更の理由:
    • 不具合:ボディフィルタが動いた後に、前のハンドラがNginx.rputsで書いた出力がリクエストの状態に残っていると、ngx_mrubyはその状態を捨てます。後のハンドラがその出力を応答の後ろに送らないようにするためです。捨てた状態には、ボディフィルタが同じ応答の残りをそのまま次のフィルタへ渡すためのフラグも入っていました。フラグが無くなると、ボディフィルタは新しいボディを待ちました。静的ファイルの応答は、最初の書き込みの後で止まり、send_timeoutが過ぎて接続が閉じるまで残りが送られませんでした。この停止は「不具合の修正」に書いています。proxyの応答が最後まで届いたのは、upstreamの応答が終わったときにボディフィルタが空のボディに対してもう一度動いたからにすぎません。#785のレビューで、この不具合が見つかりました。
    • 前の挙動を残せなかった理由:応答が止まることと、ボディフィルタが2回動くことは、同じ原因から起きます。修正では、nginxが応答の一部をまだ送っていないときに、そのフラグを持つ新しい状態をリクエストに渡します。proxyの応答だけで2回目の実行を残すには、proxyの応答にだけフラグを渡さないことになります。そうすると、ボディフィルタのコードは、応答を作り終えた後にも空のボディに対して動き続けます。新しい挙動は、前のNginx.rputsが無いときに同じlocationが既に示している挙動と同じです。そのときは、nginxが応答を1回で送っても2回以上で送っても、ボディフィルタのコードは1回だけ動き、$sent_http_content_lengthはボディの長さになります。
    • ドキュメントが示していた挙動:2.7.5のmruby_output_body_filterとNginx::Filterは、1つの応答でボディフィルタのコードが何回動くかについて、何も書いていませんでした。
  • 影響の範囲:mrubyのボディフィルタがあるlocationで、mrubyのヘッダフィルタの有無にかかわらず、前のハンドラがNginx.rputsで書いた後にproxy_passか、ほかのupstreamから来て、nginxが2回以上の書き込みで送る応答です。そのような応答で、動いた回数を数えるか空のボディに対して何かをするmruby_output_body_filterとmruby_output_body_filter_codeのコードと、$sent_http_content_lengthを使うlog_formatが影響を受けます。
  • 必要な対応:ボディを変えるだけのボディフィルタでは、対応は要りません。クライアントが受け取るボディは同じだからです。空のボディに対する2回目の実行を前提にしていたコードは、その処理を1回目の実行で行ってください。たとえば、応答の数を数えるコードや、応答の終わりに何かをするコードがこれに当たります。このような応答では、1回目の実行が唯一の実行になります。