search

Azure / azure-sdk-for-java

This repository is for active development of the Azure SDK for Java. For consumers of the SDK we recommend visiting our public developer docs at https://docs.microsoft.com/java/azure/ or our versioned developer docs at https://azure.github.io/azure-sdk-for-java.
MIT License
2.36k stars 2k forks source link

[BUG] Cannot access KeyVault from Java Function #23475

Closed markpope closed 3 years ago

markpope commented 3 years ago

Describe the bug I'm trying to access the Key Vault from a Java TimerTrigger Function following this tutorial: https://docs.microsoft.com/en-us/java/api/overview/azure/security-keyvault-secrets-readme?view=azure-java-stable

I am using the new azure-identity jar 1.3.5 My app is registered, the APP_CLIENT_ID, APP_TENNET_ID, and SECRET are in the app properties. My function has a managed identity. My Key Vault has an access policy for the function and holds one secret.

Exception or Stack Trace Connected! 2021-08-11T03:03:02 Welcome, you are now connected to log-streaming service. The default timeout is 2 hours. Change the timeout with the App Setting SCM_LOGSTREAM_TIMEOUT (in seconds). 2021-08-11T03:03:03.874 [Information] [pool-2-thread-1] INFO io.netty.handler.ssl.ReferenceCountedOpenSslContext - BoringSSL doesn't allow to enable or disable TLSv1.3 ciphers explicitly. Provided TLSv1.3 ciphers: 'TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384', default TLSv1.3 ciphers that will be used: 'TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256'. 2021-08-11T03:03:10.556 [Warning] [reactor-http-nio-1] WARN com.azure.security.keyvault.secrets.SecretAsyncClient - Failed to get secret - mySecret 2021-08-11T03:03:10.556 [Error] Max retries 3 times exceeded. Error Details: The mapper returned a null value. 2021-08-11T03:03:10.693 [Error] Executed 'Functions.Function' (Failed, Id=31b8b8c9-004a-464b-b086-10846553b965, Duration=10661ms)Result: FailureException: NullPointerException: The mapper returned a null value.Stack: java.lang.reflect.InvocationTargetExceptionat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at com.microsoft.azure.functions.worker.broker.JavaMethodInvokeInfo.invoke(JavaMethodInvokeInfo.java:22)at com.microsoft.azure.functions.worker.broker.JavaMethodExecutorImpl.execute(JavaMethodExecutorImpl.java:54)at com.microsoft.azure.functions.worker.broker.JavaFunctionBroker.invokeMethod(JavaFunctionBroker.java:57)at com.microsoft.azure.functions.worker.handler.InvocationRequestHandler.execute(InvocationRequestHandler.java:33)at com.microsoft.azure.functions.worker.handler.InvocationRequestHandler.execute(InvocationRequestHandler.java:10)at com.microsoft.azure.functions.worker.handler.MessageHandler.handle(MessageHandler.java:45)at com.microsoft.azure.functions.worker.JavaWorkerClient$StreamingMessagePeer.lambda$onNext$0(JavaWorkerClient.java:92)at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)at java.util.concurrent.FutureTask.run(FutureTask.java:266)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.lang.RuntimeException: Max retries 3 times exceeded. Error Details: The mapper returned a null value.at com.azure.core.http.policy.RetryPolicy.lambda$attemptAsync$1(RetryPolicy.java:127)at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:94)at reactor.core.publisher.MonoFlatMap$FlatMapMain.onError(MonoFlatMap.java:172)at reactor.core.publisher.MonoFlatMap$FlatMapMain.onError(MonoFlatMap.java:172)at reactor.core.publisher.MonoFlatMap$FlatMapMain.onError(MonoFlatMap.java:172)at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:132)at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:132)at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:112)at reactor.core.publisher.FluxPeek$PeekSubscriber.onNext(FluxPeek.java:200)at reactor.core.publisher.SerializedSubscriber.onNext(SerializedSubscriber.java:99)at reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.onNext(FluxRetryWhen.java:174)at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)at reactor.core.publisher.Operators$MonoInnerProducerBase.complete(Operators.java:2664)at reactor.core.publisher.MonoSingle$SingleSubscriber.onComplete(MonoSingle.java:180)at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onComplete(MonoFlatMapMany.java:260)at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onComplete(FluxMapFuseable.java:150)at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onComplete(FluxMapFuseable.java:150)at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1817)at reactor.core.publisher.MonoCollect$CollectSubscriber.onComplete(MonoCollect.java:159)at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onComplete(FluxDoFinally.java:145)at reactor.core.publisher.FluxHandle$HandleSubscriber.onComplete(FluxHandle.java:213)at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onComplete(FluxMap.java:269)at reactor.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:400)at reactor.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:419)at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:473)at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:684)at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:93)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1374)at io.netty.handler.ssl.SslHandler.decodeNonJdkCompatible(SslHandler.java:1248)at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1288)at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)... 1 moreSuppressed: java.lang.Exception: #block terminated with an errorat reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:99)at reactor.core.publisher.Mono.block(Mono.java:1704)at com.azure.security.keyvault.secrets.SecretClient.getSecretWithResponse(SecretClient.java:179)at com.azure.security.keyvault.secrets.SecretClient.getSecret(SecretClient.java:157)at com.gdca.Function.run(Function.java:26)at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at com.microsoft.azure.functions.worker.broker.JavaMethodInvokeInfo.invoke(JavaMethodInvokeInfo.java:22)at com.microsoft.azure.functions.worker.broker.JavaMethodExecutorImpl.execute(JavaMethodExecutorImpl.java:54)at com.microsoft.azure.functions.worker.broker.JavaFunctionBroker.invokeMethod(JavaFunctionBroker.java:57)at com.microsoft.azure.functions.worker.handler.InvocationRequestHandler.execute(InvocationRequestHandler.java:33)at com.microsoft.azure.functions.worker.handler.InvocationRequestHandler.execute(InvocationRequestHandler.java:10)at com.microsoft.azure.functions.worker.handler.MessageHandler.handle(MessageHandler.java:45)at com.microsoft.azure.functions.worker.JavaWorkerClient$StreamingMessagePeer.lambda$onNext$0(JavaWorkerClient.java:92)at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)at java.util.concurrent.FutureTask.run(FutureTask.java:266)at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)... 1 moreCaused by: java.lang.NullPointerException: The mapper returned a null value.at java.util.Objects.requireNonNull(Objects.java:228)at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:106)... 51 more

