AccessTokenLifetime doesn't expire if ValidationMode = ValidationEndpoint

[mandm-pt]

Issue

I have configured the AccessTokenLifetime to expire after 9 seconds. In my web api project if I specify the ValidationMode = ValidationEndpoint, the token is accepted even after the 9 seconds. If I change the mode to Local or Both after the 9 seconds the token is rejected.

An additional thing that I detected was, if I set the ValidationMode = ValidationEndpoint, every time I try to access the webapi I see the call from web api to Identity server (introspect endpoint). If I change to Both I never see that call, even if the token is valid or invalid.

I'm using latest Identity Server 3.

Clients Config:

new Client
{
    ClientName = "Custom Grant Client",
    ClientId = "customgrant.client",
    Flow = Flows.Custom,
    ClientSecrets = new List<Secret>
    {
        new Secret("secret".Sha256())
    },
    AllowedScopes = new List<string>
    {
        "read", "write", "offline_access",
    },
    AllowedCustomGrantTypes = new List<string>
    {
        "custom"
    },
    AccessTokenLifetime = 9,
}

Relevant parts of the log file

Console log:

[10:08:29 WRN] AuthorizationCodeStore not configured - falling back to InMemory
[10:08:29 WRN] TokenHandleStore not configured - falling back to InMemory
[10:08:29 WRN] ConsentStore not configured - falling back to InMemory
[10:08:29 WRN] RefreshTokenStore not configured - falling back to InMemory
identityserver up and running....
[10:08:34 INF] Start token request
[10:08:34 DBG] Start client validation
[10:08:34 DBG] Start parsing Basic Authentication secret
[10:08:34 DBG] Parser found secret: BasicAuthenticationSecretParser
[10:08:34 INF] Secret id found: customgrant.client
[10:08:34 DBG] Cache miss: customgrant.client
[10:08:34 DBG] Secret validator success: HashedSharedSecretValidator
[10:08:34 INF] Client validation success
[10:08:34 INF] Start token request validation
[10:08:34 INF] Start validation of custom grant token request
[10:08:34 DBG] Cache miss: read,write
[10:08:34 INF] Validation of custom grant token request success
[10:08:34 INF] Token request validation success
 {
  "ClientId": "customgrant.client",
  "ClientName": "Custom Grant Client",
  "GrantType": "custom",
  "Scopes": "read write",
  "Raw": {
    "grant_type": "custom",
    "scope": "read write",
    "custom_credential": "custom credential"
  }
}
[10:08:34 INF] Creating token response
[10:08:34 INF] Processing token request
[10:08:34 DBG] Creating access token
[10:08:34 DBG] Creating JWT access token
[10:08:34 INF] End token request
[10:08:34 INF] Returning token response.
[10:09:07 INF] Start introspection request
[10:09:07 DBG] Start scope validation
[10:09:07 DBG] Start parsing Basic Authentication secret
[10:09:07 DBG] Parser found secret: BasicAuthenticationSecretParser
[10:09:07 INF] Secret id found: write
[10:09:07 DBG] Cache miss: write
[10:09:07 DBG] Secret validator success: HashedSharedSecretValidator
[10:09:07 INF] Scope validation success
[10:09:07 INF] Start access token validation
[10:09:07 DBG] Cache hit: customgrant.client
[10:09:07 DBG] Cache hit: customgrant.client
[10:09:07 INF] Token validation success
{
  "ValidateLifetime": true,
  "AccessTokenType": "Jwt",
  "Claims": {
    "iss": "http://localhost:44333/core",
    "aud": "http://localhost:44333/core/resources",
    "exp": "1463735323",
    "nbf": "1463735314",
    "client_id": "customgrant.client",
    "scope": [
      "read",
      "write"
    ],
    "sub": "818727",
    "auth_time": "1463735314",
    "idp": "idsrv",
    "amr": "custom"
  }
}
[10:09:07 INF] Creating introspection response
[10:09:07 INF] Creating restricted introspection response for active token.

Fiddler log:

Call API Raw request

