Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Intermittent 500 /authorization-code/callback Blazor #273

Open
cagnew-lear opened this issue Nov 22, 2024 · 3 comments
Open

Intermittent 500 /authorization-code/callback Blazor #273

cagnew-lear opened this issue Nov 22, 2024 · 3 comments
Labels
bug Something isn't working

Comments

@cagnew-lear
Copy link

Describe the bug?

Intermittent failures are being returned to clients with 500. Re-initiating will return 302 as expected, and successfully log in.

What is expected to happen?

POST with state & code to /authorization-code/callback will return 302 and allow authentication/authorization.

What is the actual behavior?

Intermittent 500 application error returned, with no additional information available

Reproduction Steps?

Multiple internal apps (2) using ASP.NET Core Blazor experience intermittent issues.

Additional Information?

Cannot determine how to collect additional relevant logs in .net8 with startup class change. If there is an effective way to isolate & troubleshoot more, I would be happy to do that first & return more useful logs.

.NET Version

.net 8
Blazor app

SDK Version

Okta ASP.NET 4.6.1

OS version

No response
@cagnew-lear cagnew-lear added the bug Something isn't working label Nov 22, 2024
@bryanapellanes-okta
Copy link
Contributor

@cagnew-lear Thanks for bringing this to our attention, and I apologize for the delayed response. I've opened an internal issue for tracking and prioritization. OKTA-852185

@cagnew-lear
Copy link
Author

Hi Bryan -

While trying to get it replicated, we did catch something which may be part of this. I'm not sure if this could indicate the root cause? The getuserinformationasync; and if that's trying to look at the id token, or if it's making a call to the userinfo side?

Exception: 

System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 60 seconds elapsing.

---> System.TimeoutException: The operation was canceled.

---> System.Threading.Tasks.TaskCanceledException: The operation was canceled.

---> System.IO.IOException: Unable to read data from the transport connection: The I/O operation has been aborted because of either a thread exit or an application request..

