search

Azure / azure-sdk-for-cpp

This repository is for active development of the Azure SDK for C++. For consumers of the SDK we recommend visiting our versioned developer docs at https://azure.github.io/azure-sdk-for-cpp.
MIT License
170 stars 118 forks source link

Intermittent test timeout in azure-core-amqp.TestManagement.ManagementOpenCloseError after enabling async operations on connection #5675

Open ahsonkhan opened 1 month ago

ahsonkhan commented 1 month ago

Validate Ubuntu22_included_debug https://dev.azure.com/azure-sdk/public/_build/results?buildId=3828938&view=logs&j=aa5e5880-f49c-5532-bf1f-326a5a437391&t=0f83612b-84fa-5d90-0d1a-17830cccb33f

2024-05-29T18:14:36.7396689Z         Start 453: azure-core-amqp.TestManagement.ManagementOpenCloseError
2024-05-29T18:14:36.7397004Z 
2024-05-29T18:14:36.7397717Z 453: Test command: /mnt/vss/_work/1/s/build/sdk/core/azure-core-amqp/test/ut/azure-core-amqp-tests "--gtest_filter=TestManagement.ManagementOpenCloseError" "--gtest_also_run_disabled_tests"
2024-05-29T18:14:36.7398355Z 453: Working Directory: /mnt/vss/_work/1/s/build/sdk/core/azure-core-amqp/test/ut
2024-05-29T18:14:36.7398710Z 453: Test timeout computed to be: 10000000
2024-05-29T18:14:36.7432363Z 453: Note: Google Test filter = TestManagement.ManagementOpenCloseError
2024-05-29T18:14:36.7432843Z 453: [==========] Running 1 test from 1 test suite.
2024-05-29T18:14:36.7433280Z 453: [----------] Global test environment set-up.
2024-05-29T18:14:36.7433638Z 453: [----------] 1 test from TestManagement
2024-05-29T18:14:36.7434088Z 453: [ RUN      ] TestManagement.ManagementOpenCloseError
2024-05-29T18:14:36.7445280Z 453: 
2024-05-29T18:14:36.7446305Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/session_tests.cpp:120:: Trying Test port: 49615
2024-05-29T18:14:36.7447054Z 453: [2024-05-29T18:14:36.7445006Z T: 140434557108544] INFO  : Unknown port specified, assuming socket connection transport.
2024-05-29T18:14:36.7447672Z 453: [2024-05-29T18:14:36.7445274Z T: 140434557108544] DEBUG : Create socket transport for host localhost port: 49615
2024-05-29T18:14:36.7449709Z 453: 
2024-05-29T18:14:36.7450634Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:614:: Wait 5 seconds for listener to start.
2024-05-29T18:14:36.7451057Z 453: 
2024-05-29T18:14:36.7451761Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:594:: Start test listener on port 49615
2024-05-29T18:14:36.7452103Z 453: 
2024-05-29T18:14:36.7454956Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:596:: listener started
2024-05-29T18:14:36.7455620Z 453: 
2024-05-29T18:14:36.7456223Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:620:: Listener running.
2024-05-29T18:14:36.7456783Z 453: [2024-05-29T18:14:36.7447989Z T: 140434557108544] DEBUG : No credential, returning empty token.
2024-05-29T18:14:36.7459894Z 453: [2024-05-29T18:14:36.7448439Z T: 140434557108544] DEBUG : Opening message sender. Authenticate if needed with audience: Target{ Address: $management, Durable: None, Expiry Policy: session-end, Timeout: 0, Dynamic: false}
2024-05-29T18:14:36.7460858Z 453: [2024-05-29T18:14:36.7448736Z T: 140434557108544] DEBUG : Message sender state changed from Idle(1) to Opening(2).
2024-05-29T18:14:36.7461700Z 453: [2024-05-29T18:14:36.7448905Z T: 140434557108544] INFO  : ManagementClient::OnMessageSenderStateChanged: Idle -> Opening
2024-05-29T18:14:36.7462418Z 453: [2024-05-29T18:14:36.7453225Z T: 140434557108544] DEBUG : Opening message sender. Enable async operation.
2024-05-29T18:14:36.7463015Z 453: [2024-05-29T18:14:36.7453692Z T: 140434557108544] DEBUG : Opening message sender. Enable async operation.
2024-05-29T18:14:36.7463980Z 453: [2024-05-29T18:14:36.7454159Z T: 140434533770816] WARN  : File: /mnt/vss/_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-29T18:14:36.7464542Z 453: 
2024-05-29T18:14:36.7465098Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:675:: OnSocketAccepted - Socket connection received.
2024-05-29T18:14:36.7465851Z 453: [2024-05-29T18:14:36.7463116Z T: 140434533770816] DEBUG : Connection Mock Server for ManagementOpenCloseError state changed from CONNECTION_STATE_START to CONNECTION_STATE_START
2024-05-29T18:14:36.7466226Z 453: 
2024-05-29T18:14:36.7466869Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:695:: Connection State changed. Connection: Mock Server for ManagementOpenCloseError Old state : Start New state: Start
2024-05-29T18:14:36.7470079Z 453: [2024-05-29T18:14:36.7463590Z T: 140434533770816] DEBUG : ConnectionImpl::Listen: 0x7fb970001ae0 ID: Mock Server for ManagementOpenCloseError
2024-05-29T18:14:36.7470952Z 453: [2024-05-29T18:14:36.7463750Z T: 140434533770816] DEBUG : Connection Mock Server for ManagementOpenCloseError state changed from CONNECTION_STATE_START to CONNECTION_STATE_HDR_EXCH
2024-05-29T18:14:36.7471357Z 453: 
2024-05-29T18:14:36.7472019Z 453: [  INFO ] /mnt/vss/_work/1/s/sdk/core/azure-core-amqp/test/ut/mock_amqp_server.hpp:695:: Connection State changed. Connection: Mock Server for ManagementOpenCloseError Old state : Start New state: HeaderExchanged
2024-05-29T18:14:36.7472802Z 453: [2024-05-29T18:14:36.7465836Z T: 140434533770816] DEBUG : Try to enable async operation on connection: 0x7fb970001ae0 ID: Mock Server for ManagementOpenCloseError count: 0
2024-05-29T18:14:36.7473707Z 453: [2024-05-29T18:14:36.7465986Z T: 140434533770816] DEBUG : Enabled async operation on connection: 0x7fb970001ae0 ID: Mock Server for ManagementOpenCloseError
2024-05-29T19:03:16.5013634Z ##[error]The Operation will be canceled. The next steps may not contain expected logs.
2024-05-29T19:03:16.5148501Z ##[error]The operation was canceled.
2024-05-29T19:03:16.5152014Z ##[section]Finishing: Test

Last log message at:

2024-05-29T18:14:36.7473707Z Operation canceled at: 2024-05-29T19:03:16.5013634Z

image

From an unrelated PR: https://github.com/Azure/azure-sdk-for-cpp/pull/5673

cc @LarryOsterman