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

Intermittent test failure for AMQP LinkAttachDetachMultipleOneSession - Message receiver link detached #5536

Closed
ahsonkhan opened this issue Apr 15, 2024 · 5 comments · Fixed by #5651
Closed

Intermittent test failure for AMQP LinkAttachDetachMultipleOneSession - Message receiver link detached #5536

ahsonkhan opened this issue Apr 15, 2024 · 5 comments · Fixed by #5651
Assignees
@LarryOsterman
Labels
AMQP Issues related to the AMQP protocol Support in Azure Core test-reliability Issue that causes tests to be unreliable

Comments

@ahsonkhan
Copy link
Member

Validate Win2022_Win32Api_release_curl_x86

I don't see any logs marked as "error" or "failed" so it isn't clear what went wrong here without deciphering each logged step.

This is logged as an [INFO]:

[ INFO ] D:\a_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}

https://dev.azure.com/azure-sdk/internal/_build/results?buildId=3697516&view=logs&j=e725447c-1a69-585a-f6f0-491e0d04b156&t=4dce952d-fbd4-5508-085e-a15346a8cf0a

024-04-15T18:41:45.1416638Z test 563
2024-04-15T18:41:45.1417622Z         Start 563: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession
2024-04-15T18:41:45.1418302Z 
2024-04-15T18:41:45.1419315Z 563: Test command: D:\a\_work\1\s\build\sdk\core\azure-core-amqp\test\ut\Release\azure-core-amqp-tests.exe "--gtest_filter=TestLinks.LinkAttachDetachMultipleOneSession" "--gtest_also_run_disabled_tests"
2024-04-15T18:41:45.1420267Z 563: Working Directory: D:/a/_work/1/s/build/sdk/core/azure-core-amqp/test/ut
2024-04-15T18:41:45.1420943Z 563: Test timeout computed to be: 10000000
2024-04-15T18:41:45.1502435Z 563: Note: Google Test filter = TestLinks.LinkAttachDetachMultipleOneSession
2024-04-15T18:41:45.1503378Z 563: [==========] Running 1 test from 1 test suite.
2024-04-15T18:41:45.1504119Z 563: [----------] Global test environment set-up.
2024-04-15T18:41:45.1504679Z 563: [----------] 1 test from TestLinks
2024-04-15T18:41:45.1505177Z 563: [ RUN      ] TestLinks.LinkAttachDetachMultipleOneSession
2024-04-15T18:41:45.1543921Z 563: 
2024-04-15T18:41:45.1545186Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\session_tests.cpp(120):: Trying Test port: 49176
2024-04-15T18:41:45.1555886Z 563: [2024-04-***T18:41:45.***51933Z T: 1616] INFO  : Unknown port specified, assuming socket connection transport.
2024-04-15T18:41:45.1558116Z 563: [2024-04-***T18:41:45.***52472Z T: 1616] DEBUG : Create socket transport for host localhost port: 49176
2024-04-15T18:41:45.1561771Z 563: [2024-04-***T18:41:45.***53808Z T: 1616] DEBUG : Connection 767e88f6-c4ca-42e1-bfc4-a00327411bca state changed from CONNECTION_STATE_START to CONNECTION_STATE_START
2024-04-15T18:41:45.1562916Z 563: 
2024-04-15T18:41:45.1563913Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(596):: Wait 5 seconds for listener to start.
2024-04-15T18:41:45.1564800Z 563: 
2024-04-15T18:41:45.1565981Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(576):: Start test listener on port 49176
2024-04-15T18:41:45.1566915Z 563: 
2024-04-15T18:41:45.1567944Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(578):: listener started
2024-04-15T18:41:45.1568880Z 563: 
2024-04-15T18:41:45.1570016Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(602):: Listener running.
2024-04-15T18:41:45.1605172Z 563: [2024-04-***T18:41:45.***99384Z[ T: 2024-04-***T18:41:45.***99579Z T: 9480] WARN  : File: D:\a\_work\1\s\build\_deps\vcpkg-src\buildtrees\azure-c-shared-utility\src\d9ae13ea55-d48f7a9441.clean\src\dns_resolver_sync.c:50 Func: _dns_resolver_create: NULL hostname
2024-04-15T18:41:45.1606692Z 563: 
2024-04-15T18:41:45.1609132Z 563: 1616[  INFO ]]  DEBUGD:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(679): : : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:412 Func: _send_header: -> Header (AMQP 0.1.0.0)
2024-04-15T18:41:45.1610567Z 563: OnSocketAccepted - Socket connection received.
2024-04-15T18:41:45.1611674Z 563: [2024-04-***T18:41:45.1601438Z
2024-04-15T18:41:45.1613022Z 563:  T: 1616] [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: Start
2024-04-15T18:41:45.1614511Z 563: [2024-04-***T18:41:45.1602201Z T: 9480] DEBUG : ConnectionImpl::Listen: 00A311C0 ID: Mock Server for LinkAttachDetachMultipleOneSession
2024-04-15T18:41:45.1615398Z 563: DEBUG
2024-04-15T18:41:45.1616613Z 563: [  INFO ] :  Connection 767e88f6-c4ca-42e1-bfc4-a00327411bca state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_SENTD:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):
2024-04-15T18:41:45.1617835Z 563: : Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: HeaderExchanged
2024-04-15T18:41:45.1618692Z 563: 
2024-04-15T18:41:45.1619942Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : HeaderExchanged New state: OpenSent
2024-04-15T18:41:45.1622383Z 563: [2024-04-***T18:41:45.1603365Z T: 1616] DEBUG : Connection 767e88f6-c4ca-42e1-bfc4-a00327411bca state changed from CONNECTION_STATE_HDR_SENT to CONNECTION_STATE_START
2024-04-15T18:41:45.1623868Z 563: [2024-04-***T18:41:45.1605351Z T: 1616] DEBUG : Try to enable async operation on connection: 00A2AF10 ID: 767e88f6-c4ca-42e1-bfc4-a00327411bca count: 0
2024-04-15T18:41:45.1625209Z 563: [2024-04-***T18:41:45.1606410Z T: 1616] DEBUG : Enabled async operation on connection: 00A2AF10 ID: 767e88f6-c4ca-42e1-bfc4-a00327411bca
2024-04-15T18:41:45.1626535Z 563: [2024-04-***T18:41:45.1607489Z T: 1616] DEBUG : Try to enable async operation on connection: 00A2AF10 ID: 767e88f6-c4ca-42e1-bfc4-a00327411bca count: 1
2024-04-15T18:41:45.2639779Z 563: [2024-04-***T18:41:45.2636540Z T: 2400] DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:927 Func: _connection_byte_received: <- Header (AMQP 0.1.0.0)
2024-04-15T18:41:45.2641465Z 563: [2024-04-***T18:41:45.2637343Z T: 2400] DEBUG : Connection 767e88f6-c4ca-42e1-bfc4-a00327411bca state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_EXCH
2024-04-15T18:41:45.2643187Z 563: [2024-04-***T18:41:45.2638206Z T: 2400] DEBUG : 65535:-> [OPEN]* {767e88f6-c4ca-42e1-bfc4-a00327411bca,localhost,4294967295,65535,60000,NULL,NULL,NULL,NULL,{}}
2024-04-15T18:41:45.2645043Z 563: [2024-04-***T18:41:45.2639044Z T: 2400] DEBUG : Connection 767e88f6-c4ca-42e1-bfc4-a00327411bca state changed from CONNECTION_STATE_HDR_EXCH to CONNECTION_STATE_OPEN_SENT
2024-04-15T18:41:45.2646514Z 563: [2024-04-***T18:41:45.2640032Z T: 2400] DEBUG : 0:<- [OPEN]* {Mock Server for LinkAttachDetachMultipleOneSession,localhost,4294967295,65535,120000,NULL,NULL,NULL,NULL,{}}
2024-04-15T18:41:45.2647965Z 563: [2024-04-***T18:41:45.2640638Z T: 2400] DEBUG : Connection 767e88f6-c4ca-42e1-bfc4-a00327411bca state changed from CONNECTION_STATE_OPEN_SENT to CONNECTION_STATE_OPENED
2024-04-15T18:41:45.2649227Z 563: [2024-04-***T18:41:45.264***60Z T: 2400] DEBUG : 0:-> [BEGIN]* {NULL,0,1,1,4294967295}
2024-04-15T18:41:45.3732803Z 563: 
2024-04-15T18:41:45.3735816Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : OpenSent New state: Opened
2024-04-15T18:41:45.3736975Z 563: 
2024-04-15T18:41:45.3738112Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(712):: OnNewEndpoint - Incoming endpoint created, create session.
2024-04-15T18:41:45.3739392Z 563: [2024-04-***T18:41:45.3731821Z T: 2400] DEBUG : 0:<- [BEGIN]* {0,0,10000,1,4294967295}
2024-04-15T18:41:45.3740651Z 563: [2024-04-***T18:41:45.3733592Z T: 2400] DEBUG : 0:-> [ATTACH]* {KeepConnectionAlive,0,true,0,0,* {MyTarget},* {TestReceiver},NULL,NULL,NULL,0}
2024-04-15T18:41:45.3742083Z 563: [2024-04-***T18:41:45.3734537Z T: 2400] DEBUG : 0:-> [ATTACH]* {MySession,1,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-04-15T18:41:45.3742950Z 563: 
2024-04-15T18:41:45.3744069Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: Detached NewState: HalfAttachedAttachSent
2024-04-15T18:41:45.4827808Z 563: [2024-04-***T18:41:45.4824412Z T: 2400] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-04-15T18:41:45.4829263Z 563: 
2024-04-15T18:41:45.4831394Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: KeepConnectionAlive Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Receiver
2024-04-15T18:41:45.4833094Z 563: 
2024-04-15T18:41:45.4835675Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-04-15T18:41:45.4837128Z 563: 
2024-04-15T18:41:45.4838162Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(83):: Role is receiver, create sender.
2024-04-15T18:41:45.4839006Z 563: 
2024-04-15T18:41:45.4840055Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(86):: No sender found, create new sender for KeepConnectionAlive
2024-04-15T18:41:45.4841571Z 563: [2024-04-***T18:41:45.4828096Z T: 2400] DEBUG : Opening message sender. Authenticate if needed with audience: Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-04-15T18:41:45.4842907Z 563: [2024-04-***T18:41:45.4828443Z T: 2400] DEBUG : No credential, returning empty token.
2024-04-15T18:41:45.4844090Z 563: [2024-04-***T18:41:45.4828812Z T: 2400] DEBUG : Message sender state changed from Idle(1) to Opening(2).
2024-04-15T18:41:45.4844949Z 563: 
2024-04-15T18:41:45.4846123Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Idle New state: Opening
2024-04-15T18:41:45.4847593Z 563: [2024-04-***T18:41:45.4830094Z T: 2400] DEBUG : Opening message sender. Enable async operation.
2024-04-15T18:41:45.4848899Z 563: [2024-04-***T18:41:45.4830872Z T: 2400] DEBUG : Message sender state changed from Opening(2) to Open(3).
2024-04-15T18:41:45.4849775Z 563: 
2024-04-15T18:41:45.4851016Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Opening New state: Open
2024-04-15T18:41:45.4852574Z 563: [2024-04-***T18:41:45.4831681Z T: 2400] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-04-15T18:41:45.4853527Z 563: 
2024-04-15T18:41:45.4855057Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: MySession Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-04-15T18:41:45.4856278Z 563: 
2024-04-15T18:41:45.4857832Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-04-15T18:41:45.4859234Z 563: 
2024-04-15T18:41:45.4860214Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-04-15T18:41:45.4861049Z 563: 
2024-04-15T18:41:45.4862099Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession
2024-04-15T18:41:45.4863326Z 563: [2024-04-***T18:41:45.4836266Z T: 2400] DEBUG : MessageReceiver: Subscribe to link detach on:009D7138
2024-04-15T18:41:45.4864157Z 563: 
2024-04-15T18:41:45.4865134Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-04-15T18:41:45.4866267Z 563: [2024-04-***T18:41:45.4836890Z T: 2400] DEBUG : No credential, returning empty token.
2024-04-15T18:41:45.4867478Z 563: [2024-04-***T18:41:45.4838069Z T: 2400] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-04-15T18:41:45.4868778Z 563: [2024-04-***T18:41:45.4839073Z T: 2400] DEBUG : Opening message receiver. Start async
2024-04-15T18:41:45.4869984Z 563: [2024-04-***T18:41:45.4840016Z T: 2400] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-04-15T18:41:45.4870843Z 563: 
2024-04-15T18:41:45.4871983Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-04-15T18:41:45.4873434Z 563: [2024-04-***T18:41:45.4841409Z T: 2400] DEBUG : 0:<- [ATTACH]* {KeepConnectionAlive,0,false,0,0,* {TestReceiver},* {MyTarget},NULL,NULL,0,184467440737095516***}
2024-04-15T18:41:45.4874626Z 563: [2024-04-***T18:41:45.4842162Z T: 2400] DEBUG : 0:-> [FLOW]* {0,1,0,1,0,0,10000}
2024-04-15T18:41:45.4875872Z 563: [2024-04-***T18:41:45.4844992Z T: 2400] DEBUG : 0:<- [ATTACH]* {MySession,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-04-15T18:41:45.4876806Z 563: 
2024-04-15T18:41:45.4877914Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-04-15T18:41:45.4879139Z 563: [2024-04-***T18:41:45.4846501Z T: 2400] DEBUG : 0:<- [FLOW]* {0,10000,0,1,1,0,10000}
2024-04-15T18:41:45.4879914Z 563: 
2024-04-15T18:41:45.4880868Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-04-15T18:41:45.4881682Z 563: 
2024-04-15T18:41:45.4882621Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-04-15T18:41:45.4883737Z 563: [2024-04-***T18:41:45.4848378Z T: 1616] DEBUG : 0:-> [TRANSFER]* {1,0,<01 00 00 00>,0,false,false}
2024-04-15T18:41:45.5922708Z 563: 
2024-04-15T18:41:45.5924378Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(334):: MockServiceEndpoint(MyTarget) Received a message Message: <
2024-04-15T18:41:45.5927177Z 563:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-04-15T18:41:45.5928180Z 563:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-04-15T18:41:45.5928986Z 563:     Body: [AmqpValue, type=String
2024-04-15T18:41:45.5929664Z 563: >
2024-04-15T18:41:45.5930643Z 563: [2024-04-***T18:41:45.5919390Z T: 2400] DEBUG : 0:<- [DISPOSITION]* {true,0,0,true,* {}}
2024-04-15T18:41:45.5931672Z 563: [2024-04-***T18:41:45.5920444Z T: 1616] 
2024-04-15T18:41:45.5932576Z 563: DEBUG : [  INFO ]0:-> [DETACH]* {1,true}
2024-04-15T18:41:45.5933652Z 563:  D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(281):: Received message on link MySession
2024-04-15T18:41:45.5934738Z 563: : [  INFO ]Message: < 
2024-04-15T18:41:45.5936038Z 563: D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352)::     Link Header{MySessiondurable=, State Changed. OldState: falseAttached, priority= NewState: 4HalfAttachedAttachSent, firstAcquirer=
2024-04-15T18:41:45.5937086Z 563: false, deliveryCount=0}
2024-04-15T18:41:45.5938353Z 563:     [2024-04-***T18:41:45.5921685Z T: MessageProperties {1616MessageId: <null>] }DEBUG, deliveryTag= : Try to disable async operation on connection: 00A2AF10 ID: 767e88f6-c4ca-42e1-bfc4-a00327411bca count: 2
2024-04-15T18:41:45.5939342Z 563: <01 00 00 00>
2024-04-15T18:41:45.5940044Z 563:     Body: [AmqpValue, type=String
2024-04-15T18:41:45.5940834Z 563: >
2024-04-15T18:41:45.5941459Z 563: 
2024-04-15T18:41:45.5942477Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(301):: Message received on link MySession: Message: <
2024-04-15T18:41:45.5943459Z 563:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-04-15T18:41:45.5944380Z 563:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-04-15T18:41:45.5945277Z 563:     Body: [AmqpValue, type=String
2024-04-15T18:41:45.5945945Z 563: >
2024-04-15T18:41:45.7015040Z 563: 
2024-04-15T18:41:45.7016903Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-04-15T18:41:45.7019180Z 563: 
2024-04-15T18:41:45.7020886Z 563: 
2024-04-15T18:41:45.7022560Z 563: [2024-04-***T18:41:45.7011833Z[  INFO ] T: 2400 ] WARN  : D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):Message receiver link detached: : : 
2024-04-15T18:41:45.7023712Z 563: Receiver disconnected: MySession
2024-04-15T18:41:45.7025082Z 563: [[2024-04-***T18:41:45.7012433Z2024-04-***T18:41:45.7012395Z T:  T: 93522400] ] DEBUGDEBUG :  : Lock for Closing message receiver.Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-04-15T18:41:45.7026146Z 563: 
2024-04-15T18:41:45.7026770Z 563: 
2024-04-15T18:41:45.7027902Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-04-15T18:41:45.7029163Z 563: [2024-04-***T18:41:45.7013929Z T: 2400] DEBUG : 0:<- [DETACH]* {1,true}
2024-04-15T18:41:45.7029938Z 563: 
2024-04-15T18:41:45.7031047Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-04-15T18:41:45.7032310Z 563: [2024-04-***T18:41:45.7018675Z T: 9352] DEBUG : Wait for receiver detach to complete. Current state: Idle
2024-04-15T18:41:45.7033479Z 563: [2024-04-***T18:41:45.7019012Z T: 9352] DEBUG : Receiver unsubscribe from link detach event on 009D7138
2024-04-15T18:41:45.7034796Z 563: [2024-04-***T18:41:45.7019190Z T: 1616] [2024-04-***T18:41:45.7019390ZDEBUG T: 9352]  : DEBUG : 0:-> [ATTACH]* {MySession2,1,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-04-15T18:41:45.7035804Z 563: Closing message receiver. Stop async
2024-04-15T18:41:45.7036495Z 563: 
2024-04-15T18:41:45.7037596Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: Detached NewState: HalfAttachedAttachSent
2024-04-15T18:41:45.7038985Z 563: [2024-04-***T18:41:45.7020207Z T: 1616] DEBUG : Try to enable async operation on connection: 00A2AF10 ID: 767e88f6-c4ca-42e1-bfc4-a00327411bca count: 1
2024-04-15T18:41:45.8107735Z 563: [2024-04-***T18:41:45.8105232Z T: 2400] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-04-15T18:41:45.8108896Z 563: 
2024-04-15T18:41:45.8110496Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: MySession2 Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-04-15T18:41:45.8111909Z 563: 
2024-04-15T18:41:45.8114337Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-04-15T18:41:45.8116496Z 563: 
2024-04-15T18:41:45.8118610Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-04-15T18:41:45.8120046Z 563: 
2024-04-15T18:41:45.8121361Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession2
2024-04-15T18:41:45.8122639Z 563: [2024-04-***T18:41:45.8108529Z T: 2400] DEBUG : MessageReceiver: Subscribe to link detach on:009D6EF8
2024-04-15T18:41:45.8123598Z 563: 
2024-04-15T18:41:45.8124538Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-04-15T18:41:45.8125610Z 563: [2024-04-***T18:41:45.8110399Z T: 2400] DEBUG : No credential, returning empty token.
2024-04-15T18:41:45.8126760Z 563: [2024-04-***T18:41:45.8110767Z T: 2400] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-04-15T18:41:45.8127873Z 563: [2024-04-***T18:41:45.8111484Z T: 2400] DEBUG : Opening message receiver. Start async
2024-04-15T18:41:45.8129016Z 563: [2024-04-***T18:41:45.8113374Z T: 2400] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-04-15T18:41:45.8129831Z 563: 
2024-04-15T18:41:45.8130910Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-04-15T18:41:45.8132282Z 563: [2024-04-***T18:41:45.8114478Z T: 2400] DEBUG : 0:<- [ATTACH]* {MySession2,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-04-15T18:41:45.8133129Z 563: 
2024-04-15T18:41:45.8134159Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-04-15T18:41:45.8135307Z 563: [2024-04-***T18:41:45.81***395Z T: 2400] DEBUG : 0:<- [FLOW]* {1,9999,0,1,1,0,10000}
2024-04-15T18:41:45.8136028Z 563: 
2024-04-15T18:41:45.8136925Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession2
2024-04-15T18:41:45.8137689Z 563: 
2024-04-15T18:41:45.8138582Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession2
2024-04-15T18:41:45.8139609Z 563: [2024-04-***T18:41:45.8118019Z T: 1616] DEBUG : 0:-> [DETACH]* {1,true}
2024-04-15T18:41:45.8140330Z 563: 
2024-04-15T18:41:45.8141350Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: Attached NewState: HalfAttachedAttachSent
2024-04-15T18:41:45.8142649Z 563: [2024-04-***T18:41:45.8118895Z T: 1616] DEBUG : Try to disable async operation on connection: 00A2AF10 ID: 767e88f6-c4ca-42e1-bfc4-a00327411bca count: 2
2024-04-15T18:41:45.9201455Z 563: 
2024-04-15T18:41:45.9203889Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-04-15T18:41:45.9205239Z 563: 
2024-04-15T18:41:45.9208444Z 563: [2024-04-***T18:41:45.9199666Z T: 2400] WARN  : Message receiver link detached: : 
2024-04-15T18:41:45.9210154Z 563: [2024-04-***T18:41:45.9200211Z T: 2400] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-04-15T18:41:45.9211552Z 563: 
2024-04-15T18:41:45.9212741Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-04-15T18:41:45.9214277Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):: Receiver disconnected: MySession2
2024-04-15T18:41:45.9215342Z 563: [2024-04-***T18:41:45.9203390Z T: 9352] DEBUG : Lock for Closing message receiver.
2024-04-15T18:41:45.9216029Z 563: 
2024-04-15T18:41:45.9232561Z 563: [2024-04-***T18:41:45.9204858Z T: 2400] DEBUG : 0:<- [DETACH]* {1,true}
2024-04-15T18:41:45.9233468Z 563: 
2024-04-15T18:41:45.9234563Z 563: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-04-15T18:41:50.6669368Z 416/510 Test #563: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession ......................................***Failed    5.52 sec
@ahsonkhan ahsonkhan added test-reliability Issue that causes tests to be unreliable AMQP Issues related to the AMQP protocol Support in Azure Core labels Apr 15, 2024
@LarryOsterman
Copy link
Member

This is logged as an [INFO]:

[ INFO ] D:\a_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}

That log is correct - it indicates that a message receiver was disconnected without an error, which is not an error.

I'm not sure why ctest decided this test failed - my suspicion is that it access violated.

@ahsonkhan
Copy link
Member Author

ahsonkhan commented Apr 19, 2024 •
edited

Error {null}

I wonder if we can improve the logging/diagnostic a bit more here. Is {null} appropriate to be printed here? What does it mean?

@LarryOsterman
Copy link
Member

Error {null}

I wonder if we can improve the logging/diagnostic a bit more here. Is {null} appropriate to be printed here? What does it mean?

It means that an Error performative was received and the Error performative has no error code or description.

You parse it as " {}", spoken I would say "The error has no information" or "the error is null".

@ahsonkhan
Copy link
Member Author

ahsonkhan commented May 16, 2024 •
edited

Another recent hit of this test failing on ValidateLive Win2022_x86_with_unit_test_winHttp:
LinkAttachDetachMultipleOneSession

2024-05-16T18:48:48.1519232Z test 573
2024-05-16T18:48:48.1520304Z         Start 573: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession
2024-05-16T18:48:48.1520845Z 
2024-05-16T18:48:48.1522152Z 573: Test command: D:\a\_work\1\s\build\sdk\core\azure-core-amqp\test\ut\Release\azure-core-amqp-tests.exe "--gtest_filter=TestLinks.LinkAttachDetachMultipleOneSession" "--gtest_also_run_disabled_tests"
2024-05-16T18:48:48.1523517Z 573: Working Directory: D:/a/_work/1/s/build/sdk/core/azure-core-amqp/test/ut
2024-05-16T18:48:48.1524488Z 573: Test timeout computed to be: 10000000
2024-05-16T18:48:48.1606193Z 573: Note: Google Test filter = TestLinks.LinkAttachDetachMultipleOneSession
2024-05-16T18:48:48.1607038Z 573: [==========] Running 1 test from 1 test suite.
2024-05-16T18:48:48.1607859Z 573: [----------] Global test environment set-up.
2024-05-16T18:48:48.1608575Z 573: [----------] 1 test from TestLinks
2024-05-16T18:48:48.1609245Z 573: [ RUN      ] TestLinks.LinkAttachDetachMultipleOneSession
2024-05-16T18:48:48.1643902Z 573: 
2024-05-16T18:48:48.1645138Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\session_tests.cpp(120):: Trying Test port: 49553
2024-05-16T18:48:48.1655581Z 573: [2024-05-16T18:48:48.1651807Z T: 8188] INFO  : Unknown port specified, assuming socket connection transport.
2024-05-16T18:48:48.1656999Z 573: [2024-05-16T18:48:48.1652291Z T: 8188] DEBUG : Create socket transport for host localhost port: 49553
2024-05-16T18:48:48.1658828Z 573: [2024-05-16T18:48:48.1653081Z T: 8188] DEBUG : Connection 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 state changed from CONNECTION_STATE_START to CONNECTION_STATE_START
2024-05-16T18:48:48.1662637Z 573: 
2024-05-16T18:48:48.1663725Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(596):: Wait 5 seconds for listener to start.
2024-05-16T18:48:48.1664608Z 573: 
2024-05-16T18:48:48.1665655Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(576):: Start test listener on port 49553
2024-05-16T18:48:48.1666527Z 573: 
2024-05-16T18:48:48.1667476Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(578):: listener started
2024-05-16T18:48:48.1668417Z 573: 
2024-05-16T18:48:48.1669364Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(602):: Listener running.
2024-05-16T18:48:48.1700799Z 573: [2024-05-16T18:48:48.1696548Z T: 8188] DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:412 Func: _send_header: -> Header (AMQP 0.1.0.0)
2024-05-16T18:48:48.1703603Z 573: [2024-05-16T18:48:48.1697001Z T: 8188] DEBUG : Connection 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_SENT
2024-05-16T18:48:48.1705205Z 573: [2024-05-16T18:48:48.16973***Z T: 8188] DEBUG : Connection 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 state changed from CONNECTION_STATE_HDR_SENT to CONNECTION_STATE_START
2024-05-16T18:48:48.1706756Z 573: [2024-05-16T18:48:48.1697874Z T: 8188] DEBUG : Try to enable async operation on connection: 010CAE40 ID: 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 count: 0
2024-05-16T18:48:48.1708092Z 573: [2024-05-16T18:48:48.1698146Z T: 8188] DEBUG : Enabled async operation on connection: 010CAE40 ID: 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332
2024-05-16T18:48:48.1709748Z 573: [2024-05-16T18:48:48.1696668Z T: 7480] [2024-05-16T18:48:48.1698703Z T: WARN  : File: D:\a\_work\1\s\build\_deps\vcpkg-src\buildtrees\azure-c-shared-utility\src\cb3fa760af-be37e775db.clean\src\dns_resolver_sync.c:50 Func: _dns_resolver_create: NULL hostname
2024-05-16T18:48:48.1711273Z 573: 8188] DEBUG : Try to enable async operation on connection: 010CAE40 ID: 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 count: 1
2024-05-16T18:48:48.1712104Z 573: 
2024-05-16T18:48:48.1713160Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(679):: OnSocketAccepted - Socket connection received.
2024-05-16T18:48:48.1714060Z 573: 
2024-05-16T18:48:48.1715278Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: Start
2024-05-16T18:48:48.1716749Z 573: [2024-05-16T18:48:48.1699546Z T: 7480] DEBUG : ConnectionImpl::Listen: 010D5478 ID: Mock Server for LinkAttachDetachMultipleOneSession
2024-05-16T18:48:48.1717646Z 573: 
2024-05-16T18:48:48.1718882Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: HeaderExchanged
2024-05-16T18:48:48.2743924Z 573: 
2024-05-16T18:48:48.2745362Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : HeaderExchanged New state: OpenSent
2024-05-16T18:48:48.3837898Z 573: [2024-05-16T18:48:48.3834670Z T: 8052] DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:927 Func: _connection_byte_received: <- Header (AMQP 0.1.0.0)
2024-05-16T18:48:48.3839602Z 573: [2024-05-16T18:48:48.3835108Z T: 8052] DEBUG : Connection 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_EXCH
2024-05-16T18:48:48.3841708Z 573: [2024-05-16T18:48:48.3836530Z T: 8052] DEBUG : 65535:-> [OPEN]* {2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332,localhost,4294967295,65535,60000,NULL,NULL,NULL,NULL,{}}
2024-05-16T18:48:48.3843515Z 573: [2024-05-16T18:48:48.3837119Z T: 8052] DEBUG : Connection 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 state changed from CONNECTION_STATE_HDR_EXCH to CONNECTION_STATE_OPEN_SENT
2024-05-16T18:48:48.3845003Z 573: [2024-05-16T18:48:48.3837973Z T: 8052] DEBUG : 0:<- [OPEN]* {Mock Server for LinkAttachDetachMultipleOneSession,localhost,4294967295,65535,120000,NULL,NULL,NULL,NULL,{}}
2024-05-16T18:48:48.3846436Z 573: [2024-05-16T18:48:48.3838419Z T: 8052] DEBUG : Connection 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 state changed from CONNECTION_STATE_OPEN_SENT to CONNECTION_STATE_OPENED
2024-05-16T18:48:48.3847834Z 573: [2024-05-16T18:48:48.3839239Z T: 8052] DEBUG : 0:-> [BEGIN]* {NULL,0,1,1,4294967295}
2024-05-16T18:48:48.3848658Z 573: 
2024-05-16T18:48:48.3849911Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : OpenSent New state: Opened
2024-05-16T18:48:48.3850951Z 573: 
2024-05-16T18:48:48.3852026Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(712):: OnNewEndpoint - Incoming endpoint created, create session.
2024-05-16T18:48:48.4930836Z 573: [2024-05-16T18:48:48.4928173Z T: 8052] DEBUG : 0:<- [BEGIN]* {0,0,10000,1,4294967295}
2024-05-16T18:48:48.4934102Z 573: [2024-05-16T18:48:48.4929***8Z T: 8052] DEBUG : 0:-> [ATTACH]* {KeepConnectionAlive,0,true,0,0,* {MyTarget},* {TestReceiver},NULL,NULL,NULL,0}
2024-05-16T18:48:48.4935882Z 573: [2024-05-16T18:48:48.4930116Z T: 8052] DEBUG : 0:-> [ATTACH]* {MySession,1,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-05-16T18:48:48.4937012Z 573: 
2024-05-16T18:48:48.4938573Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: Detached NewState: HalfAttachedAttachSent
2024-05-16T18:48:48.4940883Z 573: [2024-05-16T18:48:48.4931480Z T: 8052] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-16T18:48:48.4942461Z 573: 
2024-05-16T18:48:48.4945595Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: KeepConnectionAlive Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Receiver
2024-05-16T18:48:48.4947649Z 573: 
2024-05-16T18:48:48.4949926Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-16T18:48:48.4951478Z 573: 
2024-05-16T18:48:48.4953019Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(83):: Role is receiver, create sender.
2024-05-16T18:48:48.4953940Z 573: 
2024-05-16T18:48:48.4955026Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(86):: No sender found, create new sender for KeepConnectionAlive
2024-05-16T18:48:48.4956511Z 573: [2024-05-16T18:48:48.4935792Z T: 8052] DEBUG : Opening message sender. Authenticate if needed with audience: Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-16T18:48:48.4957803Z 573: [2024-05-16T18:48:48.4936104Z T: 8052] DEBUG : No credential, returning empty token.
2024-05-16T18:48:48.4958987Z 573: [2024-05-16T18:48:48.4936500Z T: 8052] DEBUG : Message sender state changed from Idle(1) to Opening(2).
2024-05-16T18:48:48.4959823Z 573: 
2024-05-16T18:48:48.4960965Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Idle New state: Opening
2024-05-16T18:48:48.4962226Z 573: [2024-05-16T18:48:48.4939012Z T: 8052] DEBUG : Opening message sender. Enable async operation.
2024-05-16T18:48:48.4963366Z 573: [2024-05-16T18:48:48.4939941Z T: 8052] DEBUG : Message sender state changed from Opening(2) to Open(3).
2024-05-16T18:48:48.4964169Z 573: 
2024-05-16T18:48:48.4965301Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Opening New state: Open
2024-05-16T18:48:48.4966882Z 573: [2024-05-16T18:48:48.4942509Z T: 8052] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-16T18:48:48.4967824Z 573: 
2024-05-16T18:48:48.4969358Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: MySession Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-05-16T18:48:48.4970591Z 573: 
2024-05-16T18:48:48.4972102Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-16T18:48:48.4973321Z 573: 
2024-05-16T18:48:48.4974326Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-05-16T18:48:48.4975182Z 573: 
2024-05-16T18:48:48.4976223Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession
2024-05-16T18:48:48.4977476Z 573: [2024-05-16T18:48:48.4945075Z T: 8052] DEBUG : MessageReceiver: Subscribe to link detach on:010D1C78
2024-05-16T18:48:48.4978308Z 573: 
2024-05-16T18:48:48.4979285Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-05-16T18:48:48.4980422Z 573: [2024-05-16T18:48:48.4947482Z T: 8052] DEBUG : No credential, returning empty token.
2024-05-16T18:48:48.4981613Z 573: [2024-05-16T18:48:48.4948108Z T: 8052] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-05-16T18:48:48.4982780Z 573: [2024-05-16T18:48:48.4948729Z T: 8052] DEBUG : Opening message receiver. Start async
2024-05-16T18:48:48.4983970Z 573: [2024-05-16T18:48:48.4950567Z T: 8052] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-05-16T18:48:48.4984955Z 573: 
2024-05-16T18:48:48.4986106Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-05-16T18:48:48.6024915Z 573: [2024-05-16T18:48:48.6022123Z T: 8052] DEBUG : 0:<- [ATTACH]* {KeepConnectionAlive,0,false,0,0,* {TestReceiver},* {MyTarget},NULL,NULL,0,184467440737095516***}
2024-05-16T18:48:48.6027033Z 573: [2024-05-16T18:48:48.6022972Z T: 8052] DEBUG : 0:-> [FLOW]* {0,1,0,1,0,0,10000}
2024-05-16T18:48:48.6029202Z 573: [2024-05-16T18:48:48.6024297Z T: 8052] DEBUG : 0:<- [ATTACH]* {MySession,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-05-16T18:48:48.6030150Z 573: 
2024-05-16T18:48:48.6031434Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-05-16T18:48:48.6032699Z 573: [2024-05-16T18:48:48.6025421Z T: 8052] DEBUG : 0:<- [FLOW]* {0,10000,0,1,1,0,10000}
2024-05-16T18:48:48.6033499Z 573: 
2024-05-16T18:48:48.6034476Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-05-16T18:48:48.6035308Z 573: 
2024-05-16T18:48:48.6036275Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-05-16T18:48:48.6037406Z 573: [2024-05-16T18:48:48.6027488Z T: 8188] DEBUG : 0:-> [TRANSFER]* {1,0,<01 00 00 00>,0,false,false}
2024-05-16T18:48:48.7118169Z 573: 
2024-05-16T18:48:48.7119488Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(334):: MockServiceEndpoint(MyTarget) Received a message Message: <
2024-05-16T18:48:48.7121548Z 573:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-16T18:48:48.7122849Z 573:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-16T18:48:48.7123769Z 573:     Body: [AmqpValue, type=String
2024-05-16T18:48:48.7124482Z 573: >
2024-05-16T18:48:48.7125107Z 573: 
2024-05-16T18:48:48.7126204Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(281):: Received message on link MySession: Message: <
2024-05-16T18:48:48.7127225Z 573:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-16T18:48:48.7128132Z 573:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-16T18:48:48.7128935Z 573:     Body: [AmqpValue, type=String
2024-05-16T18:48:48.7129605Z 573: >
2024-05-16T18:48:48.7130237Z 573: 
2024-05-16T18:48:48.7131253Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(301):: Message received on link MySession: Message: <
2024-05-16T18:48:48.7132262Z 573:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-16T18:48:48.7133141Z 573:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-16T18:48:48.7133924Z 573:     Body: [AmqpValue, type=String
2024-05-16T18:48:48.7134611Z 573: >
2024-05-16T18:48:48.8214068Z 573: [2024-05-16T18:48:48.8210053Z T: 8052] DEBUG : 0:<- [DISPOSITION]* {true,0,0,true,* {}}
2024-05-16T18:48:48.8215440Z 573: [2024-05-16T18:48:48.8212050Z T: 8188] DEBUG : 0:-> [DETACH]* {1,true}
2024-05-16T18:48:48.8216300Z 573: 
2024-05-16T18:48:48.8217455Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: Attached NewState: HalfAttachedAttachSent
2024-05-16T18:48:48.8218872Z 573: [2024-05-16T18:48:48.8213121Z T: 8188] DEBUG : Try to disable async operation on connection: 010CAE40 ID: 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 count: 2
2024-05-16T18:48:48.9306658Z 573: 
2024-05-16T18:48:48.9307942Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-05-16T18:48:48.9309288Z 573: 
2024-05-16T18:48:48.9310315Z 573: [2024-05-16T18:48:48.9303913Z T: 8052] WARN  : Message receiver link detached: : 
2024-05-16T18:48:48.9311646Z 573: [2024-05-16T18:48:48.9304226Z T: 8052] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-05-16T18:48:48.9312502Z 573: 
2024-05-16T18:48:48.9313390Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-05-16T18:48:48.9314157Z 573: 
2024-05-16T18:48:48.9314930Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):: Receiver disconnected: MySession
2024-05-16T18:48:48.9315803Z 573: [2024-05-16T18:48:48.9305394Z T: 4732] DEBUG : Lock for Closing message receiver.
2024-05-16T18:48:48.9316650Z 573: [2024-05-16T18:48:48.9305698Z T: 4732] DEBUG : Wait for receiver detach to complete. Current state: Idle
2024-05-16T18:48:48.9317517Z 573: [2024-05-16T18:48:48.9305977Z T: 4732] DEBUG : Receiver unsubscribe from link detach event on 010D1C78
2024-05-16T18:48:48.9318342Z 573: [2024-05-16T18:48:48.9306924Z T: 4732] DEBUG : Closing message receiver. Stop async
2024-05-16T18:48:49.0400092Z 573: [2024-05-16T18:48:49.0397495Z T: 8052] DEBUG : 0:<- [DETACH]* {1,true}
2024-05-16T18:48:49.0402745Z 573: 
2024-05-16T18:48:49.0404493Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-05-16T18:48:49.0405962Z 573: [2024-05-16T18:48:49.0400087Z T: 8188] DEBUG : 0:-> [ATTACH]* {MySession2,2,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-05-16T18:48:49.0409634Z 573: [2024-05-16T18:48:49.0400122Z T: 8052] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-16T18:48:49.0410906Z 573: 
2024-05-16T18:48:49.0411889Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: 
2024-05-16T18:48:49.0413322Z 573: Link [  INFO ]MySession2 , State Changed. OldState: D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):Detached:  NewState: OnLinkAttached for name: MySession2HalfAttachedAttachSent Source : 
2024-05-16T18:48:49.0415119Z 573: Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false[}2024-05-16T18:48:49.0401458Z T:  Target : 8188] Target{ DEBUGAddress:  : MyTargetTry to enable async operation on connection: 010CAE40 ID: 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 count: 1, Durable: 
2024-05-16T18:48:49.0416519Z 573: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-05-16T18:48:49.0417305Z 573: 
2024-05-16T18:48:49.0418857Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-16T18:48:49.0420125Z 573: 
2024-05-16T18:48:49.0421126Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-05-16T18:48:49.0421993Z 573: 
2024-05-16T18:48:49.0423026Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession2
2024-05-16T18:48:49.0424276Z 573: [2024-05-16T18:48:49.0404331Z T: 8052] DEBUG : MessageReceiver: Subscribe to link detach on:010D35E0
2024-05-16T18:48:49.0425112Z 573: 
2024-05-16T18:48:49.0426088Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-05-16T18:48:49.0427230Z 573: [2024-05-16T18:48:49.0406630Z T: 8052] DEBUG : No credential, returning empty token.
2024-05-16T18:48:49.0428450Z 573: [2024-05-16T18:48:49.0406940Z T: 8052] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-05-16T18:48:49.0429747Z 573: [2024-05-16T18:48:49.0407524Z T: 8052] DEBUG : Opening message receiver. Start async
2024-05-16T18:48:49.0430962Z 573: [2024-05-16T18:48:49.0408026Z T: 8052] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-05-16T18:48:49.0431837Z 573: 
2024-05-16T18:48:49.0432990Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-05-16T18:48:49.1494908Z 573: [2024-05-16T18:48:49.1491287Z T: 8052] DEBUG : 0:<- [ATTACH]* {MySession2,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-05-16T18:48:49.1497331Z 573: 
2024-05-16T18:48:49.1498629Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-05-16T18:48:49.1499918Z 573: [2024-05-16T18:48:49.1492711Z T: 8052] DEBUG : 0:<- [FLOW]* {1,9999,0,1,1,0,10000}
2024-05-16T18:48:49.1500710Z 573: 
2024-05-16T18:48:49.1501718Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession2
2024-05-16T18:48:49.1502571Z 573: 
2024-05-16T18:48:49.1503541Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession2
2024-05-16T18:48:49.1504632Z 573: [2024-05-16T18:48:49.1494149Z T: 8188] DEBUG : 0:-> [DETACH]* {2,true}
2024-05-16T18:48:49.1505410Z 573: 
2024-05-16T18:48:49.1506512Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: Attached NewState: HalfAttachedAttachSent
2024-05-16T18:48:49.1508033Z 573: [2024-05-16T18:48:49.1495468Z T: 8188] DEBUG : Try to disable async operation on connection: 010CAE40 ID: 2d53da3f-b9ee-4e2d-bb7d-7d8bf445a332 count: 2
2024-05-16T18:48:49.2587392Z 573: 
2024-05-16T18:48:49.2589091Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-05-16T18:48:49.2590118Z 573: 
2024-05-16T18:48:49.2590767Z 573: 
2024-05-16T18:48:49.2591956Z 573: [2024-05-16T18:48:49.2585185Z[  INFO ] T:  8052D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):] WARN :  : Receiver disconnected: Message receiver link detached: : MySession2
2024-05-16T18:48:49.2592950Z 573: 
2024-05-16T18:48:49.2594186Z 573: [[2024-05-16T18:48:49.2585761Z2024-05-16T18:48:49.2585757Z T:  T: 47328052] ] DEBUGDEBUG :  : Lock for Closing message receiver.Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-05-16T18:48:49.2595211Z 573: 
2024-05-16T18:48:49.2595831Z 573: 
2024-05-16T18:48:49.2596977Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-05-16T18:48:49.2598266Z 573: [2024-05-16T18:48:49.2586937Z T: 4732] DEBUG : Wait for receiver detach to complete. Current state: Idle
2024-05-16T18:48:49.2599409Z 573: [2024-05-16T18:48:49.2587217Z T: 4732] DEBUG : Receiver unsubscribe from link detach event on 010D35E0
2024-05-16T18:48:49.2600531Z 573: [2024-05-16T18:48:49.2587498Z T: 4732] DEBUG : Closing message receiver. Stop async
2024-05-16T18:48:49.3686142Z 573: [2024-05-16T18:48:49.3683624Z T: 8052] DEBUG : 0:<- [DETACH]* {1,true}
2024-05-16T18:48:49.3687373Z 573: 
2024-05-16T18:48:49.3688525Z 573: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-05-16T18:48:55.3287723Z 426/520 Test #573: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession ......................................***Failed    7.18 sec

In a different run, it segfaulted - ValidateLive Win2022_x86_no_rtti_with_unit_test:
https://dev.azure.com/azure-sdk/internal/_build/results?buildId=3787351&view=logs&j=2fc98781-9230-5004-8e4b-444d4f6ce9bd&t=ad4b8b3b-0986-5035-a7a3-9a7ec6f1ca35

2024-05-14T18:32:55.0131619Z test 564
2024-05-14T18:32:55.0132646Z         Start 564: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession
2024-05-14T18:32:55.0133186Z 
2024-05-14T18:32:55.0134232Z 564: Test command: D:\a\_work\1\s\build\sdk\core\azure-core-amqp\test\ut\Release\azure-core-amqp-tests.exe "--gtest_filter=TestLinks.LinkAttachDetachMultipleOneSession" "--gtest_also_run_disabled_tests"
2024-05-14T18:32:55.0135270Z 564: Working Directory: D:/a/_work/1/s/build/sdk/core/azure-core-amqp/test/ut
2024-05-14T18:32:55.0136056Z 564: Test timeout computed to be: 10000000
2024-05-14T18:32:55.0590791Z 564: Note: Google Test filter = TestLinks.LinkAttachDetachMultipleOneSession
2024-05-14T18:32:55.0592166Z 564: [==========] Running 1 test from 1 test suite.
2024-05-14T18:32:55.0593233Z 564: [----------] Global test environment set-up.
2024-05-14T18:32:55.0594060Z 564: [----------] 1 test from TestLinks
2024-05-14T18:32:55.0594804Z 564: [ RUN      ] TestLinks.LinkAttachDetachMultipleOneSession
2024-05-14T18:32:55.0615044Z 564: 
2024-05-14T18:32:55.0616158Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\session_tests.cpp(120):: Trying Test port: 49984
2024-05-14T18:32:55.0624716Z 564: [2024-05-14T18:32:55.0621043Z T: 200] INFO  : Unknown port specified, assuming socket connection transport.
2024-05-14T18:32:55.0626666Z 564: [2024-05-14T18:32:55.062***10Z T: 200] DEBUG : Create socket transport for host localhost port: 49984
2024-05-14T18:32:55.0654112Z 564: [2024-05-14T18:32:55.0622247Z T: 200] DEBUG : Connection 74f26355-858b-4603-8c90-770acf638d5d state changed from CONNECTION_STATE_START to CONNECTION_STATE_START
2024-05-14T18:32:55.0674025Z 564: 
2024-05-14T18:32:55.0677983Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(596):: Wait 5 seconds for listener to start.
2024-05-14T18:32:55.0679425Z 564: 
2024-05-14T18:32:55.0680392Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(576):: Start test listener on port 49984
2024-05-14T18:32:55.0681328Z 564: 
2024-05-14T18:32:55.0682192Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(578):: listener started
2024-05-14T18:32:55.0682883Z 564: 
2024-05-14T18:32:55.0683635Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(602):: Listener running.
2024-05-14T18:32:55.0696068Z 564: [[2024-05-14T18:32:55.0667911Z2024-05-14T18:32:55.0668022Z T:  T: 200] DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:412 Func: _send_header: -> Header (AMQP 0.1.0.0)
2024-05-14T18:32:55.0697463Z 564: 8792[] 2024-05-14T18:32:55.0668736ZWARN  T: 200] DEBUG : Connection 74f26355-858b-4603-8c90-770acf638d5d state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_SENT
2024-05-14T18:32:55.0698664Z 564: [2024-05-14T18:32:55.0669402Z T: 200] DEBUG :  : File: D:\a\_work\1\s\build\_deps\vcpkg-src\buildtrees\azure-c-shared-utility\src\cb3fa760af-be37e775db.clean\src\dns_resolver_sync.c:50 Func: _dns_resolver_create: NULL hostname
2024-05-14T18:32:55.0699496Z 564: 
2024-05-14T18:32:55.0700287Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(679):: OnSocketAccepted - Socket connection received.
2024-05-14T18:32:55.0701005Z 564: 
2024-05-14T18:32:55.0701914Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: Start
2024-05-14T18:32:55.0703141Z 564: [2024-05-14T18:32:55.0671358Z T: 8792] DEBUG : ConnectionImpl::Listen: 0***830A0 ID: Mock Server for LinkAttachDetachMultipleOneSession
2024-05-14T18:32:55.0704145Z 564: 
2024-05-14T18:32:55.0705152Z 564: [  INFO ] Connection 74f26355-858b-4603-8c90-770acf638d5d state changed from CONNECTION_STATE_HDR_SENT to CONNECTION_STATE_STARTD:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):
2024-05-14T18:32:55.0706330Z 564: : [2024-05-14T18:32:55.0672448Z T: 200] DEBUG : Try to enable async operation on connection: 0***64220 ID: 74f26355-858b-4603-8c90-770acf638d5d count: 0
2024-05-14T18:32:55.0707595Z 564: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : [2024-05-14T18:32:55.0675312ZStart T: 200] DEBUG : Enabled async operation on connection: 0***64220 ID: 74f26355-858b-4603-8c90-770acf638d5d
2024-05-14T18:32:55.0708558Z 564:  New state: HeaderExchanged
2024-05-14T18:32:55.0709584Z 564: [2024-05-14T18:32:55.0675745Z T: 200] DEBUG : Try to enable async operation on connection: 0***64220 ID: 74f26355-858b-4603-8c90-770acf638d5d count: 1
2024-05-14T18:32:55.1763812Z 564: 
2024-05-14T18:32:55.1765409Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : HeaderExchanged New state: OpenSent
2024-05-14T18:32:55.2857590Z 564: [2024-05-14T18:32:55.2854466Z T: 7924] DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:927 Func: _connection_byte_received: <- Header (AMQP 0.1.0.0)
2024-05-14T18:32:55.2860273Z 564: [2024-05-14T18:32:55.2855031Z T: 7924] DEBUG : Connection 74f26355-858b-4603-8c90-770acf638d5d state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_EXCH
2024-05-14T18:32:55.2862326Z 564: [2024-05-14T18:32:55.2856580Z T: 7924] DEBUG : 65535:-> [OPEN]* {74f26355-858b-4603-8c90-770acf638d5d,localhost,4294967295,65535,60000,NULL,NULL,NULL,NULL,{}}
2024-05-14T18:32:55.2864005Z 564: [2024-05-14T18:32:55.2857212Z T: 7924] DEBUG : Connection 74f26355-858b-4603-8c90-770acf638d5d state changed from CONNECTION_STATE_HDR_EXCH to CONNECTION_STATE_OPEN_SENT
2024-05-14T18:32:55.2865497Z 564: [2024-05-14T18:32:55.2858076Z T: 7924] DEBUG : 0:<- [OPEN]* {Mock Server for LinkAttachDetachMultipleOneSession,localhost,4294967295,65535,120000,NULL,NULL,NULL,NULL,{}}
2024-05-14T18:32:55.2866904Z 564: [2024-05-14T18:32:55.2859070Z T: 7924] DEBUG : Connection 74f26355-858b-4603-8c90-770acf638d5d state changed from CONNECTION_STATE_OPEN_SENT to CONNECTION_STATE_OPENED
2024-05-14T18:32:55.2868153Z 564: [2024-05-14T18:32:55.2859812Z T: 7924] DEBUG : 0:-> [BEGIN]* {NULL,0,1,1,4294967295}
2024-05-14T18:32:55.2868954Z 564: 
2024-05-14T18:32:55.2870183Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : OpenSent New state: Opened
2024-05-14T18:32:55.2871217Z 564: 
2024-05-14T18:32:55.2872280Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(712):: OnNewEndpoint - Incoming endpoint created, create session.
2024-05-14T18:32:55.3950739Z 564: [2024-05-14T18:32:55.3948082Z T: 7924] DEBUG : 0:<- [BEGIN]* {0,0,10000,1,4294967295}
2024-05-14T18:32:55.3952587Z 564: [2024-05-14T18:32:55.3949380Z T: 7924] DEBUG : 0:-> [ATTACH]* {KeepConnectionAlive,0,true,0,0,* {MyTarget},* {TestReceiver},NULL,NULL,NULL,0}
2024-05-14T18:32:55.3954011Z 564: [2024-05-14T18:32:55.3950260Z T: 7924] DEBUG : 0:-> [ATTACH]* {MySession,1,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-05-14T18:32:55.3956968Z 564: 
2024-05-14T18:32:55.3959667Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: Detached NewState: HalfAttachedAttachSent
2024-05-14T18:32:55.3961451Z 564: [2024-05-14T18:32:55.3951411Z T: 7924] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-14T18:32:55.3962581Z 564: 
2024-05-14T18:32:55.3965262Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: KeepConnectionAlive Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Receiver
2024-05-14T18:32:55.3967153Z 564: 
2024-05-14T18:32:55.3969116Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-14T18:32:55.3970486Z 564: 
2024-05-14T18:32:55.3971503Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(83):: Role is receiver, create sender.
2024-05-14T18:32:55.3972530Z 564: 
2024-05-14T18:32:55.3973586Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(86):: No sender found, create new sender for KeepConnectionAlive
2024-05-14T18:32:55.3975048Z 564: [2024-05-14T18:32:55.3954218Z T: 7924] DEBUG : Opening message sender. Authenticate if needed with audience: Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-14T18:32:55.3976342Z 564: [2024-05-14T18:32:55.3954495Z T: 7924] DEBUG : No credential, returning empty token.
2024-05-14T18:32:55.3977465Z 564: [2024-05-14T18:32:55.3954835Z T: 7924] DEBUG : Message sender state changed from Idle(1) to Opening(2).
2024-05-14T18:32:55.3978274Z 564: 
2024-05-14T18:32:55.3979419Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Idle New state: Opening
2024-05-14T18:32:55.3980663Z 564: [2024-05-14T18:32:55.3955669Z T: 7924] DEBUG : Opening message sender. Enable async operation.
2024-05-14T18:32:55.3981799Z 564: [2024-05-14T18:32:55.3956596Z T: 7924] DEBUG : Message sender state changed from Opening(2) to Open(3).
2024-05-14T18:32:55.3982604Z 564: 
2024-05-14T18:32:55.3983723Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Opening New state: Open
2024-05-14T18:32:55.3985155Z 564: [2024-05-14T18:32:55.3957440Z T: 7924] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-14T18:32:55.3986099Z 564: 
2024-05-14T18:32:55.3987628Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: MySession Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-05-14T18:32:55.3988854Z 564: 
2024-05-14T18:32:55.3990384Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-14T18:32:55.3991602Z 564: 
2024-05-14T18:32:55.3992577Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-05-14T18:32:55.3993425Z 564: 
2024-05-14T18:32:55.3994444Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession
2024-05-14T18:32:55.3995722Z 564: [2024-05-14T18:32:55.3961795Z T: 7924] DEBUG : MessageReceiver: Subscribe to link detach on:0***6D578
2024-05-14T18:32:55.3996567Z 564: 
2024-05-14T18:32:55.3997676Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-05-14T18:32:55.3998820Z 564: [2024-05-14T18:32:55.3964084Z T: 7924] DEBUG : No credential, returning empty token.
2024-05-14T18:32:55.4000023Z 564: [2024-05-14T18:32:55.3964412Z T: 7924] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-05-14T18:32:55.4001185Z 564: [2024-05-14T18:32:55.3965016Z T: 7924] DEBUG : Opening message receiver. Start async
2024-05-14T18:32:55.4002397Z 564: [2024-05-14T18:32:55.3965503Z T: 7924] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-05-14T18:32:55.4003262Z 564: 
2024-05-14T18:32:55.4004400Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-05-14T18:32:55.5049153Z 564: [2024-05-14T18:32:55.5046309Z T: 7924] DEBUG : 0:<- [ATTACH]* {KeepConnectionAlive,0,false,0,0,* {TestReceiver},* {MyTarget},NULL,NULL,0,184467440737095516***}
2024-05-14T18:32:55.5051157Z 564: [2024-05-14T18:32:55.5047296Z T: 7924] DEBUG : 0:-> [FLOW]* {0,1,0,1,0,0,10000}
2024-05-14T18:32:55.5053139Z 564: [2024-05-14T18:32:55.5048098Z T: 7924] DEBUG : 0:<- [ATTACH]* {MySession,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-05-14T18:32:55.5054180Z 564: 
2024-05-14T18:32:55.5055323Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-05-14T18:32:55.5056598Z 564: [2024-05-14T18:32:55.5049007Z T: 7924] DEBUG : 0:<- [FLOW]* {0,10000,0,1,1,0,10000}
2024-05-14T18:32:55.5057396Z 564: 
2024-05-14T18:32:55.5058366Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-05-14T18:32:55.5059208Z 564: 
2024-05-14T18:32:55.5060172Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-05-14T18:32:55.5061298Z 564: [2024-05-14T18:32:55.5050683Z T: 200] DEBUG : 0:-> [TRANSFER]* {1,0,<01 00 00 00>,0,false,false}
2024-05-14T18:32:55.6142581Z 564: 
2024-05-14T18:32:55.6144019Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(334):: MockServiceEndpoint(MyTarget) Received a message Message: <
2024-05-14T18:32:55.6145131Z 564:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-14T18:32:55.6146029Z 564:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-14T18:32:55.6146888Z 564:     Body: [AmqpValue, type=String
2024-05-14T18:32:55.6147629Z 564: >
2024-05-14T18:32:55.6148266Z 564: 
2024-05-14T18:32:55.6149302Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(281):: Received message on link MySession: Message: <
2024-05-14T18:32:55.6150326Z 564:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-14T18:32:55.6151195Z 564:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-14T18:32:55.6151983Z 564:     Body: [AmqpValue, type=String
2024-05-14T18:32:55.6152677Z 564: >
2024-05-14T18:32:55.6153289Z 564: 
2024-05-14T18:32:55.6154309Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(301):: Message received on link MySession: Message: <
2024-05-14T18:32:55.6155334Z 564:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-14T18:32:55.6156191Z 564:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-14T18:32:55.6156976Z 564:     Body: [AmqpValue, type=String
2024-05-14T18:32:55.6157645Z 564: >
2024-05-14T18:32:55.7236877Z 564: [2024-05-14T18:32:55.7233941Z T: 7924] DEBUG : 0:<- [DISPOSITION]* {true,0,0,true,* {}}
2024-05-14T18:32:55.7238095Z 564: [2024-05-14T18:32:55.7234954Z T: 200] DEBUG : 0:-> [DETACH]* {1,true}
2024-05-14T18:32:55.7239082Z 564: 
2024-05-14T18:32:55.7240210Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: Attached NewState: HalfAttachedAttachSent
2024-05-14T18:32:55.7241636Z 564: [2024-05-14T18:32:55.7235634Z T: 200] DEBUG : Try to disable async operation on connection: 0***64220 ID: 74f26355-858b-4603-8c90-770acf638d5d count: 2
2024-05-14T18:32:55.8329982Z 564: 
2024-05-14T18:32:55.8331572Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-05-14T18:32:55.8332881Z 564: 
2024-05-14T18:32:55.8333620Z 564: 
2024-05-14T18:32:55.8334596Z 564: [2024-05-14T18:32:55.8328118Z[  INFO ] T:  7924] WARN  : Message receiver link detached: : 
2024-05-14T18:32:55.8336004Z 564: [2024-05-14T18:32:55.8328538Z T: 7924] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-05-14T18:32:55.8337259Z 564: D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):: Receiver disconnected: MySession
2024-05-14T18:32:55.8338289Z 564: [2024-05-14T18:32:55.8329357Z T: 7396
2024-05-14T18:32:55.8339389Z 564: ] DEBUG[  INFO ] :  Lock for Closing message receiver.D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: 
2024-05-14T18:32:55.8340422Z 564: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-05-14T18:32:55.8341535Z 564: [2024-05-14T18:32:55.8330044Z T: 7396] DEBUG : Wait for receiver detach to complete. Current state: Idle
2024-05-14T18:32:55.8342719Z 564: [2024-05-14T18:32:55.8330622Z T: 7396] DEBUG : Receiver unsubscribe from link detach event on 0***6D578
2024-05-14T18:32:55.8343837Z 564: [2024-05-14T18:32:55.8330911Z T: 7396] DEBUG : Closing message receiver. Stop async
2024-05-14T18:32:55.9424144Z 564: [2024-05-14T18:32:55.9421241Z T: 7924] DEBUG : 0:<- [DETACH]* {1,true}
2024-05-14T18:32:55.9425945Z 564: 
2024-05-14T18:32:55.9427142Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-05-14T18:32:55.9428497Z 564: [2024-05-14T18:32:55.9423062Z T: 200] DEBUG : 0:-> [ATTACH]* {MySession2,1,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-05-14T18:32:55.9429375Z 564: 
2024-05-14T18:32:55.9430487Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: Detached NewState: HalfAttachedAttachSent
2024-05-14T18:32:55.9431915Z 564: [2024-05-14T18:32:55.9424265Z T: 200] DEBUG : Try to enable async operation on connection: 0***64220 ID: 74f26355-858b-4603-8c90-770acf638d5d count: 1
2024-05-14T18:32:56.0519314Z 564: [2024-05-14T18:32:56.05***274Z T: 7924] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-14T18:32:56.0520840Z 564: 
2024-05-14T18:32:56.0524960Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: MySession2 Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-05-14T18:32:56.0526399Z 564: 
2024-05-14T18:32:56.0527993Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-14T18:32:56.0529248Z 564: 
2024-05-14T18:32:56.0530256Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-05-14T18:32:56.0531293Z 564: 
2024-05-14T18:32:56.0532363Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession2
2024-05-14T18:32:56.0533621Z 564: [2024-05-14T18:32:56.0519225Z T: 7924] DEBUG : MessageReceiver: Subscribe to link detach on:0***6D068
2024-05-14T18:32:56.0534475Z 564: 
2024-05-14T18:32:56.0535461Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-05-14T18:32:56.0536575Z 564: [2024-05-14T18:32:56.0519658Z T: 7924] DEBUG : No credential, returning empty token.
2024-05-14T18:32:56.0537801Z 564: [2024-05-14T18:32:56.0519926Z T: 7924] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-05-14T18:32:56.0539004Z 564: [2024-05-14T18:32:56.0520874Z T: 7924] DEBUG : Opening message receiver. Start async
2024-05-14T18:32:56.0540338Z 564: [2024-05-14T18:32:56.0521492Z T: 7924] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-05-14T18:32:56.0541223Z 564: 
2024-05-14T18:32:56.0542382Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-05-14T18:32:56.1615057Z 564: [2024-05-14T18:32:56.1609685Z T: 7924] DEBUG : 0:<- [ATTACH]* {MySession2,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-05-14T18:32:56.1616337Z 564: 
2024-05-14T18:32:56.1617511Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-05-14T18:32:56.1618758Z 564: [2024-05-14T18:32:56.1611165Z T: 7924] DEBUG : 0:<- [FLOW]* {1,9999,0,1,1,0,10000}
2024-05-14T18:32:56.1619556Z 564: 
2024-05-14T18:32:56.1620546Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession2
2024-05-14T18:32:56.1621394Z 564: 
2024-05-14T18:32:56.1622364Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession2
2024-05-14T18:32:56.1623440Z 564: [2024-05-14T18:32:56.1612734Z T: 200] DEBUG : 0:-> [DETACH]* {1,true}
2024-05-14T18:32:56.1624201Z 564: 
2024-05-14T18:32:56.1625297Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: Attached NewState: HalfAttachedAttachSent
2024-05-14T18:32:56.1626697Z 564: [2024-05-14T18:32:56.1613364Z T: 200] DEBUG : Try to disable async operation on connection: 0***64220 ID: 74f26355-858b-4603-8c90-770acf638d5d count: 2
2024-05-14T18:32:56.2705681Z 564: 
2024-05-14T18:32:56.2706996Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-05-14T18:32:56.2708059Z 564: 
2024-05-14T18:32:56.2708719Z 564: 
2024-05-14T18:32:56.2709872Z 564: [[  INFO ]2024-05-14T18:32:56.2703557Z  T: D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):7924: ] WARN  : Message receiver link detached: : 
2024-05-14T18:32:56.2711247Z 564: [2024-05-14T18:32:56.2704061Z T: 7924] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-05-14T18:32:56.2712121Z 564: 
2024-05-14T18:32:56.2713267Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-05-14T18:32:56.2714290Z 564: Receiver disconnected: MySession2
2024-05-14T18:32:56.2715256Z 564: [2024-05-14T18:32:56.2704969Z T: 7396] DEBUG : Lock for Closing message receiver.
2024-05-14T18:32:56.2716375Z 564: [2024-05-14T18:32:56.2705541Z T: 7396] DEBUG : Wait for receiver detach to complete. Current state: Idle
2024-05-14T18:32:56.2717596Z 564: [2024-05-14T18:32:56.2705817Z T: 7396] DEBUG : Receiver unsubscribe from link detach event on 0***6D068
2024-05-14T18:32:56.2718993Z 564: [2024-05-14T18:32:56.2706302Z T: 7396] DEBUG : Closing message receiver. Stop async
2024-05-14T18:32:56.3800023Z 564: [2024-05-14T18:32:56.3796387Z T: 7924] DEBUG : 0:<- [DETACH]* {1,true}
2024-05-14T18:32:56.3801419Z 564: 
2024-05-14T18:32:56.3802742Z 564: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession2, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-05-14T18:32:56.3828858Z 417/511 Test #564: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession ......................................***Exception: SegFault  1.37 sec

@ahsonkhan ahsonkhan mentioned this issue May 16, 2024
Closed
@ahsonkhan
Copy link
Member Author

ahsonkhan commented May 21, 2024 •
edited

@LarryOsterman the test failed again here, resulting in the CI pipeline not auto-merging an unrelated PR, last night. Hoping a re-run unblocks that:

LiveTest_Public ValidateLive Win2019_x86_with_unit_test_winHttp failed
LiveTest_Public ValidateLive Win2022_x86_with_unit_test_winHttp failed
Validate Win2022_Win32Api_release_curl_x86

https://dev.azure.com/azure-sdk/internal/_build/results?buildId=3805560&view=logs&s=d63861ce-5ccf-501a-60fc-71ab3e84ddef&j=bde6d2cb-0847-54f8-b066-ca83e951fc62

2024-05-21T01:50:20.5173659Z test 426
2024-05-21T01:50:20.5175542Z         Start 426: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession
2024-05-21T01:50:20.5176379Z 
2024-05-21T01:50:20.5178599Z 426: Test command: D:\a\_work\1\s\build\sdk\core\azure-core-amqp\test\ut\Release\azure-core-amqp-tests.exe "--gtest_filter=TestLinks.LinkAttachDetachMultipleOneSession" "--gtest_also_run_disabled_tests"
2024-05-21T01:50:20.5180608Z 426: Working Directory: D:/a/_work/1/s/build/sdk/core/azure-core-amqp/test/ut
2024-05-21T01:50:20.5181887Z 426: Test timeout computed to be: 10000000
2024-05-21T01:50:20.5295594Z 426: Note: Google Test filter = TestLinks.LinkAttachDetachMultipleOneSession
2024-05-21T01:50:20.5296748Z 426: [==========] Running 1 test from 1 test suite.
2024-05-21T01:50:20.5297776Z 426: [----------] Global test environment set-up.
2024-05-21T01:50:20.5298724Z 426: [----------] 1 test from TestLinks
2024-05-21T01:50:20.5299570Z 426: [ RUN      ] TestLinks.LinkAttachDetachMultipleOneSession
2024-05-21T01:50:20.5328901Z 426: 
2024-05-21T01:50:20.5329895Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\session_tests.cpp(120):: Trying Test port: 49433
2024-05-21T01:50:20.5341408Z 426: [2024-05-21T01:50:20.5337500Z T: 3004] INFO  : Unknown port specified, assuming socket connection transport.
2024-05-21T01:50:20.5343733Z 426: [2024-05-21T01:50:20.5338097Z T: 3004] DEBUG : Create socket transport for host localhost port: 49433
2024-05-21T01:50:20.5346074Z 426: [2024-05-21T01:50:20.5339142Z T: 3004] DEBUG : Connection bba4afca-2fca-4e68-807d-6839cf40af6a state changed from CONNECTION_STATE_START to CONNECTION_STATE_START
2024-05-21T01:50:20.5347389Z 426: 
2024-05-21T01:50:20.5348622Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(596):: Wait 5 seconds for listener to start.
2024-05-21T01:50:20.5349638Z 426: 
2024-05-21T01:50:20.5350792Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(576):: Start test listener on port 49433
2024-05-21T01:50:20.5351750Z 426: 
2024-05-21T01:50:20.5352858Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(578):: listener started
2024-05-21T01:50:20.5353941Z 426: 
2024-05-21T01:50:20.5355025Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(602):: Listener running.
2024-05-21T01:50:20.5387265Z 426: [2024-05-21T01:50:20.5381918Z[ T: 2024-05-21T01:50:20.5382109Z T: 996] WARN  : File: D:\a\_work\1\s\build\_deps\vcpkg-src\buildtrees\azure-c-shared-utility\src\cb3fa760af-be37e775db.clean\src\dns_resolver_sync.c:50 Func: _dns_resolver_create: NULL hostname
2024-05-21T01:50:20.5390502Z 426: 
2024-05-21T01:50:20.5391889Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(679):: 3004OnSocketAccepted - Socket connection received.] 
2024-05-21T01:50:20.5393092Z 426: DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:412 Func: _send_header: -> Header (AMQP 0.1.0.0)
2024-05-21T01:50:20.5393822Z 426: 
2024-05-21T01:50:20.5394737Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: [Start
2024-05-21T01:50:20.5395753Z 426: [2024-05-21T01:50:20.5384201Z T: 996] DEBUG : ConnectionImpl::Listen: 01114FB0 ID: Mock Server for LinkAttachDetachMultipleOneSession
2024-05-21T01:50:20.5396436Z 426: 
2024-05-21T01:50:20.5397329Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : Start New state: HeaderExchanged
2024-05-21T01:50:20.5398113Z 426: 
2024-05-21T01:50:20.5399001Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : HeaderExchanged New state: OpenSent
2024-05-21T01:50:20.5400080Z 426: 2024-05-21T01:50:20.5383251Z T: 3004] DEBUG : Connection bba4afca-2fca-4e68-807d-6839cf40af6a state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_SENT
2024-05-21T01:50:20.5401083Z 426: [2024-05-21T01:50:20.5387255Z T: 3004] DEBUG : Connection bba4afca-2fca-4e68-807d-6839cf40af6a state changed from CONNECTION_STATE_HDR_SENT to CONNECTION_STATE_START
2024-05-21T01:50:20.5402062Z 426: [2024-05-21T01:50:20.5388271Z T: 3004] DEBUG : Try to enable async operation on connection: 0110B880 ID: bba4afca-2fca-4e68-807d-6839cf40af6a count: 0
2024-05-21T01:50:20.5402986Z 426: [2024-05-21T01:50:20.5388928Z T: 3004] DEBUG : Enabled async operation on connection: 0110B880 ID: bba4afca-2fca-4e68-807d-6839cf40af6a
2024-05-21T01:50:20.5403912Z 426: [2024-05-21T01:50:20.5389665Z T: 3004] DEBUG : Try to enable async operation on connection: 0110B880 ID: bba4afca-2fca-4e68-807d-6839cf40af6a count: 1
2024-05-21T01:50:20.6392865Z 426: [2024-05-21T01:50:20.6388112Z T: 3296] DEBUG : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\connection.c:927 Func: _connection_byte_received: <- Header (AMQP 0.1.0.0)
2024-05-21T01:50:20.6396246Z 426: [2024-05-21T01:50:20.6388799Z T: 3296] DEBUG : Connection bba4afca-2fca-4e68-807d-6839cf40af6a state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_EXCH
2024-05-21T01:50:20.6398330Z 426: [2024-05-21T01:50:20.6390085Z T: 3296] DEBUG : 65535:-> [OPEN]* {bba4afca-2fca-4e68-807d-6839cf40af6a,localhost,4294967295,65535,60000,NULL,NULL,NULL,NULL,{}}
2024-05-21T01:50:20.6400198Z 426: [2024-05-21T01:50:20.6390847Z T: 3296] DEBUG : Connection bba4afca-2fca-4e68-807d-6839cf40af6a state changed from CONNECTION_STATE_HDR_EXCH to CONNECTION_STATE_OPEN_SENT
2024-05-21T01:50:20.6432453Z 426: [2024-05-21T01:50:20.6392164Z T: 3296] DEBUG : 0:<- [OPEN]* {Mock Server for LinkAttachDetachMultipleOneSession,localhost,4294967295,65535,120000,NULL,NULL,NULL,NULL,{}}
2024-05-21T01:50:20.6434156Z 426: [2024-05-21T01:50:20.6392774Z T: 3296] DEBUG : Connection bba4afca-2fca-4e68-807d-6839cf40af6a state changed from CONNECTION_STATE_OPEN_SENT to CONNECTION_STATE_OPENED
2024-05-21T01:50:20.6435663Z 426: [2024-05-21T01:50:20.6394004Z T: 3296] DEBUG : 0:-> [BEGIN]* {NULL,0,1,1,4294967295}
2024-05-21T01:50:20.7488609Z 426: 
2024-05-21T01:50:20.7491642Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(699):: Connection State changed. Connection: Mock Server for LinkAttachDetachMultipleOneSession Old state : OpenSent New state: Opened
2024-05-21T01:50:20.7493187Z 426: 
2024-05-21T01:50:20.7494333Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(712):: OnNewEndpoint - Incoming endpoint created, create session.
2024-05-21T01:50:20.7495712Z 426: [2024-05-21T01:50:20.7484096Z T: 3296] DEBUG : 0:<- [BEGIN]* {0,0,10000,1,4294967295}
2024-05-21T01:50:20.7497062Z 426: [2024-05-21T01:50:20.7485079Z T: 3296] DEBUG : 0:-> [ATTACH]* {KeepConnectionAlive,0,true,0,0,* {MyTarget},* {TestReceiver},NULL,NULL,NULL,0}
2024-05-21T01:50:20.7498450Z 426: [2024-05-21T01:50:20.7486187Z T: 3296] DEBUG : 0:-> [ATTACH]* {MySession,1,false,0,0,* {MySource},* {MyTarget},NULL,NULL,0,0}
2024-05-21T01:50:20.7499404Z 426: 
2024-05-21T01:50:20.7500664Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: Detached NewState: HalfAttachedAttachSent
2024-05-21T01:50:20.8579889Z 426: [2024-05-21T01:50:20.8575766Z T: 3296] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-21T01:50:20.8581227Z 426: 
2024-05-21T01:50:20.8583139Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: KeepConnectionAlive Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Receiver
2024-05-21T01:50:20.8584566Z 426: 
2024-05-21T01:50:20.8586229Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-21T01:50:20.8587820Z 426: 
2024-05-21T01:50:20.8588974Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(83):: Role is receiver, create sender.
2024-05-21T01:50:20.8589858Z 426: 
2024-05-21T01:50:20.8591080Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(86):: No sender found, create new sender for KeepConnectionAlive
2024-05-21T01:50:20.8592642Z 426: [2024-05-21T01:50:20.8580379Z T: 3296] DEBUG : Opening message sender. Authenticate if needed with audience: Target{ Address: TestReceiver, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-21T01:50:20.8594080Z 426: [2024-05-21T01:50:20.8582600Z T: 3296] DEBUG : No credential, returning empty token.
2024-05-21T01:50:20.8595529Z 426: [2024-05-21T01:50:20.8583110Z T: 3296] DEBUG : Message sender state changed from Idle(1) to Opening(2).
2024-05-21T01:50:20.8596473Z 426: 
2024-05-21T01:50:20.8597818Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Idle New state: Opening
2024-05-21T01:50:20.8599318Z 426: [2024-05-21T01:50:20.8585167Z T: 3296] DEBUG : Opening message sender. Enable async operation.
2024-05-21T01:50:20.8600560Z 426: [2024-05-21T01:50:20.8586296Z T: 3296] DEBUG : Message sender state changed from Opening(2) to Open(3).
2024-05-21T01:50:20.8601444Z 426: 
2024-05-21T01:50:20.8602686Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(354):: MockServiceEndpoint(MyTarget) Message Sender State changed.Old state : Opening New state: Open
2024-05-21T01:50:20.8604576Z 426: [2024-05-21T01:50:20.8587218Z T: 3296] WARN  : File: D:\a\_work\1\s\sdk\core\azure-core-amqp\vendor\azure-uamqp-c\src\amqpvalue.c:2265 Func: _amqpvalue_clone: NULL value
2024-05-21T01:50:20.8605589Z 426: 
2024-05-21T01:50:20.8607037Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(740):: OnLinkAttached for name: MySession Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Role: Sender
2024-05-21T01:50:20.8608165Z 426: 
2024-05-21T01:50:20.8609593Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(75):: MockServiceEndpoint::OnLinkAttached for name: MyTarget Source : Source{ Address: MySource, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false} Target : Target{ Address: MyTarget, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-21T01:50:20.8610719Z 426: 
2024-05-21T01:50:20.8611634Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(109):: Role is sender, create receiver.
2024-05-21T01:50:20.8612388Z 426: 
2024-05-21T01:50:20.8613369Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(112):: No receiver found, create new receiver for MySession
2024-05-21T01:50:20.8614467Z 426: [2024-05-21T01:50:20.8594086Z T: 3296] DEBUG : MessageReceiver: Subscribe to link detach on:011188E8
2024-05-21T01:50:20.8615199Z 426: 
2024-05-21T01:50:20.8616097Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(120):: Open new message receiver.
2024-05-21T01:50:20.8617100Z 426: [2024-05-21T01:50:20.8594637Z T: 3296] DEBUG : No credential, returning empty token.
2024-05-21T01:50:20.8618199Z 426: [2024-05-21T01:50:20.8595163Z T: 3296] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_IDLE -> MESSAGE_RECEIVER_STATE_OPENING
2024-05-21T01:50:20.8619245Z 426: [2024-05-21T01:50:20.8596436Z T: 3296] DEBUG : Opening message receiver. Start async
2024-05-21T01:50:20.8620322Z 426: [2024-05-21T01:50:20.8597259Z T: 3296] DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPENING -> MESSAGE_RECEIVER_STATE_OPEN
2024-05-21T01:50:20.8621107Z 426: 
2024-05-21T01:50:20.8622148Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Opening New state: Open
2024-05-21T01:50:20.8623506Z 426: [2024-05-21T01:50:20.8598237Z T: 3296] DEBUG : 0:<- [ATTACH]* {KeepConnectionAlive,0,false,0,0,* {TestReceiver},* {MyTarget},NULL,NULL,0,184467440737095516***}
2024-05-21T01:50:20.8624619Z 426: [2024-05-21T01:50:20.8598874Z T: 3296] DEBUG : 0:-> [FLOW]* {0,1,0,1,0,0,10000}
2024-05-21T01:50:20.8625752Z 426: [2024-05-21T01:50:20.8599525Z T: 3296] DEBUG : 0:<- [ATTACH]* {MySession,1,true,0,0,* {MyTarget},* {MySource},NULL,NULL,NULL,184467440737095516***,NULL,NULL,{}}
2024-05-21T01:50:20.8626582Z 426: 
2024-05-21T01:50:20.8627737Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Attached
2024-05-21T01:50:20.8628854Z 426: [2024-05-21T01:50:20.8602335Z T: 3296] DEBUG : 0:<- [FLOW]* {0,10000,0,1,1,0,10000}
2024-05-21T01:50:20.8629570Z 426: 
2024-05-21T01:50:20.8630454Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-05-21T01:50:20.8631197Z 426: 
2024-05-21T01:50:20.8632063Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(335):: Link Flow On on link MySession
2024-05-21T01:50:20.8633091Z 426: [2024-05-21T01:50:20.8603801Z T: 3004] DEBUG : 0:-> [TRANSFER]* {1,0,<01 00 00 00>,0,false,false}
2024-05-21T01:50:20.9672185Z 426: 
2024-05-21T01:50:20.9673865Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(334):: MockServiceEndpoint(MyTarget) Received a message Message: <
2024-05-21T01:50:20.9676343Z 426:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-21T01:50:20.9677627Z 426:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-21T01:50:20.9678583Z 426:     Body: [AmqpValue, type=String
2024-05-21T01:50:20.9679376Z 426: >
2024-05-21T01:50:20.9680311Z 426: [2024-05-21T01:50:20.9671048Z T: 
2024-05-21T01:50:20.9681602Z 426: 3296] [  INFO ]DEBUG  : D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(281):0:<- [DISPOSITION]* {true,0,0,true,* {}}
2024-05-21T01:50:20.9682716Z 426: : Received message on link MySession: Message: <
2024-05-21T01:50:20.9683671Z 426:     Header{durable=false, priority=4, firstAcquirer=false, deliveryCount=0}
2024-05-21T01:50:20.9684652Z 426:     MessageProperties {MessageId: <null>}, deliveryTag=<01 00 00 00>
2024-05-21T01:50:20.9685539Z 426:     Body: [AmqpValue, type=String
2024-05-21T01:50:20.9686321Z 426: >
2024-05-21T01:50:20.9686958Z 426: 
2024-05-21T01:50:20.9688156Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(301):: Message received on link MySession: [Message: <2024-05-21T01:50:20.9673***0Z
2024-05-21T01:50:20.9689351Z 426:  T:     3004Header{] DEBUGdurable=false : , priority=0:-> [DETACH]* {1,true}
2024-05-21T01:50:20.9690126Z 426: 4, firstAcquirer=false
2024-05-21T01:50:20.9690808Z 426: , deliveryCount=0}
2024-05-21T01:50:20.9692042Z 426: [  INFO ]     D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):MessageProperties {: MessageId: <null>Link }MySession, deliveryTag=, State Changed. OldState: Attached<01 00 00 00> NewState: 
2024-05-21T01:50:20.9693046Z 426: HalfAttachedAttachSent    Body: [
2024-05-21T01:50:20.9693748Z 426: AmqpValue, type=String
2024-05-21T01:50:20.9694401Z 426: >
2024-05-21T01:50:20.9695467Z 426: [2024-05-21T01:50:20.9674050Z T: 3004] DEBUG : Try to disable async operation on connection: 0110B880 ID: bba4afca-2fca-4e68-807d-6839cf40af6a count: 2
2024-05-21T01:50:21.0773292Z 426: 
2024-05-21T01:50:21.0774894Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(344):: Message receiver disconnected: Error {null}
2024-05-21T01:50:21.0775813Z 426: 
2024-05-21T01:50:21.0776412Z 426: 
2024-05-21T01:50:21.0777428Z 426: [  INFO ] [D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(301):: 2024-05-21T01:50:21.0765690ZReceiver disconnected:  T: MySession3296
2024-05-21T01:50:21.0778346Z 426: ] WARN  : Message receiver link detached: : 
2024-05-21T01:50:21.0779807Z 426: [2024-05-21T01:50:21.0766185Z T: 7936[] DEBUG2024-05-21T01:50:21.0766396Z :  T: Lock for Closing message receiver.3296] 
2024-05-21T01:50:21.0781167Z 426: DEBUG : Message receiver state change MESSAGE_RECEIVER_STATE_OPEN -> MESSAGE_RECEIVER_STATE_IDLE
2024-05-21T01:50:21.0781996Z 426: 
2024-05-21T01:50:21.0783731Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\mock_amqp_server.hpp(324):: MockServiceEndpoint(MyTarget): Message Receiver State changed.Old state : Open New state: Idle
2024-05-21T01:50:21.0785283Z 426: [2024-05-21T01:50:21.0767904Z T: 3296] DEBUG : 0:<- [DETACH]* {1,true}
2024-05-21T01:50:21.0786090Z 426: 
2024-05-21T01:50:21.0787161Z 426: [  INFO ] D:\a\_work\1\s\sdk\core\azure-core-amqp\test\ut\link_tests.cpp(352):: Link MySession, State Changed. OldState: HalfAttachedAttachSent NewState: Detached
2024-05-21T01:50:21.0799929Z 426/520 Test #426: azure-core-amqp.TestLinks.LinkAttachDetachMultipleOneSession ......................................***Exception: SegFault  0.56 sec

@LarryOsterman LarryOsterman linked a pull request May 22, 2024 that will close this issue
Fixed #5536, fixed a test deadlock discovered while testing the fix for 5536, added some diagnostics for uAMQP to help track the problem. #5651
Merged
14 tasks
LarryOsterman added a commit that referenced this issue May 22, 2024
@LarryOsterman
Fixed #5536, fixed a test deadlock discovered while testing the fix f…
4fcf09d 
…or 5536, added some diagnostics for uAMQP to help track the problem. (#5651)

* Fixed 5536, cleaned up a bunch of test bugs found during testing of 5536 fix
azure-sdk added a commit to azure-sdk/vcpkg that referenced this issue Jun 6, 2024
@azure-sdk
[azure-core-amqp-cpp] Update to 1.0.0-beta.10
53867ea 
## 1.0.0-beta.10 (2024-06-06)

### Bugs Fixed

- [[microsoft#5536]](Azure/azure-sdk-for-cpp#5536) Fixed use-after free in MessageSender and MessageReceiver when opening a connection.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@LarryOsterman LarryOsterman

Labels
AMQP Issues related to the AMQP protocol Support in Azure Core test-reliability Issue that causes tests to be unreliable
Projects
None yet
Milestone
No milestone
2 participants
@ahsonkhan @LarryOsterman