全く同じパラメータなのにcurlだとアクセスできてrubyだとエラーが返ってくる??

とあるサービスのAPIを利用していたある日、
rubyで利用しているAPIからシステムエラーが返ってくるとの連絡が。
しかも、ログをとってcurlで叩いてみると正常にAPIは動作するとのこと。

さて、環境情報が悪いのかプログラムの仕業か、はたまた太陽風の影響なのか?
半日ほどあれやこれややってみて、原因がわかってみればああなんだそんなことか。というお話です。

rubyやcurlの問題ではなかったので、思考の過程をメモ書きとして残しておくものです。

まずは本当なのか確認する

今回、問題が発生したのはテストサーバーなので、まずはテストサーバーにてリクエストのログを取りました。
コード自体はなんて事のない普通のNet::Httpな奴です。

(※コードはイメージです)

uri = URI.parse("https://jsonplaceholder.typicode.com/todos")
http = Net::HTTP.new(uri.host, uri.port)
http.use_ssl = uri.scheme === "https"

params = { data: params }
headers = { "content-type" => "application/json" }
headers = { "authorization" => "Basic AAA" }
headers = { "x-api-mode" => "Basic AAA" }

req = Net::HTTP::Post.new(uri.path)
req.set_form_data(params)
req.initialize_http_header(headers)

response = http.request(req)

ログを見てみます。
なるほど。確かにAPIからシステムエラー(例外的なエラーコード)が返ってきていました。

{"status": "error", "error_code": 1, "error_message": "unknown error!"}

では、curlで叩いてみましょう。

$ curl -X POST https://example.com/api/v1/hoge \
 -H "Authorization: Basic AAAAA"
 -H "x-api-mode: developer"
 -H "content-type: application/json"
 -d { /* ruby のjsonパラメータと同じ文字列 */}

# レスポンス success
{"status": "success", "data": {...}}

あれ??
普通にアクセスできますね。
(ひょっとしたら勘の鋭い方はすでにわかったかも)

エスパーしてみる

他人の問題についてはついついやってしまうのに
自分の問題だとあまりいい気分のしない事
それは憶測で発言する事、です。

とはいえ、一人で黙々と進める状況なので、現実的にありそうなところを考えてみます。

IPが違う (流石にそれはない)
エンドポイントが違う (curlにコピーした)
パラメータが違う (curlにコピーした。文字コード周り?)
ヘッダーが違う (curlにコピーした)
TLSのバージョンが古い?
Lets encryptのルート証明書問題?
railsの何かが悪さをしている??

SSL周りかどうか確認する

TLS v1.0でアクセスしてみる

TLS v1.1の廃止が進んでいるのでその影響かもしれません。
しかし、curlに --tlsv1.0 オブションをつけてみましたが、問題なくレスポンスが返ってきました。

SSLではなさそう??

しかし、よく考えてみると、エラーとはいえjsonはちゃんと返ってきています。
ということは相手のプログラム自体は動いていて、どこかの段階でシステムエラーを起こしているものと推測できます。

railsのプログラムを検証用に切り出す

流石にrailsのままでは検証しづらいので、rubyのスクリプトに抜き出しましょう。
もしそれで動くのであれば原因はrails周りということにもなります。

プログラム自体は、頭にrequire()をつけるくらいです。

動かないかな? と淡い期待を込めて実行しますが
残念!返ってきたのは同じエラーでした。

データが壊れていそう?

環境依存といえば、文字コードやタイムスタンプです。
そのため、データが破損している可能性は高そうです。

ところが、今回のデータにマルチバイト文字列はなく、渡しているURLなども問題なくアクセスできるものでした。
では、少しずつデータを渡して、どこで壊れるか探してみます。

正常なエラーコードはどこで返ってくるのか?

現在帰ってくるのは異常なシステムコードなので
正常なエラーコード(404とか400とか)が帰ってくるのか確認してみます。

まず、Authorizationヘッダーを抜いてみると、、
ちゃんと400になりました。

Authorizationのトークンを適当にxxxとすると、やはり401が返ってきます。
ということは、トークンは認証されているようです。

バリデーションチェックは走ってる?

