時折発生するOAuthエラー

外部OAuthをユーザー認証に使用しています。時折、ユーザーがプラットフォームにアクセスする際にエラー500が発生します。エラーログからの抜粋:

Started GET "/auth/oauth2_basic/callback?code=[coderemoved]&state=[stateremoved]" for [IP] at [timestamp]
(oauth2_basic) Setup endpoint detected, running now.
(oauth2_basic) Callback phase initiated.
Faraday::TimeoutError (Timeout::Error)
lib/final_destination/resolver.rb:31:in `block in lookup'
lib/final_destination/resolver.rb:8:in `synchronize'
lib/final_destination/resolver.rb:8:in `lookup'
lib/final_destination/ssrf_detector.rb:127:in `lookup_ips'
lib/final_destination/ssrf_detector.rb:95:in `lookup_and_filter_ips'
lib/final_destination/http.rb:13:in `connect'
lib/middleware/omniauth_bypass_middleware.rb:43:in `call'
lib/middleware/content_security_policy.rb:12:in `call'
lib/middleware/anonymous_cache.rb:387:in `call'
lib/middleware/gtm_script_nonce_injector.rb:10:in `call'
config/initializers/100-quiet_logger.rb:20:in `call'
config/initializers/100-silence_logger.rb:29:in `call'
lib/middleware/enforce_hostname.rb:24:in `call'
lib/middleware/request_tracker.rb:233:in `call'

ユーザーがページをリロードすると、すべて正常に動作し、ログ情報には以下のように表示されます:

Started GET "/auth/oauth2_basic/callback?code=[coderemoved]&state=[stateremoved]" for [IP] at [timestamp]
(oauth2_basic) Setup endpoint detected, running now.
(oauth2_basic) Callback phase initiated.
Processing by Users::OmniauthCallbacksController#complete as HTML
  Parameters: {"code"=>"[coderemoved]", "state"=>"[stateremoved]", "provider"=>"oauth2_basic"}
Deprecation notice: `SiteSetting.anonymous_posting_min_trust_level` has been deprecated. Please use `SiteSetting.anonymous_posting_allowed_groups` instead. (removal in Discourse 3.3)
At /var/www/discourse/lib/site_setting_extension.rb:160:in `public_send`
start
Redirected to https://[pageremoved]
Completed 302 Found in 83ms (ActiveRecord: 0.0ms | Allocations: 11138)

残念ながら、再現手順はありません。しばらくプラットフォームから離れていたユーザーに発生する傾向がありますが、確信はありません。最後にアクセスしてからプラットフォームがアップグレードされた可能性があります。
何か提案や、提供できる追加情報はありますか?

これを BUMP します。全く同じ問題が発生しています。

タイムアウトエラーはネットワークの問題を示唆しています。単なるネットワークの不具合である可能性もあります。

しかし、エラーが通常では考えられないほど早く発生するため、そのように考えていました。どこかで過剰に設定されたDNSルックアップのタイムアウトがあるのではないかと疑問に思っています。

  1. エラーは「resolver.rb」にあります。
  2. DNSルックアップがキャッシュされると、リフレッシュによって一時的に修正されます。
  3. まったく説明のつかない理由で、セルフホストされたDNSを含むURLからOIDCディスカバリー・ドキュメントを読み取ることができません。これは、Dockerインスタンス内から手動でファイルを curl できるにもかかわらずです。多くの異なる変数を排除しましたが、DNSが唯一の共通要因のようです。

重要なのは、Discourseサーバーは、このように失敗した場合でもOIDCサーバーと通信できることです。アクセスログから、1つのリクエストがあります。

21/Jan/2024:23:10:21 +0000] "POST /application/o/token/ HTTP/1.1" 200 7998 "-" "Faraday v2.9.0"

失敗した場合、および2つのリクエストがあります。

[21/Jan/2024:23:21:03 +0000] "POST /application/o/token/ HTTP/1.1" 200 7998 "-" "Faraday v2.9.0"
[21/Jan/2024:23:21:05 +0000] "GET /application/o/userinfo/ HTTP/1.1" 200 5254 "-" "Faraday v2.9.0"

成功した場合。いずれにしても、5秒以上かかることはありません。Cloudflare DNSを使用するOIDCサーバーのプロキシをセットアップしようとしていますが、それが次のステップになります。

よくある話として、それは常にDNSだと言われています。

えーと、間違いなくDNSの問題です。プロキシを設定する代わりに、DockerコンテナのhostsファイルにOIDCサーバーを追加したところ、今は機能するようです。ただし、これは脆弱で最適ではない解決策です。開発者はタイムアウトを妥当な値に修正する必要があると思います。このケースは、500マイルメールの話を思い出させます。

再構築時に/etc/hostsを更新するように、app.ymlに項目を追加できます。他のテンプレートで例を確認してください。

そうかもしれませんが、問題が発生している人はそれほど多くありません。セルフホスト型DNSサーバーが時々過負荷になっているということはありませんか?

タイムアウトを変更する方法がわかりません。以前に行った記憶がありません。

私の場合は、IdPとDiscourseのVMが隣接しており、ネットワークの問題を完全に排除することはできませんが、他のサービスでは問題が発生していません。