Error occurred while refreshing token

[cristibozga]

We are migration from the old servicebus sdk to the new one and after the first deployment we had several errors.
One of them is:

{"@timestamp":"2025-01-01T04:34:28.321Z","@Version":"1","message":"{"az.sdk.message":"Error occurred while refreshing token that is not retriable. Not scheduling refresh task. Use ActiveClientTokenManager.authorize() to schedule task again.","exception":"Cannot send a message when request response channel is disposed. ConnectionId:MF_69a7a4_1735638516319 isCacheTerminated:false isConnectionTerminated:true","scopes":"amqp://sbus-nonprod-sprint-main-pextnk.servicebus.windows.net/slot_to_events_subscription_queue","audience":"amqp://sbus-nonprod-sprint-main-pextnk.servicebus.windows.net/slot_to_events_subscription_queue"}","logger_name":"com.azure.core.amqp.implementation.ActiveClientTokenManager","thread_name":"parallel-1","level":"ERROR","level_value":40000}

We use the following code to setup the sender:

public ServiceBusSenderClient prepareSender(String queueName) {
       return new ServiceBusClientBuilder()
               .connectionString(....)
               .retryOptions(RETRY_OPTIONS)
               .sender()
               .queueName(queueName)
               .buildClient();

   }

SDK version 7.17.7
java version: 17

Can you, please, tell us why the error occurs and how can we avoid it?

Thanks,
Cristi

[cristibozga]

A new more complete case for this error:
In the logs I find first:

"message":"Operator called default onErrorDropped"
reactor.core.Exceptions$ErrorCallbackNotImplemented: java.lang.NullPointerException: Cannot invoke "java.util.concurrent.atomic.AtomicBoolean.getAndSet(boolean)" because "this.isDisposed" is null
Caused by: java.lang.NullPointerException: Cannot invoke \"java.util.concurrent.atomic.AtomicBoolean.getAndSet(boolean)\" because \"this.isDisposed\" is null
at com.azure.messaging.servicebus.implementation.ServiceBusReactorReceiver.closeAsync(ServiceBusReactorReceiver.java:199)
at com.azure.core.amqp.implementation.ReactorReceiver.lambda$new$12(ReactorReceiver.java:203)
at reactor.core.publisher.FluxFlatMap$FlatMapMain.onNext(FluxFlatMap.java:386)
at io.opentelemetry.javaagent.shaded.instrumentation.reactor.v3_1.TracingSubscriber.onNext(TracingSubscriber.java:68)
at io.opentelemetry.javaagent.shaded.instrumentation.reactor.v3_1.TracingSubscriber.onNext(TracingSubscriber.java:68)
at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839)\n\tat reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.signalCached(MonoCacheTime.java:337)\n\tat reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.onNext(MonoCacheTime.java:354)\n\tat reactor.core.publisher.Operators$MonoInnerProducerBase.complete(Operators.java:2636)\n\tat reactor.core.publisher.SinkOneMulticast.subscribe(SinkOneMulticast.java:99)\n\tat reactor.core.publisher.MonoCacheTime.subscribeOrReturn(MonoCacheTime.java:143)\n\tat reactor.core.publisher.Flux.subscribe(Flux.java:8628)\n\tat reactor.core.publisher.Flux.subscribeWith(Flux.java:8815)\n\tat reactor.core.publisher.Flux.subscribe(Flux.java:8608)\n\tat reactor.core.publisher.Flux.subscribe(Flux.java:8532)\n\tat reactor.core.publisher.Flux.subscribe(Flux.java:8450)\n\tat com.azure.core.amqp.implementation.ReactorReceiver.<init>(ReactorReceiver.java:204)\n\tat com.azure.messaging.servicebus.implementation.ServiceBusReactorReceiver.<init>(ServiceBusReactorReceiver.java:76)
at com.azure.messaging.servicebus.implementation.ServiceBusAmqpLinkProvider.createReceiveLink(ServiceBusAmqpLinkProvider.java:45)
at com.azure.core.amqp.implementation.ConsumerFactory.createConsumer(ConsumerFactory.java:64)
at com.azure.core.amqp.implementation.ReactorSession.getSubscription(ReactorSession.java:672)\n\tat com.azure.core.amqp.implementation.ReactorSession.lambda$createConsumer$11(ReactorSession.java:448)
at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1916
....

and on the same thread, the next log (at the same timestamp):

`Error occurred while refreshing token that is not retriable. Not scheduling refresh task. Use ActiveClientTokenManager.authorize() to schedule task again`
exception: Cannot send a message when request response channel is disposed. ConnectionId:MF_c8fbe3_1735224066512 isCacheTerminated:false isConnectionTerminated:true","scopes":"amqp://sbus-rnd-dev-main-qzlcup.servicebus.windows.net/tos_transport_carrier_queue","audience":"amqp://sbus-rnd-dev-main-qzlcup.servicebus.windows.net/tos_transport_carrier_queue"

[cristibozga]

New tests have been done on the 10/03.
I got several errors in sbus-rnd-dev-main-qzlcup.servicebus.windows.net and /sbus-rnd-regression-main-tjkgat.servicebus.windows.net

Examples:

{"@timestamp":"2025-03-10T20:41:30.916Z","@Version":"1","message":"{"az.sdk.message":"Error occurred while refreshing token that is not retriable. Not scheduling refresh task. Use ActiveClientTokenManager.authorize() to schedule task again.","exception":"Cannot send a message when request response channel is disposed. ConnectionId:MF_d21947_1741568332295 isCacheTerminated:true isConnectionTerminated:true","scopes":"amqp://sbus-rnd-dev-main-qzlcup.servicebus.windows.net/TMSBookingQueue","audience":"amqp://sbus-rnd-dev-main-qzlcup.servicebus.windows.net/TMSBookingQueue"}","logger_name":"com.azure.core.amqp.implementation.ActiveClientTokenManager","thread_name":"parallel-1","level":"ERROR","level_value":40000}

{"@timestamp":"2025-03-10T21:50:39.074Z","@Version":"1","message":"{"az.sdk.message":"Error occurred while refreshing token that is not retriable. Not scheduling refresh task. Use ActiveClientTokenManager.authorize() to schedule task again.","exception":"Cannot send a message when request response channel is disposed. ConnectionId:MF_53aeb1_1741568419408 isCacheTerminated:true isConnectionTerminated:true","scopes":"amqp://sbus-rnd-regression-main-tjkgat.servicebus.windows.net/ProcessTimestampAccepted","audience":"amqp://sbus-rnd-regression-main-tjkgat.servicebus.windows.net/ProcessTimestampAccepted"}","logger_name":"com.azure.core.amqp.implementation.ActiveClientTokenManager","thread_name":"parallel-1","level":"ERROR","level_value":40000}

The problems started after 21.37 CET