Omarkad
Omarkad

Reputation: 289

Hazelcast slow startup

I have a Java application with Hazelcast v3.8 for caching purposes. When I deploy on a Tomcat server, the startup takes 8 minutes to 10 minutes on an Ubuntu Linux, however it takes barely 1 minute to start on a Mac.

As recommended by some I set the system property -Djava.security.egd=file:/dev/./urandom to have a faster random library but the issue persists.

A thread dump gives me this :

"hz._hzInstance_1_app-dev.operation-parker" #44 prio=5 os_prio=0 tid=0x00007fb4b901f800 nid=0x194c waiting on condition [0x00007fb4cd709000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb979150> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:259)
    at com.hazelcast.spi.impl.operationparker.impl.OperationParkerImpl$ExpirationTask.doRun(OperationParkerImpl.java:338)
    at com.hazelcast.spi.impl.operationparker.impl.OperationParkerImpl$ExpirationTask.run(OperationParkerImpl.java:323)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
    at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

   Locked ownable synchronizers:
    - <0x00000006cb979398> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"hz._hzInstance_1_app-dev.event-10" #43 daemon prio=5 os_prio=0 tid=0x00007fb4baad1000 nid=0x194b waiting on condition [0x00007fb4cd80a000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb971f40> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-9" #42 daemon prio=5 os_prio=0 tid=0x00007fb4bd694800 nid=0x194a waiting on condition [0x00007fb4cd90b000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb973f40> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-8" #41 daemon prio=5 os_prio=0 tid=0x00007fb4b9d18000 nid=0x1949 waiting on condition [0x00007fb4cda0c000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb974150> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-7" #40 daemon prio=5 os_prio=0 tid=0x00007fb4bc4ad800 nid=0x1948 waiting on condition [0x00007fb4cdb0d000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb972150> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-6" #39 daemon prio=5 os_prio=0 tid=0x00007fb4bd99f000 nid=0x1947 waiting on condition [0x00007fb4cdc0e000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb972360> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-5" #38 daemon prio=5 os_prio=0 tid=0x00007fb4bd06d800 nid=0x1946 waiting on condition [0x00007fb4cdd0f000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb974398> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-4" #37 daemon prio=5 os_prio=0 tid=0x00007fb4bb032000 nid=0x1945 waiting on condition [0x00007fb4cde10000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb972778> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-3" #36 daemon prio=5 os_prio=0 tid=0x00007fb4bdaab800 nid=0x1944 waiting on condition [0x00007fb4cdf11000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb9747b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-2" #35 daemon prio=5 os_prio=0 tid=0x00007fb4be10f800 nid=0x1943 waiting on condition [0x00007fb4ce012000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb975f40> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.event-1" #34 daemon prio=5 os_prio=0 tid=0x00007fb4bd2d9000 nid=0x1942 waiting on condition [0x00007fb4ce113000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb972b90> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:203)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.cached.thread-5" #24 prio=5 os_prio=0 tid=0x00007fb4b4010000 nid=0x1940 waiting on condition [0x00007fb4ce214000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb712368> (a java.util.concurrent.SynchronousQueue$TransferStack)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
    at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
    at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
    at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.cached.thread-3" #22 prio=5 os_prio=0 tid=0x00007fb4b400c800 nid=0x193e waiting on condition [0x00007fb4ce416000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb712368> (a java.util.concurrent.SynchronousQueue$TransferStack)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
    at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
    at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
    at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.cached.thread-1" #20 prio=5 os_prio=0 tid=0x00007fb4b4015800 nid=0x193c waiting on condition [0x00007fb4ce618000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb712368> (a java.util.concurrent.SynchronousQueue$TransferStack)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
    at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
    at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
    at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

   Locked ownable synchronizers:
    - None

"hz._hzInstance_1_app-dev.scheduled" #19 prio=5 os_prio=0 tid=0x00007fb4bdfc6800 nid=0x193b waiting on condition [0x00007fb4ce719000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006cb716368> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
    at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

   Locked ownable synchronizers:
    - None

After doing some measurements, I found out that startup spends 6 minutes on this call (creation of hazelcast instance) : Hazelcast.newHazelcastInstance(config) with Config config = new FileSystemXmlConfig(configFile)

Config in the following : Hazelcast configuration : Config{groupConfig=GroupConfig [name=*************, password=*************], properties={hazelcast.event.thread.count=10, hazelcast.memcache.enabled=false, hazelcast.rest.enabled=false, hazelcast.logging.type=jdk, hazelcast.socket.bind.any=false}, networkConfig=NetworkConfig{publicAddress='null', port=5701, portCount=100, portAutoIncrement=true, join=JoinConfig{multicastConfig=MulticastConfig [enabled=false, multicastGroup=224.2.2.3, multicastPort=54327, multicastTimeToLive=32, multicastTimeoutSeconds=2, trustedInterfaces=[], loopbackModeEnabled=false], tcpIpConfig=TcpIpConfig [enabled=false, connectionTimeoutSeconds=5, members=[], requiredMember=null], awsConfig=AwsConfig{enabled=false, region='us-east-1', securityGroupName='null', tagKey='null', tagValue='null', hostHeader='ec2.amazonaws.com', iamRole='null', connectionTimeoutSeconds=5}, discoveryProvidersConfig=com.hazelcast.config.DiscoveryConfig@2463d057}, interfaces=InterfacesConfig{enabled=true, interfaces=[127.0.0.1]}, sslConfig=null, socketInterceptorConfig=null, symmetricEncryptionConfig=null}, mapConfigs={}, topicConfigs={}, reliableTopicConfigs={}, queueConfigs={}, multiMapConfigs={}, executorConfigs={}, semaphoreConfigs={}, ringbufferConfigs={}, wanReplicationConfigs={}, partitionGroupConfig=PartitionGroupConfig{enabled=false, groupType=PER_MEMBER, memberGroupConfigs=[]}, managementCenterConfig=ManagementCenterConfig{enabled=false, url='http://localhost:9000/mancenter', updateInterval=3}, securityConfig=SecurityConfig{enabled=false, memberCredentialsConfig=CredentialsFactoryConfig{className='null', implementation=null, properties={}}, memberLoginModuleConfigs=[], clientLoginModuleConfigs=[], clientPolicyConfig=PermissionPolicyConfig{className='null', implementation=null, properties={}}, clientPermissionConfigs=[]}, liteMember=false}

Is there something I can do to decrease startup time on Ubuntu ?

Upvotes: 1

Views: 815

Answers (1)

Omarkad
Omarkad

Reputation: 289

I changed hazelcast version I went from v3.8 to v3.4.2 and it is significantly faster (2 minutes !)

Upvotes: 0

Related Questions