To Reproduce Deploy

Code Snippet public class Function {

@FunctionName("Function")
public void run(
                @TimerTrigger(name = "timerInfo", schedule = "*/30 * * * * *") String timerInfo,
                final ExecutionContext context
) {

    SecretClient secretClient = new SecretClientBuilder()
                    .vaultUrl("https://???????.vault.azure.net/")
                    .credential(new DefaultAzureCredentialBuilder().build())
                    .buildClient();

    context.getLogger().info("" + secretClient.getSecret("mySecret"));

    context.getLogger().info("Azure Timer trigger function executed at: " + LocalDateTime.now());
}

}

Expected behavior A secret is returned

Screenshots If applicable, add screenshots to help explain your problem.

Setup (please complete the following information):

If you suspect a dependency version mismatch (e.g. you see NoClassDefFoundError, NoSuchMethodError or similar), please provide

Additional context Add any other context about the problem here.

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

joshfree commented 3 years ago

@vcolin7 can you please follow up with @markpope?

markpope commented 3 years ago

@vcolin7 My bad! I reviewed my code and found I was using the wrong Key Vault.

I'm getting: [Error] Status code 403, "{"error":{"code":"Forbidden","message":"The user, group or application 'appid=21f31c1a-3111-4815-ad05-c7c75dc080f6;iss=https://sts.windows.net/be8c0789-cb3d-4f3a-94d7-7c9301ca4803/' does not have secrets get permission on key vault 'map210701-kv;location=eastus'

It appears I have a permissions issue....

vcolin7 commented 3 years ago

No worries @markpope. Does this mean the Azure Function worked after giving it the right Key vault URL?

markpope commented 3 years ago

Same problem. I recreated everything using these steps.

image

vcolin7 commented 3 years ago

Hi @markpope, I will be out during the first half of the day (U.S. Central Time) but can look into this later on. Thanks for the details!

markpope commented 3 years ago

Hi @vcolin7, any thoughts?

vcolin7 commented 3 years ago

Hi @markpope, sorry I couldn't get back to you last week.

When you call az ad sp create-for-rbac, a new Service Principal with a given name as the -n parameter is created, so by creating one with the same name as your Azure Function it is possible you used that second Service Principal for your Key Vault's Access Policy instead of your Function's Service Principal. Could you try removing the Access Policy you have and add a new one by using your Function's Object ID? (You can find it in the same place you turned on your its System Managed Indentity):

image

Additionally, you can remove the AZURE_TENANT_ID, AZURE_CLIENT_ID and AZURE_CLIENT_SECRET as they are not required when working with a Managed Identity.

markpope commented 3 years ago

@vcolin7 Thanks! That solved the problem.