[QUERY] Excessive WARN logging when reading messages from an Azure Service Bus Topic subscription

[jochenhebbrecht]

Query/Question
azure-messaging-servicebus exposes a lot of WARN log statements. Is there something wrong in our setup?

Why is this not a Bug or a feature Request?
We have a proper working Azure Service Bus client in Java, but we're bumping into very excessive logging making it hard to understand what is happening

Setup (please complete the following information if applicable):

• OS: Linux
• IDE: IntelliJ
• Library/Libraries:

        <dependency>
            <groupId>com.azure</groupId>
            <artifactId>azure-messaging-servicebus</artifactId>
            <version>7.17.6</version>
        </dependency>

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

• Query Added
• Setup information Added

---

Our client is initialized as:

public ServiceBusReceiverClient getClient() {
        return new ServiceBusClientBuilder()
            .connectionString(connectionString)
            .clientOptions(new ClientOptions().setApplicationId(applicationId))
            .retryOptions(new AmqpRetryOptions().setTryTimeout(Duration.ofSeconds(5)))
            .receiver()
            .topicName(topicName)
            .subscriptionName(subscription)
            .disableAutoComplete()
            .receiveMode(ServiceBusReceiveMode.PEEK_LOCK)
            .buildClient();
    }

We use it as:

 client.receiveMessages(MAX_MESSAGES, Duration.ofMinutes(MAX_WAIT_TIME_MINUTES))
                      .forEach(event -> {
                          log.info("Processing message: {}", event);
                          // Do some business logic here
                      });

But this results into following excessive warning logging:

2025-01-06 17:14:31 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"The mediator is active.","messageFlux":"mf_3bf550_1735907333653","connectionId":"MF_02cd81_1735907333653","linkName":"my-topic-name/subscriptions/my-subscription_322ec6_1735907333653","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:31 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"The mediator is active.","messageFlux":"mf_640200_1735905233639","connectionId":"MF_a04d0d_1735905233639","linkName":"my-topic-name/subscriptions/my-subscription_48d653_1735905233639","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:31 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"Setting next mediator and waiting for activation.","messageFlux":"mf_3bf550_1735907333653","connectionId":"MF_02cd81_1735907333653","linkName":"my-topic-name/subscriptions/my-subscription_322ec6_1735907333653","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:31 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"Setting next mediator and waiting for activation.","messageFlux":"mf_640200_1735905233639","connectionId":"MF_a04d0d_1735905233639","linkName":"my-topic-name/subscriptions/my-subscription_48d653_1735905233639","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:31 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"Requesting a new mediator.","messageFlux":"mf_3bf550_1735907333653","connectionId":"MF_02cd81_1735907333653","linkName":"my-topic-name/subscriptions/my-subscription_322ec6_1735907333653","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:31 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"Requesting a new mediator.","messageFlux":"mf_640200_1735905233639","connectionId":"MF_a04d0d_1735905233639","linkName":"my-topic-name/subscriptions/my-subscription_48d653_1735905233639","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:30 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"The mediator is active.","messageFlux":"mf_c52022_1735909133667","connectionId":"MF_f72521_1735909133667","linkName":"my-topic-name/subscriptions/my-subscription_06aafc_1735909133667","entityPath":"my-topic-name/subscriptions/my-subscription"}
2025-01-06 17:14:30 WARN - com.azure.core.amqp.implementation.MessageFlux : {"az.sdk.message":"The mediator is active.","messageFlux":"mf_640200_1735905233639","connectionId":"MF_a04d0d_1735905233639","linkName":"my-topic-name/subscriptions/my-subscription_06aafc_1735909133667","entityPath":"my-topic-name/subscriptions/my-subscription"}

My question:
👉 A WARN gives me the indication that I'm doing something not 100% correct and I was wondering if I need to change something in my Java code, or if I should change my logging level for com.azure.core.amqp.implementation.MessageFlux to ERROR?
Even when there are no messages on the queue, we are being flooded with these WARN statements

[github-actions]

@anuchandy @conniey @lmolkova

[github-actions]

Thank you for your feedback. Tagging and routing to the team member best able to assist.

[anuchandy]

Hello @jochenhebbrecht, thanks for reaching out, these logs do not indicate issues in your usage code. The underlying receive link to the entity (such as a queue, topic:subscription) is closed by the Service Bus broker if there is no activity (also known as idle timeout) on the receiver. This log message indicates that the client successfully reconnected using a new receive link when the broker closed the existing one. The idle timeout (controlled by the broker) as of now is 5 minutes.

We'll change these to INFO or a less severe level, for now you can ignore these two loglines / filter out in the log configuration.

[jochenhebbrecht]

@anuchandy thanks for confirming that we should not be worried about the WARN statements 👌

I believe it's a good idea if you would change this logging from WARN -> INFO indeed. I'll keep an eye for future releases