エラー検知・監視ツールであるところの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をウォッチしていただければと思います。
また、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::Processor::SanitizeData::DEFAULT_FIELDS
- Ravenのconfigで指定する
sanitize_fields
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への参照を得ています。
# https://github.com/getsentry/sentry-ruby/blob/82e1ffe711af287ddc23e8517bdb8275beff94d5/sentry-raven/lib/raven/integrations/rack.rb#L87-L89 def read_data_from(request) if request.form_data? request.POST
後のRaven::Event#to_hash
というメソッドで実行環境の情報をHash化します。このときも同一のポインタをそのまま渡しています。
# https://github.com/getsentry/sentry-ruby/blob/82e1ffe711af287ddc23e8517bdb8275beff94d5/sentry-raven/lib/raven/client.rb#L74-L75 def encode(event) hash = @processors.reduce(event.to_hash) { |a, e| e.process(a) }
そしてRaven::Processor::SanitizeData
というデータマスクを行うclassにそのHashが渡るのですが、その中でHash#merge!
を実行して破壊的に更新をしています。
# https://github.com/getsentry/sentry-ruby/blob/82e1ffe711af287ddc23e8517bdb8275beff94d5/sentry-raven/lib/raven/processor/sanitizedata.rb#L44-L50 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%再現するバグなら勝利は約束されるので、最小の構成で再現するプロジェクトを作ってみました。
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が担当しました。