Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[QUERY] ServiceBusSenderClient reactor onErrorDropped logs #41637

Closed
2 tasks done
rileymichael opened this issue Aug 26, 2024 · 5 comments
Closed
2 tasks done

[QUERY] ServiceBusSenderClient reactor onErrorDropped logs #41637

rileymichael opened this issue Aug 26, 2024 · 5 comments
Assignees
Labels
Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-team-attention Workflow: This issue needs attention from Azure service team or SDK team question The issue doesn't require a change to the product in order to be resolved. Most issues start as that Service Bus

Comments

@rileymichael
Copy link

Query/Question
Hello -- we're currently running azure-messaging-servicebus:7.17.2 and we're seeing the following errors logged fairly regularly from the ServiceBusSenderClient:

message: 
Operator called default onErrorDropped
logger:
reactor.core.publisher.Operators
stack trace: 
reactor.core.Exceptions$ErrorCallbackNotImplemented: com.azure.core.amqp.exception.AmqpException: onSessionRemoteClose connectionId[MF_e4d40b_1724676323518], entityName[****-events] condition[Error{condition=amqp:connection:forced, description='The connection was closed by container '3bc1b298d34848099cab325eb0cd025e_G15' because it did not have any active links in the past 300000 milliseconds. TrackingId:3bc1b298d34848099cab325eb0cd025e_G15, SystemTracker:gateway10, Timestamp:2024-08-26T15:26:30', info=null}], errorContext[NAMESPACE: ***.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: ****-events]
Caused by: com.azure.core.amqp.exception.AmqpException: onSessionRemoteClose connectionId[MF_e4d40b_1724676323518], entityName[****-events] condition[Error{condition=amqp:connection:forced, description='The connection was closed by container '3bc1b298d34848099cab325eb0cd025e_G15' because it did not have any active links in the past 300000 milliseconds. TrackingId:3bc1b298d34848099cab325eb0cd025e_G15, SystemTracker:gateway10, Timestamp:2024-08-26T15:26:30', info=null}], errorContext[NAMESPACE: ****.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: ****-events]
	at com.azure.core.amqp.implementation.ExceptionUtil.toException(ExceptionUtil.java:90)
	at com.azure.core.amqp.implementation.handler.SessionHandler.onSessionRemoteClose(SessionHandler.java:139)
	at org.apache.qpid.proton.engine.BaseHandler.handle(BaseHandler.java:152)
	at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:108)
	at org.apache.qpid.proton.reactor.impl.ReactorImpl.dispatch(ReactorImpl.java:324)
	at org.apache.qpid.proton.reactor.impl.ReactorImpl.process(ReactorImpl.java:291)
	at com.azure.core.amqp.implementation.ReactorExecutor.run(ReactorExecutor.java:91)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)

and

message:
Error in SendLinkHandler. Disposing unconfirmed sends.
logger:
com.azure.core.amqp.implementation.RequestResponseChannel
exception:
The connection was closed by container '3bc1b298d34848099cab325eb0cd025e_G15' because it did not have any active links in the past 300000 milliseconds. TrackingId:3bc1b298d34848099cab325eb0cd025e_G15, SystemTracker:gateway10, Timestamp:2024-08-26T15:26:30, errorContext[NAMESPACE: ****.servicebus.windows.net. ERROR CONTEXT: N/A, PATH: $cbs, REFERENCE_ID: cbs:sender, LINK_CREDIT: 98]

Is this expected behavior on inactive / low volume links? If so, should the logging be adjusted?

Why is this not a Bug or a feature Request?

Unclear if this is just unneeded / verbose logs or an actual issue producing messages.

Setup (please complete the following information if applicable):

  • Library/Libraries: com.azure:azure-messaging-servicebus:7.17.2

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
@github-actions github-actions bot added Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-team-attention Workflow: This issue needs attention from Azure service team or SDK team question The issue doesn't require a change to the product in order to be resolved. Most issues start as that Service Bus labels Aug 26, 2024
Copy link

@anuchandy @conniey @lmolkova

Copy link

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

@anuchandy
Copy link
Member

Hi @rileymichael, the Service Bus broker will disconnect the sender-session and the parent TCP connection of the sender-session if there is no activity (e.g., no send operations) for 5 minutes. The logs you're seeing is printed in the background by the internal state machine when broker-side timeout happens, and when application attempt the next send, then the connectivity will be reestablished.

These appear as errors since the Service Bus library lets the Reactor library capture it, and when an error is passed to Reactor, it logs it at the error level. These logs can be ignored, and we'll look into capture in Service Bus library level and log in WARN so this won't be a noise.

@rileymichael
Copy link
Author

Thanks for the explanation @anuchandy, that makes sense. We'll ignore them as suggested until that change can be made. Appreciate it!

@anuchandy
Copy link
Member

Fixed in #41641

@anuchandy anuchandy self-assigned this Aug 29, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. needs-team-attention Workflow: This issue needs attention from Azure service team or SDK team question The issue doesn't require a change to the product in order to be resolved. Most issues start as that Service Bus
Projects
None yet
Development

No branches or pull requests

4 participants
@anuchandy @conniey @rileymichael and others