Azure / EasyAuthForK8s

Easily add Azure AD Authentication to any app running on Kubernetes
MIT License
67 stars 15 forks source link

HTTP 500 when using Bearer token to call protected endpoint #68

Closed ioeifcss closed 2 years ago

ioeifcss commented 2 years ago

I have an endpoint protected using the latest release of EasyAuthForK8S

When using a cookie, I am able to reach the endpoint without issues

When enabling bearer token mode and using a Bearer token to make the same call, I get an HTTP 500 in Postman and in my SPA.

I'm not really sure how to debug the issue, but I did capture the following from the easyauth pod logs:

{"EventId":2,"LogLevel":"Information","Category":"Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler","Message":"Successfully validated the token.","State":{"Message":"Successfully validated the token.","{OriginalFormat}":"Successfully validated the token."}} 

{"EventId":8,"LogLevel":"Debug","Category":"Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler","Message":"AuthenticationScheme: Bearer was successfully authenticated.","State":{"Message":"AuthenticationScheme: Bearer was successfully authenticated.","AuthenticationScheme":"Bearer","{OriginalFormat}":"AuthenticationScheme: {AuthenticationScheme} was successfully authenticated."}} 

{"EventId":0,"LogLevel":"Information","Category":"EasyAuthForK8s.Web.EasyAuthMiddleware","Message":"Invoke HandleAuth - Path:/easyauth/auth, Query:, AuthCookie: False, AuthHeader: True","State":{"Message":"Invoke HandleAuth - Path:/easyauth/auth, Query:, AuthCookie: False, AuthHeader: True","{OriginalFormat}":"Invoke HandleAuth - Path:/easyauth/auth, Query:, AuthCookie: False, AuthHeader: True"}} 

{"EventId":9,"LogLevel":"Debug","Category":"Microsoft.AspNetCore.Authentication.Cookies.CookieAuthenticationHandler","Message":"AuthenticationScheme: Cookies was not authenticated.","State":{"Message":"AuthenticationScheme: Cookies was not authenticated.","AuthenticationScheme":"Cookies","{OriginalFormat}":"AuthenticationScheme: {AuthenticationScheme} was not authenticated."}} 

{"EventId":8,"LogLevel":"Debug","Category":"Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler","Message":"AuthenticationScheme: Bearer was successfully authenticated.","State":{"Message":"AuthenticationScheme: Bearer was successfully authenticated.","AuthenticationScheme":"Bearer","{OriginalFormat}":"AuthenticationScheme: {AuthenticationScheme} was successfully authenticated."}} 

{"EventId":1,"LogLevel":"Debug","Category":"Microsoft.AspNetCore.Authorization.DefaultAuthorizationService","Message":"Authorization was successful.","State":{"Message":"Authorization was successful.","{OriginalFormat}":"Authorization was successful."}} 

{"EventId":0,"LogLevel":"Information","Category":"EasyAuthForK8s.Web.EasyAuthMiddleware","Message":"Returning Status202Accepted. AuthZ success: Subject  is authorized.","State":{"Message":"Returning Status202Accepted. AuthZ success: Subject  is authorized.","{OriginalFormat}":"Returning Status202Accepted. AuthZ success: Subject  is authorized."}} 

{"EventId":1,"LogLevel":"Error","Category":"Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware","Message":"An unhandled exception has occurred while executing the request.","Exception":"System.InvalidOperationException: Invalid non-ASCII or control character in header: 0x003A    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpHeaders.ThrowInvalidHeaderCharacter(Char ch)    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpHeaders.ValidateHeaderNameCharacters(String headerCharacters)    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpResponseHeaders.AddValueUnknown(String key, StringValues value)    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpResponseHeaders.AddValueFast(String key, StringValues value)    at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpHeaders.System.Collections.Generic.IDictionary\u003CSystem.String,Microsoft.Extensions.Primitives.StringValues\u003E.Add(String key, StringValues value)    at EasyAuthForK8s.Web.Models.ModelExtensions.\u003CAppendResponseHeaders\u003Eg__addHeader|6_0(String name, String value, \u003C\u003Ec__DisplayClass6_0\u0026 ) in /app/EasyAuthForK8s.Web/Models/ModelExtensions.cs:line 190    at EasyAuthForK8s.Web.Models.ModelExtensions.AppendResponseHeaders(UserInfoPayload payload, IHeaderDictionary headers, EasyAuthConfigurationOptions configOptions) in /app/EasyAuthForK8s.Web/Models/ModelExtensions.cs:line 226    at EasyAuthForK8s.Web.EasyAuthMiddleware.HandleAuth(HttpContext context) in /app/EasyAuthForK8s.Web/EasyAuthMiddleWare.cs:line 232    at EasyAuthForK8s.Web.EasyAuthMiddleware.InvokeAsync(HttpContext context) in /app/EasyAuthForK8s.Web/EasyAuthMiddleWare.cs:line 58    at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)    at EasyAuthForK8s.Web.EasyAuthBuilderExtensions.\u003C\u003Ec.\u003C\u003CUseEasyAuthForK8s\u003Eb__1_0\u003Ed.MoveNext() in /app/EasyAuthForK8s.Web/EasyAuthBuilderExtensions.cs:line 104 --- End of sta ck trace from previous location ---    at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.\u003CInvoke\u003Eg__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)","State":{"Message":"An unhandled exception has occurred while executing the request.","{OriginalFormat}":"An unhandled exception has occurred while executing the request."}} 

