[ 
https://issues.apache.org/jira/browse/IGNITE-9756?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Pavel Pereslegin updated IGNITE-9756:
-------------------------------------
    Description: 
IgniteCacheIncrementTxTest.testIncrementTxTopologyChange2 fails sometimes in 
master with timeout.

Example of such failure: 
[https://ci.ignite.apache.org/viewLog.html?buildId=1977579&tab=buildResultsDiv&buildTypeId=IgniteTests24Java8_Cache2#testNameId-613377372188362920]

Typical log output:

 
{noformat}
[2018-10-03 19:40:32,654][INFO 
][sys-#438%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander] 
Started rebalance routine [default, 
supplier=67fdbd60-24fe-4810-a6a6-41a949b00003, topic=0, fullPartitions=[28, 31, 
33, 40, 43, 56, 61, 63, 70, 86, 93, 107, 115, 129, 149, 153, 167, 187, 207, 
215, 218, 224, 247, 279, 284, 290, 329, 332, 342, 373, 377, 383, 385-386, 423, 
435, 469, 478, 494, 515, 525, 528, 537, 565, 603, 607, 610, 624, 654, 686, 707, 
718, 738, 741, 746, 766, 775, 777, 797, 807, 809, 814, 822, 849, 856, 872, 876, 
909, 911, 914, 925, 940, 943, 962, 983, 991, 1005, 1014], histPartitions=[]]
[2018-10-03 19:40:32,654][INFO 
][sys-#175%cache.IgniteCacheIncrementTxTest0%][GridDhtPartitionSupplier] 
Finished supplying rebalancing [grp=default, 
demander=688062dd-508d-4ebc-9458-a48e1ba00002, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], topic=0]
[2018-10-03 19:40:32,654][INFO 
][sys-#185%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionSupplier] 
Finished supplying rebalancing [grp=default, 
demander=3f09a855-390b-40ce-b3e0-8b411db00001, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], topic=0]
[2018-10-03 19:40:32,654][INFO 
][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridDhtPartitionSupplier] 
Finished supplying rebalancing [grp=default, 
demander=67fdbd60-24fe-4810-a6a6-41a949b00003, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], topic=0]
[2018-10-03 19:40:32,654][INFO 
][sys-#234%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander] 
Completed rebalancing [grp=default, 
supplier=67fdbd60-24fe-4810-a6a6-41a949b00003, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], progress=1/2, time=0 ms]
[2018-10-03 19:40:32,654][INFO 
][sys-#237%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionDemander] 
Completed (final) rebalancing [grp=default, 
supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], progress=2/2, time=0 ms]
[2018-10-03 19:40:32,654][INFO 
][sys-#237%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionDemander] 
Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
[grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
rebalanceId=96, routines=2]
[2018-10-03 19:40:32,655][INFO 
][sys-#162%cache.IgniteCacheIncrementTxTest2%][GridDhtPartitionDemander] 
Completed (final) rebalancing [grp=default, 
supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], progress=2/2, time=0 ms]
[2018-10-03 19:40:32,655][INFO 
][sys-#162%cache.IgniteCacheIncrementTxTest2%][GridDhtPartitionDemander] 
Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
[grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
rebalanceId=96, routines=2]

[2018-10-03 19:40:33,260][INFO 
][exchange-worker-#38%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], force=true, evt=NODE_LEFT, 
node=f675cf49-5db3-45b3-83fb-7a7788400009]

[2018-10-03 19:40:33,261][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
 Cancelled rebalancing from all nodes [grp=default, 
topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0]]
[2018-10-03 19:40:33,261][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
 Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
[grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
rebalanceId=96, routines=2]
[2018-10-03 19:40:33,261][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridCachePartitionExchangeManager]
 Rebalancing scheduled [order=[default], top=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], force=true, evt=NODE_LEFT, 
node=f675cf49-5db3-45b3-83fb-7a7788400009]
[2018-10-03 19:40:33,262][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
 Prepared rebalancing [grp=default, mode=ASYNC, 
supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, partitionsCount=97, 
topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], parallelism=1]

[2018-10-03 19:40:33,899][INFO 
][sys-#155%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Full Message creating for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 1 ms.
[2018-10-03 19:40:33,903][INFO 
][sys-#155%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Sending Full Message for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 4 ms.
[2018-10-03 19:40:35,658][INFO 
][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Full Message creating for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 0 ms.
[2018-10-03 19:40:35,663][INFO 
][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Sending Full Message for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 5 ms.
[2018-10-03 19:43:41,700][INFO 
][tcp-disco-sock-reader-#226%cache.IgniteCacheIncrementTxTest0%][TestTcpDiscoverySpi]
 Finished serving remote node connection [rmtAddr=/127.0.0.1:44749, 
rmtPort=44749
[2018-10-03 19:45:25,806][ERROR][main][root] Test has been timed out and will 
be interrupted (threads dump will be taken before interruption) 
[test=testIncrementTxTopologyChange2, timeout=300000]
{noformat}
Test forces cache rebalancing (2 backups, full_sync) on different nodes and 
hangs after cancelling previous rebalance.

*Update*:

Test fails sometimes because partition cannot change state from {{RENTING}} to 
{{EVICTED,}} because eviction task cannot release some cache entries because 
they are locked ("_Entry could not be marked obsolete (it is still used or has 
readers)_"), but eviction task successfully completes and leaves partition in 
{{RENTING}} state.
 At the same time the transaction is completes and unlocks entries, but 
eviction task is not scheduled because in IGNITE-9244 was added deduplication 
check.
 Then the partition goes to the {{MOVING}} state and it hangs, waiting for the 
clearFuture to complete.

  was:
IgniteCacheIncrementTxTest.testIncrementTxTopologyChange2 fails sometimes in 
master with timeout.

Example of such failure: 
[https://ci.ignite.apache.org/viewLog.html?buildId=1977579&tab=buildResultsDiv&buildTypeId=IgniteTests24Java8_Cache2#testNameId-613377372188362920]

Typical log output:

 
{noformat}
[2018-10-03 19:40:32,654][INFO 
][sys-#438%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander] 
Started rebalance routine [default, 
supplier=67fdbd60-24fe-4810-a6a6-41a949b00003, topic=0, fullPartitions=[28, 31, 
33, 40, 43, 56, 61, 63, 70, 86, 93, 107, 115, 129, 149, 153, 167, 187, 207, 
215, 218, 224, 247, 279, 284, 290, 329, 332, 342, 373, 377, 383, 385-386, 423, 
435, 469, 478, 494, 515, 525, 528, 537, 565, 603, 607, 610, 624, 654, 686, 707, 
718, 738, 741, 746, 766, 775, 777, 797, 807, 809, 814, 822, 849, 856, 872, 876, 
909, 911, 914, 925, 940, 943, 962, 983, 991, 1005, 1014], histPartitions=[]]
[2018-10-03 19:40:32,654][INFO 
][sys-#175%cache.IgniteCacheIncrementTxTest0%][GridDhtPartitionSupplier] 
Finished supplying rebalancing [grp=default, 
demander=688062dd-508d-4ebc-9458-a48e1ba00002, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], topic=0]
[2018-10-03 19:40:32,654][INFO 
][sys-#185%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionSupplier] 
Finished supplying rebalancing [grp=default, 
demander=3f09a855-390b-40ce-b3e0-8b411db00001, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], topic=0]
[2018-10-03 19:40:32,654][INFO 
][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridDhtPartitionSupplier] 
Finished supplying rebalancing [grp=default, 
demander=67fdbd60-24fe-4810-a6a6-41a949b00003, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], topic=0]
[2018-10-03 19:40:32,654][INFO 
][sys-#234%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander] 
Completed rebalancing [grp=default, 
supplier=67fdbd60-24fe-4810-a6a6-41a949b00003, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], progress=1/2, time=0 ms]
[2018-10-03 19:40:32,654][INFO 
][sys-#237%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionDemander] 
Completed (final) rebalancing [grp=default, 
supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], progress=2/2, time=0 ms]
[2018-10-03 19:40:32,654][INFO 
][sys-#237%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionDemander] 
Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
[grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
rebalanceId=96, routines=2]
[2018-10-03 19:40:32,655][INFO 
][sys-#162%cache.IgniteCacheIncrementTxTest2%][GridDhtPartitionDemander] 
Completed (final) rebalancing [grp=default, 
supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, topVer=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], progress=2/2, time=0 ms]
[2018-10-03 19:40:32,655][INFO 
][sys-#162%cache.IgniteCacheIncrementTxTest2%][GridDhtPartitionDemander] 
Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
[grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
rebalanceId=96, routines=2]

[2018-10-03 19:40:33,260][INFO 
][exchange-worker-#38%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], force=true, evt=NODE_LEFT, 
node=f675cf49-5db3-45b3-83fb-7a7788400009]

[2018-10-03 19:40:33,261][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
 Cancelled rebalancing from all nodes [grp=default, 
topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0]]
[2018-10-03 19:40:33,261][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
 Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
[grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
rebalanceId=96, routines=2]
[2018-10-03 19:40:33,261][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridCachePartitionExchangeManager]
 Rebalancing scheduled [order=[default], top=AffinityTopologyVersion 
[topVer=45, minorTopVer=0], force=true, evt=NODE_LEFT, 
node=f675cf49-5db3-45b3-83fb-7a7788400009]
[2018-10-03 19:40:33,262][INFO 
][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
 Prepared rebalancing [grp=default, mode=ASYNC, 
supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, partitionsCount=97, 
topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], parallelism=1]

[2018-10-03 19:40:33,899][INFO 
][sys-#155%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Full Message creating for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 1 ms.
[2018-10-03 19:40:33,903][INFO 
][sys-#155%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Sending Full Message for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 4 ms.
[2018-10-03 19:40:35,658][INFO 
][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Full Message creating for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 0 ms.
[2018-10-03 19:40:35,663][INFO 
][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
 Sending Full Message for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
performed in 5 ms.
[2018-10-03 19:43:41,700][INFO 
][tcp-disco-sock-reader-#226%cache.IgniteCacheIncrementTxTest0%][TestTcpDiscoverySpi]
 Finished serving remote node connection [rmtAddr=/127.0.0.1:44749, 
rmtPort=44749
[2018-10-03 19:45:25,806][ERROR][main][root] Test has been timed out and will 
be interrupted (threads dump will be taken before interruption) 
[test=testIncrementTxTopologyChange2, timeout=300000]
{noformat}
Test forces cache rebalancing (2 backups, full_sync) on different nodes and 
hangs after cancelling previous rebalance.

*Update*:

Test fails sometimes because partition cannot change state from {{RENTING}} to 
{{EVICTED}}, first time eviction task unable to release some cache entries 
because they are locked ("_Entry could not be marked obsolete (it is still used 
or has readers)_"), but eviction task successfully completes and leaves 
partition in {{RENTING}} state.
 At the same time the transaction is completes and unlocks entries, but 
eviction task is not scheduled because in IGNITE-9244 was added deduplication 
check.
 Then the partition goes to the {{MOVING}} state and it hangs, waiting for the 
clearFuture to complete.


> [Test Failed] IgniteCacheIncrementTxTest.testIncrementTxTopologyChange2 fails 
> sometimes in master.
> --------------------------------------------------------------------------------------------------
>
>                 Key: IGNITE-9756
>                 URL: https://issues.apache.org/jira/browse/IGNITE-9756
>             Project: Ignite
>          Issue Type: Bug
>    Affects Versions: 2.6
>            Reporter: Pavel Pereslegin
>            Assignee: Pavel Pereslegin
>            Priority: Major
>              Labels: MakeTeamcityGreenAgain
>
> IgniteCacheIncrementTxTest.testIncrementTxTopologyChange2 fails sometimes in 
> master with timeout.
> Example of such failure: 
> [https://ci.ignite.apache.org/viewLog.html?buildId=1977579&tab=buildResultsDiv&buildTypeId=IgniteTests24Java8_Cache2#testNameId-613377372188362920]
> Typical log output:
>  
> {noformat}
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#438%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander] 
> Started rebalance routine [default, 
> supplier=67fdbd60-24fe-4810-a6a6-41a949b00003, topic=0, fullPartitions=[28, 
> 31, 33, 40, 43, 56, 61, 63, 70, 86, 93, 107, 115, 129, 149, 153, 167, 187, 
> 207, 215, 218, 224, 247, 279, 284, 290, 329, 332, 342, 373, 377, 383, 
> 385-386, 423, 435, 469, 478, 494, 515, 525, 528, 537, 565, 603, 607, 610, 
> 624, 654, 686, 707, 718, 738, 741, 746, 766, 775, 777, 797, 807, 809, 814, 
> 822, 849, 856, 872, 876, 909, 911, 914, 925, 940, 943, 962, 983, 991, 1005, 
> 1014], histPartitions=[]]
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#175%cache.IgniteCacheIncrementTxTest0%][GridDhtPartitionSupplier] 
> Finished supplying rebalancing [grp=default, 
> demander=688062dd-508d-4ebc-9458-a48e1ba00002, topVer=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], topic=0]
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#185%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionSupplier] 
> Finished supplying rebalancing [grp=default, 
> demander=3f09a855-390b-40ce-b3e0-8b411db00001, topVer=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], topic=0]
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridDhtPartitionSupplier] 
> Finished supplying rebalancing [grp=default, 
> demander=67fdbd60-24fe-4810-a6a6-41a949b00003, topVer=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], topic=0]
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#234%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander] 
> Completed rebalancing [grp=default, 
> supplier=67fdbd60-24fe-4810-a6a6-41a949b00003, topVer=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], progress=1/2, time=0 ms]
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#237%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionDemander] 
> Completed (final) rebalancing [grp=default, 
> supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, topVer=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], progress=2/2, time=0 ms]
> [2018-10-03 19:40:32,654][INFO 
> ][sys-#237%cache.IgniteCacheIncrementTxTest3%][GridDhtPartitionDemander] 
> Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
> [grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
> rebalanceId=96, routines=2]
> [2018-10-03 19:40:32,655][INFO 
> ][sys-#162%cache.IgniteCacheIncrementTxTest2%][GridDhtPartitionDemander] 
> Completed (final) rebalancing [grp=default, 
> supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, topVer=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], progress=2/2, time=0 ms]
> [2018-10-03 19:40:32,655][INFO 
> ][sys-#162%cache.IgniteCacheIncrementTxTest2%][GridDhtPartitionDemander] 
> Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
> [grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
> rebalanceId=96, routines=2]
> [2018-10-03 19:40:33,260][INFO 
> ][exchange-worker-#38%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
>  Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], force=true, evt=NODE_LEFT, 
> node=f675cf49-5db3-45b3-83fb-7a7788400009]
> [2018-10-03 19:40:33,261][INFO 
> ][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
>  Cancelled rebalancing from all nodes [grp=default, 
> topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0]]
> [2018-10-03 19:40:33,261][INFO 
> ][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
>  Completed rebalance future: RebalanceFuture [grp=CacheGroupContext 
> [grp=default], topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], 
> rebalanceId=96, routines=2]
> [2018-10-03 19:40:33,261][INFO 
> ][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridCachePartitionExchangeManager]
>  Rebalancing scheduled [order=[default], top=AffinityTopologyVersion 
> [topVer=45, minorTopVer=0], force=true, evt=NODE_LEFT, 
> node=f675cf49-5db3-45b3-83fb-7a7788400009]
> [2018-10-03 19:40:33,262][INFO 
> ][exchange-worker-#151%cache.IgniteCacheIncrementTxTest1%][GridDhtPartitionDemander]
>  Prepared rebalancing [grp=default, mode=ASYNC, 
> supplier=4b3e5c6e-cec4-4fb6-b1b2-47fd71900000, partitionsCount=97, 
> topVer=AffinityTopologyVersion [topVer=45, minorTopVer=0], parallelism=1]
> [2018-10-03 19:40:33,899][INFO 
> ][sys-#155%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
>  Full Message creating for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
> performed in 1 ms.
> [2018-10-03 19:40:33,903][INFO 
> ][sys-#155%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
>  Sending Full Message for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
> performed in 4 ms.
> [2018-10-03 19:40:35,658][INFO 
> ][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
>  Full Message creating for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
> performed in 0 ms.
> [2018-10-03 19:40:35,663][INFO 
> ][sys-#179%cache.IgniteCacheIncrementTxTest0%][GridCachePartitionExchangeManager]
>  Sending Full Message for AffinityTopologyVersion [topVer=45, minorTopVer=0] 
> performed in 5 ms.
> [2018-10-03 19:43:41,700][INFO 
> ][tcp-disco-sock-reader-#226%cache.IgniteCacheIncrementTxTest0%][TestTcpDiscoverySpi]
>  Finished serving remote node connection [rmtAddr=/127.0.0.1:44749, 
> rmtPort=44749
> [2018-10-03 19:45:25,806][ERROR][main][root] Test has been timed out and will 
> be interrupted (threads dump will be taken before interruption) 
> [test=testIncrementTxTopologyChange2, timeout=300000]
> {noformat}
> Test forces cache rebalancing (2 backups, full_sync) on different nodes and 
> hangs after cancelling previous rebalance.
> *Update*:
> Test fails sometimes because partition cannot change state from {{RENTING}} 
> to {{EVICTED,}} because eviction task cannot release some cache entries 
> because they are locked ("_Entry could not be marked obsolete (it is still 
> used or has readers)_"), but eviction task successfully completes and leaves 
> partition in {{RENTING}} state.
>  At the same time the transaction is completes and unlocks entries, but 
> eviction task is not scheduled because in IGNITE-9244 was added deduplication 
> check.
>  Then the partition goes to the {{MOVING}} state and it hangs, waiting for 
> the clearFuture to complete.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to