가끔 발생하는 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/content_security_policy/middleware.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)

불행히도 재현 단계는 없습니다. 비교적 긴 기간 동안 접속하지 않았던 사용자에게서 발생하는 경향이 있지만, 이를 확신할 수는 없습니다. 마지막 방문 이후 플랫폼 업그레이드가 이루어졌을 가능성도 있습니다.
제안 사항이나 추가로 제공해야 할 정보가 있을까요?

올려드립니다. 저 역시 정확히 같은 문제를 겪고 있습니다.

타임아웃 오류는 네트워크 문제를 시사합니다. 단순히 네트워크 일시 장애일 수도 있습니다.

그렇게 생각은 했는데, 오류가 너무 빨리 발생해서 정상적인 동작이라고 보기 어렵습니다. 어딘가에 지나치게 엄격한 DNS 조회 타임아웃이 있는 건 아닌지 의심이 듭니다:

  1. 오류는 "resolver.rb"에서 발생합니다.
  2. DNS 조회가 캐시될 때를 제외하면 일시적으로 해결됩니다.
  3. 완전히 설명할 수 없는 이유로, 자체 호스팅 DNS를 포함하는 URL에서는 OIDC discovery 문서를 읽을 수 없습니다. docker 인스턴스 내에서 파일을 수동으로 curl하는 것은 완벽하게 가능함에도 불구하고요. 많은 변수를 제거해 봤는데, DNS가 유일한 공통 요인인 것 같습니다.

중요한 점은, 이렇게 실패하더라도 Discourse 서버가 OIDC 서버와 통신은 한다는 것입니다. 액세스 로그를 보면 실패할 때 요청이 하나 있습니다:

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

성공할 때는 요청이 두 개입니다:

[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초를 넘어서는 일은 없습니다. OIDC 서버용 프록시를 설정하여 Cloudflare DNS를 사용하는 것은 아직 시도해 보지 않았지만, 다음 단계로 진행할 예정입니다.

통념으로는 항상 DNS 탓이라고 한다.

글쎄, 확실히 DNS 문제인 것 같아. 프록시를 설정하는 대신 도커 컨테이너의 hosts 파일에 내 OIDC 서버를 추가했는데, 지금은 잘 작동하는 것 같아. 다만 이 방법은 취약하고 최적의 해결책은 아니야. 개발자들이 타임아웃을 합리적인 수준으로 수정해야 한다고 생각해. 이 사례는 500마일 이메일 이야기에 대해 떠올리게 해.

app.yml에 항목을 추가하여 재빌드 시 /etc/hosts를 업데이트할 수 있습니다. 예시를 확인하려면 다른 템플릿을 참고해 보세요.

그럴 수도 있지만, 문제를 겪는 사람은 많지 않습니다. 자체 호스팅 DNS 서버가 가끔 과부하 상태인 것은 아닌가요?

타임아웃을 변경하는 방법을 모르겠습니다. 제가 직접 변경해 본 기억이 없네요.

제 경우, IdP와 Discourse VM은 인접해 있으며, 네트워크 문제를 완전히 배제할 수는 없지만, 다른 서비스에서는 이러한 문제가 발생하지 않습니다.