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.

Sign up for GitHub

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

Jump to bottom

[BUG] Continuous logs from com.azure.core.amqp.implementation.RequestResponseChannel as part of the event hub messaging implementation #31487

Closed
meethishkm opened this issue Oct 14, 2022 · 6 comments
Closed

[BUG] Continuous logs from com.azure.core.amqp.implementation.RequestResponseChannel as part of the event hub messaging implementation #31487

meethishkm opened this issue Oct 14, 2022 · 6 comments
Assignees
@conniey
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. Event Hubs question The issue doesn't require a change to the product in order to be resolved. Most issues start as that

Comments

@meethishkm
Copy link

meethishkm commented Oct 14, 2022 •
edited by saragluna
Loading

Continuous logs from com.azure.core.amqp.implementation.RequestResponseChannel

2022-10-14 12:26:33 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_376698_1665730591541] entityPath[$cbs]: Setting next AMQP channel.
2022-10-14 12:26:33 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_376698_1665730591541] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-14 12:26:34 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_376698_1665730591541] entityPath[$cbs]: Channel is now active.
2022-10-14 12:26:43 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_55426b_1665730601586] entityPath[$cbs]: Setting next AMQP channel.
2022-10-14 12:26:43 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_55426b_1665730601586] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-14 12:26:44 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_55426b_1665730601586] entityPath[$cbs]: Channel is now active.
2022-10-14 12:26:55 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_4f79bf_1665730612493] entityPath[$cbs]: Setting next AMQP channel.
2022-10-14 12:26:55 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_4f79bf_1665730612493] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-14 12:26:55 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_4f79bf_1665730612493] entityPath[$cbs]: Channel is now active.
2022-10-14 12:27:04 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_d1cccb_1665730621741] entityPath[$cbs]: Setting next AMQP channel.
2022-10-14 12:27:04 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_d1cccb_1665730621741] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-14 12:27:04 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_d1cccb_1665730621741] entityPath[$cbs]: Channel is now active.
2022-10-14 12:27:13 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_35e03e_1665730631578] entityPath[$cbs]: Setting next AMQP channel.
2022-10-14 12:27:13 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_35e03e_1665730631578] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-14 12:27:14 INFO  RequestResponseChannel:$cbs:429 - namespace[MF_35e03e_1665730631578] entityPath[$cbs]: Channel is now active.

Using EventProcessorClient for streaming Eventhub.

 <dependency>
            <groupId>com.azure</groupId>
            <artifactId>azure-messaging-eventhubs</artifactId>
            <version>5.10.0</version>
        </dependency>
        <dependency>
            <groupId>com.azure</groupId>
            <artifactId>azure-messaging-eventhubs-checkpointstore-blob</artifactId>
            <version>1.9.0</version>
        </dependency>

Have also tried to exclude the logs of the library with log4j2 but logs continue to flow!
@ghost ghost added needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. customer-reported Issues that are reported by GitHub users external to the Azure organization. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that labels Oct 14, 2022
@joshfree joshfree added Event Hubs Client This issue points to a problem in the data-plane of the library. labels Oct 20, 2022
@ghost ghost removed the needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. label Oct 20, 2022
@joshfree
Copy link
Member

@conniey could you please follow up

@conniey
Copy link
Member

conniey commented Oct 20, 2022

We've made several reliability changes in 5.14.0 that reduce the number of attempts. Does it still reproduce on the latest version?

@meethishkm
Copy link
Author

Hi @conniey ,

No, I don't see a considerable difference in the continuous logs with 5.14.0

