Pulsar: [Java Client 2.6.1] Client keeps retrying for about 30 seconds when there is an Authentication failure

[frankjkelly]

Describe the bug
While testing Authentication the Java Client keeps retrying a number of times for approx. 30 seconds even though there is a bad JWT token or a missing JWT token and the broker is responding with

To Reproduce
Steps to reproduce the behavior:

1. Turn on Authentication in the Proxy and the Broker
2. Build a Pulsar Client with no authentication

            return PulsarClient.builder()
                    .allowTlsInsecureConnection(false)
                    .serviceUrl("pulsar://" + SERVER + ":6650")
                    .build();

1. Create a Producer e.g.

        Producer<byte[]> producer = pulsarClient.newProducer()
                .topic(topicBeingRequested)
                .create();

1. See errors and retries in log file - takes approx 30 seconds for this to stop
2. Setting .maxNumberOfRejectedRequestPerConnection(1) on the client did not improve things
3. I see the same problem on an Authorization error (can provide separate logs if neede)

Expected behavior
I would expect an AuthN or AuthZ failure to return immediately and not retry

Screenshots
The client logs show this repeatedly

2020-08-28 11:52:17,368 - INFO  - [pulsar-client-io-8-1:ClientCnx@226] - [id: 0xa0555737, L:/127.0.0.1:63523 ! R:localhost/127.0.0.1:6650] Disconnected
2020-08-28 11:52:23,382 - WARN  - [pulsar-external-listener-9-1:PulsarClientImpl@695] - [topic: persistent://testTenant1/testNamespace1/topic1] Could not get connection while getPartitionedTopicMetadata -- Will try again in 6010 ms
2020-08-28 11:52:23,383 - INFO  - [pulsar-client-io-8-1:ConnectionPool@167] - [[id: 0x87f61dcc, L:/127.0.0.1:63524 - R:localhost/127.0.0.1:6650]] Connected to server
2020-08-28 11:52:23,423 - ERROR - [pulsar-client-io-8-1:ClientCnx@898] - [id: 0x87f61dcc, L:/127.0.0.1:63524 - R:localhost/127.0.0.1:6650] Close connection because received internal-server error org.apache.pulsar.client.api.PulsarClientException: Disconnected from server at pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650
2020-08-28 11:52:23,424 - WARN  - [pulsar-client-io-8-1:BinaryProtoLookupService@197] - [persistent://testTenant1/testNamespace1/topic1] failed to get Partitioned metadata : org.apache.pulsar.client.api.PulsarClientException: Disconnected from server at pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650

I see this in the logs for the proxy repeatedly

5:51:53.467 [pulsar-proxy-io-2-1] INFO  org.apache.pulsar.client.impl.ConnectionPool - [[id: 0xec6c801e, L:/172.17.0.4:55792 - R:pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650]] Connected to server
15:51:53.486 [pulsar-proxy-io-2-1] WARN  org.apache.pulsar.client.impl.ClientCnx - [id: 0xec6c801e, L:/172.17.0.4:55792 - R:pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650] Received error from server: Unable to authenticate
15:51:53.486 [pulsar-proxy-io-2-1] WARN  org.apache.pulsar.client.impl.ClientCnx - [id: 0xec6c801e, L:/172.17.0.4:55792 - R:pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650] Received unknown request id from server: -1
15:51:53.487 [pulsar-proxy-io-2-1] INFO  org.apache.pulsar.client.impl.ClientCnx - [id: 0xec6c801e, L:/172.17.0.4:55792 ! R:pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650] Disconnected
15:51:53.488 [pulsar-proxy-io-2-1] WARN  org.apache.pulsar.proxy.server.LookupProxyHandler - [persistent://testTenant1/testNamespace1/topic1] failed to get Partitioned metadata : Disconnected from server at pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException: Disconnected from server at pulsar-broker.cogito.svc.cluster.local/10.100.43.26:6650

Desktop (please complete the following information):

• Pulsar 2.6.1 deployed in Minikube (separate proxy/broker/bookies/zk etc.)
• Pulsar Client 2.6.1

[jiazhai]

@zymap Would you please help take a look at this issue?

[zymap]

Sure. I will take a look.

[frankjkelly]

Awesome thank you @jiazhai @zymap and @sijie I am excited to try this out in 2.7.0