Azure / Azure/azure-sdk-for-java
[BUG] [azure-identity] ClientSecretCredential.getTokenSync logs InterruptedException at ERROR — surfaces reactive cancellation as log spam
- Dominant language
- Java
- Stars
- 2.6k
- Forks
- 2.2k
- Avg merge
- 2d 8h
- Merged PRs (30d)
- 178
Description
### Library name
azure-identity
### Library version
1.18.3 (also reproduces on the latest releases I checked — code path unchanged)
### Describe the bug
`ClientSecretCredential.getTokenSync` (and `IdentitySyncClient.authenticateWithConfidentialClient` it delegates to) unconditionally logs `InterruptedException` at **ERROR** level even though `InterruptedException` is a cooperative cancellation signal, not an actual authentication failure.
In a Spring Boot Reactor / Microsoft Graph application running under Kubernetes, this surfaces as a flood of:
```
Azure Identity => ERROR in getToken() call for scopes [https://graph.microsoft.com/.default]: java.lang.InterruptedException
```
during pod scale-down and any other moment when an upstream Reactor subscription is cancelled while the caller thread is mid-call to `getTokenSync`.
### Root cause (from a source trace)
In `sdk/identity/azure-identity/src/main/java/com/azure/identity/implementation/IdentitySyncClient.java` (~line 135):
```java
public AccessToken authenticateWithConfidentialClient(TokenRequestContext request) {
// ...
try {
return new MsalToken(confidentialClient.acquireToken(builder.build()).get());
} catch (InterruptedException | ExecutionException e) {
throw LOGGER.logExceptionAsError(new RuntimeException(e)); // ← logs at ERROR
}
}
```
`CompletableFuture.get()` runs on the **caller's** thread. If the caller's interrupt flag is set while `.get()` is blocking — which is exactly what `reactor.core.scheduler.BoundedElasticScheduler.Worker.dispose()` does when an upstream subscription is cancelled — `Future.get()` throws `InterruptedException` immediately, even though MSAL has done nothing wrong.
That exception is then caught at `ClientSecretCredential.getTokenSync` (~line 137):
```java
} catch (Exception e) {
LoggingUtil.logTokenError(LOGGER, identityClient.getIdentityClientOptions(), request, e);
throw e;
}
```
and logged unconditionally at ERROR via `LoggingUtil.logTokenError`.
Microsoft Graph SDK reaches this path through `microsoft-kiota-authentication-azure`'s `AzureIdentityAccessTokenProvider.getAuthorizationToken` at `creds.getTokenSync(context).getToken()`, which is called synchronously from the request pipeline. So any Reactor cancellation upstream of a Graph call manifests as ERROR-level log noise on the caller thread.
### Why this matters
- Operational dashboards light up during normal pod scale-down — the "errors" aren't real failures; the request will retry on another replica.
- `InterruptedException` is the JVM's standard cooperative-cancellation signal. By every Java convention, it shouldn't be treated as ERROR.
- Downstream wrappers can't suppress the log: it fires inside the SDK's own `try/catch` before any caller can intercept.
### Reproducer (self-contained, ~0.5s)
```java
import ch.qos.logback.classic.*;
import ch.qos.logback.core.read.ListAppender;
import ch.qos.logback.classic.spi.ILoggingEvent;
import com.azure.core.credential.TokenRequestContext;
import com.azure.identity.ClientSecretCredentialBuilder;
import com.sun.net.httpserver.HttpServer;
import java.net.InetSocketAddress;
import java.util.concurrent.atomic.AtomicBoolean;
import org.slf4j.LoggerFactory;
public class Repro {
public static void main(String[] args) throws Exception {
HttpServer slow = HttpServer.create(new InetSocketAddress("127.0.0.1", 0), 0);
slow.createContext("/", ex -> {
try { Thread.sleep(2000); } catch (InterruptedException ignored) {}
ex.sendResponseHeaders(404, -1); ex.close();
});
slow.start();
var appender = new ListAppender();
appender.start();
var sdkLogger = (Logger) LoggerFactory.getLogger("com.azure.identity.ClientSecretCredential");
sdkLogger.addAppender(appender);
sdkLogger.setLevel(Level.ERROR);
var credential = new ClientSecretCredentialBuilder()
.tenantId("11111111-1111-1111-1111-111111111111")
.clientId("22222222-2222-2222-2222-222222222222")
.clientSecret("not-a-real-secret")
.authorityHost("https://127.0.0.1:" + slow.getAddress().getPort() + "/")
.build();
Thread target = Thread.currentThread();
AtomicBoolean stop = new AtomicBoolean();
Thread interrupter = new Thread(() -> {
// Mimic BoundedElasticScheduler.Worker.dispose() interrupting a cancelled worker
while (!stop.get()) {
target.interrupt();
try { Thread.sleep(20); } catch (InterruptedException ignored) {}
}
});
interrupter.setDaemon(true);
interrupter.start();
try {
credential.getTokenSync(new TokenRequestContext()
.addScopes("https://graph.microsoft.com/.default"));
} catch (Throwable ignored) {}
stop.set(true);
Thread.interrupted();
interrupter.join();
slow.stop(0);
appender.list.stream()
.filter(e -> e.getLevel() == Level.ERROR)
.forEach(e -> System.out.println(e.getFormattedMessage()));
}
}
```
Output:
```
Azure Identity => ERROR in getToken() call for scopes [https://graph.microsoft.com/.default]: java.lang.InterruptedException
```
(Note: a single interrupt is absorbed by `getTokenSync`'s cache path silent `catch (Exception e) {}`, so the reproducer keeps interrupting to land on the non-cache `.get()` too. Production conditions match: schedulers typically re-interrupt cancelled workers during disposal.)
### Expected behavior
`InterruptedException` (and any cause containing it) should not be logged at ERROR — it's not an error. Options I'd find acceptable, in rough order of preference:
1. **Special-case it**: skip the `LoggingUtil.logTokenError` call when the cause is `InterruptedException`; just rethrow. Caller can still observe the exception.
```java
} catch (Exception e) {
if (!hasCause(e, InterruptedException.class)) {
LoggingUtil.logTokenError(LOGGER, identityClient.getIdentityClientOptions(), request, e);
}
throw e;
}
```
2. **Demote to DEBUG**: log `InterruptedException` cases at DEBUG instead of ERROR.
3. **Add a configuration knob** so consumers can suppress the log.
Either way, preserving the interrupt flag (`Thread.currentThread().interrupt()`) before rethrowing would also be friendlier to downstream code.
### Workaround
Wrap the credential, override `getTokenSync` to route through the async path (`getToken().block()`), and catch `InterruptedException` before it reaches the SDK's logging path. Documented locally at [datarobot/browser-sharepoint#302](https://github.com/datarobot/browser-sharepoint/pull/302) with a reproducer test at [datarobot/browser-sharepoint#301](https://github.com/datarobot/browser-sharepoint/pull/301).
Happy to open a PR with the upstream fix if the maintainers indicate which of the options above is preferred.
### Setup (`pom.xml`/`build.gradle` and Java version used)
```kotlin
implementation("com.azure:azure-identity:1.18.3")
implementation("com.azure:azure-core:1.58.0")
implementation("com.azure:azure-core-http-okhttp:1.13.4")
implementation("com.microsoft.graph:microsoft-graph:6.64.0") // optional, sync path also reached directly
```
Java 17/21 — behaviour is the same because the bug is in the sync API contract, not the JDK version.
Contributor guide
Assessment
This issue has not been assessed yet.