search

AzureAD / microsoft-authentication-library-for-java

Microsoft Authentication Library (MSAL) for Java http://aka.ms/aadv2
MIT License
288 stars 144 forks source link

[Bug] AcquireTokenByAuthorizationGrantSupplier failed: Socket Timeout #784

Closed ph33rtehgd closed 8 months ago

ph33rtehgd commented 9 months ago

Library version used

1.13.5

Java version

OpenJDK 8 and Spring 5

Scenario

PublicClient (AcquireTokenInteractive, AcquireTokenByUsernamePassword)

Is this a new or an existing app?

The app is in production, I haven't upgraded MSAL, but started seeing this issue

Issue description and reproduction steps

We're using msal4j to connect to an Azure SQL Server Database through the ActiveDirectoryPassword authentication method. Over the past few months we've been sporadically seeing the below exception occur. This issue is sporadic, it works most of the time but it fails often enough to cause noise in our application.

We've tried numerous things, such as increasing the login timeout on the SQL JDBC connection URL to 30 seconds, increasing the OS nproc/nfile limits, etc. We haven't upgraded the msal4j library to the latest version as of now, but none of the release notes between our version and the latest version seem to indicate that this issue would be resolved. We're not quite sure how to proceed. As far as we're concerned we're not utilizing this library in any odd manner (just using the regular Microsoft SQL JDBC driver in the Spring framework).

2023-08-07 18:15:37.284 [pool-390-thread-1] ERROR c.m.a.m.PublicClientApplication - [Correlation ID: XXXXXXXXXXXXXXXXXXXXX] Execution of class com.microsoft.aad.msal4j.AcquireTokenByAuthorizationGrantSupplier failed. com.microsoft.aad.msal4j.MsalClientException: java.net.SocketTimeoutException: Read timed out at com.microsoft.aad.msal4j.HttpHelper.executeHttpRequest(HttpHelper.java:53) at com.microsoft.aad.msal4j.UserDiscoveryRequest.execute(UserDiscoveryRequest.java:31) at com.microsoft.aad.msal4j.AcquireTokenByAuthorizationGrantSupplier.processPasswordGrant(AcquireTokenByAuthorizationGrantSupplier.java:91) at com.microsoft.aad.msal4j.AcquireTokenByAuthorizationGrantSupplier.execute(AcquireTokenByAuthorizationGrantSupplier.java:43) at com.microsoft.aad.msal4j.AuthenticationResultSupplier.get(AuthenticationResultSupplier.java:69) at com.microsoft.aad.msal4j.AuthenticationResultSupplier.get(AuthenticationResultSupplier.java:18) at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:975) at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:933) at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) at java.io.BufferedInputStream.read1(BufferedInputStream.java:286) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735) at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678) at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1593) at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498) at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480) at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:352) at com.microsoft.aad.msal4j.DefaultHttpClient.readResponseFromConnection(DefaultHttpClient.java:105) at com.microsoft.aad.msal4j.DefaultHttpClient.executeHttpGet(DefaultHttpClient.java:47) at com.microsoft.aad.msal4j.DefaultHttpClient.send(DefaultHttpClient.java:35) at com.microsoft.aad.msal4j.HttpHelper.executeHttpRequestWithRetries(HttpHelper.java:96) at com.microsoft.aad.msal4j.HttpHelper.executeHttpRequest(HttpHelper.java:49) ... 9 common frames omitted

