ServiceBus SDK: Session-enabled queue receiver links detach immediately after successful attachment with "Session error" #38629
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.
issue-addressed
Workflow: The Azure SDK team believes it to be addressed and ready to close.
Messaging
Messaging crew
question
The issue doesn't require a change to the product in order to be resolved. Most issues start as that
Service Bus
Comments
github-actions
bot
added
Client
|
Thank you for your feedback. Tagging and routing to the team member best able to assist. |
|
Thank you for the feedback @ADevBelgie , a few follow up questions
This is the way to set up additional logging -> set logging to DEBUG and pass in import logging
import sys
handler = logging.StreamHandler(stream=sys.stdout)
log_fmt = logging.Formatter(fmt="%(asctime)s | %(threadName)s | %(levelname)s | %(name)s | %(message)s")
handler.setFormatter(log_fmt)
logger = logging.getLogger('azure.servicebus')
logger.setLevel(logging.DEBUG)
logger.addHandler(handler)
...
from azure.servicebus import ServiceBusClient
client = ServiceBusClient(..., logging_enable=True) |
|
Hi @ADevBelgie , I was unable to repro the issue with the following sample. I got back exactly 10 messages and my queue had 100 messages with a particular session. the logs and sample are in sync, but the same happens in async. I even had it waiting on a completely empty queue for over a minute and didnt get that error.
import os
from azure.servicebus import ServiceBusClient, ServiceBusMessage, NEXT_AVAILABLE_SESSION
from azure.identity import AzurePowerShellCredential
from dotenv import load_dotenv, find_dotenv
load_dotenv(find_dotenv())
FULLY_QUALIFIED_NAMESPACE = os.environ["SERVICEBUS_FULLY_QUALIFIED_NAMESPACE"]
SESSION_QUEUE_NAME = os.environ["SERVICEBUS_SESSION_QUEUE_NAME"]
import logging
import sys
log_fmt = logging.Formatter(fmt="%(asctime)s | %(threadName)s | %(levelname)s | %(name)s | %(message)s")
logger = logging.getLogger("azure")
logger.setLevel(logging.DEBUG)
file_handler = logging.FileHandler(filename="sample.log")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(log_fmt)
logger.addHandler(file_handler)
if __name__ == "__main__":
credential = AzurePowerShellCredential()
servicebus_client = ServiceBusClient(FULLY_QUALIFIED_NAMESPACE, credential, logging_enable=True)
with servicebus_client:
receiver = servicebus_client.get_queue_receiver(queue_name=SESSION_QUEUE_NAME, session_id=NEXT_AVAILABLE_SESSION)
with receiver:
messages = receiver.receive_messages(max_message_count=10)
print(f"Received {len(messages)} messages.")
for idx, message in enumerate(messages):
print(str(message))
receiver.complete_message(message)
print("Receive is done.") |
kashifkhan
added
the
needs-author-feedback
github-actions
bot
removed
the
needs-team-attention
|
Hi @ADevBelgie. Thank you for opening this issue and giving us the opportunity to assist. To help our team better understand your issue and the details of your scenario please provide a response to the question asked above or the information requested above. This will help us more accurately address your issue. |
|
@kashifkhan Thank you for the quick response and sample. Some clarifications:
The key difference I notice is that your sample uses synchronous code while we're using async. Our async implementation shows:
We've also tried your suggested logging config and can now see the frame-level details. Key sequence: The difference seems to be in how the async session receiver maintains its lifecycle. Could this be related to session lock acquisition timing in the async path? |
github-actions
bot
added
needs-team-attention
|
@kashifkhan We've found the root cause and a solution. The issue was in the async receiver lifecycle management, specifically around how the session link is established and maintained. Root Cause:
Solution: # Before - would cause immediate detachment
async with self._receiver: # Context closes immediately after verification
if await self._receiver._handler.client_ready_async():
return self._receiver
# After - maintains the session
receiver = self._client.get_queue_receiver(...)
await receiver._open_with_retry() # Start receiver without closing context
if hasattr(receiver, '_handler') and receiver._handler:
if await receiver._handler.client_ready_async():
self._receiver = receiver
return receiverThis keeps the session link active while allowing the receiver to process messages. Verification: The CBS token remains valid and the session stays active for continuous message processing. This seems to be a key difference in how session receivers need to be managed in the async path compared to sync. Would it be worth documenting this pattern for other async users? |
|
Hi @ADevBelgie , thank you for your response and some clarifications. We were wondering why a Session error was showing up at the customer level and your code snippet makes that clear. We would not document or suggest that as a pattern for customers to use since its using private methods at the deepest levels of the library, which can be changed at any time and lead to apps being broken. There is no need to be using those methods publicly. The recommended approach for async is below a long with the logs. It works similar to sync and I have tested the following scenarios
import os
import asyncio
from azure.servicebus.aio import ServiceBusClient
from azure.servicebus import NEXT_AVAILABLE_SESSION
from azure.identity.aio import AzurePowerShellCredential
from dotenv import load_dotenv, find_dotenv
load_dotenv(find_dotenv())
FULLY_QUALIFIED_NAMESPACE = os.environ["SERVICEBUS_FULLY_QUALIFIED_NAMESPACE"]
SESSION_QUEUE_NAME = os.environ["SERVICEBUS_SESSION_QUEUE_NAME"]
import logging
import sys
log_fmt = logging.Formatter(fmt="%(asctime)s | %(threadName)s | %(levelname)s | %(name)s | %(message)s")
logger = logging.getLogger("azure")
logger.setLevel(logging.DEBUG)
file_handler = logging.FileHandler(filename="sample.log")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(log_fmt)
logger.addHandler(file_handler)
async def main():
credential = AzurePowerShellCredential()
servicebus_client = ServiceBusClient(FULLY_QUALIFIED_NAMESPACE, credential, logging_enable=True)
receiver = servicebus_client.get_queue_receiver(queue_name=SESSION_QUEUE_NAME, session_id=NEXT_AVAILABLE_SESSION)
async with receiver:
messages = await receiver.receive_messages(max_message_count=10)
print(f"Received {len(messages)} messages.")
for idx, message in enumerate(messages):
print(str(message))
await receiver.complete_message(message)
print("Receive is done.")
asyncio.run(main())2024-11-21 14:28:43,089 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: None -> <ConnectionState.START: 0>
2024-11-21 14:28:43,158 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._connection_async | -> Header(b'AMQP\x00\x01\x00\x00')
2024-11-21 14:28:43,158 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.START: 0> -> <ConnectionState.HDR_SENT: 2>
2024-11-21 14:28:43,159 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.HDR_SENT: 2> -> <ConnectionState.HDR_SENT: 2>
2024-11-21 14:28:43,159 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._connection_async | -> OpenFrame(container_id='SBReceiver-081a0dba-4ce6-45b8-81e2-3fa9e0676725', hostname='****.servicebus.windows.net', max_frame_size=1048576, channel_max=65535, idle_timeout=None, outgoing_locales=None, incoming_locales=None, offered_capabilities=None, desired_capabilities=None, properties={'product': 'azsdk-python-servicebus', 'version': '7.13.0', 'framework': 'Python/3.11.10', 'platform': 'Linux-5.15.167.4-microsoft-standard-WSL2-x86_64-with-glibc2.35', 'user-agent': 'azsdk-python-servicebus/7.13.0 pyamqp/2.0.0a1 Python/3.11.10 (Linux-5.15.167.4-microsoft-standard-WSL2-x86_64-with-glibc2.35)'})
2024-11-21 14:28:43,159 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.HDR_SENT: 2> -> <ConnectionState.OPEN_PIPE: 4>
2024-11-21 14:28:43,159 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> BeginFrame(remote_channel=None, next_outgoing_id=0, incoming_window=65536, outgoing_window=65536, handle_max=4294967295, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,160 | MainThread | INFO | azure.servicebus._pyamqp.aio._session_async | Session state changed: <SessionState.UNMAPPED: 0> -> <SessionState.BEGIN_SENT: 1>
2024-11-21 14:28:43,160 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | -> AttachFrame(name='e33e55bd-9389-496e-b10d-0ab98070b156', handle=2, role=True, send_settle_mode=0, rcv_settle_mode=0, source=Source(address='$cbs', durable=None, expiry_policy=None, timeout=None, dynamic=None, dynamic_node_properties=None, distribution_mode=None, filters=None, default_outcome=None, outcomes=None, capabilities=None), target=Target(address='$cbs', durable=None, expiry_policy=None, timeout=None, dynamic=None, dynamic_node_properties=None, capabilities=None), unsettled=None, incomplete_unsettled=None, initial_delivery_count=None, max_message_size=None, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,160 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.DETACHED: 0> -> <LinkState.ATTACH_SENT: 1>
2024-11-21 14:28:43,160 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link receiver state changed: <LinkState.DETACHED: 0> -> <LinkState.ATTACH_SENT: 1>
2024-11-21 14:28:43,161 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | -> AttachFrame(name='6df3e435-3a3a-46f3-ad28-0fe058396eff', handle=1, role=False, send_settle_mode=0, rcv_settle_mode=0, source=Source(address='$cbs', durable=None, expiry_policy=None, timeout=None, dynamic=None, dynamic_node_properties=None, distribution_mode=None, filters=None, default_outcome=None, outcomes=None, capabilities=None), target=Target(address='$cbs', durable=None, expiry_policy=None, timeout=None, dynamic=None, dynamic_node_properties=None, capabilities=None), unsettled=None, incomplete_unsettled=None, initial_delivery_count=0, max_message_size=None, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,161 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.DETACHED: 0> -> <LinkState.ATTACH_SENT: 1>
2024-11-21 14:28:43,161 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link sender state changed: <LinkState.DETACHED: 0> -> <LinkState.ATTACH_SENT: 1>
2024-11-21 14:28:43,193 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._connection_async | <- Header(b'AMQP\x00\x01\x00\x00')
2024-11-21 14:28:43,193 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.OPEN_PIPE: 4> -> <ConnectionState.OPEN_SENT: 7>
2024-11-21 14:28:43,244 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._connection_async | <- OpenFrame(container_id=b'52a139e9f93743d7b0ce32db98b64ce0_G10', hostname=None, max_frame_size=65536, channel_max=4999, idle_timeout=120000, outgoing_locales=None, incoming_locales=None, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,245 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.OPEN_SENT: 7> -> <ConnectionState.OPENED: 9>
2024-11-21 14:28:43,295 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | <- BeginFrame(remote_channel=1, next_outgoing_id=1, incoming_window=5000, outgoing_window=65536, handle_max=255, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,296 | MainThread | INFO | azure.servicebus._pyamqp.aio._session_async | Session state changed: <SessionState.BEGIN_SENT: 1> -> <SessionState.MAPPED: 3>
2024-11-21 14:28:43,346 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | <- AttachFrame(name=b'e33e55bd-9389-496e-b10d-0ab98070b156', handle=0, role=False, send_settle_mode=0, rcv_settle_mode=0, source=[b'$cbs', None, None, None, None, None, None, None, None, None, None], target=[b'$cbs', None, None, None, None, None, None], unsettled=None, incomplete_unsettled=None, initial_delivery_count=0, max_message_size=18446744073709551615, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,347 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.ATTACH_SENT: 1> -> <LinkState.ATTACHED: 3>
2024-11-21 14:28:43,347 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link receiver state changed: <LinkState.ATTACH_SENT: 1> -> <LinkState.ATTACHED: 3>
2024-11-21 14:28:43,347 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> FlowFrame(next_incoming_id=1, incoming_window=65536, next_outgoing_id=0, outgoing_window=65536, handle=2, delivery_count=0, link_credit=10000, available=None, drain=None, echo=None, properties=None)
2024-11-21 14:28:43,398 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | <- AttachFrame(name=b'6df3e435-3a3a-46f3-ad28-0fe058396eff', handle=1, role=True, send_settle_mode=0, rcv_settle_mode=0, source=[b'$cbs', None, None, None, None, None, None, None, None, None, None], target=[b'$cbs', None, None, None, None, None, None], unsettled=None, incomplete_unsettled=None, initial_delivery_count=None, max_message_size=18446744073709551615, offered_capabilities=None, desired_capabilities=None, properties=None)
2024-11-21 14:28:43,398 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.ATTACH_SENT: 1> -> <LinkState.ATTACHED: 3>
2024-11-21 14:28:43,399 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link sender state changed: <LinkState.ATTACH_SENT: 1> -> <LinkState.ATTACHED: 3>
2024-11-21 14:28:43,399 | MainThread | INFO | azure.servicebus._pyamqp.aio._cbs_async | CBS completed opening with status: <ManagementOpenResult.OK: 1>
2024-11-21 14:28:43,399 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> FlowFrame(next_incoming_id=1, incoming_window=65536, next_outgoing_id=0, outgoing_window=65536, handle=1, delivery_count=0, link_credit=10000, available=None, drain=None, echo=None, properties=None)
2024-11-21 14:28:45,981 | MainThread | INFO | azure.identity.aio._internal.decorators | AzurePowerShellCredential.get_token succeeded
2024-11-21 14:28:45,981 | MainThread | DEBUG | azure.identity.aio._internal.decorators | [Authenticated account] Client ID: 1950a258-227b-4e31-a9cf-717495945fc2. Tenant ID: 72f988bf-86f1-41af-91ab-2d7cd011db47. User Principal Name: [email protected]. Object ID (user): fa54e51e-ab45-4fa9-b655-4b8b601b82c4
2024-11-21 14:28:45,982 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> TransferFrame(handle=1, delivery_id=0, delivery_tag=b'\x00\x00\x00\x01', message_format=0, settled=False, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=None, payload=b'***')
2024-11-21 14:28:45,982 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | <- FlowFrame(next_incoming_id=0, incoming_window=5000, next_outgoing_id=1, outgoing_window=65536, handle=1, delivery_count=0, link_credit=100, available=0, drain=None, echo=False, properties=None)
2024-11-21 14:28:46,033 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS update in progress. Token put time: 1732199325
2024-11-21 14:28:46,034 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | <- DispositionFrame(role=True, first=0, last=None, settled=True, state={'accepted': []}, batchable=None)
2024-11-21 14:28:46,085 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS update in progress. Token put time: 1732199325
2024-11-21 14:28:46,085 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=0, delivery_id=0, delivery_tag=b'\x01\x00\x00\x00', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=False, payload=b'***')
2024-11-21 14:28:46,086 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS Put token result (<ManagementExecuteOperationResult.OK: 0>), status code: 202, status_description: b'Accepted'.
2024-11-21 14:28:46,136 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,136 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | -> AttachFrame(name='df33ec07-b36c-4a20-a058-f9136645917c', handle=3, role=True, send_settle_mode=0, rcv_settle_mode=1, source=Source(address='amqps://****.servicebus.windows.net/****-session-queue', durable=None, expiry_policy=None, timeout=None, dynamic=None, dynamic_node_properties=None, distribution_mode=None, filters={b'com.microsoft:session-filter': None}, default_outcome=None, outcomes=None, capabilities=None), target=Target(address='receiver-link-df33ec07-b36c-4a20-a058-f9136645917c', durable=None, expiry_policy=None, timeout=None, dynamic=None, dynamic_node_properties=None, capabilities=None), unsettled=None, incomplete_unsettled=None, initial_delivery_count=None, max_message_size=1048576, offered_capabilities=None, desired_capabilities=None, properties={b'com.microsoft:receiver-name': 'SBReceiver-081a0dba-4ce6-45b8-81e2-3fa9e0676725'})
2024-11-21 14:28:46,137 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.DETACHED: 0> -> <LinkState.ATTACH_SENT: 1>
2024-11-21 14:28:46,173 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | <- AttachFrame(name=b'df33ec07-b36c-4a20-a058-f9136645917c', handle=2, role=False, send_settle_mode=0, rcv_settle_mode=1, source=[b'amqps://****.servicebus.windows.net/****-session-queue', None, None, None, None, None, None, {b'com.microsoft:session-filter': b'hi'}, None, None, None], target=[b'receiver-link-df33ec07-b36c-4a20-a058-f9136645917c', None, None, None, None, None, None], unsettled=None, incomplete_unsettled=None, initial_delivery_count=0, max_message_size=1048576, offered_capabilities=b'SHARED-SUBS', desired_capabilities=None, properties={b'com.microsoft:receiver-name': b'SBReceiver-081a0dba-4ce6-45b8-81e2-3fa9e0676725', b'app-id': b'1950a258-227b-4e31-a9cf-717495945fc2', b'auth-type': b'AAD', b'client-id': b'SBReceiver-081a0dba-4ce6-45b8-81e2-3fa9e0676725', b'com.microsoft:timeout': 65000, b'client-ip': b'13.66.10.149', b'client-network-type': 1, b'client-auth-id': b'1950a258-227b-4e31-a9cf-717495945fc2', b'client-auth-type': 4, b'com.microsoft:locked-until-utc': 638677964261447280})
2024-11-21 14:28:46,173 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.ATTACH_SENT: 1> -> <LinkState.ATTACHED: 3>
2024-11-21 14:28:46,173 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> FlowFrame(next_incoming_id=2, incoming_window=65535, next_outgoing_id=1, outgoing_window=65535, handle=3, delivery_count=0, link_credit=0, available=None, drain=None, echo=None, properties=None)
2024-11-21 14:28:46,224 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,224 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> FlowFrame(next_incoming_id=2, incoming_window=65535, next_outgoing_id=1, outgoing_window=65535, handle=3, delivery_count=0, link_credit=10, available=None, drain=None, echo=None, properties=None)
2024-11-21 14:28:46,225 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,260 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=1, delivery_tag=b'\x84\xf5Q\xfd$\xb4\xa7J\x96\xa6\x92I)\xd9\xc1=', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,260 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,261 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=2, delivery_tag=b'\xccu\xf4 <7\x9bH\x88\xd5\x00\xb6\x13o\xe89', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,261 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,261 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=3, delivery_tag=b'\xd0JK9\xc0\x1a\xaeH\xb5\x8e\x93D\x81t\xfb\x81', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,262 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,262 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=4, delivery_tag=b' \xa7i\xc0\xee\xec\xa1O\xb4\x90\xba6s\x9e\xe3\x02', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,262 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,262 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=5, delivery_tag=b'\x7fk\xc5\xa1\x9dE\x01K\x81Z\xb8/\x9e\x81"z', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,262 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,262 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=6, delivery_tag=b'>b\x8e=\xa3\x00IH\xa6\x02:\xa0\xf4\x0f\x8a\xe0', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,263 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,263 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=7, delivery_tag=b'\x1f\xe1\x1e0\xa0\xed\xe1G\xaa\x82\xbb\xb8\xa9 \xdd\xd0', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,263 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,263 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=8, delivery_tag=b'\xc3\xb36\x8c\xaf\tVI\x85\xef\xd5\xe5\x8b\xccQS', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,263 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,263 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=9, delivery_tag=b'\xe8\x87\xc8\xa6\x9e\xf3\xd8K\xa8"\x03\x14\xa7\xda{\xfd', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,264 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._cbs_async | CBS status check: state == <CbsAuthState.OK: 0>, expired == False, refresh required == False
2024-11-21 14:28:46,264 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | <- TransferFrame(handle=2, delivery_id=10, delivery_tag=b'\\\x0b\x14"@\xda\x9dD\xa5^v\x00\xa0L\xfd%', message_format=0, settled=None, more=False, rcv_settle_mode=None, state=None, resume=None, aborted=None, batchable=True, payload=b'***')
2024-11-21 14:28:46,264 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 253, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,264 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 254, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,264 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 255, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,264 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 256, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,265 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 257, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,265 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 258, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,265 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 259, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,265 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 260, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,265 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 261, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,265 | MainThread | DEBUG | azure.servicebus._transport._pyamqp_transport | Received message: seq-num: 262, enqd-utc: datetime.datetime(2024, 11, 21, 14, 28, 2, 206000, tzinfo=datetime.timezone.utc), lockd-til-utc: None, ttl: None, dlvry-cnt: 0
2024-11-21 14:28:46,266 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=1, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,266 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=2, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,266 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=3, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,267 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=4, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,267 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=5, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,267 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=6, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,268 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=7, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,268 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=8, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,268 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=9, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,269 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._receiver_async | -> DispositionFrame(role=True, first=10, last=None, settled=True, state=Accepted(), batchable=None)
2024-11-21 14:28:46,269 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | -> DetachFrame(handle=3, closed=True, error=None)
2024-11-21 14:28:46,269 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.ATTACHED: 3> -> <LinkState.DETACH_SENT: 4>
2024-11-21 14:28:46,269 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | -> DetachFrame(handle=2, closed=True, error=None)
2024-11-21 14:28:46,270 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.ATTACHED: 3> -> <LinkState.DETACH_SENT: 4>
2024-11-21 14:28:46,270 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link receiver state changed: <LinkState.ATTACHED: 3> -> <LinkState.DETACH_SENT: 4>
2024-11-21 14:28:46,270 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._link_async | -> DetachFrame(handle=1, closed=True, error=None)
2024-11-21 14:28:46,270 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.ATTACHED: 3> -> <LinkState.DETACH_SENT: 4>
2024-11-21 14:28:46,270 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link sender state changed: <LinkState.ATTACHED: 3> -> <LinkState.DETACH_SENT: 4>
2024-11-21 14:28:46,270 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._session_async | -> EndFrame(error=None)
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._session_async | Session state changed: <SessionState.MAPPED: 3> -> <SessionState.END_SENT: 4>
2024-11-21 14:28:46,271 | MainThread | DEBUG | azure.servicebus._pyamqp.aio._connection_async | -> CloseFrame(error=None)
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.OPENED: 9> -> <ConnectionState.CLOSE_SENT: 11>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._connection_async | Connection state changed: <ConnectionState.CLOSE_SENT: 11> -> <ConnectionState.END: 13>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._session_async | Session state changed: <SessionState.END_SENT: 4> -> <SessionState.DISCARDING: 6>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.DETACH_SENT: 4> -> <LinkState.DETACHED: 0>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link sender state changed: <LinkState.DETACH_SENT: 4> -> <LinkState.DETACHED: 0>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.DETACH_SENT: 4> -> <LinkState.DETACHED: 0>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._management_link_async | Management link receiver state changed: <LinkState.DETACH_SENT: 4> -> <LinkState.DETACHED: 0>
2024-11-21 14:28:46,271 | MainThread | INFO | azure.servicebus._pyamqp.aio._link_async | Link state changed: <LinkState.DETACH_SENT: 4> -> <LinkState.DETACHED: 0> |
kashifkhan
added
the
issue-addressed
|
Hi @ADevBelgie. Thank you for opening this issue and giving us the opportunity to assist. We believe that this has been addressed. If you feel that further discussion is needed, please add a comment with the text "/unresolve" to remove the "issue-addressed" label and continue the conversation. |
github-actions
bot
removed
the
needs-team-attention
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Describe the bug
When working with session-enabled Service Bus queues, the receiver link initially attaches but immediately detaches with a "Session error". This occurs even after successful CBS authentication and initial link attachment.
To Reproduce
Expected behavior
The receiver should successfully establish and maintain a link with the session-enabled queue and be able to receive messages.
Actual behavior
The link cycle shows:
Logs showing the pattern:
Technical Analysis
The issue appears to be in the session handling lifecycle:
The problem may be related to:
Workaround Attempts
However, both still result in the same session error pattern.
Additional context
The issue specifically affects session-enabled queues
Suggested debugging enhancements:
The text was updated successfully, but these errors were encountered: