[ https://issues.apache.org/jira/browse/IGNITE-23465?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Pavel Tupitsyn updated IGNITE-23465: ------------------------------------ Description: The log shows that handhsake succeeds on two different cluster IDs - might be a race condition. {code} Condition not reached after 00:00:05.0085011 (Entry { Message = Ignite.NET client version 3.1.0.0-snapshot+6f4bc94b7e is starting, Level = Information, Category = Apache.Ignite.Internal.ClientFailoverSocket, Exception = }, Entry { Message = Connection established [remoteAddress=[::ffff:127.0.0.1]:58706], Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-263, Exception = }, Entry { Message = Handshake succeeded [remoteAddress=[::ffff:127.0.0.1]:58706, context=ConnectionContext { Version = ClientProtocolVersion { Version = 3.0.0 }, IdleTimeout = 00:00:00, ClusterNode = ClusterNode { Id = 3f799f7e-2fec-4b36-b324-968c82dae9c0, Name = s2, Address = 127.0.0.1:58706 }, ClusterIds = System.Guid[], ClusterName = fake-cluster, SslInfo = , ClusterId = 00000002-0000-0000-0000-000000000000 }], Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-263, Exception = }, Entry { Message = Server-side IdleTimeout is not set, using configured IgniteClientConfiguration.HeartbeatInterval: 00:00:30, Level = Information, Category = Apache.Ignite.Internal.ClientSocket-263, Exception = }, Entry { Message = Connection established [remoteAddress=[::ffff:127.0.0.1]:58705], Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { Message = Handshake succeeded [remoteAddress=[::ffff:127.0.0.1]:58705, context=ConnectionContext { Version = ClientProtocolVersion { Version = 3.0.0 }, IdleTimeout = 00:00:00, ClusterNode = ClusterNode { Id = 4081e834-0b91-49b1-8f09-a83e93a079ee, Name = s1, Address = 127.0.0.1:58705 }, ClusterIds = System.Guid[], ClusterName = fake-cluster, SslInfo = , ClusterId = 00000001-0000-0000-0000-000000000000 }], Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { Message = Server-side IdleTimeout is not set, using configured IgniteClientConfiguration.HeartbeatInterval: 00:00:30, Level = Information, Category = Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { Message = Connection closed gracefully [remoteAddress=127.0.0.1:58705], Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { Message = Exception while reading from socket, connection closed: The operation was canceled., Level = Error, Category = Apache.Ignite.Internal.ClientSocket-264, Exception = System.OperationCanceledException: The operation was canceled. at System.Threading.CancellationToken.ThrowOperationCanceledException() at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken) at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Int32>.GetResult(Int16 token) at Apache.Ignite.Internal.ClientSocket.ReceiveBytesAsync(Stream stream, Byte[] buffer, Int32 size, MetricsContext metricsContext, CancellationToken cancellationToken) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line 506 at Apache.Ignite.Internal.ClientSocket.ReadMessageSizeAsync(Stream stream, Byte[] buffer, MetricsContext metricsContext, CancellationToken cancellationToken) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line 490 at Apache.Ignite.Internal.ClientSocket.ReadResponseAsync(Stream stream, Byte[] messageSizeBytes, MetricsContext metricsContext, CancellationToken cancellationToken) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line 463 at Apache.Ignite.Internal.ClientSocket.RunReceiveLoop(CancellationToken cancellationToken) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line 767 }, Entry { Message = Trying to establish secondary connections - awaiting 0 tasks..., Level = Debug, Category = Apache.Ignite.Internal.ClientFailoverSocket, Exception = }, Entry { Message = 0 secondary connections established, 0 failed., Level = Debug, Category = Apache.Ignite.Internal.ClientFailoverSocket, Exception = }) at Apache.Ignite.Tests.TestUtils.WaitForConditionAsync(Func`1 condition, Int32 timeoutMs, Func`1 messageFactory) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\TestUtils.cs:line 76 at Apache.Ignite.Tests.TestUtils.WaitForCondition(Func`1 condition, Int32 timeoutMs, Func`1 messageFactory) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\TestUtils.cs:line 45 at Apache.Ignite.Tests.MultiClusterTest.TestClientDropsConnectionOnClusterIdMismatch() in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\MultiClusterTest.cs:line 50 at NUnit.Framework.Internal.TaskAwaitAdapter.GenericAdapter`1.BlockUntilCompleted() at NUnit.Framework.Internal.MessagePumpStrategy.NoMessagePumpStrategy.WaitForCompletion(AwaitAdapter awaiter) at NUnit.Framework.Internal.AsyncToSyncAdapter.Await(Func`1 invoke) at NUnit.Framework.Internal.Commands.TestMethodCommand.RunTestMethod(TestExecutionContext context) at NUnit.Framework.Internal.Commands.TestMethodCommand.Execute(TestExecutionContext context) at NUnit.Framework.Internal.Commands.BeforeAndAfterTestCommand.<>c__DisplayClass1_0.<Execute>b__0() at NUnit.Framework.Internal.Commands.DelegatingTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext context, Action action) 1) at Apache.Ignite.Tests.TestUtils.WaitForConditionAsync(Func`1 condition, Int32 timeoutMs, Func`1 messageFactory) in C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\TestUtils.cs:line 76 {code} was: https://ci.ignite.apache.org/test/7936611520850929785?currentProjectId=ApacheIgnite3xGradle_Test&expandTestHistoryChartSection=true {code} Condition not reached after 00:00:01.0084379 at Apache.Ignite.Tests.TestUtils.WaitForConditionAsync(Func`1 condition, Int32 timeoutMs, Func`1 messageFactory) in /opt/buildagent/work/b8d4df1365f1f1e5/modules/platforms/dotnet/Apache.Ignite.Tests/TestUtils.cs:line 76 at Apache.Ignite.Tests.TestUtils.WaitForCondition(Func`1 condition, Int32 timeoutMs, Func`1 messageFactory) in /opt/buildagent/work/b8d4df1365f1f1e5/modules/platforms/dotnet/Apache.Ignite.Tests/TestUtils.cs:line 45 at Apache.Ignite.Tests.MultiClusterTest.TestClientDropsConnectionOnClusterIdMismatch() in /opt/buildagent/work/b8d4df1365f1f1e5/modules/platforms/dotnet/Apache.Ignite.Tests/MultiClusterTest.cs:line 49 at NUnit.Framework.Internal.TaskAwaitAdapter.GenericAdapter`1.BlockUntilCompleted() at NUnit.Framework.Internal.MessagePumpStrategy.NoMessagePumpStrategy.WaitForCompletion(AwaitAdapter awaiter) at NUnit.Framework.Internal.AsyncToSyncAdapter.Await(Func`1 invoke) at NUnit.Framework.Internal.Commands.TestMethodCommand.RunTestMethod(TestExecutionContext context) at NUnit.Framework.Internal.Commands.TestMethodCommand.Execute(TestExecutionContext context) at NUnit.Framework.Internal.Commands.BeforeAndAfterTestCommand.<>c__DisplayClass1_0.<Execute>b__0() at NUnit.Framework.Internal.Commands.DelegatingTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext context, Action action) 1) at Apache.Ignite.Tests.TestUtils.WaitForConditionAsync(Func`1 condition, Int32 timeoutMs, Func`1 messageFactory) in /opt/buildagent/work/b8d4df1365f1f1e5/modules/platforms/dotnet/Apache.Ignite.Tests/TestUtils.cs:line 76 ------- Stdout: ------- Fake server started [port=36191, test=TestClientDropsConnectionOnClusterIdMismatch] Fake server started [port=34381, test=TestClientDropsConnectionOnClusterIdMismatch] {code} > .NET: > Apache.Ignite.Tests.MultiClusterTest.TestClientDropsConnectionOnClusterIdMismatch > is flaky > ------------------------------------------------------------------------------------------------ > > Key: IGNITE-23465 > URL: https://issues.apache.org/jira/browse/IGNITE-23465 > Project: Ignite > Issue Type: Bug > Components: platforms, thin client > Reporter: Pavel Tupitsyn > Assignee: Pavel Tupitsyn > Priority: Major > Labels: ignite-3 > Fix For: 3.1 > > > The log shows that handhsake succeeds on two different cluster IDs - might be > a race condition. > {code} > Condition not reached after 00:00:05.0085011 (Entry { Message = Ignite.NET > client version 3.1.0.0-snapshot+6f4bc94b7e is starting, Level = Information, > Category = Apache.Ignite.Internal.ClientFailoverSocket, Exception = }, Entry > { Message = Connection established [remoteAddress=[::ffff:127.0.0.1]:58706], > Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-263, Exception > = }, Entry { Message = Handshake succeeded > [remoteAddress=[::ffff:127.0.0.1]:58706, context=ConnectionContext { Version > = ClientProtocolVersion { Version = 3.0.0 }, IdleTimeout = 00:00:00, > ClusterNode = ClusterNode { Id = 3f799f7e-2fec-4b36-b324-968c82dae9c0, Name = > s2, Address = 127.0.0.1:58706 }, ClusterIds = System.Guid[], ClusterName = > fake-cluster, SslInfo = , ClusterId = 00000002-0000-0000-0000-000000000000 > }], Level = Debug, Category = Apache.Ignite.Internal.ClientSocket-263, > Exception = }, Entry { Message = Server-side IdleTimeout is not set, using > configured IgniteClientConfiguration.HeartbeatInterval: 00:00:30, Level = > Information, Category = Apache.Ignite.Internal.ClientSocket-263, Exception = > }, Entry { Message = Connection established > [remoteAddress=[::ffff:127.0.0.1]:58705], Level = Debug, Category = > Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { Message = > Handshake succeeded [remoteAddress=[::ffff:127.0.0.1]:58705, > context=ConnectionContext { Version = ClientProtocolVersion { Version = 3.0.0 > }, IdleTimeout = 00:00:00, ClusterNode = ClusterNode { Id = > 4081e834-0b91-49b1-8f09-a83e93a079ee, Name = s1, Address = 127.0.0.1:58705 }, > ClusterIds = System.Guid[], ClusterName = fake-cluster, SslInfo = , ClusterId > = 00000001-0000-0000-0000-000000000000 }], Level = Debug, Category = > Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { Message = > Server-side IdleTimeout is not set, using configured > IgniteClientConfiguration.HeartbeatInterval: 00:00:30, Level = Information, > Category = Apache.Ignite.Internal.ClientSocket-264, Exception = }, Entry { > Message = Connection closed gracefully [remoteAddress=127.0.0.1:58705], Level > = Debug, Category = Apache.Ignite.Internal.ClientSocket-264, Exception = }, > Entry { Message = Exception while reading from socket, connection closed: The > operation was canceled., Level = Error, Category = > Apache.Ignite.Internal.ClientSocket-264, Exception = > System.OperationCanceledException: The operation was canceled. > at System.Threading.CancellationToken.ThrowOperationCanceledException() > at > System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError > error, CancellationToken cancellationToken) > at > System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Int32>.GetResult(Int16 > token) > at Apache.Ignite.Internal.ClientSocket.ReceiveBytesAsync(Stream stream, > Byte[] buffer, Int32 size, MetricsContext metricsContext, CancellationToken > cancellationToken) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line > 506 > at Apache.Ignite.Internal.ClientSocket.ReadMessageSizeAsync(Stream stream, > Byte[] buffer, MetricsContext metricsContext, CancellationToken > cancellationToken) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line > 490 > at Apache.Ignite.Internal.ClientSocket.ReadResponseAsync(Stream stream, > Byte[] messageSizeBytes, MetricsContext metricsContext, CancellationToken > cancellationToken) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line > 463 > at Apache.Ignite.Internal.ClientSocket.RunReceiveLoop(CancellationToken > cancellationToken) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite\Internal\ClientSocket.cs:line > 767 }, Entry { Message = Trying to establish secondary connections - > awaiting 0 tasks..., Level = Debug, Category = > Apache.Ignite.Internal.ClientFailoverSocket, Exception = }, Entry { Message > = 0 secondary connections established, 0 failed., Level = Debug, Category = > Apache.Ignite.Internal.ClientFailoverSocket, Exception = }) > at Apache.Ignite.Tests.TestUtils.WaitForConditionAsync(Func`1 condition, > Int32 timeoutMs, Func`1 messageFactory) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\TestUtils.cs:line > 76 > at Apache.Ignite.Tests.TestUtils.WaitForCondition(Func`1 condition, Int32 > timeoutMs, Func`1 messageFactory) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\TestUtils.cs:line > 45 > at > Apache.Ignite.Tests.MultiClusterTest.TestClientDropsConnectionOnClusterIdMismatch() > in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\MultiClusterTest.cs:line > 50 > at > NUnit.Framework.Internal.TaskAwaitAdapter.GenericAdapter`1.BlockUntilCompleted() > at > NUnit.Framework.Internal.MessagePumpStrategy.NoMessagePumpStrategy.WaitForCompletion(AwaitAdapter > awaiter) > at NUnit.Framework.Internal.AsyncToSyncAdapter.Await(Func`1 invoke) > at > NUnit.Framework.Internal.Commands.TestMethodCommand.RunTestMethod(TestExecutionContext > context) > at > NUnit.Framework.Internal.Commands.TestMethodCommand.Execute(TestExecutionContext > context) > at > NUnit.Framework.Internal.Commands.BeforeAndAfterTestCommand.<>c__DisplayClass1_0.<Execute>b__0() > at > NUnit.Framework.Internal.Commands.DelegatingTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext > context, Action action) > 1) at Apache.Ignite.Tests.TestUtils.WaitForConditionAsync(Func`1 > condition, Int32 timeoutMs, Func`1 messageFactory) in > C:\opt\BuildAgent\work\b8d4df1365f1f1e5\modules\platforms\dotnet\Apache.Ignite.Tests\TestUtils.cs:line > 76 > {code} -- This message was sent by Atlassian Jira (v8.20.10#820010)