JWT builder time issue

[c00crane]

The JWT builder tests use an app that allows the test cases that call it to pass is various token attributes. The app uses the set methods to update the “builder” with those values. Then, it creates a token from that builder.
We’re seeing an issue where the iat and exp are being modified - When the test cases to to validate that the token contains the correct information, the times are not matching.

The test cases do the following:

1. Get the current time - set iat to that, and exp to the current time + expiration time
2. Invokes the builder app
   1. The builder app creates a builder
   2. Runs all of the set api’s that the test requested (if any - none means we’re just using the builder config from the server.xml)
   3. Invokes .buildJwt()
   4. Invokes a test method called outputHeader (this method calls compact on the JwtToken created by buildJwt() - it then pulls the header from the token string, decodes it to get attributes and finally prints each attribute (for the test case to later validate)
   5. Invokes a test method called outputClaims to invoke .getClaims() and each of the get method apis on those claims and logs the claims and their values. Let’s say iat is 1601666766 and exp is 1601673966. The method also logs the claims JSON string ie: {"sub”:”xxxx”,”iss":"https://10.239.29.yyy:8920/jwt/jwkEnabled","token_type":"Bearer","exp":1601673966,"iat":1601666766}
   6. Invokes .compact() (token from step 3)
   7. I’ve added code to take the jwtTokenString produced in step 6, parse it and log the contents. The payload contents for iat and exp don’t match what we just recorded using the apis. Ie: {"token_type":"Bearer","sub”:”xxxx”,”iss":"https://10.239.29.yyy:8920/jwt/jwkEnabled","exp":1601673965,"iat":1601666765}
3. The test case will compare the iat and exp that it created before the test against the values in the token (before values <= token value <= token value + fudge factor). That validation works
4. The test case then tries to take the iat and exp from the payload and compare that against the values logged by the test as (as those are the values from the token). We do this to make sure the api’s are recording the correct info. This is where things blow up as they don’t match.

Even though the test isn’t getting a match, you can see that things were already out of sync in the app (between steps 5 & 7).
Many of the api’s that the test app invokes end up invoking populateClaims which updates the time attributes.

I’ve rearranged the steps, so, now, we’ve “built the JWT” and done the compact before I try to log anything - I ran the test several times and thought that this would resolve the test issue, but, on run #5, it failed in the same way.
Old -> New step order:

1. -> 1.
2. -> 2.
3. -> 3.
4. -> 6.
5. -> 5.
6. -> 4.
7. -> 7.
   The time difference is negligible, and I don’t think it matters with regard to the use of the tokens generated, but we should understand what’s causing it before making a final decision.

[c00crane]

[10/02/2020 14:26:06:178 CDT] 001 CommonFatLoggingUtils JwkEndpointValidationUrlTests_ I Response (Full): ******************* Start of jwtbuilderclient/JwtBuilderSetApisClient output *******************
configId: jwkEnabled
attrs: {"sub":"testuser"}
JsonAttrs: {"sub":"testuser"}
Claim: iss: https://10.239.29.102:8920/jwt/jwkEnabled
Claim: sub: testuser
Claim: aud: null
Claim: exp: 1601673966
Claim: nbf: -1
Claim: iat: 1601666766
Claim: jti: null
Claim: azp: null
Claim: JSON: {"sub":"testuser","iss":"https://10.239.29.102:8920/jwt/jwkEnabled","token_type":"Bearer","exp":1601673966"iat":1601666766}
Claim: JSON: getAllClaims: Key: sub Value: testuser
Claim: JSON: getAllClaims: Key: iss Value: https://10.239.29.102:8920/jwt/jwkEnabled
Claim: JSON: getAllClaims: Key: token_type Value: Bearer
Claim: JSON: getAllClaims: Key: exp Value: 1601673966
Claim: JSON: getAllClaims: Key: iat Value: 1601666766
Header: JSON: {"kid":"SgagmSTdCRO2YMKrbubR","typ":"JWT","alg":"RS256"}
Header: JSON Header: Key: kid Value: SgagmSTdCRO2YMKrbubR
Header: JSON Header: Key: typ Value: JWT
Header: JSON Header: Key: alg Value: RS256
DebugJSON: {"kid":"SgagmSTdCRO2YMKrbubR","typ":"JWT","alg":"RS256"}
DebugJSON: {"token_type":"Bearer","sub":"testuser","iss":"https://10.239.29.102:8920/jwt/jwkEnabled","exp":1601673965,"iat":1601666765}
Built JWT Token: eyJraWQiOiJTZ2FnbVNUZENSTzJZTUtyYnViUiIsInR5cCI6IkpXVCIsImFsZyI6IlJTMjU2In0.eyJ0b2tlbl90eXBlIjoiQmVhcmVyIiwic3ViIjoidGVzdHVzZXIiLCJpc3MiOiJodHRwczovLzEwLjIzOS4yOS4xMDI6ODkyMC9qd3QvandrRW5hYmxlZCIsImV4cCI6MTYwMTY3Mzk2NSwiaWF0IjoxNjAxNjY2NzY1fQ.D6IuODDdCx45xGG8lDaqBFtgsvcIWRr-l3Uxy3CrpPrXjg2R_t_ZomCebE5L4KcLiCQgcz6GjM6Hr4M0BY3nU6epbumeGOS6CYWTPuPA7m2xn96eqZsCkAJ_X7l9vt9tFfZ8W7AB6GX4R242kEK5pwMqZcKF_E4FfT1-9vV8HoVFOkyHzFkN2_7ICmZOeWgox-UwK3CL9MpoY7NYmccdQRTHejcAQWqBE7J5lpPUBhK0LsMpMY1EgUVfnFxU3lWj499ARxQvASfKDhSDm6-dPD1VXeR2KstLPq5AT4qLBzj12boXXUxqqtK0R4atRmHAZemlQDAJsYOB8gNrtrzEZw
******************* End of JWTBuilderClient output *******************

[c00crane]

https://ibm.box.com/s/2edwwp2ne5rikwcpvi679szhx61k8fs2

[ayoho]

I'm actually going to close this issue because it was for a bug in code that we haven't delivered yet (the initial drop of JWE support). Once I open that PR, I'll link it here.