GET http://localhost:2727/identity HTTP/1.1
Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6ImEzck1VZ01Gdjl0UGNsTGE2eUYzekFrZnF1RSIsImtpZCI6ImEzck1VZ01Gdjl0UGNsTGE2eUYzekFrZnF1RSJ9.eyJpc3MiOiJodHRwOi8vbG9jYWxob3N0OjQ0MzMzL2NvcmUiLCJhdWQiOiJodHRwOi8vbG9jYWxob3N0OjQ0MzMzL2NvcmUvcmVzb3VyY2VzIiwiZXhwIjoxNDYzNzM1MzIzLCJuYmYiOjE0NjM3MzUzMTQsImNsaWVudF9pZCI6ImN1c3RvbWdyYW50LmNsaWVudCIsInNjb3BlIjpbInJlYWQiLCJ3cml0ZSJdLCJzdWIiOiI4MTg3MjciLCJhdXRoX3RpbWUiOjE0NjM3MzUzMTQsImlkcCI6Imlkc3J2IiwiYW1yIjpbImN1c3RvbSJdfQ.N6MPnugC8l5A-Og2kr6x-5PeIfZamNE-9XkSr69DatiwpsD4IJEIpuzp0fzyzgI_226DljTSYn18D8iPPE7UWL_KYDOTcHM7oJOpfFUFbjXDLprEyYuS4QzJssa-PDnlbh6ys_xu8QVNBoLfoeBPLrU5nbKv6HzzVP69q4iufDtDA1AjFh0jfaRESt8HZ3XlfR4NLOv8U0YK0FPqWngwfnctzO8KENa4dysFRgE4LYlpHnKh6SxscoyoAgyqA2xA3vpD_YvBYvAfSOYR95vz3fhtZgnvr4i8OE45uGNsA1SGDiX-_MRNVJhgfHNwS36jQCDdN9-ln2iHbev2jFctZw
Host: localhost:2727

introspect Raw Request

POST http://localhost:44333/core/connect/introspect HTTP/1.1
Accept: application/json
Authorization: Basic d3JpdGU6c2VjcmV0
Content-Type: application/x-www-form-urlencoded
Host: localhost:44333
Content-Length: 808
Expect: 100-continue
Connection: Keep-Alive

token=eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6ImEzck1VZ01Gdjl0UGNsTGE2eUYzekFrZnF1RSIsImtpZCI6ImEzck1VZ01Gdjl0UGNsTGE2eUYzekFrZnF1RSJ9.eyJpc3MiOiJodHRwOi8vbG9jYWxob3N0OjQ0MzMzL2NvcmUiLCJhdWQiOiJodHRwOi8vbG9jYWxob3N0OjQ0MzMzL2NvcmUvcmVzb3VyY2VzIiwiZXhwIjoxNDYzNzM1MzIzLCJuYmYiOjE0NjM3MzUzMTQsImNsaWVudF9pZCI6ImN1c3RvbWdyYW50LmNsaWVudCIsInNjb3BlIjpbInJlYWQiLCJ3cml0ZSJdLCJzdWIiOiI4MTg3MjciLCJhdXRoX3RpbWUiOjE0NjM3MzUzMTQsImlkcCI6Imlkc3J2IiwiYW1yIjpbImN1c3RvbSJdfQ.N6MPnugC8l5A-Og2kr6x-5PeIfZamNE-9XkSr69DatiwpsD4IJEIpuzp0fzyzgI_226DljTSYn18D8iPPE7UWL_KYDOTcHM7oJOpfFUFbjXDLprEyYuS4QzJssa-PDnlbh6ys_xu8QVNBoLfoeBPLrU5nbKv6HzzVP69q4iufDtDA1AjFh0jfaRESt8HZ3XlfR4NLOv8U0YK0FPqWngwfnctzO8KENa4dysFRgE4LYlpHnKh6SxscoyoAgyqA2xA3vpD_YvBYvAfSOYR95vz3fhtZgnvr4i8OE45uGNsA1SGDiX-_MRNVJhgfHNwS36jQCDdN9-ln2iHbev2jFctZw

