Open uslon opened 6 months ago
Test coordination_test::describe_semaphore_test tends to fail in an unpredictable manner. What causes test to crush is this assertion. It seems that one of the concurrent sessions is too late to take a semaphore ticket after it was released.
coordination_test::describe_semaphore_test
Here is failed check and
Test
coordination_test::describe_semaphore_testtends to fail in an unpredictable manner. What causes test to crush is this assertion. It seems that one of the concurrent sessions is too late to take a semaphore ticket after it was released.Here is failed check and
Test output
``` running 41 tests test auth_test::wrong_password_test - should panic ... ok test auth_test::auth_success_test ... ok test auth_test::wrong_username_test - should panic ... ok test auth_test::auth_async_success_test ... ok test client_builder::test::database_from_arg ... ok test client_builder::test::database_from_path ... ok test client_builder::test::password_without_username ... ok test auth_test::password_client_test ... ok test client_table_test_integration::create_session ... ok test client_directory_test_integration::create_list_remove_directory ... ok test client_table_test_integration::execute_data_query ... ok test client_table_test_integration::execute_data_query_params ... ok test client_table_test_integration::execute_data_query_field_name ... ok test client_table_test_integration::query_yson ... ok test client_table_test_integration::retry_test ... ok test client_table_test_integration::copy_tables ... ok test client_table_test_integration::copy_table ... ok test client_table_test_integration::select_int64_null4 ... ok test client_table_test_integration::select_int ... ok test client_table_test_integration::select_optional ... ok test client_table_test_integration::select_list ... ok test client_table_test_integration::interactive_transaction ... ok test client_table_test_integration::select_void_null ... ok test client_table_test_integration::select_struct ... ok test client_table_test_integration::scheme_query ... ok test coordination_test::create_delete_node_test ... ok test coordination_test::ephemeral_mutex_test ... ok test coordination_test::mutex_test ... ok test grpc_wrapper::raw_table_service::value::proto_test::convert_raw_protobuf ... ok test grpc_wrapper::raw_table_service::value::r#type::type_test::consistent_conversion ... ok test grpc_wrapper::raw_table_service::value::value_ydb::value_ydb_test::convert_ydb_raw_grpc ... ok test load_balancer::test::random_load_balancer ... ok test load_balancer::test::shared_load_balancer ... ok test load_balancer::test::update_load_balancer_test ... ok test discovery::test::test_background_discovery ... ok test session_pool::test::max_active_session ... ok test topics_test::create_delete_topic_test ... ok test types_test::test_is_optional ... ok test coordination_test::describe_semaphore_test ... FAILED test topics_test::send_message_test ... ok test client_table_test_integration::stream_query ... ok failures: ---- coordination_test::describe_semaphore_test stdout ---- 2024-03-14T12:15:20.305457Z TRACE describe_semaphore_test:create_client: ydb::test_integration_helper: get client 2024-03-14T12:15:20.305628Z TRACE describe_semaphore_test:create_client: ydb::test_integration_helper: start wait 2024-03-14T12:15:20.305641Z TRACE ydb::client_common: token renewed 2024-03-14T12:15:20.305657Z TRACE describe_semaphore_test:create_client: ydb::client: waiting_token 2024-03-14T12:15:20.305674Z TRACE describe_semaphore_test:create_client: ydb::client: wait discovery 2024-03-14T12:15:20.305688Z TRACE describe_semaphore_test:create_client: ydb::discovery: start discovery shared state 2024-03-14T12:15:20.305699Z TRACE describe_semaphore_test:create_client: ydb::discovery: loop 2024-03-14T12:15:20.305719Z TRACE describe_semaphore_test: ydb::discovery: timer discovery wait token 2024-03-14T12:15:20.305727Z TRACE describe_semaphore_test: ydb::discovery: timer discovery first token done with result: Ok(()) 2024-03-14T12:15:20.305750Z TRACE describe_semaphore_test:background_discovery{interval=60s}: ydb::discovery: rekby-discovery 2024-03-14T12:15:20.305768Z TRACE describe_semaphore_test:background_discovery{interval=60s}:discovery_now: ydb::discovery: discovery locking 2024-03-14T12:15:20.305780Z TRACE describe_semaphore_test:background_discovery{interval=60s}:discovery_now: ydb::discovery: creating grpc client 2024-03-14T12:15:20.309661Z TRACE describe_semaphore_test:background_discovery{interval=60s}: ydb::discovery: rekby-res: Ok(()) 2024-03-14T12:15:20.309745Z TRACE describe_semaphore_test:create_client: ydb::discovery: loop 2024-03-14T12:15:20.309762Z TRACE describe_semaphore_test:create_client: ydb::discovery: return ok 2024-03-14T12:15:20.309770Z TRACE describe_semaphore_test:create_client: ydb::client: wait balancer 2024-03-14T12:15:20.309874Z TRACE describe_semaphore_test: ydb::grpc_wrapper::raw_coordination_service::client: $ClientType.drop_node request: {"path":"/local/test_describe_semaphore","operation_params":{"operation_mode":1,"operation_timeout":{"seconds":60,"nanos":0},"cancel_after":{"seconds":60,"nanos":0},"labels":{},"report_cost_info":0}} 2024-03-14T12:15:20.312571Z TRACE describe_semaphore_test: ydb::grpc_wrapper::raw_coordination_service::client: $ClientType.create_node request: {"path":"/local/test_describe_semaphore","config":{"path":"","self_check_period_millis":0,"session_grace_period_millis":0,"read_consistency_mode":0,"attach_consistency_mode":0,"rate_limiter_counters_mode":0},"operation_params":{"operation_mode":1,"operation_timeout":{"seconds":60,"nanos":0},"cancel_after":{"seconds":60,"nanos":0},"labels":{},"report_cost_info":0}} 2024-03-14T12:15:20.335502Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: session started! SessionStarted { session_id: 1, timeout_millis: 0 } 2024-03-14T12:15:20.335660Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(Ping(PingPong { opaque: 10685316807501029190 })) 2024-03-14T12:15:20.338218Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: session started! SessionStarted { session_id: 2, timeout_millis: 0 } 2024-03-14T12:15:20.339035Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(Ping(PingPong { opaque: 10821633199977610807 })) 2024-03-14T12:15:20.342961Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: session started! SessionStarted { session_id: 3, timeout_millis: 0 } 2024-03-14T12:15:20.343032Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(Ping(PingPong { opaque: 4780101435558417356 })) 2024-03-14T12:15:20.344803Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(CreateSemaphoreResult(RawCreateSemaphoreResult { req_id: 0 })) 2024-03-14T12:15:20.345690Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(DescribeSemaphoreResult(RawDescribeSemaphoreResult { req_id: 0, semaphore_description: SemaphoreDescription { name: "my-resource", data: [], count: 0, limit: 2, ephemeral: false, owners: [], waiters: [] }, watch_added: false })) 2024-03-14T12:15:20.347190Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(AcquireSemaphoreResult(RawAcquireSemaphoreResult { req_id: 0, acquired: true })) 2024-03-14T12:15:20.347757Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(DescribeSemaphoreResult(RawDescribeSemaphoreResult { req_id: 1, semaphore_description: SemaphoreDescription { name: "my-resource", data: [], count: 1, limit: 2, ephemeral: false, owners: [SemaphoreSession { order_id: 1, session_id: 1, timeout_millis: 0, count: 1, data: [] }], waiters: [] }, watch_added: false })) 2024-03-14T12:15:20.349183Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(AcquireSemaphoreResult(RawAcquireSemaphoreResult { req_id: 0, acquired: true })) 2024-03-14T12:15:20.349649Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(DescribeSemaphoreResult(RawDescribeSemaphoreResult { req_id: 2, semaphore_description: SemaphoreDescription { name: "my-resource", data: [], count: 2, limit: 2, ephemeral: false, owners: [SemaphoreSession { order_id: 1, session_id: 1, timeout_millis: 0, count: 1, data: [] }, SemaphoreSession { order_id: 2, session_id: 2, timeout_millis: 0, count: 1, data: [2, 2, 2, 2, 2] }], waiters: [] }, watch_added: false })) 2024-03-14T12:15:20.351098Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(AcquireSemaphorePending(AcquireSemaphorePending { req_id: 0 })) 2024-03-14T12:15:20.552182Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(DescribeSemaphoreResult(RawDescribeSemaphoreResult { req_id: 3, semaphore_description: SemaphoreDescription { name: "my-resource", data: [], count: 2, limit: 2, ephemeral: false, owners: [SemaphoreSession { order_id: 1, session_id: 1, timeout_millis: 0, count: 1, data: [] }, SemaphoreSession { order_id: 2, session_id: 2, timeout_millis: 0, count: 1, data: [2, 2, 2, 2, 2] }], waiters: [SemaphoreSession { order_id: 3, session_id: 3, timeout_millis: 20000, count: 1, data: [3, 3, 3, 3, 3] }] }, watch_added: false })) 2024-03-14T12:15:20.552368Z TRACE describe_semaphore_test: ydb::client_coordination::session::lease: releaseing semaphore my-resource 2024-03-14T12:15:20.552438Z TRACE describe_semaphore_test: ydb::client_coordination::session::lease: releaseing semaphore my-resource 2024-03-14T12:15:20.554060Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(ReleaseSemaphoreResult(RawReleaseSemaphoreResult { req_id: 0, released: true })) 2024-03-14T12:15:20.554122Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(ReleaseSemaphoreResult(RawReleaseSemaphoreResult { req_id: 1, released: false })) 2024-03-14T12:15:20.554204Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(AcquireSemaphoreResult(RawAcquireSemaphoreResult { req_id: 0, acquired: true })) 2024-03-14T12:15:20.554260Z TRACE describe_semaphore_test: ydb::client_coordination::session::lease: semaphore my-resource released 2024-03-14T12:15:20.554399Z TRACE describe_semaphore_test: ydb::client_coordination::session::lease: releaseing semaphore my-resource 2024-03-14T12:15:20.555790Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(ReleaseSemaphoreResult(RawReleaseSemaphoreResult { req_id: 0, released: true })) 2024-03-14T12:15:20.555853Z TRACE describe_semaphore_test: ydb::client_coordination::session::coordination_session: received response: Ok(DescribeSemaphoreResult(RawDescribeSemaphoreResult { req_id: 4, semaphore_description: SemaphoreDescription { name: "my-resource", data: [], count: 1, limit: 2, ephemeral: false, owners: [SemaphoreSession { order_id: 1, session_id: 1, timeout_millis: 0, count: 1, data: [] }], waiters: [] }, watch_added: false })) 2024-03-14T12:15:20.555897Z TRACE describe_semaphore_test: ydb::client_coordination::session::lease: semaphore my-resource released thread 'coordination_test::describe_semaphore_test' panicked at ydb/src/coordination_test.rs:317:5: assertion `left == right` failed left: 1 right: 2 failures: coordination_test::describe_semaphore_test test result: FAILED. 40 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 13.96s error: test failed, to rerun pass `-p ydb --lib` Error: Process completed with exit code 101. ```