現在担当しているOAuth2サーバーでここ数日原因不明のエラーに悩まされ続けていました。

2020/10/11 22:13:54 [error] 21#21: *76 connect() failed (111: Connection refused) while connecting to upstream

サーバーからStripeでSubscriptionを解約をした後、問題がなければ一覧画面へリダイレクトするといった操作でした。 しかし、サーバーは200のレスポンスを返すところまでエラーは発生していないのに、何故か502のエラーを返していました。

厄介だったのは自分の統治下にない、外部のサービスと連携していたので、何が原因だったのかが曖昧でした。 また、ローカル環境では問題が発生せず、Nginxのreverse proxyで運用している時に限って起こっていたのでちょっとした実験もいちいちステージング環境にデプロイしないと確認できませんでした。 そのため先週から原因不明のエラーに悩まされていて精神的に追い詰められていました。

たまたまデバッグしていた時に、Stripeのコードを入れずに単純なレスポンスを返したときは問題が発生しなかったのでStripe側の処理が怪しいのではないかと思い至りました。 そこでのやり取りは割愛しますが、Stripe側には問題が検出されなかったのでやはりこちら側の実装が原因だろうという回答でした。

特に先週は設定された期限も短く、プレッシャーをかけられていたので調査は思うようにいきませんでした。 とはいえ、今回は見当違いの調査を依頼してしまったのでStripeの担当者には申し訳ない気分です。

改めてバックエンド側のサーバーのログを調べてみると以下のような記述がありました。

node_modules/proxy-addr/index.js:228
    throw new TypeError('trust argument is required')
    ^

TypeError: trust argument is required

http://expressjs.com/en/guide/behind-proxies.html

Proxy関連で検索した結果、trust proxyという設定があることがわかりました。 Stripeのサポートに問い合わせをする前にもこの設定が怪しいとは思っていましたが、trust proxyにtrueやfalseを指定したり、あるいはIPアドレスの一覧、関数で常にtrueを返すようにしても挙動は全く変わりませんでした。

今週も同じエラーに悩まされ続けるのかと思うとずいぶん気が重くなりましたが、DuckDuckGoだけでなく久しぶりにGoogleをつかって検索してみました。 そこでたまたまヒットしたページによると:

https://github.com/expressjs/express/issues/3118

I have set up an Express app with Morgan for logging behind an NGINX proxy. I have configured the trust proxy setting in my root file like so:

ここにきてMorganが出てきました。MorganはExpressのlogger用のライブラリなのですが、試しに削除してみたところ今までの苦労がまるで嘘のようにうまくいくようになりました。

自分の書いたプログラムに不具合があるならデバッグはそこまで難しくはないものですが、ミドルウェア側に不具合が出ているとは夢にも思いませんでした。 前回のCORSもそうですが、どこに不具合が潜んでいるかわからないものなのでWebの世界もなかなか一筋縄にはいかないものだと思い知らされる一件でした。