---> System.Net.Sockets.SocketException (995): The I/O operation has been aborted because of either a thread exit or an application request.

   --- End of inner exception stack trace ---

   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)

   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Int32>.GetResult(Int16 token)

   at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](CancellationToken cancellationToken, Int32 estimatedSize)

   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)

   at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](Memory`1 buffer, CancellationToken cancellationToken)

   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)

   at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)

   --- End of inner exception stack trace ---

   at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)

   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)

   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)

   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)

   at Okta.AspNet.Abstractions.OktaHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)

   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)

   --- End of inner exception stack trace ---

   --- End of inner exception stack trace ---

   at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)

   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)

   at Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler.GetUserInformationAsync(OpenIdConnectMessage message, JwtSecurityToken jwt, ClaimsPrincipal principal, AuthenticationProperties properties)

   at Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler.HandleRemoteAuthenticateAsync()

@cagnew-lear
Copy link
Author

cagnew-lear commented Mar 7, 2025 •
edited
Loading

The scenario's causing the issue were mitigated slightly with extending the timeouts, but it appears to be related to retrieval of information from the /userinfo endpoint.

Q1: Can we eliminate that call entirely, and lean on the information provided in the ID Token retrieved?

2025-03-05 15:40:43.0049		Adding HSTS header to response.

2025-03-05 15:40:43.0049		Entering Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler's HandleRemoteAuthenticateAsync.

2025-03-05 15:40:43.0200		Performing unprotect operation to key {d6f81b34-843a-490c-be50-aa459c546eac} with purposes ('C:\Apps\OktaTest\', 'Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler', 'OpenIdConnect', 'v1').

2025-03-05 15:40:43.0200		MessageReceived: '?code=fH6MAroM6iJchHc8mf5l8c6D1orlkpJe8fyMUG4GIpw'.

2025-03-05 15:40:43.0200		Authorization code received.

2025-03-05 15:40:43.4193		Token response received.

2025-03-05 15:40:43.4193		Performing unprotect operation to key {d6f81b34-843a-490c-be50-aa459c546eac} with purposes ('C:\Apps\OktaTest\', 'Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler', 'System.String', 'OpenIdConnect', 'v1').

2025-03-05 15:40:43.4193		Retrieving claims from the user info endpoint.

2025-03-05 15:40:47.8885		Connection cfaINFL66HH0DOGXGPGlQA timed out.

2025-03-05 15:40:47.8885		Disposing connection cfaINFL66HH0DOGXGPGlQA.

2025-03-05 15:40:47.8885		Waiting for LongPolling transport to complete.

2025-03-05 15:40:47.8885		LongPolling transport complete.

2025-03-05 15:40:58.9009		Connection oBP-VEcX-gK-AEXc2UTeow timed out.

2025-03-05 15:40:58.9009		Disposing connection oBP-VEcX-gK-AEXc2UTeow.

2025-03-05 15:40:58.9009		Waiting for application to complete.

2025-03-05 15:40:58.9009		Application complete.

2025-03-05 15:42:44.6626		User information received: System.Text.Json.JsonDocument


        -------------- Nlog.config Trace (2025-03-05 15:40:43.0200) --------------
                     Call Site: Microsoft.Extensions.Logging.LoggingExtensions.MessageReceived
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: MessageReceived: '?code=fH6MAroM6iJchHc8mf5l8c6D1orlkpJe8fyMUG4GIpw'.
 
                     -------------- Nlog.config Debug (2025-03-05 15:40:43.0200) --------------
                     Call Site: Microsoft.Extensions.Logging.LoggingExtensions.UpdatingConfiguration
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Updating configuration
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:43.0200) --------------
                     Call Site: Microsoft.Extensions.Logging.LoggingExtensions.AuthorizationCodeReceived
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Authorization code received.
 
                     -------------- Nlog.config Debug (2025-03-05 15:40:43.0200) --------------
                     Call Site: Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler.RedeemAuthorizationCodeAsync
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Redeeming code for tokens.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:43.4193) --------------
                     Call Site: Microsoft.Extensions.Logging.LoggingExtensions.TokenResponseReceived
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Token response received.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:43.4193) --------------
                     Call Site: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingBasedDataProtector.UnprotectCore
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Performing unprotect operation to key {d6f81b34-843a-490c-be50-aa459c546eac} with purposes ('C:\Apps\OktaTest\', 'Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler', 'System.String', 'OpenIdConnect', 'v1').
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:43.4193) --------------
                     Call Site: Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler.GetUserInformationAsync
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Retrieving claims from the user info endpoint.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:47.8885) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager+Log.ConnectionTimedOut
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Connection cfaINFL66HH0DOGXGPGlQA timed out.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:47.8885) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.DisposeAsync
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Disposing connection cfaINFL66HH0DOGXGPGlQA.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:47.8885) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.WaitOnTasks
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Waiting for LongPolling transport to complete.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:47.8885) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.WaitOnTasks
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: LongPolling transport complete.
 
                     -------------- Nlog.config Debug (2025-03-05 15:40:47.8885) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager.RemoveConnection
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Removing connection j9-WD0H5XQXhF8GzDlS75w from the list of connections.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:58.9009) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager+Log.ConnectionTimedOut
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Connection oBP-VEcX-gK-AEXc2UTeow timed out.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:58.9009) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.DisposeAsync
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Disposing connection oBP-VEcX-gK-AEXc2UTeow.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:58.9009) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.WaitOnTasks
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Waiting for application to complete.
 
                     -------------- Nlog.config Debug (2025-03-05 15:40:58.9009) --------------
                     Call Site: Microsoft.AspNetCore.SignalR.HubConnectionHandlerLog.ConnectedEnding
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: OnConnectedAsync ending.
 
                     -------------- Nlog.config Trace (2025-03-05 15:40:58.9009) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.WaitOnTasks
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Application complete.
 
                     -------------- Nlog.config Debug (2025-03-05 15:40:58.9009) --------------
                     Call Site: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager.RemoveConnection
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: Removing connection CgypzE3HnXXnz4ajIkoCDw from the list of connections.
 
                     -------------- Nlog.config Trace (2025-03-05 15:42:44.6626) --------------
                     Call Site: Microsoft.Extensions.Logging.LoggingExtensions.UserInformationReceived
                     Exception Type: 
                     Exception Message: 
                     Stack Trace: 
                     Additional Info: User information received: System.Text.Json.JsonDocument

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@bryanapellanes-okta @cagnew-lear