Zenn
🚀

stripe rubyで遭遇するEncoding::UndefinedConversionErrorになやまされた話

2021/05/26に公開
Ruby
Stripe
tech

この話の結論

🙅 Stripe.log_level = Stripe::LEVEL_DEBUG
🙆 Stripe.log_level = Stripe::LEVEL_INFO

何があったのか

こういうことしたときに

 Stripe::PaymentIntent.retrieve(payment_intent_id)

こういうログが出てきますよっと。

DEBU Request details query=
INFO Response from Stripe API api_version=2020-08-27 elapsed=0.36431508301757276 method=get path=/v1/payment_intents/xxxxxxxxxxxxx request_id=req_xxxxxxxxxxxx status=200
ERRO Request error elapsed=0.4061092500342056 error_message="\"\xE3\" from ASCII-8BIT to UTF-8" method=get path=/v1/payment_intents/xxxxxxxxxxxxx
Traceback (most recent call last):
        3: from (irb):1
        2: from app/models/xxxxxxxxx.rb:40:in `stripe_payment'
        1: from app/models/xxxxxxxxx.rb:24:in `find'
Encoding::UndefinedConversionError ("\xE3" from ASCII-8BIT to UTF-8)

エラーの文言通り、error_messageに入っている文字のUTF-8エンコードにとちって死ぬケースですね(´・ω・｀)
とはいえ、このerror_message、Stripeから渡されてくるやつなのでこちらでは対処できないのです。何が契機で発生するかも謎。とはいえここで落ち続けられても困る。さあどうしたものか。

とりあえずコードを読んで見る

今回問題を起こしてるretrieveは下記で実装されてます。
https://github.com/stripe/stripe-ruby/blob/83b0cb369edff234f0ebbacc82595bc3aee6e6cb/lib/stripe/api_resource.rb#L101

    # lib/stripe/api_resource.rb#L101
    def self.retrieve(id, opts = {})
      opts = Util.normalize_opts(opts)
      instance = new(id, opts)
      instance.refresh
      instance
    end
    
    # lib/stripe/api_resource.rb#L95
    def refresh
      resp, opts = execute_resource_request(:get, resource_url,
                                            @retrieve_params)
      initialize_from(resp.data, opts)
    end

追っていくとわかるんですが、StripeのAPIにリクエスト投げ込んで返ってきたものを受け取ってるだけですね。やはりこちら側ではどうしようもできない。ううむ。

処理を追ってあたりをつける

ヒントがほとんどないので、どこで発生しているかのあたりを付けます。あって嬉しいbinding.pry

From: /usr/local/lib/ruby/2.7.0/irb.rb:550 IRB::Irb#eval_input:

    545:           rescue Exception => exc
    546:           else
    547:             exc = nil
    548:             next
    549:           end
 => 550:           handle_exception(exc)
    551:         end
    552:       end
    553:     end
    554:
    555:     def handle_exception(exc)

[3] pry(#<IRB::Irb>)> exc
=> #<Encoding::UndefinedConversionError: "\xE3" from ASCII-8BIT to UTF-8>
[4] pry(#<IRB::Irb>)> exc.backtrace
=> ["/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/util.rb:320:in `write'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/util.rb:320:in `puts'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/util.rb:320:in `log_internal'",
 # ここに注目↓
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/util.rb:103:in `log_debug'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/stripe_client.rb:856:in `log_response'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/stripe_client.rb:525:in `execute_request_with_rescues'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/stripe_client.rb:264:in `execute_request'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/api_operations/request.rb:25:in `execute_resource_request'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/api_operations/request.rb:89:in `execute_resource_request'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/api_resource.rb:96:in `refresh'",
 "/bundle/ruby/2.7.0/gems/stripe-5.32.1/lib/stripe/api_resource.rb:104:in `retrieve'",
...

デバッグログを出すところで発生している？🤔
ということがわかりますね。ここはログレベルを変えても再現するかをチェックします。

Stripe.log_level = Stripe::LEVEL_DEBUG

↓

Stripe.log_level = Stripe::LEVEL_INFO

これでRails立ち上げ直して実行してみると、発生しなくなりました🎉

しかし、問題は回避できたものの、何も解決できてない気がする....
もうちょっと落ち着いたら詳しく調査してPR投げておきたいところですね。

Discussion