aws-msk-iam-auth: Access Denied despite correct policy being attatched

I have been experimenting with a cluster that has IAM Authentication, and I cannot seem to get it working. -I have a security group in the cluster that allows in-bound traffic from the ec2 instance I am testing from. I can even do zookeeper interactions like list topics just fine. -My ec2 instance has an IAM role with a policy that specifically allows for all kafka interactions on all resources -I also tried an aws local profile that has the same attached policy. -I am using the following command to attempt a consumer interaction bin/kafka-console-consumer.sh --bootstrap-server b-1.examplename.kafka.us-east-1.amazonaws.com:9098 --topic exampleTopic --consumer.config config/consumer.properties

consumer.properties has the below properties security.protocol=SASL_SSL sasl.mechanism=AWS_MSK_IAM sasl.jaas.config=software.amazon.msk.auth.iam.IAMLoginModule required; sasl.client.callback.handler.class=software.amazon.msk.auth.iam.IAMClientCallbackHandler

Am I missing anything?

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. [2021-06-16 14:51:21,365] INFO AdminClientConfig values: bootstrap.servers = [b-1.test-cluster.kafka.us-east-1.amazonaws.com:9098, b-3.test-cluster.kafka.us-east-1.amazonaws.com:9098, b-2.test-cluster.kafka.us-east-1.amazonaws.com:9098] client.dns.lookup = default client.id = connections.max.idle.ms = 300000 default.api.timeout.ms = 60000 metadata.max.age.ms = 300000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 receive.buffer.bytes = 65536 reconnect.backoff.max.ms = 1000 reconnect.backoff.ms = 50 request.timeout.ms = 30000 retries = 2147483647 retry.backoff.ms = 100 sasl.client.callback.handler.class = class software.amazon.msk.auth.iam.IAMClientCallbackHandler sasl.jaas.config = [hidden] sasl.kerberos.kinit.cmd = /usr/bin/kinit sasl.kerberos.min.time.before.relogin = 60000 sasl.kerberos.service.name = null sasl.kerberos.ticket.renew.jitter = 0.05 sasl.kerberos.ticket.renew.window.factor = 0.8 sasl.login.callback.handler.class = null sasl.login.class = null sasl.login.refresh.buffer.seconds = 300 sasl.login.refresh.min.period.seconds = 60 sasl.login.refresh.window.factor = 0.8 sasl.login.refresh.window.jitter = 0.05 sasl.mechanism = AWS_MSK_IAM security.protocol = SASL_SSL security.providers = null send.buffer.bytes = 131072 ssl.cipher.suites = null ssl.enabled.protocols = [TLSv1.2] ssl.endpoint.identification.algorithm = https ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLSv1.2 ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS (org.apache.kafka.clients.admin.AdminClientConfig) [2021-06-16 14:51:21,506] DEBUG [AdminClient clientId=adminclient-1] Setting bootstrap cluster metadata Cluster(id = null, nodes = [b-3.test-cluster.kafka.us-east-1.amazonaws.com:9098 (id: -2 rack: null), b-1.test-cluster.kafka.us-east-1.amazonaws.com:9098 (id: -1 rack: null), b-2.test-cluster.kafka.us-east-1.amazonaws.com:9098 (id: -3 rack: null)], partitions = [], controller = null). (org.apache.kafka.clients.admin.internals.AdminMetadataManager) [2021-06-16 14:51:23,321] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin) [2021-06-16 14:51:24,609] DEBUG Created SSL context with keystore null, truststore null, provider SunJSSE. (org.apache.kafka.common.security.ssl.SslEngineBuilder) [2021-06-16 14:51:24,886] WARN The configuration 'sasl.jaas.config' was supplied but isn't a known config. (org.apache.kafka.clients.admin.AdminClientConfig) [2021-06-16 14:51:24,895] WARN The configuration 'sasl.client.callback.handler.class' was supplied but isn't a known config. (org.apache.kafka.clients.admin.AdminClientConfig) [2021-06-16 14:51:24,898] INFO Kafka version: 2.5.0 (org.apache.kafka.common.utils.AppInfoParser) [2021-06-16 14:51:24,898] INFO Kafka commitId: 66563e712b0b9f84 (org.apache.kafka.common.utils.AppInfoParser) [2021-06-16 14:51:24,898] INFO Kafka startTimeMs: 1623855084895 (org.apache.kafka.common.utils.AppInfoParser) [2021-06-16 14:51:24,901] DEBUG [AdminClient clientId=adminclient-1] Kafka admin client initialized (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:24,928] DEBUG [AdminClient clientId=adminclient-1] Queueing Call(callName=listTopics, deadlineMs=1623855144917) with a timeout 60000 ms from now. (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:24,983] DEBUG [AdminClient clientId=adminclient-1] Initiating connection to node b-2.test-cluster.kafka.us-east-1.amazonaws.com:9098 (id: -3 rack: null) using address b-2.test-cluster.kafka.us-east-1.amazonaws.com/10.1.1.132 (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:25,302] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to SEND_APIVERSIONS_REQUEST (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:25,323] DEBUG [AdminClient clientId=adminclient-1] Creating SaslClient: client=null;service=kafka;serviceHostname=b-2.test-cluster.kafka.us-east-1.amazonaws.com;mechs=[AWS_MSK_IAM] (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:25,453] DEBUG [AdminClient clientId=adminclient-1] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node -3 (org.apache.kafka.common.network.Selector) [2021-06-16 14:51:27,191] DEBUG [AdminClient clientId=adminclient-1] Completed connection to node -3. Fetching API versions. (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:28,279] DEBUG [SslTransportLayer channelId=-3 key=sun.nio.ch.SelectionKeyImpl@2ed0f78a] SSL handshake completed successfully with peerHost 'b-2.test-cluster.kafka.us-east-1.amazonaws.com' peerPort 9098 peerPrincipal 'CN=*.test-cluster.kafka.us-east-1.amazonaws.com' cipherSuite 'TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384' (org.apache.kafka.common.network.SslTransportLayer) [2021-06-16 14:51:29,077] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to RECEIVE_APIVERSIONS_RESPONSE (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:29,122] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to SEND_HANDSHAKE_REQUEST (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:29,133] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to RECEIVE_HANDSHAKE_RESPONSE (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:29,136] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to INITIAL (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:29,155] DEBUG Unable to load credentials from EnvironmentVariableCredentialsProvider: Unable to load AWS credentials from environment variables (AWS_ACCESS_KEY_ID (or AWS_ACCESS_KEY) and AWS_SECRET_KEY (or AWS_SECRET_ACCESS_KEY)) (aws_msk_iam_auth_shadow.com.amazonaws.auth.AWSCredentialsProviderChain) [2021-06-16 14:51:29,156] DEBUG Unable to load credentials from SystemPropertiesCredentialsProvider: Unable to load AWS credentials from Java system properties (aws.accessKeyId and aws.secretKey) (aws_msk_iam_auth_shadow.com.amazonaws.auth.AWSCredentialsProviderChain) [2021-06-16 14:51:29,158] DEBUG Unable to load credentials from WebIdentityTokenCredentialsProvider: To use assume role profiles the aws-java-sdk-sts module must be on the class path. (aws_msk_iam_auth_shadow.com.amazonaws.auth.AWSCredentialsProviderChain) [2021-06-16 14:51:29,207] DEBUG Loading credentials from aws_msk_iam_auth_shadow.com.amazonaws.auth.profile.ProfileCredentialsProvider@5b3a7a7e (aws_msk_iam_auth_shadow.com.amazonaws.auth.AWSCredentialsProviderChain) [2021-06-16 14:51:29,217] DEBUG Loading credentials from aws_msk_iam_auth_shadow.com.amazonaws.auth.DefaultAWSCredentialsProviderChain@19e7618e (aws_msk_iam_auth_shadow.com.amazonaws.auth.AWSCredentialsProviderChain) [2021-06-16 14:51:30,378] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to INTERMEDIATE (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:30,913] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to FAILED (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:30,916] INFO [AdminClient clientId=adminclient-1] Failed authentication with b-2.test-cluster.kafka.us-east-1.amazonaws.com/10.1.1.132 ([d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied) (org.apache.kafka.common.network.Selector) [2021-06-16 14:51:30,928] DEBUG [AdminClient clientId=adminclient-1] Node -3 disconnected. (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:30,931] ERROR [AdminClient clientId=adminclient-1] Connection to node -3 (b-2.test-cluster.kafka.us-east-1.amazonaws.com/10.1.1.132:9098) failed authentication due to: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:30,944] WARN [AdminClient clientId=adminclient-1] Metadata update failed due to authentication error (org.apache.kafka.clients.admin.internals.AdminMetadataManager) org.apache.kafka.common.errors.SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied [2021-06-16 14:51:30,951] DEBUG [AdminClient clientId=adminclient-1] Requesting metadata update. (org.apache.kafka.clients.admin.internals.AdminMetadataManager) [2021-06-16 14:51:30,960] DEBUG [AdminClient clientId=adminclient-1] Metadata is not usable: failed to get metadata. (org.apache.kafka.clients.admin.internals.AdminMetadataManager) org.apache.kafka.common.errors.SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied [2021-06-16 14:51:30,962] DEBUG [AdminClient clientId=adminclient-1] Unable to choose node for Call(callName=listTopics, deadlineMs=1623855144917) (org.apache.kafka.clients.admin.KafkaAdminClient) org.apache.kafka.common.errors.SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied [2021-06-16 14:51:30,963] DEBUG [AdminClient clientId=adminclient-1] Call(callName=listTopics, deadlineMs=1623855144917) failed with non-retriable exception after 1 attempt(s) (org.apache.kafka.clients.admin.KafkaAdminClient) java.lang.Exception: SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied at org.apache.kafka.clients.admin.KafkaAdminClient$Call.fail(KafkaAdminClient.java:735) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.maybeDrainPendingCall(KafkaAdminClient.java:997) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.maybeDrainPendingCalls(KafkaAdminClient.java:970) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.processRequests(KafkaAdminClient.java:1249) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.run(KafkaAdminClient.java:1203) at java.lang.Thread.run(Thread.java:748) [2021-06-16 14:51:30,983] DEBUG [AdminClient clientId=adminclient-1] Initiating connection to node b-3.test-cluster.kafka.us-east-1.amazonaws.com:9098 (id: -2 rack: null) using address b-3.test-cluster.kafka.us-east-1.amazonaws.com/10.1.23.170 (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:30,996] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to SEND_APIVERSIONS_REQUEST (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) Error while executing topic command : org.apache.kafka.common.errors.SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied [2021-06-16 14:51:31,012] DEBUG [AdminClient clientId=adminclient-1] Creating SaslClient: client=null;service=kafka;serviceHostname=b-3.test-cluster.kafka.us-east-1.amazonaws.com;mechs=[AWS_MSK_IAM] (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:31,012] ERROR java.util.concurrent.ExecutionException: org.apache.kafka.common.errors.SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied at org.apache.kafka.common.internals.KafkaFutureImpl.wrapAndThrow(KafkaFutureImpl.java:45) at org.apache.kafka.common.internals.KafkaFutureImpl.access$000(KafkaFutureImpl.java:32) at org.apache.kafka.common.internals.KafkaFutureImpl$SingleWaiter.await(KafkaFutureImpl.java:89) at org.apache.kafka.common.internals.KafkaFutureImpl.get(KafkaFutureImpl.java:260) at kafka.admin.TopicCommand$AdminClientTopicService.getTopics(TopicCommand.scala:333) at kafka.admin.TopicCommand$AdminClientTopicService.listTopics(TopicCommand.scala:252) at kafka.admin.TopicCommand$.main(TopicCommand.scala:66) at kafka.admin.TopicCommand.main(TopicCommand.scala) Caused by: org.apache.kafka.common.errors.SaslAuthenticationException: [d4c3dbd3-45c5-485c-b33f-2e962eb541ca]: Access denied (kafka.admin.TopicCommand$) [2021-06-16 14:51:31,015] DEBUG [AdminClient clientId=adminclient-1] Initiating close operation. (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:31,016] DEBUG [AdminClient clientId=adminclient-1] Waiting for the I/O thread to exit. Hard shutdown in 31535999999 ms. (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:31,027] DEBUG [AdminClient clientId=adminclient-1] Initiating connection to node b-1.test-cluster.kafka.us-east-1.amazonaws.com:9098 (id: -1 rack: null) using address b-1.test-cluster.kafka.us-east-1.amazonaws.com/10.1.33.250 (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:31,028] DEBUG [AdminClient clientId=adminclient-1] Set SASL client state to SEND_APIVERSIONS_REQUEST (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:31,028] DEBUG [AdminClient clientId=adminclient-1] Creating SaslClient: client=null;service=kafka;serviceHostname=b-1.test-cluster.kafka.us-east-1.amazonaws.com;mechs=[AWS_MSK_IAM] (org.apache.kafka.common.security.authenticator.SaslClientAuthenticator) [2021-06-16 14:51:31,058] DEBUG [AdminClient clientId=adminclient-1] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node -2 (org.apache.kafka.common.network.Selector) [2021-06-16 14:51:31,225] DEBUG [AdminClient clientId=adminclient-1] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node -1 (org.apache.kafka.common.network.Selector) [2021-06-16 14:51:31,287] DEBUG [AdminClient clientId=adminclient-1] Completed connection to node -2. Fetching API versions. (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:31,288] DEBUG [AdminClient clientId=adminclient-1] Completed connection to node -1. Fetching API versions. (org.apache.kafka.clients.NetworkClient) [2021-06-16 14:51:31,292] DEBUG [AdminClient clientId=adminclient-1] Call(callName=fetchMetadata, deadlineMs=1623855114918) timed out at 9223372036854775807 after 1 attempt(s) (org.apache.kafka.clients.admin.KafkaAdminClient) java.lang.Exception: TimeoutException: Timed out waiting to send the call. at org.apache.kafka.clients.admin.KafkaAdminClient$Call.failWithTimeout(KafkaAdminClient.java:755) at org.apache.kafka.clients.admin.KafkaAdminClient$Call.fail(KafkaAdminClient.java:728) at org.apache.kafka.clients.admin.KafkaAdminClient$TimeoutProcessor.handleTimeouts(KafkaAdminClient.java:850) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.timeoutCallsToSend(KafkaAdminClient.java:931) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.run(KafkaAdminClient.java:1214) at java.lang.Thread.run(Thread.java:748) [2021-06-16 14:51:31,317] INFO [AdminClient clientId=adminclient-1] Metadata update failed (org.apache.kafka.clients.admin.internals.AdminMetadataManager) org.apache.kafka.common.errors.TimeoutException: Call(callName=fetchMetadata, deadlineMs=1623855114918) timed out at 9223372036854775807 after 1 attempt(s) Caused by: org.apache.kafka.common.errors.TimeoutException: Timed out waiting to send the call. [2021-06-16 14:51:31,318] DEBUG [AdminClient clientId=adminclient-1] Call(callName=fetchMetadata, deadlineMs=1623855120960) timed out at 9223372036854775807 after 1 attempt(s) (org.apache.kafka.clients.admin.KafkaAdminClient) java.lang.Exception: TimeoutException: Timed out waiting to send the call. at org.apache.kafka.clients.admin.KafkaAdminClient$Call.failWithTimeout(KafkaAdminClient.java:755) at org.apache.kafka.clients.admin.KafkaAdminClient$Call.fail(KafkaAdminClient.java:728) at org.apache.kafka.clients.admin.KafkaAdminClient$TimeoutProcessor.handleTimeouts(KafkaAdminClient.java:850) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.timeoutCallsToSend(KafkaAdminClient.java:931) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.run(KafkaAdminClient.java:1214) at java.lang.Thread.run(Thread.java:748) [2021-06-16 14:51:31,318] INFO [AdminClient clientId=adminclient-1] Metadata update failed (org.apache.kafka.clients.admin.internals.AdminMetadataManager) org.apache.kafka.common.errors.TimeoutException: Call(callName=fetchMetadata, deadlineMs=1623855120960) timed out at 9223372036854775807 after 1 attempt(s) Caused by: org.apache.kafka.common.errors.TimeoutException: Timed out waiting to send the call. [2021-06-16 14:51:31,319] DEBUG [AdminClient clientId=adminclient-1] Timed out 2 call(s) with assigned nodes. (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:31,319] DEBUG [AdminClient clientId=adminclient-1] Timed out 2 remaining operation(s). (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:31,320] DEBUG [SslTransportLayer channelId=-1 key=sun.nio.ch.SelectionKeyImpl@2143c6fe] Failed to send SSL Close message (org.apache.kafka.common.network.SslTransportLayer) java.io.IOException: Unexpected status returned by SSLEngine.wrap, expected CLOSED, received OK. Will not send close message to peer. at org.apache.kafka.common.network.SslTransportLayer.close(SslTransportLayer.java:192) at org.apache.kafka.common.utils.Utils.closeAll(Utils.java:855) at org.apache.kafka.common.network.KafkaChannel.close(KafkaChannel.java:155) at org.apache.kafka.common.network.Selector.doClose(Selector.java:929) at org.apache.kafka.common.network.Selector.close(Selector.java:913) at org.apache.kafka.common.network.Selector.close(Selector.java:859) at org.apache.kafka.common.network.Selector.close(Selector.java:368) at org.apache.kafka.clients.NetworkClient.close(NetworkClient.java:641) at org.apache.kafka.common.utils.Utils.closeQuietly(Utils.java:873) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.run(KafkaAdminClient.java:1220) at java.lang.Thread.run(Thread.java:748) [2021-06-16 14:51:31,321] DEBUG [SslTransportLayer channelId=-2 key=sun.nio.ch.SelectionKeyImpl@168feda2] Failed to send SSL Close message (org.apache.kafka.common.network.SslTransportLayer) java.io.IOException: Unexpected status returned by SSLEngine.wrap, expected CLOSED, received OK. Will not send close message to peer. at org.apache.kafka.common.network.SslTransportLayer.close(SslTransportLayer.java:192) at org.apache.kafka.common.utils.Utils.closeAll(Utils.java:855) at org.apache.kafka.common.network.KafkaChannel.close(KafkaChannel.java:155) at org.apache.kafka.common.network.Selector.doClose(Selector.java:929) at org.apache.kafka.common.network.Selector.close(Selector.java:913) at org.apache.kafka.common.network.Selector.close(Selector.java:859) at org.apache.kafka.common.network.Selector.close(Selector.java:368) at org.apache.kafka.clients.NetworkClient.close(NetworkClient.java:641) at org.apache.kafka.common.utils.Utils.closeQuietly(Utils.java:873) at org.apache.kafka.clients.admin.KafkaAdminClient$AdminClientRunnable.run(KafkaAdminClient.java:1220) at java.lang.Thread.run(Thread.java:748) [2021-06-16 14:51:31,385] DEBUG [AdminClient clientId=adminclient-1] Exiting AdminClientRunnable thread. (org.apache.kafka.clients.admin.KafkaAdminClient) [2021-06-16 14:51:31,403] DEBUG [AdminClient clientId=adminclient-1] Kafka admin client closed. (org.apache.kafka.clients.admin.KafkaAdminClient)