Base solution for your next web application
Open Closed

IDX10223: Lifetime validation failed #7951

User avatar
0
kasem created

Hi

App in dev mode keeps failing with the following thrown exception:

IDX10223: Lifetime validation failed. The token is expired. ValidTo: '[PII is hidden]', Current time: '[PII is hidden]'.

Go to accepted answer
46 Answer(s)
  • User Avatar
    0
    musa.demir created

    Can you please check if your AccessTokenExpiration has so small time? Its located in *.Application.Shared-> AppConsts.cs

  • User Avatar
    0
    kasem created

    Thanks for your feedback.

    I have the following values:

    public static TimeSpan AccessTokenExpiration = TimeSpan.FromDays(1); public static TimeSpan RefreshTokenExpiration = TimeSpan.FromDays(365);

    I'm getting this (in dev) multiple times a day. Fixing this requires closing browser and restarting app.

    Note: I've been struggling a crash on production without any logs. Do you think this can be related?

  • User Avatar
    0
    musa.demir created

    What is your abp version? What is your zero version? It is angular project or mvc?

    And additionally, can you please share an error screenshot with more detail?

  • User Avatar
    0
    kasem created

    AspNetCore + Angular v7.2.3

  • User Avatar
    0
    maliming created
    Support Team

    @kasem

    Can you please share an error screenshot & error stack with more detail?

  • User Avatar
    0
    kasem created

    Hi!

    Sorry for the late reply. Attaching the requested

    It turns out that this a very serious problem as it's related to many tickets I created here that haven't been closed yet. It wasn't clear that this problem is serious to that extent. The side-effect of this problem is seriously impacting my production app due to many related crashes happening everyday. I've recently discovered that crashes in production are happening with users leaving app idle for sometime (~30min) exactly as it happens to me in development mode. Appreciate your support to help fixing this urgently.

    Stack trace: at Microsoft.IdentityModel.Tokens.Validators.ValidateLifetime(Nullable1 notBefore, Nullable1 expires, SecurityToken securityToken, TokenValidationParameters validationParameters) at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateLifetime(Nullable1 notBefore, Nullable1 expires, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters) at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters) at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken) at MyApp.Web.Authentication.JwtBearer.MyAppJwtSecurityTokenHandler.ValidateToken(String securityToken, TokenValidationParameters validationParameters, SecurityToken& validatedToken) in C:\code\MyApp\aspnet-core\src\MyApp.Web.Core\Authentication\JwtBearer\MyAppJwtSecurityTokenHandler.cs:line 40 at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.<HandleAuthenticateAsync>d__6.MoveNext()

  • User Avatar
    0
    maliming created
    Support Team

    Even if this exception occurs, by default it won't cause the app to crash, it just appears in the log.

    Does this exception cause a server internal error in a production environment?

    Is it possible to reproduce this problem using Zero's Demo project?

  • User Avatar
    0
    musa.demir created

    It is normal if you get that error several times and your app goes back to the login page, because the angular project does several async calls to the server and if any of them return 401 client project returns to the login page. So your server can get several requests whose token was expired that's why you can get that error multiple times. But then it should go back to the login page.

  • User Avatar
    0
    kasem created

    Thank you for your feedback.

    The problem that this exception doesn't only redirects to login. It requires resetting browser cache or closing the whole browser after re-executing app. It happens to me locally but my users in production reported the same case. App crashes for them when it's idle for sometime. I can't see this exception in log maybe because it's sort of an unhandled exception so it's swallowed up by the system.

  • User Avatar
    0
    maliming created
    Support Team

    hi kasem Is it possible to reproduce this problem in a short time? For example, 30 seconds idle?

  • User Avatar
    0
    kasem created

    Hi @maliming

    I can't reproduce in 30seconds. It takes more time and I don't know the exact time. I feel like 30+mins

  • User Avatar
    0
    kasem created

    I was able to reproduce now. I launched the backend in debugging mode and I run frontend 32min later (npm start)

  • User Avatar
    0
    kasem created

    Attaching the validatedToken if it helps:

    {{"alg":"HS256","typ":"JWT"}.{"http://schemas.xmlsoap.org/ws/2005/05/identity/claims/nameidentifier":"9","http://schemas.xmlsoap.org/ws/2005/05/identity/claims/name":"admin","AspNet.Identity.SecurityStamp":"SQCXBUYKAOGSPZ6AKQV2TOC5ZXE3X6NI","http://schemas.microsoft.com/ws/2008/06/identity/claims/role":["Admin"],"http://www.aspnetboilerplate.com/identity/claims/tenantId":"2","Application_StudyYearId":"4","sub":"9","jti":"400fd00d-3479-43da-82e0-e4f6c65bd538","iat":1574614578,"token_validity_key":"62d29227-3ce2-4e67-9395-3c68044d9c30","user_identifier":"9@2","token_type":"0","nbf":1574614578,"exp":1574700978,"iss":"MyApp","aud":"MyApp"}}

  • User Avatar
    0
    ismcagdas created
    Support Team

    Hi @kasem

    Is this the main cause of your problem ? At least do you think like that ? We can investigate according to this.

  • User Avatar
    0
    kasem created

    Hi @ismcagdas

    Many cases are pointing to this one but I'm not 100% sure. It's a problem that worths investigating I think since I encounter it many times in debugging and users in production started complaining about a similar case

  • User Avatar
    0
    musa.demir created

    Hi @karen Can you share a demo project which contains that problem?

  • User Avatar
    0
    kasem created

    Hi @demirmusa

    I'm sorry I can't provide a demo project. As I understood @ismcagdas is working to try reproducing and fixing the problem. Does this override the previous state of this ticket and demo is really blocking you now?

  • User Avatar
    0
    musa.demir created

    Solving problem would be faster if there is a demo project to reproduce it.

  • User Avatar
    0
    muhittincelik created

    I have the same problem. I am restarting app and browser but nothing changed.

  • User Avatar
    0
    maliming created
    Support Team

    hi muhittincelik

    Can you share a demo project which contains that problem?

  • User Avatar
    0
    muhittincelik created

    i ran your last release without any code addition. core 3+angular

    ran your application and npm start, open your browser and login, wait 1 day.

  • User Avatar
    0
    maliming created
    Support Team

    I simulated everyone's problem by modifying the date of the system after the user logged in to angular, but the application was as expected, the response returned http 401, and angular redirected to the login page.

    INFO  2019-12-13 11:39:25,835 [5    ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 GET http://localhost:22742/api/services/app/Edition/GetEditions  
INFO  2019-12-13 11:39:25,835 [5    ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful.
INFO  2019-12-13 11:39:25,884 [5    ] uthentication.JwtBearer.JwtBearerHandler - Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenExpiredException: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '12/06/2019 03:37:19', Current time: '12/13/2019 03:39:25'.
   at Microsoft.IdentityModel.Tokens.Validators.ValidateLifetime(Nullable`1 notBefore, Nullable`1 expires, SecurityToken securityToken, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateLifetime(Nullable`1 notBefore, Nullable`1 expires, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
   at MyCompanyName.AbpZeroTemplate.Web.Authentication.JwtBearer.AbpZeroTemplateJwtSecurityTokenHandler.ValidateToken(String securityToken, TokenValidationParameters validationParameters, SecurityToken& validatedToken) in D:\Github\volo\aspnet-zero-core\aspnet-core\src\MyCompanyName.AbpZeroTemplate.Web.Core\Authentication\JwtBearer\AbpZeroTemplateJwtSecurityTokenHandler.cs:line 40
   at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
INFO  2019-12-13 11:39:25,884 [5    ] uthentication.JwtBearer.JwtBearerHandler - Bearer was not authenticated. Failure message: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '12/06/2019 03:37:19', Current time: '12/13/2019 03:39:25'.
DEBUG 2019-12-13 11:39:25,991 [56   ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
INFO  2019-12-13 11:39:25,996 [5    ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 GET http://localhost:22742/.well-known/openid-configuration  
INFO  2019-12-13 11:39:25,998 [5    ] Server4.Hosting.IdentityServerMiddleware - Invoking IdentityServer endpoint: IdentityServer4.Endpoints.DiscoveryEndpoint for /.well-known/openid-configuration
INFO  2019-12-13 11:39:25,999 [5    ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 3.7872000000000003ms 200 application/json; charset=UTF-8
INFO  2019-12-13 11:39:26,038 [5    ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 GET http://localhost:22742/.well-known/openid-configuration/jwks  
INFO  2019-12-13 11:39:26,041 [5    ] Server4.Hosting.IdentityServerMiddleware - Invoking IdentityServer endpoint: IdentityServer4.Endpoints.DiscoveryKeyEndpoint for /.well-known/openid-configuration/jwks
INFO  2019-12-13 11:39:26,041 [5    ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 3.1260000000000003ms 200 application/jwk-set+json; charset=UTF-8
INFO  2019-12-13 11:39:26,146 [20   ] uthentication.JwtBearer.JwtBearerHandler - Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenInvalidSignatureException: IDX10503: Signature validation failed. Keys tried: 'Microsoft.IdentityModel.Tokens.RsaSecurityKey, KeyId: '121bf32a6b07cdc4c121fab45edfff44', InternalId: '562b04ce-676a-446b-8183-923c2425fd53'. , KeyId: 121bf32a6b07cdc4c121fab45edfff44
'.
Exceptions caught:
 'System.NotSupportedException: IDX10634: Unable to create the SignatureProvider.
Algorithm: 'HS256', SecurityKey: 'Microsoft.IdentityModel.Tokens.RsaSecurityKey, KeyId: '121bf32a6b07cdc4c121fab45edfff44', InternalId: '562b04ce-676a-446b-8183-923c2425fd53'.'
 is not supported. The list of supported algorithms is available here: https://aka.ms/IdentityModel/supported-algorithms
   at Microsoft.IdentityModel.Tokens.CryptoProviderFactory.CreateSignatureProvider(SecurityKey key, String algorithm, Boolean willCreateSignatures)
   at Microsoft.IdentityModel.Tokens.CryptoProviderFactory.CreateForVerifying(SecurityKey key, String algorithm)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(Byte[] encodedBytes, Byte[] signature, SecurityKey key, String algorithm, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(String token, TokenValidationParameters validationParameters)
'.
token: '{"alg":"HS256","typ":"JWT"}.{"sub":"1","name":"admin","AspNet.Identity.SecurityStamp":"2NJTSQYWMBUMFV7QOQKE7FDMEG74AYSK","role":"Admin","jti":"03382578-8e96-4a12-ba83-f78055f39d35","iat":1575517039,"token_validity_key":"585e1064-5e69-41ea-9439-74dd7ab35042","user_identifier":"1","token_type":"0","nbf":1575517039,"exp":1575603439,"iss":"AbpZeroTemplate","aud":"AbpZeroTemplate"}'.
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(String token, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
   at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
INFO  2019-12-13 11:39:26,146 [20   ] uthentication.JwtBearer.JwtBearerHandler - IdentityBearerIdentityServerAuthenticationJwt was not authenticated. Failure message: IDX10503: Signature validation failed. Keys tried: 'Microsoft.IdentityModel.Tokens.RsaSecurityKey, KeyId: '121bf32a6b07cdc4c121fab45edfff44', InternalId: '562b04ce-676a-446b-8183-923c2425fd53'. , KeyId: 121bf32a6b07cdc4c121fab45edfff44
'.
Exceptions caught:
 'System.NotSupportedException: IDX10634: Unable to create the SignatureProvider.
Algorithm: 'HS256', SecurityKey: 'Microsoft.IdentityModel.Tokens.RsaSecurityKey, KeyId: '121bf32a6b07cdc4c121fab45edfff44', InternalId: '562b04ce-676a-446b-8183-923c2425fd53'.'
 is not supported. The list of supported algorithms is available here: https://aka.ms/IdentityModel/supported-algorithms
   at Microsoft.IdentityModel.Tokens.CryptoProviderFactory.CreateSignatureProvider(SecurityKey key, String algorithm, Boolean willCreateSignatures)
   at Microsoft.IdentityModel.Tokens.CryptoProviderFactory.CreateForVerifying(SecurityKey key, String algorithm)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(Byte[] encodedBytes, Byte[] signature, SecurityKey key, String algorithm, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(String token, TokenValidationParameters validationParameters)
'.
token: '{"alg":"HS256","typ":"JWT"}.{"sub":"1","name":"admin","AspNet.Identity.SecurityStamp":"2NJTSQYWMBUMFV7QOQKE7FDMEG74AYSK","role":"Admin","jti":"03382578-8e96-4a12-ba83-f78055f39d35","iat":1575517039,"token_validity_key":"585e1064-5e69-41ea-9439-74dd7ab35042","user_identifier":"1","token_type":"0","nbf":1575517039,"exp":1575603439,"iss":"AbpZeroTemplate","aud":"AbpZeroTemplate"}'.
INFO  2019-12-13 11:39:26,146 [20   ] tion.IdentityServerAuthenticationHandler - IdentityBearer was not authenticated. Failure message: IDX10503: Signature validation failed. Keys tried: 'Microsoft.IdentityModel.Tokens.RsaSecurityKey, KeyId: '121bf32a6b07cdc4c121fab45edfff44', InternalId: '562b04ce-676a-446b-8183-923c2425fd53'. , KeyId: 121bf32a6b07cdc4c121fab45edfff44
'.
Exceptions caught:
 'System.NotSupportedException: IDX10634: Unable to create the SignatureProvider.
Algorithm: 'HS256', SecurityKey: 'Microsoft.IdentityModel.Tokens.RsaSecurityKey, KeyId: '121bf32a6b07cdc4c121fab45edfff44', InternalId: '562b04ce-676a-446b-8183-923c2425fd53'.'
 is not supported. The list of supported algorithms is available here: https://aka.ms/IdentityModel/supported-algorithms
   at Microsoft.IdentityModel.Tokens.CryptoProviderFactory.CreateSignatureProvider(SecurityKey key, String algorithm, Boolean willCreateSignatures)
   at Microsoft.IdentityModel.Tokens.CryptoProviderFactory.CreateForVerifying(SecurityKey key, String algorithm)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(Byte[] encodedBytes, Byte[] signature, SecurityKey key, String algorithm, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(String token, TokenValidationParameters validationParameters)
'.
token: '{"alg":"HS256","typ":"JWT"}.{"sub":"1","name":"admin","AspNet.Identity.SecurityStamp":"2NJTSQYWMBUMFV7QOQKE7FDMEG74AYSK","role":"Admin","jti":"03382578-8e96-4a12-ba83-f78055f39d35","iat":1575517039,"token_validity_key":"585e1064-5e69-41ea-9439-74dd7ab35042","user_identifier":"1","token_type":"0","nbf":1575517039,"exp":1575603439,"iss":"AbpZeroTemplate","aud":"AbpZeroTemplate"}'.
INFO  2019-12-13 11:39:26,146 [20   ] tCore.Cors.Infrastructure.CorsMiddleware - No CORS policy found for the specified request.
INFO  2019-12-13 11:39:26,147 [20   ] ft.AspNetCore.Routing.EndpointMiddleware - Executing endpoint 'MyCompanyName.AbpZeroTemplate.Editions.EditionAppService.GetEditions (MyCompanyName.AbpZeroTemplate.Application)'
INFO  2019-12-13 11:39:26,149 [20   ] c.Infrastructure.ControllerActionInvoker - Route matched with {area = "app", action = "GetEditions", controller = "Edition"}. Executing controller action with signature System.Threading.Tasks.Task`1[Abp.Application.Services.Dto.ListResultDto`1[MyCompanyName.AbpZeroTemplate.Editions.Dto.EditionListDto]] GetEditions() on controller MyCompanyName.AbpZeroTemplate.Editions.EditionAppService (MyCompanyName.AbpZeroTemplate.Application).
WARN  2019-12-13 11:39:26,466 [20   ] Mvc.Authorization.AbpAuthorizationFilter - Abp.Authorization.AbpAuthorizationException: Current user did not login to the application!
   at Abp.Authorization.AuthorizationHelper.AuthorizeAsync(IEnumerable`1 authorizeAttributes)
   at Abp.Authorization.AuthorizationHelper.CheckPermissionsAsync(MethodInfo methodInfo, Type type)
   at Abp.Authorization.AuthorizationHelper.AuthorizeAsync(MethodInfo methodInfo, Type type)
   at Abp.AspNetCore.Mvc.Authorization.AbpAuthorizationFilter.OnAuthorizationAsync(AuthorizationFilterContext context)
Abp.Authorization.AbpAuthorizationException: Current user did not login to the application!
   at Abp.Authorization.AuthorizationHelper.AuthorizeAsync(IEnumerable`1 authorizeAttributes)
   at Abp.Authorization.AuthorizationHelper.CheckPermissionsAsync(MethodInfo methodInfo, Type type)
   at Abp.Authorization.AuthorizationHelper.AuthorizeAsync(MethodInfo methodInfo, Type type)
   at Abp.AspNetCore.Mvc.Authorization.AbpAuthorizationFilter.OnAuthorizationAsync(AuthorizationFilterContext context)
INFO  2019-12-13 11:39:26,466 [20   ] c.Infrastructure.ControllerActionInvoker - Authorization failed for the request at filter 'Abp.AspNetCore.Mvc.Authorization.AbpAuthorizationFilter'.
INFO  2019-12-13 11:39:26,466 [20   ] .Mvc.Infrastructure.ObjectResultExecutor - Executing ObjectResult, writing value of type 'Abp.Web.Models.AjaxResponse'.
INFO  2019-12-13 11:39:26,467 [20   ] c.Infrastructure.ControllerActionInvoker - Executed action MyCompanyName.AbpZeroTemplate.Editions.EditionAppService.GetEditions (MyCompanyName.AbpZeroTemplate.Application) in 317.9118ms
INFO  2019-12-13 11:39:26,467 [20   ] ft.AspNetCore.Routing.EndpointMiddleware - Executed endpoint 'MyCompanyName.AbpZeroTemplate.Editions.EditionAppService.GetEditions (MyCompanyName.AbpZeroTemplate.Application)'
INFO  2019-12-13 11:39:26,467 [20   ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 632.0074000000001ms 401 application/json; charset=utf-8
  • User Avatar
    0
    muhittincelik created 
    DEBUG 2019-12-02 14:29:49,513 [24 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
DEBUG 2019-12-02 14:29:54,580 [20 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
DEBUG 2019-12-02 14:29:59,649 [23 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
INFO 2019-12-02 14:30:03,276 [24 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 OPTIONS http://localhost:22742/AbpUserConfiguration/GetAll?d=1575286203265
INFO 2019-12-02 14:30:03,290 [24 ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful.
INFO 2019-12-02 14:30:03,300 [24 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 23.6981ms 204
INFO 2019-12-02 14:30:03,306 [24 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 GET http://localhost:22742/AbpUserConfiguration/GetAll?d=1575286203265 application/json
INFO 2019-12-02 14:30:03,306 [24 ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful.
INFO 2019-12-02 14:32:08,624 [24 ] uthentication.JwtBearer.JwtBearerHandler - Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenExpiredException: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]', Current time: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
GetCurrentLoginInformations() on controller Smart.Sessions.SessionAppService (Smart.Application).
DEBUG 2019-12-02 14:32:58,968 [35 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
DEBUG 2019-12-02 14:32:59,026 [29 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
INFO 2019-12-02 14:32:59,150 [35 ] .Mvc.Infrastructure.ObjectResultExecutor - Executing ObjectResult, writing value of type 'Abp.Web.Models.AjaxResponse'.
INFO 2019-12-02 14:32:59,177 [35 ] c.Infrastructure.ControllerActionInvoker - Executed action Smart.Sessions.SessionAppService.GetCurrentLoginInformations (Smart.Application) in 242.1742ms
INFO 2019-12-02 14:32:59,177 [35 ] ft.AspNetCore.Routing.EndpointMiddleware - Executed endpoint 'Smart.Sessions.SessionAppService.GetCurrentLoginInformations (Smart.Application)'
INFO 2019-12-02 14:32:59,178 [35 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 48856.624800000005ms 200 application/json; charset=utf-8
DEBUG 2019-12-02 14:32:59,223 [20 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
DEBUG 2019-12-02 14:33:04,122 [39 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
INFO 2019-12-02 14:33:07,790 [39 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 OPTIONS http://localhost:22742/AbpUserConfiguration/GetAll?d=1575286387785
INFO 2019-12-02 14:33:07,792 [39 ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful.
INFO 2019-12-02 14:33:07,796 [39 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 4.7914ms 204
INFO 2019-12-02 14:33:07,823 [39 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 GET http://localhost:22742/AbpUserConfiguration/GetAll?d=1575286387785 application/json
INFO 2019-12-02 14:33:07,823 [39 ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful.
DEBUG 2019-12-02 14:36:13,492 [29 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
INFO 2019-12-02 14:36:13,494 [39 ] uthentication.JwtBearer.JwtBearerHandler - Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenExpiredException: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]', Current time: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
at Microsoft.IdentityModel.Tokens.Validators.ValidateLifetime(Nullable`1 notBefore, Nullable`1 expires, SecurityToken securityToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateLifetime(Nullable`1 notBefore, Nullable`1 expires, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
at Smart.Web.Authentication.JwtBearer.SmartJwtSecurityTokenHandler.ValidateToken(String securityToken, TokenValidationParameters validationParameters, SecurityToken& validatedToken) in D:\Fide\Projeler\Smart Inventory V8.0.0\Core\src\Smart.Web.Core\Authentication\JwtBearer\SmartJwtSecurityTokenHandler.cs:line 40
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
INFO 2019-12-02 14:36:13,495 [39 ] uthentication.JwtBearer.JwtBearerHandler - Bearer was not authenticated. Failure message: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]', Current time: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
INFO 2019-12-02 14:36:13,495 [39 ] ft.AspNetCore.Routing.EndpointMiddleware - Executing endpoint 'Abp.AspNetCore.Mvc.Controllers.AbpUserConfigurationController.GetAll (Abp.AspNetCore)'
DEBUG 2019-12-02 14:36:26,124 [43 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
INFO 2019-12-02 14:36:33,926 [39 ] c.Infrastructure.ControllerActionInvoker - Route matched with {action = "GetAll", controller = "AbpUserConfiguration", area = ""}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.JsonResult] GetAll() on controller Abp.AspNetCore.Mvc.Controllers.AbpUserConfigurationController (Abp.AspNetCore). DEBUG 2019-12-02 14:36:35,257 [44 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null DEBUG 2019-12-02 14:36:42,761 [42 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null INFO 2019-12-02 14:36:46,256 [20 ] tonsoftJson.NewtonsoftJsonResultExecutor - Executing JsonResult, writing value of type 'Abp.Web.Models.AjaxResponse'. INFO 2019-12-02 14:36:46,298 [6 ] c.Infrastructure.ControllerActionInvoker - Executed action Abp.AspNetCore.Mvc.Controllers.AbpUserConfigurationController.GetAll (Abp.AspNetCore) in 12370.986700000001ms INFO 2019-12-02 14:36:46,298 [6 ] ft.AspNetCore.Routing.EndpointMiddleware - Executed endpoint 'Abp.AspNetCore.Mvc.Controllers.AbpUserConfigurationController.GetAll (Abp.AspNetCore)' INFO 2019-12-02 14:36:46,298 [6 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 218475.90730000002ms 200 application/json; charset=utf-8 INFO 2019-12-02 14:36:46,355 [29 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 OPTIONS http://localhost:22742/api/services/app/Session/GetCurrentLoginInformations INFO 2019-12-02 14:36:46,355 [29 ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful. INFO 2019-12-02 14:36:46,356 [29 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 1.2573ms 204 INFO 2019-12-02 14:36:46,362 [29 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request starting HTTP/1.1 GET http://localhost:22742/api/services/app/Session/GetCurrentLoginInformations INFO 2019-12-02 14:36:46,363 [29 ] pNetCore.Cors.Infrastructure.CorsService - CORS policy execution successful. DEBUG 2019-12-02 14:37:26,264 [36 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null INFO 2019-12-02 14:37:26,266 [29 ] uthentication.JwtBearer.JwtBearerHandler - Failed to validate the token. Microsoft.IdentityModel.Tokens.SecurityTokenExpiredException: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]', Current time: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. at Microsoft.IdentityModel.Tokens.Validators.ValidateLifetime(Nullable`1 notBefore, Nullable`1 expires, SecurityToken securityToken, TokenValidationParameters validationParameters) at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateLifetime(Nullable`1 notBefore, Nullable`1 expires, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters) at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters) at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken) at Smart.Web.Authentication.JwtBearer.SmartJwtSecurityTokenHandler.ValidateToken(String securityToken, TokenValidationParameters validationParameters, SecurityToken& validatedToken) in D:\Fide\Projeler\Smart Inventory V8.0.0\Core\src\Smart.Web.Core\Authentication\JwtBearer\SmartJwtSecurityTokenHandler.cs:line 40 at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync() INFO 2019-12-02 14:37:26,268 [29 ] uthentication.JwtBearer.JwtBearerHandler - Bearer was not authenticated. Failure message: IDX10223: Lifetime validation failed. The token is expired. ValidTo: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]', Current time: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. INFO 2019-12-02 14:37:26,269 [29 ] ft.AspNetCore.Routing.EndpointMiddleware - Executing endpoint 'Smart.Sessions.SessionAppService.GetCurrentLoginInformations (Smart.Application)' INFO 2019-12-02 14:37:26,275 [29 ] c.Infrastructure.ControllerActionInvoker - Route matched with {area = "app", action = "GetCurrentLoginInformations", controller = "Session"}. Executing controller action with signature System.Threading.Tasks.Task`1[Smart.Sessions.Dto.GetCurrentLoginInformationsOutput] GetCurrentLoginInformations() on controller Smart.Sessions.SessionAppService (Smart.Application).
INFO 2019-12-02 14:37:26,581 [44 ] .Mvc.Infrastructure.ObjectResultExecutor - Executing ObjectResult, writing value of type 'Abp.Web.Models.AjaxResponse'.
INFO 2019-12-02 14:37:26,582 [44 ] c.Infrastructure.ControllerActionInvoker - Executed action Smart.Sessions.SessionAppService.GetCurrentLoginInformations (Smart.Application) in 306.5673ms
INFO 2019-12-02 14:37:26,582 [44 ] ft.AspNetCore.Routing.EndpointMiddleware - Executed endpoint 'Smart.Sessions.SessionAppService.GetCurrentLoginInformations (Smart.Application)'
INFO 2019-12-02 14:37:26,583 [44 ] Microsoft.AspNetCore.Hosting.Diagnostics - Request finished in 40220.9236ms 200 application/json; charset=utf-8
DEBUG 2019-12-02 14:37:31,499 [48 ] HttpRequestEntityChangeSetReasonProvider - Unable to get URL from HttpRequest, fallback to null
  • User Avatar
    0
    muhittincelik created

  • User Avatar
    0
    musa.demir created

    Hi @muhittincelik is that ok if I connect your pc and check that error via teamviewer?

  • User Avatar
    0
    muhittincelik created

    [email protected] a webex meeting daveti gönderdim.

  • User Avatar
    0
    maliming created
    Support Team

    hi muhittincelik

    Did you enable Identity Server4?

    When you run the application using the Start without Debugging method, I believe the application will run as expected, except that the above log may be included in the log.

  • User Avatar
    0
    kasem created

    What do you mean by Start without Debugging ? How can I do this?

  • User Avatar
    0
    BobIngham created

    I can confirm that this is a problem. Here is a screen shot of Application Insights from my Azure production system. my logs are written direct to Application Insights and not to text file.... I am currently trying to reduce exceptions in my logs, can someone advise accordingly?

  • User Avatar
    0
    musa.demir created

    Hi @bobingham, As i mentioned here : 39f1b34bb292 it is normal if the page redirect back to login page after get 401. Is it going back to login ?

  • User Avatar
    0
    musa.demir created

    What do you mean by Start without Debugging ? How can I do this?

  • User Avatar
    0
    BobIngham created

    Hi @demimursa, We seem to be using exception to handle programming flow. Let me give a simple example. I want to oursource the support of my system to a third party. One of the things this out-sourcing company will do is to check HTTP 500 errors and report them back to me. At the moment it is not possible to monitor HTTP 500 errors with Zero because the error log is full of exceptions such as "wrong password" and "token expired". These are not exceptions and should not be handled as such. So, I have to order my out-sourcing company to ignore exceptions because 99.5% of them are not actually exceptions: Failed login and token expired should both be warnings at best. And, moreover, as I said, this is a production system. Am I supposed to trace each exception back to the user and find out if they were redirected to the login page? The following issues would address the problem to some extent, they have all been on the backlog for months. Silent refresh token for JWT Session lock screen User lockout

  • User Avatar
    0
    musa.demir created

    Login failed returns Http 401 unauthorized error (which is totaly correct http result code in this case) If you think there is something unexpected please open new issue. Then we can continue to discussion on new issue.

  • User Avatar
    0
    BobIngham created

    @demirmusa, Forgive my ignorance. Why is a 401 reported as an exception?

  • User Avatar
    0
    musa.demir created

    @bobingham https://developer.mozilla.org/en-US/docs/Web/HTTP/Status/401

  • User Avatar
    0
    BobIngham created

    @demimursa, I stand corrected but flummoxed as to why a 401 should be considered as an exception, it's a user error not a system error. Can anypone throw any light on this?

  • User Avatar
    0
    musa.demir created

    It is not a user error. It is generated by that line AbpZeroTemplateJwtSecurityTokenHandler.cs#L40 when any endpoint gets request with an expired token. Then the requested endpoint returns http 401 response to says to the client you are unauthorized.

  • User Avatar
    0
    BobIngham created

    Because the user has left open the system in the browser or has entered an incorrect password. In a large system this happens so often that it is extremely difficult to find exceptions thrown by the system as a result of cose error.

  • User Avatar
    0
    ismcagdas created
    Support Team

    Hi @bobingham

    Sorry but this is not a decision that we can make. HTTP 401 is accepted as an error code. Do you mean we should throw any other error when the token is expired ?

  • User Avatar
    1
    BobIngham created

    Hi @ismcagdas, Ok, I hear what you're saying. At the moment I'm up to my ears trying to feed my logs into Sumo Logic. Once I'm done I may be to reach out and see if I can filter out these types of erros as exceptions in the end solution. Can we leave this item as open and I will revert when I know more.

  • User Avatar
    0
    ashishani created

    Hi, I am having the same issue. I am a recent client who uses v8.0.0

    However, the reason I am currently investigating this issue is that I suspect it is causing some data leak which causes my app to reach the maximum number of connections in the pool "100 connections". This forces me to restart the application in IIS.

    The reason for me to think that the error in this Question is the cause, I am suspecting that there is a unit of work within that scope and it doesn't execute "uow.Complete();" to close the DB Connection.

    I am not sure it is the cause, but this is the error I get and it always happen the same time when the token get expired.

    System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. at Microsoft.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection) at Microsoft.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource1 retry, DbConnectionOptions userOptions) at Microsoft.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry) at Microsoft.Data.SqlClient.SqlConnection.Open() at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnection(Boolean errorsExpected) at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected) at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.BeginTransaction(IsolationLevel isolationLevel) at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func3 operation, Func3 verifySucceeded) at Microsoft.EntityFrameworkCore.RelationalDatabaseFacadeExtensions.BeginTransaction(DatabaseFacade databaseFacade, IsolationLevel isolationLevel) at Abp.EntityFrameworkCore.Uow.DbContextEfCoreTransactionStrategy.CreateDbContext[TDbContext](String connectionString, IDbContextResolver dbContextResolver) at Abp.EntityFrameworkCore.Uow.EfCoreUnitOfWork.GetOrCreateDbContext[TDbContext](Nullable1 multiTenancySide, String name) at Abp.EntityFrameworkCore.Repositories.EfCoreRepositoryBase3.get_Table() at Abp.EntityFrameworkCore.Repositories.EfCoreRepositoryBase3.Insert(TEntity entity) at Abp.EntityFrameworkCore.Repositories.EfCoreRepositoryBase`3.InsertAsync(TEntity enti...

    This is how my log looks like:

  • User Avatar
    0
    ismcagdas created
    Support Team

    @ashishani Do you still have this problem ?

    Thanks,

  • User Avatar
    0
    ashishani created

    Hi @ismcagdas, Yes it is still happening and it is hard to spot the location of the database connection leak. My app reaches the limit of SQL connections (100 open connections) every couple of days. At the moment I do restart IIS almost everyday to kill the open DB connections until I identify the scope of problem. I did a code review and added a UnitOfWork using statement and made sure that I complete the UnitOfWork in the end, like this:

            using (var unitOfWork = _unitOfWorkManager.Begin())
        {
            ... some code
            
            await unitOfWork.CompleteAsync();
        }

    I do have 2 DBContexts each one accessing a different database to migrate list of customers, products and other type of data every day. Not sure if it can be relavent.

    Other scope that I am suspecting to be the cause is an exception when validating tokens. There is a Salesforce App that consumes my .Net Core 3 API. I am also using Angular 8. I noticed that there are lots of Token validation throwing an exception because the token used is expired. I am just suspecing that this may be a scope which has a unit of work and the exception doesn't allow the unit of work to complete (Maybe?)

    I am trying to think of an approach to identify the source. I am open for suggestions.

    Thanks, Ali

  • User Avatar
    0
    ismcagdas created
    Support Team

    Hi @ashishani

    Thank you for the extra information. Do you have any "async void" methods ?

  • User Avatar
    0
    ashishani created

    Hi @ismcagdas, yes I do. like the example below:

    public async Task DeleteAdjustmentMap(EntityDto<int> input)
{
    var allAdjustmentMaps = _adjustmentMapRepository.GetAll();
    
    ... some code...
    
    await _adjustmentMapRepository.DeleteAsync(adjustmentMap);
}

    Your question reminded me of an issue that I fixed recently. It could be the cause but let me confirm with you first.

    The bug was that I have an async method to delete records and and I used to call it without the key-word await. of course the DBContext was not happy sometimes, and I had an exception (sometimes) at that scope because I am using the same DBContext in 2 threads. I just rememberd that I only deployed that fix in production few days ago. I didn't see the error yet because I restart IIS everyday.

    The code before fixing the bug looked like this:

    var opportunityLineItemIdsToDelete = (from l in allOpportunityLineItems
                                                              where l.OpportunityId == opportunityOutput.Id
                                                              && !opportunityLineItemReferences.Contains(l.LineItemReference)
                                                              select l.Id).ToList();

if (opportunityLineItemIdsToDelete.Count() > 0)
{
    **_ = DeleteOpportunityLineItemsRelatedEntities(opportunityLineItemIdsToDelete, true);**
}

    after fixing the bug, the code looked like this:

    var opportunityLineItemIdsToDelete = (from l in allOpportunityLineItems
                                                              where l.OpportunityId == opportunityOutput.Id
                                                              && !opportunityLineItemReferences.Contains(l.LineItemReference)
                                                              select l.Id).ToList();

if (opportunityLineItemIdsToDelete.Count() > 0)
{
    **await DeleteOpportunityLineItemsRelatedEntities(opportunityLineItemIdsToDelete, true);**
}

    Would that lead to the leak issue? I stopped restarting the server so I can see the error if it happens.

    Sorry, most probably the issue I was having is not relevant to the Lifetime validation failed.

    Thanks

  • User Avatar
    0
    ismcagdas created
    Support Team

    Hi @ashishani

    Sorry for my late reply. Your method is good because it is async Task, not async void.

    Yes, it might be the cause. Not using await can cause such problems. I also think your problem is not related to token lifetime validation. You can create a new issue if you face same problem again.

    Thanks.

Assignee
No one
Labels
Non yet