abpframework / abp

Open-source web application framework for ASP.NET Core! Offers an opinionated architecture to build enterprise software solutions with best practices on top of the .NET. Provides the fundamental infrastructure, cross-cutting-concern implementations, startup templates, application modules, UI themes, tooling and documentation.
https://abp.io
GNU Lesser General Public License v3.0
12.77k stars 3.41k forks source link

/connect/authorize timeout after a while #20800

Closed zeinali-ali closed 1 day ago

zeinali-ali commented 6 days ago

Is there an existing issue for this?

Description

http://mydomain.me/connect/authorize?client_id=Console_Blazor&redirect_uri=http%3A%2F%2Fconsole.pezhvak.im%2Fauthentication%2Flogin-callback&response_type=code&scope=openid%20profile%20Console%20roles%20email%20phone&state=ca3256e5a7c445a5bfb672faa56fbdfe&code_challenge=aL8CnW0rcQxDjq32MVSbYY7Qx6bIMDIZ7YArSATxYa0&code_challenge_method=S256&prompt=none&response_mode=query

After I upgraded my project from 8.1.3 to 8.2.1 the above authorize method timeout a while after login and I have to clear site data in my browser or restart server to get it work again.

image

Reproduction Steps

No response

Expected behavior

No response

Actual behavior

No response

Regression?

No response

Known Workarounds

No response

Version

8.2.1

User Interface

Blazor

Database Provider

EF Core (Default)

Tiered or separate authentication server

Tiered

Operation System

Linux

Other information

No response

maliming commented 5 days ago

Please check your application logs to see what's going on.

zeinali-ali commented 5 days ago

Here is the logs, the last line shows the authorization marked as skiped, but I cant figured out why? I didn't changed anything I just upgraded all packages to version 8.2.1

