Service Bus Java client logs contain many WARN level error messages

Yaari, Yossi 1 Reputation point
2022-08-02T15:50:52.52+00:00

We are running a Java client on a container in AKS, with Azure Service bus. And we are seeing a whole error sequence every seconds.
The functionality is working OK.
Is this valid normal flow?

We set the log level to WARN, to minimize the volume. It's taking up too much of our log storage.

log:

2022-08-02 15:00:12,696|reactor-executor-799|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Error in SendLinkHandler. Disposing unconfirmed sends.","exception":"The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:3d62a3e1fc9140cca62c3b89c88ee725_G5S2, SystemTracker:gateway5, Timestamp:2022-08-02T15:00:12, errorContext[NAMESPACE: mip-sb-prod.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 99]","connectionId":"MF_a62f4e_1659451512612","linkName":"cbs"}
2022-08-02 15:00:08,886|reactor-executor-527|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Error in SendLinkHandler. Disposing unconfirmed sends.","exception":"The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:67242eedc3d047c2b16fb4492c439a2a_G4S2, SystemTracker:gateway5, Timestamp:2022-08-02T15:00:08, errorContext[NAMESPACE: mip-sb-prod.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 99]","connectionId":"MF_44c395_1659451508855","linkName":"cbs"}
2022-08-02 15:00:09,527|reactor-executor-528|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Error in SendLinkHandler. Disposing unconfirmed sends.","exception":"The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:67242eedc3d047c2b16fb4492c439a2a_G4S2, SystemTracker:gateway5, Timestamp:2022-08-02T15:00:09, errorContext[NAMESPACE: mip-sb-prod.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 99]","connectionId":"MF_675432_1659451509439","linkName":"cbs"}
2022-08-02 15:00:09,527|reactor-executor-529|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Error in SendLinkHandler. Disposing unconfirmed sends.","exception":"The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:67242eedc3d047c2b16fb4492c439a2a_G4S2, SystemTracker:gateway5, Timestamp:2022-08-02T15:00:09, errorContext[NAMESPACE: mip-sb-prod.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 99]","connectionId":"MF_7e0193_1659451509543","linkName":"cbs"}
2022-08-02 15:00:12,606|reactor-executor-530|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Error in SendLinkHandler. Disposing unconfirmed sends.","exception":"The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:67242eedc3d047c2b16fb4492c439a2a_G4S2, SystemTracker:gateway5, Timestamp:2022-08-02T15:00:12, errorContext[NAMESPACE: mip-sb-prod.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 99]","connectionId":"MF_8aba75_1659451512656","linkName":"cbs"}
2022-08-02 15:00:14,050|boundedElastic-1314|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","exception":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","connectionId":"MF_675432_1659451509439"}
2022-08-02 15:00:14,050|reactor-executor-528|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","exception":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","connectionId":"MF_675432_1659451509439"}
2022-08-02 15:00:14,050|boundedElastic-1309|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"signalWorkQueue failed before reactor closed.","exception":null,"connectionId":"MF_675432_1659451509439"}
2022-08-02 15:00:14,050|reactor-executor-528|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Unable to open send and receive link.","exception":"Unable to open send and receive link.","connectionId":"MF_675432_1659451509439","linkName":"cbs"}
2022-08-02 15:00:14,050|reactor-executor-528|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Retry attempts exhausted or exception was not retriable.","exception":"Unable to open send and receive link.","connectionId":"MF_675432_1659451509439","entityPath":"$cbs","retry":2}
2022-08-02 15:01:13,452|parallel-1|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","exception":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","connectionId":"MF_44c395_1659451508855"}
2022-08-02 15:01:13,452|boundedElastic-1312|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","exception":"ReactorDispatcher instance is closed. Should not continue dispatching work to this reactor.","connectionId":"MF_44c395_1659451508855"}
2022-08-02 15:01:13,452|parallel-1|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Unable to open send and receive link.","exception":"Unable to open send and receive link.","connectionId":"MF_44c395_1659451508855","linkName":"cbs"}
2022-08-02 15:01:13,452|parallel-1|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Retry attempts exhausted or exception was not retriable.","exception":"Unable to open send and receive link.","connectionId":"MF_44c395_1659451508855","entityPath":"$cbs","retry":2}
2022-08-02 15:30:09,283|reactor-executor-536|WARN||com.azure.core.util.logging.LoggingEventBuilder - {"az.sdk.message":"Error in SendLinkHandler. Disposing unconfirmed sends.","exception":"The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:c89977773fc745d680279b1f91198644_G2S3, SystemTracker:gateway5, Timestamp:2022-08-02T15:30:09, errorContext[NAMESPACE: mip-sb-prod.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 99]","connectionId":"MF_5202a5_1659453309229","linkName":"cbs"}

Azure API Management
Azure API Management
An Azure service that provides a hybrid, multi-cloud management platform for APIs.
2,175 questions
0 comments No comments
{count} votes

1 answer

Sort by: Most helpful
  1. JananiRamesh-MSFT 27,921 Reputation points
    2022-08-19T05:29:11.82+00:00

    Hi @Yaari, Yossi Thanks for reaching out. These warnings occurs when all links in the connection gets closed due to inactivity (idle) and new link has not been created in 5 minutes.

    These are all standard behaviors of the service, and you can avoid them by making send/receive calls on their Connection/Link which will automatically recreate connection/link.

    For more information please refer: https://learn.microsoft.com/bs-latn-ba/azure/service-bus-messaging/service-bus-amqp-troubleshoot

    let me know incase of further queries, I would be happy to assist you.

    Please 'Accept as answer' and ‘Upvote’ if it helped so that it can help others in the community looking for help on similar topics.


Your answer

Answers can be marked as Accepted Answers by the question author, which helps users to know the answer solved the author's problem.