Open AndrewDryga opened 6 months ago
We have such logs seen both in test suite and production:
Error: :13:59.244 line=172 pid=<0.1372.0> file=/home/runner/work/firezone/firezone/elixir/deps/telemetry/src/telemetry.erl mfa=:telemetry.execute/3 [error] Handler {OpentelemetryFinch, :request_stop} has failed and has been detached. Class=:error Reason={:badkey, :status, {%Finch.Response{ status: 200, body: ["" | "{\"authorization_endpoint\":\"http://localhost:41537/authorize\",\"claims_supported\":[\"aud\",\"auth_time\",\"created_at\",\"email\",\"email_verified\",\"exp\",\"family_name\",\"given_name\",\"iat\",\"identities\",\"iss\",\"name\",\"nickname\",\"phone_number\",\"picture\",\"sub\"],\"client_authorization_endpoint\":\"http://localhost:41537/oauth/client/code\",\"code_challenge_methods_supported\":[\"S256\",\"plain\"],\"end_session_endpoint\":\"https://example.com\",\"id_token_signing_alg_values_supported\":[\"HS256\",\"RS256\"],\"issuer\":\"http://localhost:41537/\",\"jwks_uri\":\"http://localhost:41537/.well-known/jwks.json\",\"mfa_challenge_endpoint\":\"http://localhost:41537/mfa/challenge\",\"registration_endpoint\":\"http://localhost:41537/oidc/register\",\"request_parameter_supported\":false,\"request_uri_parameter_supported\":false,\"response_modes_supported\":[\"query\",\"fragment\",\"form_post\"],\"response_types_supported\":[\"code\",\"token\",\"id_token\",\"code token\",\"code id_token\",\"token id_token\",\"code token id_token\"],\"revocation_endpoint\":\"http://localhost:41537/oauth/revoke\",\"scopes_supported\":[\"openid\",\"profile\",\"offline_access\",\"name\",\"given_name\",\"family_name\",\"nickname\",\"email\",\"email_verified\",\"picture\",\"created_at\",\"identities\",\"phone\",\"address\"],\"subject_types_supported\":[\"public\"],\"token_endpoint\":\"http://localhost:41537/oauth/token\",\"token_endpoint_auth_methods_supported\":[\"client_secret_basic\",\"client_secret_post\"],\"userinfo_endpoint\":\"http://localhost:41537/userinfo\"}"], headers: [ {"cache-control", "max-age=0, private, must-revalidate"}, {"content-length", "1425"}, {"date", "Sun, 12 May 2024 16:13:59 GMT"}, {"server", "Cowboy"} ], trailers: [] }, 1425}} Stacktrace=[ {OpentelemetryFinch, :handle_request_stop, 4, [file: ~c"lib/opentelemetry_finch.ex", line: 44]}, {:telemetry, :"-execute/3-fun-0-", 4, [ file: ~c"/home/runner/work/firezone/firezone/elixir/deps/telemetry/src/telemetry.erl", line: 160 ]}, {:lists, :foreach_1, 2, [file: ~c"lists.erl", line: [168](https://github.com/firezone/firezone/actions/runs/9052663558/job/24870602094?pr=4962#step:7:169)6]}, {:telemetry, :span, 3, [ file: ~c"/home/runner/work/firezone/firezone/elixir/deps/telemetry/src/telemetry.erl", line: 324 ]}, {OpenIDConnect.Document, :read_finch_response, 1, [file: ~c"lib/openid_connect/document.ex", line: 83]}, {OpenIDConnect.Document, :fetch_remote_resource, 1, [file: ~c"lib/openid_connect/document.ex", line: 64]}, {OpenIDConnect.Document, :fetch_document, 1, [file: ~c"lib/openid_connect/document.ex", line: 31]}, {Domain.Auth.Adapters.OpenIDConnect.Settings.Changeset, :"-validate_discovery_document_uri/1-fun-0-", 2, [ file: ~c"lib/domain/auth/adapters/openid_connect/settings/changeset.ex", line: 23 ]}, {Ecto.Changeset, :validate_change, 3, [file: ~c"lib/ecto/changeset.ex", line: 2427]}, {Domain.Auth.Adapters.OpenIDConnect.Settings.Changeset, :changeset, 2, [ file: ~c"lib/domain/auth/adapters/openid_connect/settings/changeset.ex", line: 13 ]}, {Domain.Repo.Changeset, :cast_polymorphic_embed, 3, [file: ~c"lib/domain/repo/changeset.ex", line: 423]}, {Domain.Auth.Adapters, :provider_changeset, 1, [file: ~c"lib/domain/auth/adapters.ex", line: 52]}, {Domain.Auth, :create_provider, 2, [file: ~c"lib/domain/auth.ex", line: 224]}, {Domain.Fixtures.Auth, :create_openid_connect_provider, 1, [file: ~c"test/support/fixtures/auth.ex", line: 156]}, {Domain.Fixtures.Auth, :start_and_create_openid_connect_provider, 1, [file: ~c"test/support/fixtures/auth.ex", line: 81]}, {Domain.Fixtures.Auth, :"-create_identity/1-fun-1-", 2, [file: ~c"test/support/fixtures/auth.ex", line: 317]}, {Domain.Fixture, :pop_assoc_fixture, 3, [file: ~c"test/support/fixture.ex", line: 29]}, {Domain.Fixtures.Auth, :create_identity, 1, [file: ~c"test/support/fixtures/auth.ex", line: 313]}, {Domain.Auth.Adapters.EmailTest, :"test request_sign_in_token/1 deletes previous sign in tokens", 1, [file: ~c"test/domain/auth/adapters/email_test.exs", line: 118]}, {ExUnit.Runner, :exec_test, 2, [file: ~c"lib/ex_unit/runner.ex", line: 472]} ]
My theory is that it fails when Finch.stream_while/3 is used: https://github.com/firezone/openid_connect/blob/master/lib/openid_connect/document.ex#L83.
Finch.stream_while/3
We have such logs seen both in test suite and production:
My theory is that it fails when
Finch.stream_while/3
is used: https://github.com/firezone/openid_connect/blob/master/lib/openid_connect/document.ex#L83.