{"EventId":0,"LogLevel":"Error","Category":"EasyAuthEvents","Message":"Error: Invalid non-ASCII or control character in header: 0x003A, TraceId: 0HMF77EPCJG49:00000002, Status: 500","State":{"Message":"Error: Invalid non-ASCII or control character in header: 0x003A, TraceId: 0HMF77EPCJG49:00000002, Status: 500","{OriginalFormat}":"Error: Invalid non-ASCII or control character in header: 0x003A, TraceId: 0HMF77EPCJG49:00000002, Status: 500"}} 

Any thoughts what might be causing this invalid character to come from?

jonlester commented 2 years ago

If you have a tool like fiddler available, is it possible to capture the headers that your client is sending in the request? If you don't want to post it here, I can give you an email address to send it to.

ioeifcss commented 2 years ago

Please provide an email address and I'll capture the headers from Postman and my single page app send them both to you

jonlester commented 2 years ago

jon.lester@microsoft.com

ioeifcss commented 2 years ago

Hi Jon. Any chance you've been able to look into this?

ioeifcss commented 2 years ago

OK, I've been debugging the codebase to try and get to the bottom of this.

So far, I've modified ModelExtensions.cs to add some debug lines


    internal static void AppendResponseHeaders(this UserInfoPayload payload, IHeaderDictionary headers,
        EasyAuthConfigurationOptions configOptions, ILogger logger)
    {
        if (headers == null)
        {
            return;
        }

        void addHeader(string name, string value)
        {
            string headerName = SanitizeHeaderName($"{configOptions.ResponseHeaderPrefix}{name}");
            string encodedValue = EncodeValue(value, configOptions.ClaimEncodingMethod);

            logger.LogInformation($"[DEBUG] Raw name is [{name}] and parsed name is [{headerName}]");
            logger.LogInformation($"[DEBUG] Raw value is [{value}] and parsed value is [{encodedValue}]");

            //nginx will only forward the first header of a given name,
            //so we must combine them into a single comma-delimited value
            if (headers.ContainsKey(headerName))
            {
                logger.LogInformation("[DEBUG] headers.ContainsKey is TRUE");
                headers[headerName] = string.Concat(headers[headerName], "|", encodedValue);
            }
            else
            {
                logger.LogInformation("[DEBUG] headers.ContainsKey is FALSE");
                headers.Add(headerName, encodedValue);
            }
        };

        if (configOptions.HeaderFormatOption == EasyAuthConfigurationOptions.HeaderFormat.Combined)
        {
            string serialized = JsonSerializer.Serialize<UserInfoPayload>(payload);
            addHeader("userinfo", serialized);
        }

        else
        {
            addHeader("name", payload.name);
            addHeader("oid", payload.oid);
            addHeader("preferred-username", payload.preferred_username);
            addHeader("sub", payload.sub);
            addHeader("tid", payload.tid);
            addHeader("email", payload.email);
            addHeader("groups", payload.groups);
            addHeader("scp", payload.scp);

            foreach (ClaimValue claim in payload.otherClaims)
            {
                addHeader(claim.name, claim.value);
            }

            foreach (string role in payload.roles)
            {
                addHeader("roles", role);
            }

            foreach (string graph in payload.graph)
            {
                addHeader("graph", graph);
            }
        }
    }

The output from those debug lines is fairly benign, but the final debug triplet looks to be the culprit:

[DEBUG] Raw name is [http://schemas.xmlsoap.org/ws/2005/05/identity/claims/nameidentifier] and parsed name is [x-injected-http://schemas.xmlsoap.org/ws/2005/05/identity/claims/nameidentifier]

[DEBUG] Raw value is [iaNEmI...F2V7L1ExY] and parsed value is [iaNEmI...F2V7L1ExY]

[DEBUG] headers.ContainsKey is FALSE

In other words, I think the culprit is x-injected-http://schemas.xmlsoap.org/ws/2005/05/identity/claims/nameidentifier

This would also tally up with the details in my first post which mentions

Invalid non-ASCII or control character in header: 0x003A

and 0x003A is unicode hex for :

My next question is therefore, where is this nameidentifier property coming from? Is it because I've misconfigured my app registration or is it because of how our AAD instance is setup (on-premises AD synced to AAD)?

jonlester commented 2 years ago

@ioeifcss Thank you for your help on this. The fact that you are syncing identities from on-prem wasn't the direct cause of this, but it did help expose a regression bug because it introduced a claim name that we hadn't tested with before.