org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is com.microsoft.sqlserver.jdbc.SQLServerException: Failed to authenticate the user USER@DOMAIN in Active Directory (Authentication=ActiveDirectoryPassword). java.net.SocketTimeoutException: Read timed out at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:309) at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400) at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:137) at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:273) at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:82) at org.springframework.batch.repeat.support.TaskExecutorRepeatTemplate$ExecutingRunnable.run(TaskExecutorRepeatTemplate.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Failed to authenticate the user USER@DOMAIN in Active Directory (Authentication=ActiveDirectoryPassword). java.net.SocketTimeoutException: Read timed out at com.microsoft.sqlserver.jdbc.SQLServerMSAL4JUtils.getCorrectedException(SQLServerMSAL4JUtils.java:228) at com.microsoft.sqlserver.jdbc.SQLServerMSAL4JUtils.getSqlFedAuthToken(SQLServerMSAL4JUtils.java:65) at com.microsoft.sqlserver.jdbc.SQLServerConnection.getFedAuthToken(SQLServerConnection.java:4751) at com.microsoft.sqlserver.jdbc.SQLServerConnection.onFedAuthInfo(SQLServerConnection.java:4724) at com.microsoft.sqlserver.jdbc.SQLServerConnection.processFedAuthInfo(SQLServerConnection.java:4680) at com.microsoft.sqlserver.jdbc.TDSTokenHandler.onFedAuthInfo(tdsparser.java:293) at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:125) at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:37) at com.microsoft.sqlserver.jdbc.SQLServerConnection.sendLogon(SQLServerConnection.java:5560) at com.microsoft.sqlserver.jdbc.SQLServerConnection.logon(SQLServerConnection.java:4289) at com.microsoft.sqlserver.jdbc.SQLServerConnection.access$000(SQLServerConnection.java:88) at com.microsoft.sqlserver.jdbc.SQLServerConnection$LogonCommand.doExecute(SQLServerConnection.java:4227) at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7417) at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:3488) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:2978) at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:2628) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:2471) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1470) at com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:915) at org.apache.commons.dbcp2.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:52) at org.apache.commons.dbcp2.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:374) at org.apache.commons.pool2.impl.GenericObjectPool.create(GenericObjectPool.java:565) at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:307) at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:428) at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:232) at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:141) at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:731) at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:265) ... 9 common frames omitted Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.net.SocketTimeoutException: Read timed out at com.microsoft.sqlserver.jdbc.SQLServerMSAL4JUtils.getCorrectedException(SQLServerMSAL4JUtils.java:226) ... 36 common frames omitted Caused by: java.lang.RuntimeException: java.net.SocketTimeoutException: Read timed out at com.microsoft.sqlserver.jdbc.SQLServerMSAL4JUtils.getCorrectedException(SQLServerMSAL4JUtils.java:218) ... 36 common frames omitted

Relevant code snippets

No response

Expected behavior

No response

Identity provider

Azure Active Directory Federation Services (ADFS)

Regression

No response

Solution and workarounds

No response

Avery-Dunn commented 9 months ago

Hello @ph33rtehgd : 'Read time out' generally means the server isn't responding quick enough, and since this is happening sporadically then it's likely an issue with the server and there's not much MSAL can do other than wait longer.

In our 1.13.10 release we actually removed our default HTTP timeouts entirely, so that our library relies entirely on server-side timeouts or ones set by the app developer. You can try updating to at least 1.13.10 in order to avoid read time outs, and you can try adjusting the readTimeoutForDefaultHttpClient param when building your client app if requests end up taking too long (I believe the token service's internal timeouts are either 30 or 60 seconds).

ph33rtehgd commented 9 months ago

Hi @Avery-Dunn Thank you for the response. We were considering upgrading, so we will try that first. If we wanted to adjust the readTimeoutForDefaultHttpClient, how would we go about doing that? We don't directly use msal4j in our application, it is pulled in as a part of the Microsoft sqljdbc package. When we configure the authentication method in the JDBC URL to use ActiveDirectoryPassword this sqljdbc library knows to use msal4j, but there's no where in our application where we are explicitly configuring anything related to it. Part of me is worried there's no way for us to get a handle on this and we'd rely on the sqljdbc team to expose this, but I'm not an expert on this.

Avery-Dunn commented 9 months ago

If you aren't using msal4j directly, then JDBC's timeouts should work once you upgrade msal4j since it will no longer be limited by msal4j's old default timeouts. What JDBC package are you using? mssql-jdbc? If so, it looks like as of 12.6.0.jre8 they started using a more recent msal4j, so upgrading that should also work.

ph33rtehgd commented 9 months ago

@Avery-Dunn Yes, we are using mssql-jdbc. We are using an older version, 9.4.1.jre8., but we are managing the msal4j dependency version independently. Upgrading the jdbc driver will take some more effort, so we will try just the msal4j library first. If that doesn't work we'll look to upgrade the mssql-jdbc driver.

Avery-Dunn commented 8 months ago

Closing due to inactivity. If you're still having issues or have any other questions, feel free to leave a comment or start a new thread.