introspect Raw Response

HTTP/1.1 200 OK
Cache-Control: no-store, no-cache, max-age=0, private
Pragma: no-cache
Content-Length: 253
Content-Type: application/json; charset=utf-8
Server: Microsoft-HTTPAPI/2.0
Date: Fri, 20 May 2016 09:09:07 GMT

{"iss":"http://localhost:44333/core","aud":"http://localhost:44333/core/resources","exp":"1463735323","nbf":"1463735314","client_id":"customgrant.client","sub":"818727","auth_time":"1463735314","idp":"idsrv","amr":"custom","active":true,"scope":"write"}

[brockallen]

This might be due to clock skew -- I forget where/if we have that in there. Is there any point in time where it does get rejected?

[mandm-pt]

I've tested this again, If I change the clock to +/- 7 minutes ahead, the token is considered invalid. I was trying to debug the project System.IdentityModel.Tokens.Jwt, which is the responsible to validate the token but I couldn't, I can't breakpoint inside "ValidateToken".

Here's other sample:

Token

eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6ImEzck1VZ01Gdjl0UGNsTGE2eUYzekFrZnF1RSIsImtpZCI6ImEzck1VZ01Gdjl0UGNsTGE2eUYzekFrZnF1RSJ9.eyJpc3MiOiJodHRwOi8vbG9jYWxob3N0OjQ0MzMzL2NvcmUiLCJhdWQiOiJodHRwOi8vbG9jYWxob3N0OjQ0MzMzL2NvcmUvcmVzb3VyY2VzIiwiZXhwIjoxNDY0MzQ5OTUwLCJuYmYiOjE0NjQzNDk5NDEsImNsaWVudF9pZCI6ImN1c3RvbWdyYW50LmNsaWVudCIsInNjb3BlIjpbIm9mZmxpbmVfYWNjZXNzIiwicmVhZCIsIndyaXRlIl0sInN1YiI6IjgxODcyNyIsImF1dGhfdGltZSI6MTQ2NDM0OTk0MSwiaWRwIjoiaWRzcnYiLCJhbXIiOlsiY3VzdG9tIl19.NSZVgLMavDB1qzuS2H9pIG5Iin-iztHEmrnvWAEp8IQ51M4XQ5ycMvFAJ9XYnWZize5hAcd2cs4yNnX76o4nFDPTR3zqlnEffIwntut0X3Jcmh-kYfm9kN3paFOIvcjejvWzQX_Ip3JMVFrxvYxdYmTNuMDM8nvTVVHyWaH2sZ2Fh4wQhNfMECaUkIMtBiTjMQGVyuwwTH6PRZZTCZaW1rnYd9oG9OLvAUfI6ECaQSz94GMkgUJEDjlq-ftr84C_2Sel5mBOcRk-XR-Gg36rXo9QRk8pyS8xekQkMKoM4kYRRcDwonRHee88MNv5X-G3ak7JGZ3s8nKHNcMLDzinHw

Here's the exception that I'm getting:

IDX10223: Lifetime validation failed. The token is expired.
ValidTo: '05/27/2016 11:52:30'
Current time: '05/27/2016 11:59:50'.

So even in the exception it says that is valid to 11:52:30, but if I change the clock to 11:55:00 is valid!

[mandm-pt]

Ok so I finally manage how to debug System.IdentityModel.Tokens.Jwt.

It has: public static readonly TimeSpan DefaultClockSkew = TimeSpan.FromSeconds(300); // 5 min.

Ok, so this explains the token validation.

But what about the other "issue" when I set the ValidationMode = ValidationEndpoint, every time I try to access the webapi I see the call from web api to Identity server (introspect endpoint). If I change to Both I never see that call, even if the token is valid or invalid.

[brockallen]

ValidationEndpoint means always call to IdSvr to validate and (even if it's a JWT). If it's Both then the middleware detects if it's a JWT or not. If it's a JWT then it does local validation.