[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was marked as skipped by OpenIddict.Server.OpenIddictServerHandlers+Authentication+HandleAuthorizationRequest.
[15:11:37 INF] Request starting HTTP/2 GET https://localhost:44352/connect/authorize?client_id=Console_Blazor&redirect_uri=https%3A%2F%2Flocalhost%3A44328%2Fauthentication%2Flogin-callback&response_type=code&scope=openid%20profile%20Console%20roles%20email%20phone&state=95d90f996bf443e0b37c08ccdfaa0b0f&code_challenge=S49hKQxcyPgcvG0BS1xP_JydUXz2NxG2a5dn-vwupPo&code_challenge_method=S256&prompt=none&response_mode=query - null null
[15:11:37 DBG] The event OpenIddict.Validation.OpenIddictValidationEvents+ProcessRequestContext was successfully processed by OpenIddict.Validation.AspNetCore.OpenIddictValidationAspNetCoreHandlers+ResolveRequestUri.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was successfully processed by OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlers+ResolveRequestUri.
[15:11:37 INF] The request URI matched a server endpoint: Authorization.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+InferEndpointType.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was successfully processed by OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlers+ValidateHostHeader.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ExtractAuthorizationRequestContext was successfully processed by OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlers+ExtractGetOrPostRequest`1[[OpenIddict.Server.OpenIddictServerEvents+ExtractAuthorizationRequestContext, OpenIddict.Server, Version=5.5.0.0, Culture=neutral, PublicKeyToken=35a561290d20de2f]].
[15:11:37 INF] The authorization request was successfully extracted: {
  "client_id": "Console_Blazor",
  "redirect_uri": "https://localhost:44328/authentication/login-callback",
  "response_type": "code",
  "scope": "openid profile Console roles email phone",
  "state": "95d90f996bf443e0b37c08ccdfaa0b0f",
  "code_challenge": "S49hKQxcyPgcvG0BS1xP_JydUXz2NxG2a5dn-vwupPo",
  "code_challenge_method": "S256",
  "prompt": "none",
  "response_mode": "query"
}.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ExtractAuthorizationRequest.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateRequestParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateRequestUriParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateClientIdParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateRedirectUriParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateResponseTypeParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateResponseModeParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateScopeParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateNonceParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidatePromptParameter.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateProofKeyForCodeExchangeParameters.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ValidateAuthenticationDemand.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+EvaluateValidatedTokens.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ResolveValidatedTokens.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ValidateRequiredTokens.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ValidateClientId.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ValidateClientType.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ValidateIdentityToken.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ResolveHostAuthenticationProperties.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessAuthenticationContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+ReformatValidatedTokens.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateAuthentication.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateResponseType.
[15:11:37 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateClientRedirectUri.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateScopes.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateEndpointPermissions.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateGrantTypePermissions.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateResponseTypePermissions.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateScopePermissions.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateProofKeyForCodeExchangeRequirement.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ValidateAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateAuthorizedParty.
[15:11:38 INF] The authorization request was successfully validated.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+ValidateAuthorizationRequest.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+HandleAuthorizationRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+AttachPrincipal.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+HandleAuthorizationRequestContext was successfully processed by OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlers+EnablePassthroughMode`2[[OpenIddict.Server.OpenIddictServerEvents+HandleAuthorizationRequestContext, OpenIddict.Server, Version=5.5.0.0, Culture=neutral, PublicKeyToken=35a561290d20de2f],[OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlerFilters+RequireAuthorizationEndpointPassthroughEnabled, OpenIddict.Server.AspNetCore, Version=5.5.0.0, Culture=neutral, PublicKeyToken=35a561290d20de2f]].
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+HandleAuthorizationRequestContext was marked as skipped by OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlers+EnablePassthroughMode`2[[OpenIddict.Server.OpenIddictServerEvents+HandleAuthorizationRequestContext, OpenIddict.Server, Version=5.5.0.0, Culture=neutral, PublicKeyToken=35a561290d20de2f],[OpenIddict.Server.AspNetCore.OpenIddictServerAspNetCoreHandlerFilters+RequireAuthorizationEndpointPassthroughEnabled, OpenIddict.Server.AspNetCore, Version=5.5.0.0, Culture=neutral, PublicKeyToken=35a561290d20de2f]].
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was successfully processed by OpenIddict.Server.OpenIddictServerHandlers+Authentication+HandleAuthorizationRequest.
[15:11:38 DBG] The event OpenIddict.Server.OpenIddictServerEvents+ProcessRequestContext was marked as skipped by OpenIddict.Server.OpenIddictServerHandlers+Authentication+HandleAuthorizationRequest.
maliming commented 1 day ago

Please share complete request and response logs.

Request finished HTTP/2 GET https://localhost:44352/connect/authorize logs.

zeinali-ali commented 1 day ago

There is no Request finished HTTP/2 GET https://localhost:44352/connect/authorize in logs and also there is no response, that's why it timeout after 10s. it seems it totally skip and ignore the authorize request

zeinali-ali commented 1 day ago

I figured out the problem. I have below IAbpClaimsPrincipalContributor in my app and the AuthenticateAsync cause dead-lock when HttpContext.Request.Headers.Authorization is null or empty and that's because of ForwardIdentityAuthenticationForBearer is setting ForwardDefaultSelector to return null when HttpContext.Request.Headers.Authorization is null or empty

internal class IdentitySessionClaimsPrincipalContributor(IHttpContextAccessor httpContextAccessor) : IAbpClaimsPrincipalContributor, ITransientDependency
{
    public async Task ContributeAsync(AbpClaimsPrincipalContributorContext context)
    {
        var sessionId = Guid.NewGuid();
        bool newSessionCreated = true;
        if (httpContextAccessor.HttpContext is not null)
        {
            var principal = await httpContextAccessor.HttpContext.AuthenticateAsync(IdentityConstants.ApplicationScheme);
            if (principal?.Principal?.GetClaim("p_session_id") is string sessionIdStr)
            {
                sessionId = Guid.Parse(sessionIdStr);
                newSessionCreated = false;
            }
        }

        context.ClaimsPrincipal.Identities.FirstOrDefault()?.AddIfNotContains(new Claim("p_session_id", sessionId.ToString()));

        if (newSessionCreated)
        {
            context.ClaimsPrincipal.Identities.FirstOrDefault()?.AddIfNotContains(new Claim("new_session_created", sessionId.ToString()));
        }
    }
}
maliming commented 1 day ago

ok