次にバリデーションチェックを試してみましょう。
もしデータが壊れていたり、不正なバイト列が紛れ込んでいるのであれば、データを取り除いて試していけばわかるはずです。

ボディを空にしてアクセスする

まずはパラメータを空にしてみます。
JSONフォーマットエラーが返ってきました。

{"status": "error", "error_code": 100, "error_message": "json parse error."}

ruby側のJSON出力がおかしいかもしれないので文字列を直接投げてみる

壊れたjson文字列を入れてみる

上記とほぼ同じですが、まあ結果も同じでした。
一応、パラメータを受け取ってjsonパースしようとしているようです。
ということは、データはちゃんと相手に渡っているということです。

空のjson "{}" を投げてみる

パースできるjsonを投げてみます。
必須チェックが走りそうですが、、、
お、ちゃんと必須チェックは返ってきました。

{"status": "error", "error_code": 101, "error_message": "field 'data' is required."}

第一階層のデータを入れてみる

今回のデータはかなり階層が深いので、最初の階層に空のオブジェクトを入れてみます。
そして少しずつ深くしていけば、問題のある階層にたどり着くはずです。

最初のdataフィールドの型チェックは通りました。

入力 : {"data": "本当は配列フィールドだよん"}
結果 : {"status": "error", "error_code": 101, "error_message": "field 'data' must be array."}

次に、{"data": []} というデータを投げたところで例のエラーが返ってきました。

入力 : {"data": []}
結果 : {"status": "error", "error_code": 1, "error_message": "unknown error."}

ということはデータが原因ではない?

むむ、流石にascii文字列がちゃんと送信できないことはないでしょう。
データに問題がないとすると、、、あとはヘッダーくらいでしょうか。

改めてヘッダーを確認する

curlには --verbose オブションをつけることでヘッダーを確認できます。
rubyの方もひょっとしたらライブラリ側で何か処理が行われているかも? と思いダンプする処理を入れてみました。

すると、

curl
HTTP/2
...
Authorization: Basic AAA
x-api-mode: developer

ruby
HTTP/1.1
...
Authorization: Basic AAA
X-Api-Mode: developer

お?
ruby側のヘッダーが大文字になっている!?
これか!? こいつのせいか!

ちなみに、ヘッダーが大文字になるのはRFCの規約のようです。参照記事
ヘッダーを小文字にするには別のライブラリを使うしかなさそうです。

仕方ないのでとりあえずcurlの方を大文字にして試してみます。

あれ? でもアクセスできますね。

$ curl -X POST ...
-H 'X-Api-Mode: developer'
-d '{"data": [ /* 正常なデータ */ ]}'

> {"status": "success", "data": ...}

ここまできて、手詰まりでしょうか。
wiresharkなどで通信パケットの内容を比較しないといけないのでしょうか。

いや、待てよ??
curl HTTP/2 ??
ひょっとして、HTTP1.1なら処理も違うかも??

curlに-http1.1 をつけて試してみます。

$ curl --http1.1 -X POST https://example.com/api/v1/hoge \
-H "Authorization: Basic AAA"
-H "X-Api-Mode: developer"
-d '{"data": [ /* 正常なデータ */ ]}'

> {"status": "error", "error_code": 1, "error_message": "unknown error."}

お!
システムエラーになりました!
curlでもシステムエラーを引き起こすことに成功しました。

ということは、HTTP1.1でヘッダーが大文字 X-Api-Mode だと向こうの想定外のシステムエラーになるようです!

あー、そういえば数ヶ月前にLINEもヘッダーを全て小文字から X-Line-Hoge 形式に直していたことを思い出しました。
その時にも500が返ってきてハマりかけたのですが、新着情報にお知らせがあったのですぐに気づけたのでした。

結論

HTTPヘッダーはRFCに従って、X-Hoge-Fuga にしましょう!

おまけ

さて、これが自社開発のAPIであればヘッダーを合わせば問題ないのですが、
残念なことに海外サービスのAPIなので要望を出すのも大変です。

結局、rubyだとリクエストヘッダーを小文字にするのはややこしそうなので
open3を使ってcurlを叩くようにしてしまいました。

require("open3")

result, stdout, stderr = Open3.capture3("curl -X POST https://example.com/api/v1/hoge ...ヘッダーとデータ")