Bug in com.azure:azure-identity since 1.4.0 causing AccessToken to appear expired in AccessTokenCache

[rudolfbartel]

After upgrade the version of the azure-identity-spring from version 1.8.0 to 1.10.0 we got the problem that sugested the access token would expire immediately. The reason for that ist the change in the MSIToken class in this changeset:
3b57be8

@JsonProperty(value = "expires_on")
@JsonAlias("expires_in")
private String expiresOn;

The added annotation maps the wrong field from the JSON token expires_in to the atribute expiresOn. So the Values is somewhat in the year 1970 which is already expired.

Logs:
...
15.11.2021 12:34:07.555 [ INFO] [main] AzureManager - Fetching EventHubNamespace with name '' ...
15.11.2021 12:34:08.757 [ INFO] [main] ManagedIdentityCredential - Azure Identity => Managed Identity environment: AZURE VM IMDS ENDPOINT
15.11.2021 12:34:08.758 [ INFO] [main] ManagedIdentityCredential - Azure Identity => getToken() result for scopes [https://management.core.windows.net//.default]: SUCCESS
15.11.2021 12:34:08.758 [ INFO] [main] ChainedTokenCredential - Azure Identity => Attempted credential ManagedIdentityCredential returns a token
15.11.2021 12:34:08.759 [ INFO] [main] AccessTokenCache - Acquired a new access token.
15.11.2021 12:34:12.778 [ INFO] [main] AzureManager - Fetching EventHubNamespace with name '' finished in 5 seconds
15.11.2021 12:34:38.796 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => Managed Identity environment: AZURE VM IMDS ENDPOINT
15.11.2021 12:34:38.797 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => getToken() result for scopes [https://management.core.windows.net//.default]: SUCCESS
15.11.2021 12:34:38.798 [ INFO] [parallel-1] ChainedTokenCredential - Azure Identity => Attempted credential ManagedIdentityCredential returns a token
15.11.2021 12:34:38.798 [ INFO] [parallel-1] AccessTokenCache - Acquired a new access token at 1636896542 seconds after expiry. Retry may be attempted after 30 seconds.
15.11.2021 12:35:08.820 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => Managed Identity environment: AZURE VM IMDS ENDPOINT
15.11.2021 12:35:08.821 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => getToken() result for scopes [https://management.core.windows.net//.default]: SUCCESS
15.11.2021 12:35:08.821 [ INFO] [parallel-1] ChainedTokenCredential - Azure Identity => Attempted credential ManagedIdentityCredential returns a token
15.11.2021 12:35:08.821 [ INFO] [parallel-1] AccessTokenCache - Acquired a new access token at 1636896600 seconds after expiry. Retry may be attempted after 30 seconds.
15.11.2021 12:35:09.676 [ INFO] [main] AzureManager - Fetching StorageAccount with name '' ...
15.11.2021 12:35:38.843 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => Managed Identity environment: AZURE VM IMDS ENDPOINT
15.11.2021 12:35:38.843 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => getToken() result for scopes [https://management.core.windows.net//.default]: SUCCESS
15.11.2021 12:35:38.844 [ INFO] [parallel-1] ChainedTokenCredential - Azure Identity => Attempted credential ManagedIdentityCredential returns a token
15.11.2021 12:35:38.844 [ INFO] [parallel-1] AccessTokenCache - Acquired a new access token at 1636896659 seconds after expiry. Retry may be attempted after 30 seconds.
15.11.2021 12:35:39.352 [ INFO] [main] AzureManager - Fetching StorageAccount with name '' finished in 29 seconds
15.11.2021 12:36:08.863 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => Managed Identity environment: AZURE VM IMDS ENDPOINT
15.11.2021 12:36:08.863 [ INFO] [parallel-1] ManagedIdentityCredential - Azure Identity => getToken() result for scopes [https://management.core.windows.net//.default]: SUCCESS
15.11.2021 12:36:08.863 [ INFO] [parallel-1] ChainedTokenCredential - Azure Identity => Attempted credential ManagedIdentityCredential returns a token
15.11.2021 12:36:08.864 [ INFO] [parallel-1] AccessTokenCache - Acquired a new access token at 1636896719 seconds after expiry. Retry may be attempted after 30 seconds.
15.11.2021 12:36:08.952 [ INFO] [main] EventHubTemplate - Started EventHubTemplate with properties: {checkpointConfig=CheckpointConfig{checkpointMode=RECORD, checkpointCount=0, checkpointInterval=null}, startPosition=LATEST}
15.11.2021 12:36:09.388 [ INFO] [main] FunctionConfiguration$FunctionBindingRegistrar - Functional binding is disabled due to the presense of @EnableBinding annotation in your configuration
15.11.2021 12:36:09.456 [ INFO] [main] BeanFactoryAwareFunctionRegistry - Looking up function 'supply' with acceptedOutputTypes: []
15.11.2021 12:36:10.162 [ INFO] [main] EndpointLinksResolver - Exposing 1 endpoint(s) beneath base path '/actuator'
15.11.2021 12:36:10.479 [ INFO] [main] EventDrivenConsumer - Adding {logging-channel-adapter:_org.springframework.integration.errorLogger} as a subscriber to the 'errorChannel' channel
15.11.2021 12:36:10.480 [ INFO] [main] PublishSubscribeChannel - Channel 'ScanService.errorChannel' has 1 subscriber(s).

Here is the test which proves that the wring value is taken:

public class MSITokenTest {
private static final SerializerAdapter SERIALIZER_ADAPTER = JacksonAdapter.createDefaultSerializerAdapter();
private static String result = "{\n" +
" "access_token": "eyJ0eXAi...",\n" +
" "refresh_token": "",\n" +
" "expires_in": "3599",\n" +
" "expires_on": "1506484173",\n" +
" "not_before": "1506480273",\n" +
" "resource": "https://management.azure.com/\",\n" +
" "token_type": "Bearer"\n" +
"}";
@test
public void msiTokenTest() throws IOException {
MSIToken msiToken = SERIALIZER_ADAPTER.deserialize(result, MSIToken.class, SerializerEncoding.JSON);
//Assertions.assertEquals(OffsetDateTime.MAX, msiToken.getExpiresAt());
System.out.println("msiToken: " +msiToken.getExpiresAt());

    MSITokenNoAnnotation msiTokenNoAnnotation = SERIALIZER_ADAPTER.deserialize(result, MSITokenNoAnnotation.class, SerializerEncoding.JSON);
    //Assertions.assertEquals(OffsetDateTime.MAX, msiTokenNoAnnotation.getExpiresAt());
    System.out.println("msiTokeNoAnnotation" + msiTokenNoAnnotation.getExpiresAt());
}

}

The second class is a copy of MSIToken without the added annotation:

public final class MSITokenNoAnnotation extends AccessToken {
private static final OffsetDateTime EPOCH = OffsetDateTime.of(1970, 1, 1, 0, 0, 0, 0, ZoneOffset.UTC);

@JsonProperty(value = "token_type")
private String tokenType;

@JsonProperty(value = "access_token")
private String accessToken;

@JsonProperty(value = "expires_on")
//@JsonAlias("expires_in")
private String expiresOn;

/**
 * Creates an access token instance.
 *
 * @param token the token string.
 * @param expiresOn the expiration time.
 */
@JsonCreator
public MSITokenNoAnnotation(
    @JsonProperty(value = "access_token") String token,
    @JsonProperty(value = "expires_on") String expiresOn) {
    super(token, EPOCH.plusSeconds(parseDateToEpochSeconds(expiresOn)));
    this.accessToken = token;
    this.expiresOn =  expiresOn;
}

@Override
public String getToken() {
    return accessToken;
}

private static Long parseDateToEpochSeconds(String dateTime) {
    ClientLogger logger = new ClientLogger(MSITokenNoAnnotation.class);
    DateTimeFormatter dtf = DateTimeFormatter.ofPattern("M/d/yyyy H:mm:ss XXX").withLocale(Locale.US);
    // This is the format for app service on Windows as of API version 2017-09-01.
    // The format is changed to Unix timestamp in 2019-08-01 but this API version
    // has not been deployed to Linux app services.
    DateTimeFormatter dtfWindows = DateTimeFormatter.ofPattern("M/d/yyyy h:mm:ss a XXX").withLocale(Locale.US);
    try {
        return Long.parseLong(dateTime);
    } catch (NumberFormatException e) {
        logger.verbose(e.getMessage());
    }

    try {
        return Instant.from(dtf.parse(dateTime)).getEpochSecond();
    } catch (DateTimeParseException e) {
        logger.verbose(e.getMessage());
    }

    try {
        return Instant.from(dtfWindows.parse(dateTime)).getEpochSecond();
    } catch (DateTimeParseException e) {
        logger.verbose(e.getMessage());
    }

    throw logger.logExceptionAsError(new IllegalArgumentException("Unable to parse date time " + dateTime));
}

}

The error appears in the AccessTokenCache class wherre the token is validating if it is allready expired (method retrieveToken)

Java version 15.0.2

[pallavit]

Thank you for reporting the issue, @g2vinay can you please investigate.

[g2vinay]

@rudolfbartel Thank you for reporting this issue.
I am investigating this issue and will update here soon.

[rudolfbartel]

@g2vinay Cool, thx

[g2vinay]

@rudolfbartel
This issue should be fixed in 1.4.2 version of azure-identity.
You can upgrade to that version.
Let me know if you see any other problems and we can reopen this issue.

[rudolfbartel]

@g2vinay
Thanks a lot
Yes, I did a test run, so it looks very good. Since this is a transient dependency of azure-identity-spring when this dependency will be adjusted?