2022-10-21 10:55:09 INFO RequestResponseChannel:$management:429 - namespace[MF_db5a6b_1666329907985] entityPath[$management]: Setting next AMQP channel.
2022-10-21 10:55:09 INFO RequestResponseChannel:$management:429 - namespace[MF_db5a6b_1666329907985] entityPath[$management]: Next AMQP channel received, updating 2 current subscribers
2022-10-21 10:55:09 INFO RequestResponseChannel:$management:429 - namespace[MF_db5a6b_1666329907985] entityPath[$management]: Channel is now active.
2022-10-21 10:55:15 INFO RequestResponseChannel:$cbs:429 - namespace[MF_857fd3_1666329914416] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:55:15 INFO RequestResponseChannel:$cbs:429 - namespace[MF_857fd3_1666329914416] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:55:16 INFO RequestResponseChannel:$cbs:429 - namespace[MF_857fd3_1666329914416] entityPath[$cbs]: Channel is now active.
2022-10-21 10:55:18 INFO RequestResponseChannel:$management:171 - Upstream connection publisher was completed. Terminating processor.
2022-10-21 10:55:18 INFO RequestResponseChannel:$management:429 - namespace[MF_db5a6b_1666329907985] entityPath[$management]: AMQP channel processor completed. Notifying 1 subscribers.
2022-10-21 10:55:18 INFO RequestResponseChannel:$management:171 - Upstream connection publisher was completed. Terminating processor.
2022-10-21 10:55:18 INFO RequestResponseChannel:$management:429 - namespace[MF_db5a6b_1666329907985] entityPath[$management]: AMQP channel processor completed. Notifying 0 subscribers.
2022-10-21 10:55:26 INFO RequestResponseChannel:$cbs:429 - namespace[MF_b02a33_1666329924847] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:55:26 INFO RequestResponseChannel:$cbs:429 - namespace[MF_b02a33_1666329924847] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:55:27 INFO RequestResponseChannel:$cbs:429 - namespace[MF_b02a33_1666329924847] entityPath[$cbs]: Channel is now active.
2022-10-21 10:55:36 INFO RequestResponseChannel:$cbs:429 - namespace[MF_8dd109_1666329934947] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:55:36 INFO RequestResponseChannel:$cbs:429 - namespace[MF_8dd109_1666329934947] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:55:37 INFO RequestResponseChannel:$cbs:429 - namespace[MF_8dd109_1666329934947] entityPath[$cbs]: Channel is now active.
2022-10-21 10:55:50 INFO RequestResponseChannel:$cbs:429 - namespace[MF_f0e040_1666329947617] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:55:50 INFO RequestResponseChannel:$cbs:429 - namespace[MF_f0e040_1666329947617] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:56:21 INFO RequestResponseChannel:$cbs:429 - namespace[MF_a46226_1666329979531] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:56:21 INFO RequestResponseChannel:$cbs:429 - namespace[MF_a46226_1666329979531] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:56:22 INFO RequestResponseChannel:$cbs:429 - namespace[MF_a46226_1666329979531] entityPath[$cbs]: Channel is now active.
2022-10-21 10:56:29 INFO RequestResponseChannel:$cbs:429 - namespace[MF_beb688_1666329984999] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:56:29 INFO RequestResponseChannel:$cbs:429 - namespace[MF_beb688_1666329984999] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:56:29 INFO RequestResponseChannel:$cbs:429 - namespace[MF_beb688_1666329984999] entityPath[$cbs]: Channel is now active.
2022-10-21 10:56:40 INFO RequestResponseChannel:$cbs:429 - namespace[MF_6feb43_1666329997070] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:56:40 INFO RequestResponseChannel:$cbs:429 - namespace[MF_6feb43_1666329997070] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:56:40 INFO RequestResponseChannel:$cbs:429 - namespace[MF_6feb43_1666329997070] entityPath[$cbs]: Channel is now active.
2022-10-21 10:56:50 INFO RequestResponseChannel:$cbs:429 - namespace[MF_057bfb_1666330006952] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:56:50 INFO RequestResponseChannel:$cbs:429 - namespace[MF_057bfb_1666330006952] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:56:59 INFO RequestResponseChannel:$cbs:429 - namespace[MF_4833d3_1666330014782] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:56:59 INFO RequestResponseChannel:$cbs:429 - namespace[MF_4833d3_1666330014782] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:57:00 INFO RequestResponseChannel:$cbs:429 - namespace[MF_4833d3_1666330014782] entityPath[$cbs]: Channel is now active.
2022-10-21 10:57:20 INFO RequestResponseChannel:$cbs:429 - namespace[MF_a158de_1666330037210] entityPath[$cbs]: Setting next AMQP channel.
2022-10-21 10:57:20 INFO RequestResponseChannel:$cbs:429 - namespace[MF_a158de_1666330037210] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2022-10-21 10:57:20 INFO RequestResponseChannel:$cbs:429 - namespace[MF_a158de_1666330037210] entityPath[$cbs]: Channel is now active.

@conniey
Copy link
Member

conniey commented Oct 24, 2022 •
edited
Loading

If I understand correctly, the processing doesn't stop, but the issue is seeing a lot of logs. Unfortunately, this is our current behaviour due to the asynchronous state of each AMQP component. But we do have a github issue to reduce the number of logs #20836

What is the expression in log4j2 you're using to exclude the logs? We have a few examples linked in our TROUBLESHOOTING.md

@conniey
Copy link
Member

conniey commented Feb 23, 2023

This will be fixed as part of #33378

@anuchandy
Copy link
Member

Fixed by #34854 and #39107

@github-actions github-actions bot locked and limited conversation to collaborators Dec 10, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@conniey conniey

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. Event Hubs question The issue doesn't require a change to the product in order to be resolved. Most issues start as that
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@joshfree @anuchandy @conniey @meethishkm