Hello All,
I was wondering if anybody has encountered the following issue.
I have 2 servers (Ignite 2.0.1) in the cluster. Each of these 2 servers
loads different caches (with different names) in LOCAL mode using
DataStreamer.
I am starting these servers simultaneously (say the second server is started
1 sec. after the first one). Very often, say with the 25% chance,
the first server's addData(DataStreamerImpl.java:665) call fails with the
error "java.lang.IllegalStateException: Data streamer has been closed".
Looking at the log one can see that this error is always
preceeded with the error "org.apache.ignite.IgniteCheckedException: Failed
to finish operation (too many remaps): 32" Caused by:
"org.apache.ignite.IgniteCheckedException: Topology changed during batch
preparation".
I have verified already that this is not not us calling the close() on the
DataStreamer. I seem to never observe this issue when I start only the first
(one) server.
Fragment of the log is attached below.
Thank you in advance for any help or suggestion,
Zbyszek
evt=DISCOVERY_CUSTOM_EVT, node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Exchange_BOND-L1555-1500303702823, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=125], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Exchange_EQUITY-U1300-1500296583907, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=126], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Exchange_EQUITY-U1100-1500289395073, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=127], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Exchange_EQUITY-U1200-1500293005458, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=128], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Listing_EQUITY-U0800-1500278534000, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=129], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Listing_EQUITY-U1000-1500285783155, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=130], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:39 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Listing_EQUITY-U1400-1500300190375, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:39 ERROR [sys-#131%null%] o.a.i.i.p.d.DataStreamerImpl
[Slf4jLogger.java:119] DataStreamer operation failed.
org.apache.ignite.IgniteCheckedException: Failed to finish operation (too
many remaps): 32
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl$5.apply(DataStreamerImpl.java:861)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl$5.apply(DataStreamerImpl.java:826)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:382)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.future.GridFutureAdapter.unblock(GridFutureAdapter.java:346)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.future.GridFutureAdapter.unblockAll(GridFutureAdapter.java:334)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:494)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:473)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl$Buffer.update(DataStreamerImpl.java:1410)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl.load0(DataStreamerImpl.java:930)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl.access$1000(DataStreamerImpl.java:122)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl$5$1.run(DataStreamerImpl.java:874)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl$5$2.call(DataStreamerImpl.java:901)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl$5$2.call(DataStreamerImpl.java:889)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUtils.java:6621)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.processors.closure.GridClosureProcessor$2.body(GridClosureProcessor.java:954)
[ignite-core-2.0.1.jar:2.0.1]
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
[ignite-core-2.0.1.jar:2.0.1]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[na:1.8.0_111]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[na:1.8.0_111]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111]
Caused by: org.apache.ignite.IgniteCheckedException: Topology changed during
batch preparation.[batchTopVer=AffinityTopologyVersion [topVer=2,
minorTopVer=128], topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=129]]
... 12 common frames omitted
2017-07-17 21:40:40 INFO [exchange-worker-#65%null%]
o.a.i.i.p.c.GridCachePartitionExchangeManager [Slf4jLogger.java:99] Skipping
rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion [topVer=2,
minorTopVer=131], evt=DISCOVERY_CUSTOM_EVT,
node=918cd6f8-e761-43d7-9467-a28f65163c8c]
2017-07-17 21:40:40 INFO [exchange-worker-#65%null%]
o.a.i.i.p.cache.GridCacheProcessor [Slf4jLogger.java:99] Started cache
[name=fvpd_Listing_EQUITY-U0900-1500282168028, memoryPolicyName=null,
mode=LOCAL]
2017-07-17 21:40:40 ERROR [Namespace Loader-3] server.IncidentsLog
[ContentLogPersistenceImpl.java:82]
[{"incidentClass":"EntityHandler","details":{"responsible:ClassInfo":{"simpleName":"FutureTask","name":"java.util.concurrent.FutureTask"},"reporter:ClassInfo":{"simpleName":"EntityHandlerImpl","module":{"image":"\/s6\/images\/S6.png","name":"S6"},"name":"com.markit.n6platform.s6.entity.handler.EntityHandlerImpl"},"details":"SectorCurve.N1600_400849_1"},"stackTrace":"java.lang.IllegalStateException:
Data streamer has been closed.\n\tat
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl.enterBusy(DataStreamerImpl.java:404)\n\tat
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl.addDataInternal(DataStreamerImpl.java:611)\n\tat
org.apache.ignite.internal.processors.datastreamer.DataStreamerImpl.addData(DataStreamerImpl.java:665)\n\tat
com.markit.n6platform.s6.entity.EntityStore.addData(EntityStore.java:44)\n\tat
com.markit.n6platform.s6.store.StoreProviderImpl.lambda$loadBatchRunStore$4(StoreProviderImpl.java:89)\n\tat
com.markit.n6platform.s6.binary.AbstractEntityLoader.lambda$loadEntity$62(AbstractEntityLoader.java:62)\n\tat
com.markit.n6platform.s6.entity.handler.EntityHandlerImpl.entityEnd(EntityHandlerImpl.java:26)\n\tat
com.markit.n6platform.s6.entity.handler.EntityHandlerBase.endEntity(EntityHandlerBase.java:96)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.MongoDocumentEntityParser.serialize(MongoDocumentEntityParser.java:67)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.loadAndProcessResults(N6EntityRetrievalImpl.java:280)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.lambda$null$86(N6EntityRetrievalImpl.java:237)\n\tat
com.markit.n6platform.model.retrieval.pool.ResourcePoolTemplate.doWith(ResourcePoolTemplate.java:18)\n\tat
com.markit.n6platform.model.retrieval.pool.ResourcePoolTemplate.doWith(ResourcePoolTemplate.java:11)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.lambda$loadBatchRun$87(N6EntityRetrievalImpl.java:237)\n\tat
java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1626)\n\tat
java.util.concurrent.CompletableFuture.asyncRunStage(CompletableFuture.java:1640)\n\tat
java.util.concurrent.CompletableFuture.runAsync(CompletableFuture.java:1858)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.loadBatchRun(N6EntityRetrievalImpl.java:237)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.loadEntity(N6EntityRetrievalImpl.java:163)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.lambda$loadBatchRun$78(N6EntityRetrievalImpl.java:134)\n\tat
java.util.ArrayList.forEach(ArrayList.java:1249)\n\tat
com.markit.n6platform.model.retrieval.internal.mongo.N6EntityRetrievalImpl.loadBatchRun(N6EntityRetrievalImpl.java:133)\n\tat
com.markit.n6platform.s6.binary.AbstractEntityLoader.loadEntity(AbstractEntityLoader.java:87)\n\tat
com.markit.n6platform.s6.binary.AbstractEntityLoader.loadEntity(AbstractEntityLoader.java:67)\n\tat
com.markit.n6platform.s6.binary.BatchRunLoader.load(BatchRunLoader.java:38)\n\tat
com.markit.n6platform.s6.store.StoreProviderImpl.loadBatchRunStore(StoreProviderImpl.java:85)\n\tat
com.markit.n6platform.s6.store.StoreProviderImpl.loadBatchRun(StoreProviderImpl.java:67)\n\tat
com.markit.n6platform.s6.batch.BatchRunServiceImpl.loadBatchRun(BatchRunServiceImpl.java:53)\n\tat
com.markit.n6platform.s6.batch.BatchStreamer.asyncLoad(BatchStreamer.java:174)\n\tat
com.markit.n6platform.s6.batch.BatchStreamer.lambda$null$48(BatchStreamer.java:111)\n\tat
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\n\tat
java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)\n\tat
java.lang.Thread.run(Thread.java:745)\n"}]
--
View this message in context:
http://apache-ignite-users.70518.x6.nabble.com/java-lang-IllegalStateException-Data-streamer-has-been-closed-tp15061.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.
