Hello, Ilya, In the post above one week ago I've attached necessary thread dumps. Could you please say whether do you have sufficient information to investigate the problem with hanging of IgniteAtomicLong? I think the issue not all that harmless, it concerns the last Ignite 2.8.1 and its fixing may be IMHO important for the community (I think the cause is in initialization of ignite-sys-atomic-cache simultaneously in several nodes, but certainly I may be mistaken). But unfortunately I see no reaction on this since a week. Could you please give at least a hint that the problem is under investigation and there is a slightest chance that the problem can be resolved? Or it is better to work out some workarounds?
Thank you very much in advance for any response. My best regards, Ilya ilya.kasnacheev wrote > Hello! > > Can you collect thread dumps from all nodes once you get them hanging? > > Can you throw together a reproducer project? > > Regards, > -- > Ilya Kasnacheev > > > вт, 4 авг. 2020 г. в 12:51, Ilya Roublev < > iroublev@ > >: > >> We are developing Jira cloud app using Apache Ignite both as data storage >> and as job scheduler. This is done via a standard Ignite client node. But >> we need to use Atlassian Connect Spring Boot to be able to communicate >> with >> Jira. In short, all is done exactly as in our article Boosting Jira Cloud >> app development with Apache Ignite >> <https://medium.com/alliedium/boosting-jira-cloud-app-development-with-apache-ignite-7eebc7bb3d48>. >> At first we used simple Ignite JDBC driver >> <https://apacheignite-sql.readme.io/docs/jdbc-driver> just for >> Atlassian >> Connect Spring Boot along with a separate Ignite client node for our own >> purposes. But this turned out to be very unstable being deployed in our >> local Kubernetes cluster (built via Kubespray) due to constant exceptions >> >> java.net.SocketException: Connection reset >> >> occuring from time to time (in fact, this revealed only in our local >> cluster, in AWS EKS all worked fine). To make all this more stable we >> tried >> to use Ignite JDBC Client driver >> <https://apacheignite-sql.readme.io/docs/jdbc-client-driver> >> exactly as >> described in the article mentioned above. Thus, now our backend uses two >> Ignite client nodes per single JVM: the first one for JDBC used by >> Atlassian Connect Spring Boot, the second one for our own purposes. This >> solution turned out to be good enough, because our app works now very >> stable both in our local cluster and in AWS EKS. But when we deploy our >> app >> in Docker for testing and developing purposes, our Ignite client nodes >> hang >> from time to time. After some investigation we were able to see that this >> occurs exactly at the instant when an object of IgniteAtomicLong is >> created. Below are logs both for successful initialization of our app and >> for the case when Ignite client node hanged. Logs when all is ok >> ignite-appclientnode-successful.log >> <http://apache-ignite-users.70518.x6.nabble.com/file/t2262/ignite-appclientnode-successful.log> >> ignite-jdbcclientnode-successful.log >> <http://apache-ignite-users.70518.x6.nabble.com/file/t2262/ignite-jdbcclientnode-successful.log> >> Logs >> when both client node hang ignite-appclientnode-failed.log >> <http://apache-ignite-users.70518.x6.nabble.com/file/t2262/ignite-appclientnode-failed.log> >> ignite-jdbcclientnode-failed.log >> <http://apache-ignite-users.70518.x6.nabble.com/file/t2262/ignite-jdbcclientnode-failed.log> >> Some >> analysis and questions From logs one can see that caches default, >> tenants, atlassian_host_audit, SQL_PUBLIC_ATLASSIAN_HOST are manipulated, >> in fact, default is given in client configuration: client.xml >> <http://apache-ignite-users.70518.x6.nabble.com/file/t2262/client.xml>, >> the cache SQL_PUBLIC_ATLASSIAN_HOST contains atlassian_host table >> mentioned >> in Boosting Jira Cloud app development with Apache Ignite >> <https://medium.com/alliedium/boosting-jira-cloud-app-development-with-apache-ignite-7eebc7bb3d48> >> and is created in advance even before the app starts. Further, >> atlassian_host_audit is a copy of atlassian_host, in any case it is not >> yet >> created when the app hangs. What concerns other entities processed by >> Ignite, they are created by the following code: >> >> CacheConfiguration<Long, Tenant> tenantCacheCfg = new >> CacheConfiguration<>(); >> tenantCacheCfg.setName("tenants"); >> tenantCacheCfg.setSqlSchema("PROD"); >> tenantCacheCfg.setIndexedTypes(Long.class, Tenant.class); >> >> tenantCacheCfg.setAtomicityMode(CacheAtomicityMode.TRANSACTIONAL); >> tenantCacheCfg.setEncryptionEnabled(true); >> >> IgniteCache<Long, Tenant> tenantCache = >> ignite.getOrCreateCache(tenantCacheCfg); >> IgniteAtomicLong idGen = >> ignite.atomicLong("PROD_tenants_seq", 0, true); >> >> And from the logs of the app itself it is clear that the app hangs >> exactly >> on the last line. This is confirmed by the fact that the in >> ignite-jdbcclientnode-successful.log we have the following lines: >> >> [2020-07-31 09:52:12,237][INFO ][exchange-worker-#43][GridCacheProcessor] >> Started cache [name=ignite-sys-atomic-cache@default-ds-group, >> id=1481046058, group=default-ds-group, dataRegionName=null, >> mode=PARTITIONED, atomicity=TRANSACTIONAL, backups=1, mvcc=false] >> [2020-07-31 09:52:12,263][INFO ][exchange-worker-#43][time] Finished >> exchange init [topVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], >> crd=false] >> [2020-07-31 09:52:12,631][INFO >> ][sys-#109%ignite-jdbc-driver-e1f562e1-5127-4f55-80d2-18661982769c%][GridDhtPartitionsExchangeFuture] >> Received full message, will finish exchange >> [node=c7d1e091-da48-46a3-98ea-6971e8a811e0, >> resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2]] >> [2020-07-31 09:52:12,634][INFO >> ][sys-#54][GridDhtPartitionsExchangeFuture] Received full message, will >> finish exchange [node=c7d1e091-da48-46a3-98ea-6971e8a811e0, >> resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2]] >> [2020-07-31 09:52:12,639][INFO >> ][sys-#109%ignite-jdbc-driver-e1f562e1-5127-4f55-80d2-18661982769c%][GridDhtPartitionsExchangeFuture] >> Finish exchange future [startVer=AffinityTopologyVersion [topVer=6, >> minorTopVer=2], resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], >> err=null, rebalanced=true, wasRebalanced=true] >> [2020-07-31 09:52:12,645][INFO >> ][sys-#54][GridDhtPartitionsExchangeFuture] Finish exchange future >> [startVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], >> resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], err=null, >> rebalanced=true, wasRebalanced=true] >> [2020-07-31 09:52:12,645][INFO >> ][sys-#109%ignite-jdbc-driver-e1f562e1-5127-4f55-80d2-18661982769c%][GridDhtPartitionsExchangeFuture] >> Completed partition exchange >> [localNode=3b6ad97d-0ac9-4b2f-8703-f734968a5ec0, >> exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion >> [topVer=6, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=TcpDiscoveryNode [id=292cfc60-bf04-4000-9589-d633f980f06a, >> consistentId=292cfc60-bf04-4000-9589-d633f980f06a, addrs=ArrayList >> [127.0.0.1, 172.24.0.7], sockAddrs=HashSet [/127.0.0.1:0, >> da98724605ca/172.24.0.7:0], discPort=0, order=3, intOrder=3, >> lastExchangeTime=1596189127174, loc=false, >> ver=2.8.1#20200521-sha1:86422096, isClient=true], done=true, >> newCrdFut=null], topVer=AffinityTopologyVersion [topVer=6, >> minorTopVer=2]] >> [2020-07-31 09:52:12,646][INFO >> ][sys-#109%ignite-jdbc-driver-e1f562e1-5127-4f55-80d2-18661982769c%][GridDhtPartitionsExchangeFuture] >> Exchange timings [startVer=AffinityTopologyVersion [topVer=6, >> minorTopVer=2], resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], >> stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters >> initialization" (0 ms), stage="Update caches registry" (3 ms), >> stage="Start caches" (0 ms), stage="Affinity initialization on cache >> group start" (5 ms), stage="Determine exchange type" (0 ms), >> stage="Waiting for Full message" (400 ms), stage="Affinity recalculation" >> (0 ms), stage="Full map updating" (6 ms), stage="Exchange done" (7 ms), >> stage="Total time" (421 ms)] >> [2020-07-31 09:52:12,646][INFO >> ][sys-#109%ignite-jdbc-driver-e1f562e1-5127-4f55-80d2-18661982769c%][GridDhtPartitionsExchangeFuture] >> Exchange longest local stages [startVer=AffinityTopologyVersion >> [topVer=6, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=6, >> minorTopVer=2], stage="Affinity initialization on cache group start >> [grp=default-ds-group]" (5 ms) (parent=Affinity initialization on cache >> group start)] >> [2020-07-31 09:52:12,646][INFO >> ][exchange-worker-#104%ignite-jdbc-driver-e1f562e1-5127-4f55-80d2-18661982769c%][GridCachePartitionExchangeManager] >> Skipping rebalancing (no affinity changes) [top=AffinityTopologyVersion >> [topVer=6, minorTopVer=2], rebTopVer=AffinityTopologyVersion [topVer=-1, >> minorTopVer=0], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=292cfc60-bf04-4000-9589-d633f980f06a, client=true] >> [2020-07-31 09:52:12,659][INFO ][sys-#54][GridCacheProcessor] Finish >> proxy initialization, cacheName=ignite-sys-atomic-cache@default-ds-group, >> localNodeId=292cfc60-bf04-4000-9589-d633f980f06a >> [2020-07-31 09:52:12,660][INFO >> ][exchange-worker-#43][GridCachePartitionExchangeManager] Skipping >> rebalancing (no affinity changes) [top=AffinityTopologyVersion [topVer=6, >> minorTopVer=2], rebTopVer=AffinityTopologyVersion [topVer=-1, >> minorTopVer=0], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=292cfc60-bf04-4000-9589-d633f980f06a, client=true] >> [2020-07-31 09:52:12,660][INFO >> ][sys-#54][GridDhtPartitionsExchangeFuture] Completed partition exchange >> [localNode=292cfc60-bf04-4000-9589-d633f980f06a, >> exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion >> [topVer=6, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=TcpDiscoveryNode [id=292cfc60-bf04-4000-9589-d633f980f06a, >> consistentId=292cfc60-bf04-4000-9589-d633f980f06a, addrs=ArrayList >> [127.0.0.1, 172.24.0.7], sockAddrs=HashSet [/127.0.0.1:0, >> da98724605ca/172.24.0.7:0], discPort=0, order=3, intOrder=0, >> lastExchangeTime=1596189105382, loc=true, >> ver=2.8.1#20200521-sha1:86422096, isClient=true], done=true, >> newCrdFut=null], topVer=AffinityTopologyVersion [topVer=6, >> minorTopVer=2]] >> [2020-07-31 09:52:12,660][INFO >> ][sys-#54][GridDhtPartitionsExchangeFuture] Exchange timings >> [startVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], >> resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], stage="Waiting >> in exchange queue" (0 ms), stage="Exchange parameters initialization" (0 >> ms), stage="Update caches registry" (0 ms), stage="Start caches" (47 ms), >> stage="Affinity initialization on cache group start" (4 ms), >> stage="Determine exchange type" (0 ms), stage="Waiting for Full message" >> (371 ms), stage="Affinity recalculation" (0 ms), stage="Full map >> updating" (11 ms), stage="Exchange done" (15 ms), stage="Total time" (448 >> ms)] >> [2020-07-31 09:52:12,661][INFO >> ][sys-#54][GridDhtPartitionsExchangeFuture] Exchange longest local stages >> [startVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], >> resVer=AffinityTopologyVersion [topVer=6, minorTopVer=2], stage="Affinity >> initialization on cache group start [grp=default-ds-group]" (4 ms) >> (parent=Affinity initialization on cache group start)] >> >> while in ignite-jdbcclientnode-failed.log all the lines starting the >> first >> time the cache ignite-sys-atomic-cache@default-ds-group (the cache used >> for atomics) was mentioned are as follows: >> >> [2020-08-03 21:52:00,386][INFO >> ][exchange-worker-#104%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][time] >> Started exchange init [topVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], crd=false, evt=DISCOVERY_CUSTOM_EVT, >> evtNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> customEvt=DynamicCacheChangeBatch >> [id=2954f46b371-f60b9b4c-244f-458a-bb18-2ff0893c1d05, reqs=ArrayList >> [DynamicCacheChangeRequest >> [cacheName=ignite-sys-atomic-cache@default-ds-group, hasCfg=true, >> nodeId=653143b2-6e80-49ff-9e9a-ae10237b32e8, clientStartOnly=false, >> stop=false, destroy=false, disabledAfterStartfalse]], >> exchangeActions=ExchangeActions >> [startCaches=[ignite-sys-atomic-cache@default-ds-group], stopCaches=null, >> startGrps=[default-ds-group], stopGrps=[], resetParts=null, >> stateChangeRequest=null], startCaches=false], allowMerge=false, >> exchangeFreeSwitch=false] >> [2020-08-03 21:52:00,403][INFO >> ][exchange-worker-#104%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][time] >> Finished exchange init [topVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], crd=false] >> [2020-08-03 21:52:00,406][INFO ][exchange-worker-#43][time] Started >> exchange init [topVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> crd=false, evt=DISCOVERY_CUSTOM_EVT, >> evtNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> customEvt=DynamicCacheChangeBatch >> [id=2954f46b371-f60b9b4c-244f-458a-bb18-2ff0893c1d05, reqs=ArrayList >> [DynamicCacheChangeRequest >> [cacheName=ignite-sys-atomic-cache@default-ds-group, hasCfg=true, >> nodeId=653143b2-6e80-49ff-9e9a-ae10237b32e8, clientStartOnly=false, >> stop=false, destroy=false, disabledAfterStartfalse]], >> exchangeActions=ExchangeActions >> [startCaches=[ignite-sys-atomic-cache@default-ds-group], stopCaches=null, >> startGrps=[default-ds-group], stopGrps=[], resetParts=null, >> stateChangeRequest=null], startCaches=false], allowMerge=false, >> exchangeFreeSwitch=false] >> [2020-08-03 21:52:00,415][INFO ][exchange-worker-#43][time] Finished >> exchange init [topVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> crd=false] >> [2020-08-03 21:52:00,838][INFO >> ][sys-#52][GridDhtPartitionsExchangeFuture] Received full message, will >> finish exchange [node=c0138e03-465d-4944-a1ee-8bee59fbf909, >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1]] >> [2020-08-03 21:52:00,839][INFO >> ][sys-#107%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][GridDhtPartitionsExchangeFuture] >> Received full message, will finish exchange >> [node=c0138e03-465d-4944-a1ee-8bee59fbf909, >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1]] >> [2020-08-03 21:52:00,853][INFO >> ][sys-#107%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][GridDhtPartitionsExchangeFuture] >> Finish exchange future [startVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> err=null, rebalanced=true, wasRebalanced=true] >> [2020-08-03 21:52:00,861][INFO >> ][sys-#52][GridDhtPartitionsExchangeFuture] Finish exchange future >> [startVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], err=null, >> rebalanced=true, wasRebalanced=true] >> [2020-08-03 21:52:00,870][INFO >> ][sys-#107%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][GridDhtPartitionsExchangeFuture] >> Completed partition exchange >> [localNode=467aae9a-d21c-45bf-8184-2837941ba650, >> exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion >> [topVer=8, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=TcpDiscoveryNode [id=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> consistentId=653143b2-6e80-49ff-9e9a-ae10237b32e8, addrs=ArrayList >> [127.0.0.1, 172.23.0.8], sockAddrs=HashSet [/127.0.0.1:0, >> d371f9a8ea1f/172.23.0.8:0], discPort=0, order=7, intOrder=6, >> lastExchangeTime=1596491518929, loc=false, >> ver=2.8.1#20200521-sha1:86422096, isClient=true], done=true, >> newCrdFut=null], topVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1]] >> [2020-08-03 21:52:00,870][INFO >> ][sys-#107%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][GridDhtPartitionsExchangeFuture] >> Exchange timings [startVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters >> initialization" (9 ms), stage="Update caches registry" (0 ms), >> stage="Start caches" (0 ms), stage="Affinity initialization on cache >> group start" (6 ms), stage="Determine exchange type" (0 ms), >> stage="Waiting for Full message" (436 ms), stage="Affinity recalculation" >> (0 ms), stage="Full map updating" (14 ms), stage="Exchange done" (16 ms), >> stage="Total time" (481 ms)] >> [2020-08-03 21:52:00,870][INFO >> ][sys-#107%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][GridDhtPartitionsExchangeFuture] >> Exchange longest local stages [startVer=AffinityTopologyVersion >> [topVer=8, minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], stage="Affinity initialization on cache group start >> [grp=default-ds-group]" (6 ms) (parent=Affinity initialization on cache >> group start)] >> [2020-08-03 21:52:00,870][INFO >> ][sys-#52][GridDhtPartitionsExchangeFuture] Completed partition exchange >> [localNode=3bbe2ea9-7ba5-4de5-84be-be23bd27f312, >> exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion >> [topVer=8, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=TcpDiscoveryNode [id=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> consistentId=653143b2-6e80-49ff-9e9a-ae10237b32e8, addrs=ArrayList >> [127.0.0.1, 172.23.0.8], sockAddrs=HashSet [/127.0.0.1:0, >> d371f9a8ea1f/172.23.0.8:0], discPort=0, order=7, intOrder=6, >> lastExchangeTime=1596491518929, loc=false, >> ver=2.8.1#20200521-sha1:86422096, isClient=true], done=true, >> newCrdFut=null], topVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1]] >> [2020-08-03 21:52:00,871][INFO >> ][exchange-worker-#104%ignite-jdbc-driver-31920dc9-8960-4130-8469-3d589aa6e1b4%][GridCachePartitionExchangeManager] >> Skipping rebalancing (no affinity changes) [top=AffinityTopologyVersion >> [topVer=8, minorTopVer=1], rebTopVer=AffinityTopologyVersion [topVer=-1, >> minorTopVer=0], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, client=true] >> [2020-08-03 21:52:00,873][INFO >> ][exchange-worker-#43][GridCachePartitionExchangeManager] Skipping >> rebalancing (no affinity changes) [top=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], rebTopVer=AffinityTopologyVersion [topVer=-1, >> minorTopVer=0], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, client=true] >> [2020-08-03 21:52:00,873][INFO >> ][sys-#52][GridDhtPartitionsExchangeFuture] Exchange timings >> [startVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], stage="Waiting >> in exchange queue" (0 ms), stage="Exchange parameters initialization" (0 >> ms), stage="Update caches registry" (0 ms), stage="Start caches" (0 ms), >> stage="Affinity initialization on cache group start" (7 ms), >> stage="Determine exchange type" (0 ms), stage="Waiting for Full message" >> (423 ms), stage="Affinity recalculation" (0 ms), stage="Full map >> updating" (22 ms), stage="Exchange done" (9 ms), stage="Total time" (461 >> ms)] >> [2020-08-03 21:52:00,873][INFO >> ][sys-#52][GridDhtPartitionsExchangeFuture] Exchange longest local stages >> [startVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], stage="Affinity >> initialization on cache group start [grp=default-ds-group]" (7 ms) >> (parent=Affinity initialization on cache group start)] >> >> In particular, the following line from >> ignite-jdbcclientnode-successful.log is absent in >> ignite-jdbcclientnode-failed.log: >> >> [2020-07-31 09:52:12,237][INFO ][exchange-worker-#43][GridCacheProcessor] >> Started cache [name=ignite-sys-atomic-cache@default-ds-group, >> id=1481046058, group=default-ds-group, dataRegionName=null, >> mode=PARTITIONED, atomicity=TRANSACTIONAL, backups=1, mvcc=false] >> >> But it should be noted that for the failure case there are other client >> nodes executed in separate containers executed simultaneously with the >> backend app and with the same code creating the cache tenants and >> IgniteAtomicLong idGen what concerns the logs below (see above for the >> code), their node ids are 653143b2-6e80-49ff-9e9a-ae10237b32e8 and >> 30e24e06-ab76-4053-a36e-548e87ffe5d1, respectively (and it can be easily >> seen that all the lines in ignite-jdbcclientnode-failed.log with >> ignite-sys-atomic-cache@default-ds-group relate namely to these nodes), >> the logs for the time segment when the code with tenants and idGen is >> executed are as follows: >> >> [2020-08-03 21:52:00,838: INFO/MainProcess] [2020-08-03 >> 21:52:00,838][INFO ][sys-#44][GridDhtPartitionsExchangeFuture] Received >> full message, will finish exchange >> [node=c0138e03-465d-4944-a1ee-8bee59fbf909, >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1]] >> [2020-08-03 21:52:00,872: INFO/MainProcess] [2020-08-03 >> 21:52:00,864][INFO ][sys-#44][GridDhtPartitionsExchangeFuture] Finish >> exchange future [startVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> err=null, rebalanced=true, wasRebalanced=true] >> [2020-08-03 21:52:00,909: INFO/MainProcess] [2020-08-03 >> 21:52:00,908][INFO ][sys-#44][GridCacheProcessor] Finish proxy >> initialization, cacheName=ignite-sys-atomic-cache@default-ds-group, >> localNodeId=653143b2-6e80-49ff-9e9a-ae10237b32e8 >> [2020-08-03 21:52:00,911: INFO/MainProcess] [2020-08-03 >> 21:52:00,910][INFO >> ][exchange-worker-#43][GridCachePartitionExchangeManager] Skipping >> rebalancing (no affinity changes) [top=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], rebTopVer=AffinityTopologyVersion [topVer=-1, >> minorTopVer=0], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, client=true] >> [2020-08-03 21:52:00,911: INFO/MainProcess] [2020-08-03 >> 21:52:00,911][INFO ][sys-#44][GridDhtPartitionsExchangeFuture] Completed >> partition exchange [localNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion >> [topVer=8, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=TcpDiscoveryNode [id=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> consistentId=653143b2-6e80-49ff-9e9a-ae10237b32e8, addrs=ArrayList >> [127.0.0.1, 172.23.0.8], sockAddrs=HashSet [/127.0.0.1:0, >> d371f9a8ea1f/172.23.0.8:0], discPort=0, order=7, intOrder=0, >> lastExchangeTime=1596491517591, loc=true, >> ver=2.8.1#20200521-sha1:86422096, isClient=true], done=true, >> newCrdFut=null], topVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1]] >> [2020-08-03 21:52:00,912: INFO/MainProcess] [2020-08-03 >> 21:52:00,912][INFO ][sys-#44][GridDhtPartitionsExchangeFuture] Exchange >> timings [startVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], stage="Waiting >> in exchange queue" (1 ms), stage="Exchange parameters initialization" (2 >> ms), stage="Update caches registry" (2 ms), stage="Start caches" (33 ms), >> stage="Affinity initialization on cache group start" (8 ms), >> stage="Determine exchange type" (0 ms), stage="Waiting for Full message" >> (390 ms), stage="Affinity recalculation" (1 ms), stage="Full map >> updating" (24 ms), stage="Exchange done" (47 ms), stage="Total time" (508 >> ms)] >> [2020-08-03 21:52:00,912: INFO/MainProcess] [2020-08-03 >> 21:52:00,912][INFO ][sys-#44][GridDhtPartitionsExchangeFuture] Exchange >> longest local stages [startVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> stage="Affinity initialization on cache group start >> [grp=default-ds-group]" (8 ms) (parent=Affinity initialization on cache >> group start)] >> [2020-08-03 21:52:01,151: INFO/MainProcess] [2020-08-03 >> 21:52:01,151][INFO ][grid-nio-worker-tcp-comm-1-#29][TcpCommunicationSpi] >> Established outgoing communication connection [locAddr=/172.23.0.8:39978, >> rmtAddr=59ec515a30e8/172.23.0.2:47100] >> [2020-08-03 21:52:09,305: INFO/MainProcess] [2020-08-03 >> 21:52:09,305][INFO ][ignite-update-notifier-timer][GridUpdateNotifier] >> Your version is up to date. >> >> [2020-08-03 21:52:00,854: INFO/MainProcess] [2020-08-03 >> 21:52:00,852][INFO ][sys-#46][GridDhtPartitionsExchangeFuture] Received >> full message, will finish exchange >> [node=c0138e03-465d-4944-a1ee-8bee59fbf909, >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1]] >> [2020-08-03 21:52:00,877: INFO/MainProcess] [2020-08-03 >> 21:52:00,874][INFO ][sys-#46][GridDhtPartitionsExchangeFuture] Finish >> exchange future [startVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> err=null, rebalanced=true, wasRebalanced=true] >> [2020-08-03 21:52:00,881: INFO/MainProcess] [2020-08-03 >> 21:52:00,879][INFO ][sys-#46][GridDhtPartitionsExchangeFuture] Completed >> partition exchange [localNode=30e24e06-ab76-4053-a36e-548e87ffe5d1, >> exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion >> [topVer=8, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=TcpDiscoveryNode [id=653143b2-6e80-49ff-9e9a-ae10237b32e8, >> consistentId=653143b2-6e80-49ff-9e9a-ae10237b32e8, addrs=ArrayList >> [127.0.0.1, 172.23.0.8], sockAddrs=HashSet [/127.0.0.1:0, >> d371f9a8ea1f/172.23.0.8:0], discPort=0, order=7, intOrder=6, >> lastExchangeTime=1596491519416, loc=false, >> ver=2.8.1#20200521-sha1:86422096, isClient=true], done=true, >> newCrdFut=null], topVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1]] >> [2020-08-03 21:52:00,881: INFO/MainProcess] [2020-08-03 >> 21:52:00,880][INFO ][sys-#46][GridDhtPartitionsExchangeFuture] Exchange >> timings [startVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], stage="Waiting >> in exchange queue" (89 ms), stage="Exchange parameters initialization" (7 >> ms), stage="Update caches registry" (14 ms), stage="Start caches" (1 ms), >> stage="Affinity initialization on cache group start" (10 ms), >> stage="Determine exchange type" (0 ms), stage="Waiting for Full message" >> (314 ms), stage="Affinity recalculation" (2 ms), stage="Full map >> updating" (19 ms), stage="Exchange done" (5 ms), stage="Total time" (461 >> ms)] >> [2020-08-03 21:52:00,881: INFO/MainProcess] [2020-08-03 >> 21:52:00,880][INFO ][sys-#46][GridDhtPartitionsExchangeFuture] Exchange >> longest local stages [startVer=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], resVer=AffinityTopologyVersion [topVer=8, minorTopVer=1], >> stage="Affinity initialization on cache group start >> [grp=default-ds-group]" (10 ms) (parent=Affinity initialization on cache >> group start)] >> [2020-08-03 21:52:00,882: INFO/MainProcess] [2020-08-03 >> 21:52:00,881][INFO >> ][exchange-worker-#43][GridCachePartitionExchangeManager] Skipping >> rebalancing (no affinity changes) [top=AffinityTopologyVersion [topVer=8, >> minorTopVer=1], rebTopVer=AffinityTopologyVersion [topVer=-1, >> minorTopVer=0], evt=DISCOVERY_CUSTOM_EVT, >> evtNode=653143b2-6e80-49ff-9e9a-ae10237b32e8, client=true] >> [2020-08-03 21:52:00,894: INFO/MainProcess] [2020-08-03 >> 21:52:00,892][INFO ][exchange-worker-#43][GridCacheProcessor] Started >> cache [name=tenants, id=-1427624695, dataRegionName=null, >> mode=PARTITIONED, atomicity=TRANSACTIONAL, backups=1, mvcc=false] >> [2020-08-03 21:52:00,968: INFO/MainProcess] [2020-08-03 >> 21:52:00,966][INFO ][exchange-worker-#43][GridCacheProcessor] Finish >> proxy initialization, cacheName=tenants, >> localNodeId=30e24e06-ab76-4053-a36e-548e87ffe5d1 >> [2020-08-03 21:52:01,000: INFO/MainProcess] [2020-08-03 >> 21:52:00,999][INFO ][exchange-worker-#43][GridCacheProcessor] Started >> cache [name=ignite-sys-atomic-cache@default-ds-group, id=1481046058, >> group=default-ds-group, dataRegionName=null, mode=PARTITIONED, >> atomicity=TRANSACTIONAL, backups=1, mvcc=false] >> [2020-08-03 21:52:01,036: INFO/MainProcess] [2020-08-03 >> 21:52:01,035][INFO ][exchange-worker-#43][GridCacheProcessor] Finish >> proxy initialization, cacheName=ignite-sys-atomic-cache@default-ds-group, >> localNodeId=30e24e06-ab76-4053-a36e-548e87ffe5d1 >> [2020-08-03 21:52:01,212: INFO/MainProcess] [2020-08-03 >> 21:52:01,212][INFO ][grid-nio-worker-tcp-comm-1-#29][TcpCommunicationSpi] >> Established outgoing communication connection [locAddr=/172.23.0.9:53310, >> rmtAddr=59ec515a30e8/172.23.0.2:47100] >> [2020-08-03 21:52:09,702: INFO/MainProcess] [2020-08-03 >> 21:52:09,701][INFO ][ignite-update-notifier-timer][GridUpdateNotifier] >> Your version is up to date. >> >> And the code creating tenants and idGen is executed successfully. But is >> it possible that this simultaneous creation of idGen may hang some nodes? >> (As for the case when all was executed successfully, there we also have >> two >> separate containers, but they are executed strictly after all is done in >> the main app, so the simultaneous execution of the same code in several >> client nodes may be the reason of hanging, isn't it?) And in the case the >> answer is positive, what is to do? Certainly it is possible to set a >> delay >> for those separate containers, but this does not look as a rather safe >> solution... And we have another small question, when we have two separate >> client nodes in our app, both configured for logging, why starting from >> some instant only the log for JDBC client node is used for logging, not >> both? >> ------------------------------ >> Sent from the Apache Ignite Users mailing list archive >> <http://apache-ignite-users.70518.x6.nabble.com/> at Nabble.com. >> -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/
