Pavel Tupitsyn created IGNITE-27647:
---------------------------------------
Summary:
PartitionAwarenessRealClusterTests.TestPutRoutesRequestToPrimaryNode is flaky
Key: IGNITE-27647
URL: https://issues.apache.org/jira/browse/IGNITE-27647
Project: Ignite
Issue Type: Bug
Components: platforms ai3, thin clients ai3
Reporter: Pavel Tupitsyn
Assignee: Pavel Tupitsyn
Fix For: 3.2
Problem:
{code}
[Apache.Ignite.Internal.ClientFailoverSocket] 1 secondary connections
established, 0 failed.
{code}
*GetProxies()* method uses *Client.GetConnections()*, which had only 1 at the
moment - so we need to add another wait there.
Full log:
{code}
Expected string length 60 but was 62. Strings differ at index 60.
Expected: "org.apache.ignite.internal.runner.app.PlatformTestNodeRunner"
But was: "org.apache.ignite.internal.runner.app.PlatformTestNodeRunner_2"
-----------------------------------------------------------------------^
at
Apache.Ignite.Tests.PartitionAwarenessRealClusterTests.TestPutRoutesRequestToPrimaryNode(Boolean
withTx) in
/opt/buildagent/work/69bdbe372c424384/ignite-3/modules/platforms/dotnet/Apache.Ignite.Tests/PartitionAwarenessRealClusterTests.cs:line
81
at
Apache.Ignite.Tests.PartitionAwarenessRealClusterTests.TestPutRoutesRequestToPrimaryNode(Boolean
withTx) in
/opt/buildagent/work/69bdbe372c424384/ignite-3/modules/platforms/dotnet/Apache.Ignite.Tests/PartitionAwarenessRealClusterTests.cs:line
87
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.PartitionAwarenessRealClusterTests.TestPutRoutesRequestToPrimaryNode(Boolean
withTx) in
/opt/buildagent/work/69bdbe372c424384/ignite-3/modules/platforms/dotnet/Apache.Ignite.Tests/PartitionAwarenessRealClusterTests.cs:line
81
at
System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object
s)
------- Stdout: -------
SetUp: TestPutRoutesRequestToPrimaryNode(True)
Fake server started [port=37705, test=TestPutRoutesRequestToPrimaryNode(True)]
Accepted connection [port=37705, test=TestPutRoutesRequestToPrimaryNode(True),
endpoint=127.0.0.1:40666]
[09:15:12] [info] [Apache.Ignite.Internal.ClientFailoverSocket] Ignite.NET
client version 3.2.0.0-snapshot+8def725ff5 is starting
[09:15:12] [trce] [Apache.Ignite.Internal.ClientFailoverSocket] Endpoints
updated [added=[127.0.0.1:37705], removed=[]]
[09:15:12] [dbug] [Apache.Ignite.Internal.ClientSocket-319] Connection
established [remoteAddress=[::ffff:127.0.0.1]:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientFailoverSocket] ObservableTs
updated [prev=0, current=115937988582703104]
[09:15:12] [dbug] [Apache.Ignite.Internal.ClientSocket-319] Handshake succeeded
[remoteAddress=[::ffff:127.0.0.1]:37705, context=ConnectionContext { Version =
ClientProtocolVersion { Version = 3.0.0 }, IdleTimeout = 00:00:06, ClusterNode
= ClusterNode { Id = efe9d64b-4f7b-4108-89b4-ff2bfd374963, Name =
org.apache.ignite.internal.runner.app.PlatformTestNodeRunner_2, Address =
127.0.0.1:37705 }, ClusterIds = System.Guid[], ClusterName = cluster, SslInfo =
, Features = TableReqsUseQualifiedName, PlatformComputeJob,
StreamerReceiverExecutionOptions, ClusterId =
4e80e02e-ccc6-4cba-a1ba-0910c950bb51 }]
[09:15:12] [warn] [Apache.Ignite.Internal.ClientSocket-319] Server-side
IdleTimeout is 00:00:06, configured IgniteClientConfiguration.HeartbeatInterval
is 00:00:30, which is longer than recommended IdleTimeout / 3. Overriding
heartbeat interval with max(IdleTimeout / 3, 500ms): 00:00:02
[09:15:12] [dbug] [Apache.Ignite.Internal.ClientFailoverSocket] Trying to
establish secondary connections - awaiting 1 tasks...
[09:15:12] [dbug] [Apache.Ignite.Internal.ClientFailoverSocket] 1 secondary
connections established, 0 failed.
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=1, op=TableGetQualified, remoteAddress=127.0.0.1:37705]
[09:15:12] [info] [Apache.Ignite.Internal.ClientSocket-319] Partition
assignment change notification received [remoteAddress=127.0.0.1:37705,
timestamp=115937983374426112]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=1, op=TableGetQualified, flags=PartitionAssignmentChanged,
remoteAddress=127.0.0.1:37705, duration=00:00:00.0007808, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=2, op=SchemasGet, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=2, op=SchemasGet, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0005893, observableTs=0]
[09:15:12] [dbug] [Apache.Ignite.Internal.Table.Table] Schema loaded
[tableId=19, schemaVersion=1]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=3, op=PartitionAssignmentGet, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=3, op=PartitionAssignmentGet, flags=0,
remoteAddress=127.0.0.1:37705, duration=00:00:00.0005792, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=4, op=TupleGet, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientFailoverSocket] ObservableTs
updated [prev=115937988582703104, current=115937988583096321]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=4, op=TupleGet, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0011409, observableTs=115937988583096321]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=5, op=TableGetQualified, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=5, op=TableGetQualified, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0004340, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=6, op=ComputeExecuteColocated, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=6, op=ComputeExecuteColocated, flags=0,
remoteAddress=127.0.0.1:37705, duration=00:00:00.0017485, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientFailoverSocket] ObservableTs
updated [prev=115937988583096321, current=115937988583292928]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=6, op=None, flags=Notification, remoteAddress=127.0.0.1:37705,
duration=(null), observableTs=115937988583292928]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Lazy tx
created [options=TransactionOptions { ReadOnly = False, TimeoutMillis = 0 },
readTimestamp=115937988583292928]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=7, op=TxBegin, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=7, op=TxBegin, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0005643, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Tx started
[options=TransactionOptions { ReadOnly = False, TimeoutMillis = 0 },
readTimestamp=115937988583292928, txId=1]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=8, op=TupleUpsert, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=8, op=TupleUpsert, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0024523, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=9, op=TxRollback, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=9, op=TxRollback, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0035159, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Tx rolled
back [txId=1]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=10, op=ComputeExecuteColocated, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=10, op=ComputeExecuteColocated, flags=0,
remoteAddress=127.0.0.1:37705, duration=00:00:00.0013505, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientFailoverSocket] ObservableTs
updated [prev=115937988583292928, current=115937988583882752]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=10, op=None, flags=Notification, remoteAddress=127.0.0.1:37705,
duration=(null), observableTs=115937988583882752]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Lazy tx
created [options=TransactionOptions { ReadOnly = False, TimeoutMillis = 0 },
readTimestamp=115937988583882752]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=11, op=TxBegin, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=11, op=TxBegin, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0006499, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Tx started
[options=TransactionOptions { ReadOnly = False, TimeoutMillis = 0 },
readTimestamp=115937988583882752, txId=2]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=12, op=TupleUpsert, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=12, op=TupleUpsert, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0022375, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=13, op=TxRollback, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=13, op=TxRollback, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0032690, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Tx rolled
back [txId=2]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=14, op=ComputeExecuteColocated, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=14, op=ComputeExecuteColocated, flags=0,
remoteAddress=127.0.0.1:37705, duration=00:00:00.0033510, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientFailoverSocket] ObservableTs
updated [prev=115937988583882752, current=115937988584538112]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=14, op=None, flags=Notification, remoteAddress=127.0.0.1:37705,
duration=(null), observableTs=115937988584538112]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Lazy tx
created [options=TransactionOptions { ReadOnly = False, TimeoutMillis = 0 },
readTimestamp=115937988584538112]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=15, op=TxBegin, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=15, op=TxBegin, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0006903, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Tx started
[options=TransactionOptions { ReadOnly = False, TimeoutMillis = 0 },
readTimestamp=115937988584538112, txId=3]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=16, op=TupleUpsert, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=16, op=TupleUpsert, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0032835, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Sending request
[requestId=17, op=TxRollback, remoteAddress=127.0.0.1:37705]
[09:15:12] [trce] [Apache.Ignite.Internal.ClientSocket-319] Received response
[requestId=17, op=TxRollback, flags=0, remoteAddress=127.0.0.1:37705,
duration=00:00:00.0058764, observableTs=0]
[09:15:12] [trce] [Apache.Ignite.Internal.Transactions.Transactions] Tx rolled
back [txId=3]
[09:15:12] [dbug] [Apache.Ignite.Internal.ClientSocket-319] Connection closed
gracefully [remoteAddress=127.0.0.1:37705]
{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
