azure-sdk-for-java
azure-sdk-for-java copied to clipboard
Azure
[BUG] Azure SQL ActiveDirectoryManagedIdentity authentication with sleuth
Describe the bug Our Spring Boot 2.18 application, utilizing the spring-boot-starter-data-jpa, is configured with the mssql-jdbc version 12.6.1.jre11, azure-identity version 1.12.0, msal4j version 1.15.0, spring-cloud-starter-sleuth version 3.1.11 dependencies. Java version 11
The application, dockerized with the base image openjdk:11, is earmarked for deployment on Azure Kubernetes Service (AKS). A crucial requirement mandates that the application establish a connection to Azure SQL utilizing ActiveDirectoryManagedIdentity authentication.
Interestingly, the application connects to the database successfully in the absence of the spring-cloud-starter-sleuth dependency. However, upon its inclusion, the application encounters a freezing behavior(Doesn't connect to db and no exceptions in log).
Exception or Stack Trace I've reproduced Managed Identity behavior on my environment, by putting environment variables. I noticed several blocked threads, that I think responsible for bug. Print here thread trace:
`"main" #1 prio=5 os_prio=31 cpu=1854.71ms elapsed=1248.18s tid=0x000000014300cc00 nid=0x1803 waiting on condition [0x000000016f307000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
- parking to wait for <0x00000005d0007bd8> (a java.util.concurrent.CountDownLatch$Sync)
at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:211)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire([email protected]/AbstractQueuedSynchronizer.java:715)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly([email protected]/AbstractQueuedSynchronizer.java:1047)
at java.util.concurrent.CountDownLatch.await([email protected]/CountDownLatch.java:230)
at reactor.core.publisher.BlockingOptionalMonoSubscriber.blockingGet(BlockingOptionalMonoSubscriber.java:108)
at reactor.core.publisher.Mono.blockOptional(Mono.java:1787)
at com.microsoft.sqlserver.jdbc.SQLServerSecurityUtility.getManagedIdentityCredAuthToken(SQLServerSecurityUtility.java:353)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.getFedAuthToken(SQLServerConnection.java:6014)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.onFedAuthInfo(SQLServerConnection.java:5963)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.processFedAuthInfo(SQLServerConnection.java:5797)
at com.microsoft.sqlserver.jdbc.TDSTokenHandler.onFedAuthInfo(tdsparser.java:322)
at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:130)
at com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:42)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.sendLogon(SQLServerConnection.java:6855)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.logon(SQLServerConnection.java:5402)
at com.microsoft.sqlserver.jdbc.SQLServerConnection$LogonCommand.doExecute(SQLServerConnection.java:5334)
at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7739)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:4384)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:3823)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:3348)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:3179)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1953)
at com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:1263)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:121)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476)
at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112)
- locked <0x00000005d00b8810> (a com.zaxxer.hikari.HikariDataSource)
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess.obtainConnection(JdbcEnvironmentInitiator.java:181)
at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:68)
at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:35)
at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:101)
- locked <0x00000005cfc09620> (a org.hibernate.boot.registry.internal.StandardServiceRegistryImpl)
at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:272)
at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:246)
at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:223)
- locked <0x00000005cfc09620> (a org.hibernate.boot.registry.internal.StandardServiceRegistryImpl)
at org.hibernate.id.factory.internal.DefaultIdentifierGeneratorFactory.injectServices(DefaultIdentifierGeneratorFactory.java:175)
at org.hibernate.service.internal.AbstractServiceRegistryImpl.injectDependencies(AbstractServiceRegistryImpl.java:295)
at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:252)
at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:223)
- locked <0x00000005cfc09620> (a org.hibernate.boot.registry.internal.StandardServiceRegistryImpl)
at org.hibernate.boot.internal.InFlightMetadataCollectorImpl.<init>(InFlightMetadataCollectorImpl.java:173)
at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.complete(MetadataBuildingProcess.java:127)
at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.metadata(EntityManagerFactoryBuilderImpl.java:1460)
at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1494)
at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:58)
at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365)
at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:409)
at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:396)
at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:341)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1863)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1800)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)
at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$334/0x00000070002e36e0.getObject(Unknown Source)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
- locked <0x00000005c0c02488> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1168)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:919)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:591)
- locked <0x00000005c0da5b40> (a java.lang.Object)
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:147)
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:732)
at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:409)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:308)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1300)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1289)
at com.luxoft.demoservice.DemoServiceApplication.main(DemoServiceApplication.java:11)
"ForkJoinPool.commonPool-worker-1" #25 daemon prio=5 os_prio=31 cpu=25.30ms elapsed=1239.41s tid=0x0000000141a3e800 nid=0x9e03 waiting for monitor entry [0x0000000173fdc000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.getSingletonFactoryBeanForTypeCheck(AbstractAutowireCapableBeanFactory.java:1006)
- waiting to lock <0x00000005c0c02488> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.getTypeForFactoryBean(AbstractAutowireCapableBeanFactory.java:907)
at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:637)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doGetBeanNamesForType(DefaultListableBeanFactory.java:583)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:542)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:527)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:520)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveNamedBean(DefaultListableBeanFactory.java:1230)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveBean(DefaultListableBeanFactory.java:494)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBean(DefaultListableBeanFactory.java:349)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBean(DefaultListableBeanFactory.java:342)
at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1186)
at org.springframework.cloud.sleuth.internal.LazyBean.getOrError(LazyBean.java:79)
at org.springframework.cloud.sleuth.internal.LazyBean.get(LazyBean.java:59)
at org.springframework.cloud.sleuth.instrument.reactor.ReactorSleuth.lambda$scopePassingOnScheduleHook$7(ReactorSleuth.java:323)
at org.springframework.cloud.sleuth.instrument.reactor.ReactorSleuth$$Lambda$556/0x00000070004deb10.apply(Unknown Source)
at reactor.core.scheduler.Schedulers.onSchedule(Schedulers.java:1017)
at reactor.core.scheduler.Schedulers.directSchedule(Schedulers.java:1380)
at reactor.core.scheduler.ParallelScheduler.schedule(ParallelScheduler.java:243)
at reactor.core.scheduler.Schedulers$CachedScheduler.schedule(Schedulers.java:1308)
at reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.signalCached(MonoCacheTime.java:320)
at reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.onNext(MonoCacheTime.java:354)
at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839)
at reactor.core.publisher.MonoCallable.subscribe(MonoCallable.java:62)
at reactor.core.publisher.MonoCacheTime.subscribeOrReturn(MonoCacheTime.java:143)
at reactor.core.publisher.Mono.subscribe(Mono.java:4475)
at reactor.core.publisher.Mono.subscribeWith(Mono.java:4605)
at reactor.core.publisher.Mono.toFuture(Mono.java:5010)
at com.azure.identity.implementation.IdentityClientBase.lambda$getManagedIdentityConfidentialClient$3(IdentityClientBase.java:424)
at com.azure.identity.implementation.IdentityClientBase$$Lambda$1047/0x000000700082fcb8.apply(Unknown Source)
at com.microsoft.aad.msal4j.AcquireTokenByAppProviderSupplier.fetchTokenUsingAppTokenProvider(AcquireTokenByAppProviderSupplier.java:75)
at com.microsoft.aad.msal4j.AcquireTokenByAppProviderSupplier.execute(AcquireTokenByAppProviderSupplier.java:56)
at com.microsoft.aad.msal4j.AcquireTokenByClientCredentialSupplier.acquireTokenByClientCredential(AcquireTokenByClientCredentialSupplier.java:78)
at com.microsoft.aad.msal4j.AcquireTokenByClientCredentialSupplier.execute(AcquireTokenByClientCredentialSupplier.java:49)
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([email protected]/CompletableFuture.java:1768)
at java.util.concurrent.CompletableFuture$AsyncSupply.exec([email protected]/CompletableFuture.java:1760)
at java.util.concurrent.ForkJoinTask.doExec([email protected]/ForkJoinTask.java:373)
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec([email protected]/ForkJoinPool.java:1182)
at java.util.concurrent.ForkJoinPool.scan([email protected]/ForkJoinPool.java:1655)
at java.util.concurrent.ForkJoinPool.runWorker([email protected]/ForkJoinPool.java:1622)
at java.util.concurrent.ForkJoinWorkerThread.run([email protected]/ForkJoinWorkerThread.java:165)
To Reproduce You can use this repository to reproduce the issue. To imitate Managed Identity behavior add properties from readme to env variables. https://github.com/alekseistepanovvl/demo-service main branch To reproduce try run application from repo with env variables.
Code Snippet I noticed that Sleuth removal resolves fixes and issues. Therefore, I believe there may be an issue with the interaction between Azure Identity and Sleuth.
at org.springframework.cloud.sleuth.instrument.reactor.ReactorSleuth.lambda$scopePassingOnScheduleHook$7(ReactorSleuth.java:323)
at org.springframework.cloud.sleuth.instrument.reactor.ReactorSleuth$$Lambda$556/0x00000070004deb10.apply(Unknown Source)
at reactor.core.scheduler.Schedulers.onSchedule(Schedulers.java:1017)
at reactor.core.scheduler.Schedulers.directSchedule(Schedulers.java:1380)
at reactor.core.scheduler.ParallelScheduler.schedule(ParallelScheduler.java:243)
at reactor.core.scheduler.Schedulers$CachedScheduler.schedule(Schedulers.java:1308)
at reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.signalCached(MonoCacheTime.java:320)
at reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.onNext(MonoCacheTime.java:354)
at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839)
at reactor.core.publisher.MonoCallable.subscribe(MonoCallable.java:62)
at reactor.core.publisher.MonoCacheTime.subscribeOrReturn(MonoCacheTime.java:143)
at reactor.core.publisher.Mono.subscribe(Mono.java:4475)
at reactor.core.publisher.Mono.subscribeWith(Mono.java:4605)
at reactor.core.publisher.Mono.toFuture(Mono.java:5010)
at com.azure.identity.implementation.IdentityClientBase.lambda$getManagedIdentityConfidentialClient$3(IdentityClientBase.java:424)
at com.azure.identity.implementation.IdentityClientBase$$Lambda$1047/0x000000700082fcb8.apply(Unknown Source)
Expected behavior Connection is getting set using authentication=ActiveDirectoryManagedIdentity with and without sleuth dependency.
Screenshots If applicable, add screenshots to help explain your problem.
Setup (please complete the following information):
- Library/Libraries: com.azure:azure-identity:1.12.0 com.microsoft.azure:msal4j:1.15.0 com.microsoft.sqlserver:mssql-jdbc:12.6.1.jre11 org.springframework.cloud:spring-cloud-starter-sleuth:3.1.11
- Java version: 11
- App Server/Environment: AKS, Managed Identity, Azure SQL
- Frameworks: Spring Boot 2.18
Additional context
I guess issue in org.springframework.cloud.sleuth.instrument.reactor.ReactorSleuth.lambda$scopePassingOnScheduleHook.
Called it in debug and it's calculation seems blocked the thread.
Information Checklist Kindly make sure that you have added all the following information above and checkoff the required fields otherwise we will treat the issuer as an incomplete report
- [x] Bug Description Added
- [x] Repro Steps Added
- [x] Setup information Added
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}
Thank you for your feedback. Tagging and routing to the team member best able to assist.
Looks like deadlock:
"main@1" prio=5 tid=0x1 nid=NA waiting
java.lang.Thread.State: WAITING
blocks ForkJoinPool.commonPool-worker-1@9633
at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
"ForkJoinPool.commonPool-worker-1@9633" daemon prio=5 tid=0x1b nid=NA waiting for monitor entry
java.lang.Thread.State: BLOCKED
waiting for main@1 to release lock on <0x312b> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.getSingletonFactoryBeanForTypeCheck(AbstractAutowireCapableBeanFactory.java:1006)
@alekseistepanovvl Thank you for reporting this issue. This looks to be a spring dependency issue.
Assigning to @saragluna to take a look.
Thanks @alekseistepanovvl for investigating!
We can see the method invocation of the ReactorSleuth appears in the call stack, and blocked. The class ReactorSleuth initialization will try to get the bean org.springframework.cloud.sleuth.CurrentTraceContext and finally it will be blocked with the lock that has been acquired in the main thread.
The sleuth hooks are hooked for each reactor operator when enabling the Sleuth, after checking the doc - Reactor in Sleuth , we can use the manual type, so to mitigate the locking to update the configuration:
spring.sleuth.reactor.instrumentation-type=MANUAL
Hi @alekseistepanovvl. Thank you for opening this issue and giving us the opportunity to assist. To help our team better understand your issue and the details of your scenario please provide a response to the question asked above or the information requested above. This will help us more accurately address your issue.
Hi @alekseistepanovvl, we're sending this friendly reminder because we haven't heard back from you in 7 days. We need more information about this issue to help address it. Please be sure to give us your input. If we don't hear back from you within 14 days of this comment the issue will be automatically closed. Thank you!