エラー検知・監視ツールであるところのSentryが提供するRubyのSDKにsentry-ravenというgemがあります。
このgemを利用するとごくわずかなコードの記述をするだけでSentryに対してイベントを送信することができます。イベントにはユーザーが定義したカスタムタグや実行環境を含む多様な情報を含めることができ大変便利です。
begin
some_dangerous_code!
rescue => ex
Raven.capture_exception(ex)
end
if record.unknown?
Raven.capture_message("Found suspisious data")
end
上述のようなコードを見た/書いた方も多いと思います。しかしながら特定条件下では上記のような Raven.capture_*メソッドの呼び出しの内部でRack envの一部を書き換えてしまう ことがあります。
なお、本件が意図した挙動なのか不明だったので本体にレポートしまして、トリアージ待ちです。本件の行く末が気になる方はissueをウォッチしていただければと思います。
github.com
また、sentry-ravenはすでにアクティブな開発が停止しており、sentry-rubyやsentry-railsに移行するようアナウンスがされています。僕が遭遇したプロジェクトでもこの問題による不具合を契機としてmigrationを実施しています。
Migration Guide for Ruby | Sentry Documentation
環境
- rack 2.1.1
- sentry-raven 3.1.1
事象の説明
以下の条件をすべて満たすときRack envのenv["rack.request.form_hash"]のHashのうち、2で該当したkeyのvalueがマスク用の文字列 ("********") に破壊的に書き換えられます。
Rack::Request#form_data?がtrueとなる
Content-Typeが"application/x-www-form-urlencoded"や"multipart/form-data"であるとき- 画像アップロードでハマった
- リクエストのform dataのkeyが以下のいずれかに一致・マッチする
Raven.configure do |config|
config.sanitize_fields = %w[quite_sensitive_field]
end
後継のsentry-rubyでは起きない？
はい。
sentry-ravenが持つdata sanitization等を行う機構をprocessorと呼ぶのですが、この機構は後継のsentry-rubyや周辺のgemには存在しません。ユーザーが自前でhookを書いたり、SentryのGUIからfilter ruleを登録するようになっています。
何が問題か
Raven.capture_*に副作用がないと思っていると痛い目を見る…。
具体的な例を挙げます。
RailsがActionParameterのインスタンスを作るより手前のRack middlewareでRaven.capture_*を呼び出した場合、paramsの中身の一部が"********"になり、クライアントから送信されたform dataを参照できません。
もしくはRailsのcontrollerやmodelでRaven.capture_*を呼び出し、そのあとでenv["rack.request.form_hash"]を見るようなことがあれば同様にマスクされた文字列になっています。
ActionParameterのインスタンスが保持するform dataはコピーされたものなのでRailsアプリケーション内でparamsを見るふつうの（？）コードを書いていれば途中でRavenを使っても問題ないでしょう。
発見の経緯
そんなことするか？って思いますかね。まぁたしかにenvを直接触ることはほぼ無いと思いますが、rack middlewareのどこかでうっかりSentryに通知することはあるんじゃないでしょうか。というか、あった。
僕がハマったパターンは「committeeのCommittee::Middleware::RequestValidation middlewareでOpenAPI定義に違反するリクエストが来たらSentryに記録する（けど後続の処理はそのまま行う）」という使い方でした。
最初はユーザーが不正なリクエストをして400になっただけと思ったけど、開発環境でも事象が再現すること、および僕が変更したOpenAPIの定義をrevertすると再現しないことを同僚が発見してくれたのでバグだと気づくことができました。
sentry-ravenの実装の詳細
Rack::Request#form_data?がtrueのときRaven::RackはRack::Request#POSTを呼び出し、書き換える対象のHashへの参照を得ています。
def read_data_from(request)
if request.form_data?
request.POST
後のRaven::Event#to_hashというメソッドで実行環境の情報をHash化します。このときも同一のポインタをそのまま渡しています。
def encode(event)
hash = @processors.reduce(event.to_hash) { |a, e| e.process(a) }
そしてRaven::Processor::SanitizeDataというデータマスクを行うclassにそのHashが渡るのですが、その中でHash#merge!を実行して破壊的に更新をしています。
def sanitize_hash_value(key, value)
if key =~ sensitive_fields
STRING_MASK
elsif value.frozen?
value.merge(value) { |k, v| process v, k }
else
value.merge!(value) { |k, v| process v, k }
デバグ
さらっと書きましたが最初は「OpenAPI定義を変更したらリクエストパラメータがマスクされるようになった」ように見えたのでわけがわかりませんでした。
Raven configのsanitize_fieldを変更すると再現しない、Sentryへの通知をやめると再現しない、といったあたりまで同僚が絞り込んでくれたので、僕の方ではsentry-ravenのコードを読みながらステップ実行していってようやく原因にあたりがつきました。
最小の再現プロジェクトを作る
100%再現するバグなら勝利は約束されるので、最小の構成で再現するプロジェクトを作ってみました。
github.com
Raven::Rackをかませたrack appを作り、その中でRaven.capture_*を呼ぶ。その前後でrack envの中身が変わっていることを確認する。
味の秘密は、それだけ。
require 'rack'
require 'sentry-raven'
Raven.configure do |config|
config.dsn = ENV['SENTRY_DSN']
config.sanitize_fields = %w[name]
end
class SentryRavenSanitizeDemo
def call(env)
r = Rack::Request.new(env)
puts "=========Before========="
puts r.POST
puts env[Rack::RACK_REQUEST_FORM_HASH]
before = env[Rack::RACK_REQUEST_FORM_HASH].dup
begin
raise "foo"
rescue => ex
Raven.capture_exception(ex)
end
puts "=========After========="
puts r.POST
puts env[Rack::RACK_REQUEST_FORM_HASH]
after = env[Rack::RACK_REQUEST_FORM_HASH].dup
[200, {"Content-Type" => "text/plain"}, ["before: #{before}, after: #{after}"]]
end
end
use Raven::Rack
run SentryRavenSanitizeDemo.new
rackupで起動し、curlでform dataをPOSTしてみると…
$ curl -X POST http://localhost:9292 -F 'name=foo' -F 'age=32'
before: {"name"=>"foo", "age"=>"32"}, after: {"name"=>"********", "age"=>"32"}%
BINGOです。sanitize_fieldをいじったりRaven.capture_exception(ex)を呼ばなければ再現しなくなることもすぐに確認できました。
結論
- 特定条件下では上記のような
Raven.capture_*メソッドの呼び出しの内部でRack envの一部を書き換えてしまう ことがある
sentry-ravenはすでにアクティブな開発が停止しているのでsentry-rubyやsentry-railsに移行しよう
ohbarye Advent Calendar 2020の1日目は@ohbaryeが担当しました。
