title: Hazelcast IMap.tryLock with tryTimeout 100 mills get stuck for more than 1 minute
body: <p>We are using Hazelcast 3.9.2</p>
  
  <p>2 nodes cluster runs on:
  Windows Server 2012 R2 Standard
  with Oracle JAVA_VERSION="1.8.0_144"</p>
  
  <p>from 2 up to 20 clients runs on separate VMs:
  3.10.0-327.28.3.el7.x86_64 #1 SMP Fri Aug 12 13:21:05 EDT 2016 x86_64 x86_64 x86_64 GNU/Linux
  with IBM JAVA_VERSION="1.7.1_64"</p>
  
  <p>hazelcast.xml snippet:</p>
  
  <pre><code>&lt;map name="lock*"&gt;
      &lt;in-memory-format&gt;BINARY&lt;/in-memory-format&gt;
      &lt;statistics-enabled&gt;true&lt;/statistics-enabled&gt;
      &lt;backup-count&gt;1&lt;/backup-count&gt;
      &lt;eviction-policy&gt;NONE&lt;/eviction-policy&gt;
  &lt;/map&gt;
  </code></pre>
  
  <p>That's our hazelcast-client.xml</p>
  
  <pre><code>&lt;hazelcast-client xmlns="http://www.hazelcast.com/schema/client-config" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.hazelcast.com/schema/client-config file:///C:/caching/hazelcast-client-config-3.9.xsd"&gt;
  &lt;group&gt;
      &lt;name&gt;OUR_GROUP_NAME&lt;/name&gt;
  &lt;/group&gt;
  &lt;properties&gt;
      &lt;property name="hazelcast.client.shuffle.member.list"&gt;true&lt;/property&gt;
      &lt;property name="hazelcast.client.heartbeat.timeout"&gt;60000&lt;/property&gt;
      &lt;property name="hazelcast.client.heartbeat.interval"&gt;5000&lt;/property&gt;
      &lt;property name="hazelcast.client.event.thread.count"&gt;10&lt;/property&gt;
      &lt;property name="hazelcast.client.event.queue.capacity"&gt;1000000&lt;/property&gt;
      &lt;property name="hazelcast.client.invocation.timeout.seconds"&gt;35&lt;/property&gt;
      &lt;property name="hazelcast.client.statistics.enabled"&gt;true&lt;/property&gt;
  &lt;/properties&gt;
  &lt;network&gt;
      &lt;cluster-members&gt;
          &lt;address&gt;tvlcacheqa1.blqa.qa:5709&lt;/address&gt;
          &lt;address&gt;tvlcacheqa2.blqa.qa:5709&lt;/address&gt;
      &lt;/cluster-members&gt;
      &lt;smart-routing&gt;true&lt;/smart-routing&gt;
      &lt;redo-operation&gt;true&lt;/redo-operation&gt;
      &lt;connection-attempt-period&gt;15000&lt;/connection-attempt-period&gt;
      &lt;connection-attempt-limit&gt;1048576&lt;/connection-attempt-limit&gt;
  &lt;socket-options&gt;
          &lt;tcp-no-delay&gt;false&lt;/tcp-no-delay&gt;
          &lt;keep-alive&gt;true&lt;/keep-alive&gt;
          &lt;reuse-address&gt;true&lt;/reuse-address&gt;
          &lt;linger-seconds&gt;5&lt;/linger-seconds&gt;
          &lt;timeout&gt;-1&lt;/timeout&gt;
          &lt;buffer-size&gt;64&lt;/buffer-size&gt;
      &lt;/socket-options&gt;
  &lt;/network&gt;
  
  &lt;near-cache name="cache*"&gt;
      &lt;in-memory-format&gt;OBJECT&lt;/in-memory-format&gt;
      &lt;invalidate-on-change&gt;true&lt;/invalidate-on-change&gt;
      &lt;time-to-live-seconds&gt;1800&lt;/time-to-live-seconds&gt;
      &lt;max-idle-seconds&gt;1800&lt;/max-idle-seconds&gt;
      &lt;eviction eviction-policy="LRU" max-size-policy="ENTRY_COUNT" size="10000"/&gt;
  &lt;/near-cache&gt;   
  </code></pre>
  
  <p></p>
  
  <blockquote>
    <p>Every preference that not mentioned above are DEFAULT and we do not make preference changes in code.</p>
  </blockquote>
  
  <p>In batch processing we run this code on every client concurrently:</p>
  
  <pre><code>synchronizer.startSyncSection(key, 100);
  try {
       doSomeCriticalStuff();
  } finally {
       synchronizer.endSyncSection(key);
  }
  </code></pre>
  
  <p>This is our <code>Synchronizer</code> implementation based on Hazelcast <code>IMap</code> features:</p>
  
  <pre><code>@Override
  public void startSynchedSection(MultiKey&lt;?&gt; key, long tryLockTimeoutInMs, long releaseLockTimeoutInMs) {
      keyNullCheck(key);
      tryLockTimeoutInMs = Math.max(tryLockTimeoutInMs, minimumObtainLockTimeoutInMs);
      if (isClusterReady()) {
          boolean locked = false;
          try {
              locked = this.locks.tryLock(key, tryLockTimeoutInMs, TimeUnit.MILLISECONDS, releaseLockTimeoutInMs, TimeUnit.MILLISECONDS);
          } catch (InterruptedException e) {
              throw new TechnicalException(e);
          }
          if (!locked) {
              throw new SyncTimeoutException(FAILED_TO_OBTAIN_EXCEPTION + key);
          }
          int lockCounter = incrementLockCounter(key);
      } else {
          throw new SyncTimeoutException(CLUSTER_NOT_READY_EXCEPTION);
      }
  }
  /** Note This should be called in a FINALLY section!!! */
  @Override
  public void endSynchedSection(MultiKey&lt;?&gt; key) {
      keyNullCheck(key);
      int lockCounterBefore = getThreadLocalCounter(key.toString()).get();
      if (lockCounterBefore == 0) {
          return;
      }
      try {
          int lockCounterAfter = decrementLockCounter(key);
          if (this.locks.isLocked(key)) {
              this.locks.unlock(key);
          }
      } catch (OperationTimeoutException e) {
          this.logger.warn("endSynchedSection - Lock-&gt; {} was not released properly in Hazelcast because of exception:\n{}\n in Thread={}", key, e
              .getMessage(), Thread.currentThread().getName());
      }
  }
  </code></pre>
  
  <p>Sometimes (very often when we run our batches) thread get stuck on this IMap call:</p>
  
  <pre><code>locked = this.locks.tryLock(key, tryLockTimeoutInMs, TimeUnit.MILLISECONDS, releaseLockTimeoutInMs, TimeUnit.MILLISECONDS);
  </code></pre>
  
  <p>where <code>this.locks</code> is <code>private IMap&lt;String, String&gt; locks;</code></p>
  
  <h1>Although we set <code>tryLockTimeoutInMs = 100ms</code> thread may be hung for 2 minutes!</h1>
  
  <p>Unfortunately, we can't reproduce this situation in a test environment, but we use Dynatrace tool where we see such report in production:
   <a href="https://user-images.githubusercontent.com/12655866/39863775-74a3da5a-53fc-11e8-96b4-d55bea1f5e06.PNG" rel="nofollow noreferrer">https://user-images.githubusercontent.com/12655866/39863775-74a3da5a-53fc-11e8-96b4-d55bea1f5e06.PNG</a></p>
  
  <p>I looked through every cluster members &amp; clients logs and did not found something special. Any warnings or connection losses at this times.</p>
  
  <h1>There are some of my assumptions:</h1>
  
  <ol>
  <li>I call to <code>IMap.tryLock(key, tryTime, TimeUnit.MILLISECONDS, leaseTime, TimeUnit.MILLISECONDS);</code> with leaseTime = 30 minutes according to my business requirements, i.e. I make unlock myself like this:<code>if (this.locks.isLocked(key)) this.locks.unlock(key);</code> So maybe very frequent calls to <code>IMap.isLocked(key)</code> and/or <code>IMap.unlock(key)</code> at the same time as <code>IMap.tryLock</code> that's a reason?</li>
  <li>Different JRE's on my member and client-side. And especially Websphere 8.5.5.12 app server and Java 1.7.1_64 from IBM on a <strong>client</strong> side. Maybe because of the method <code>Unsafe.park(boolean, long)</code> is using architecture specific code (thus the reason it's 'unsafe') and we see the hangs during this method.</li>
  <li>It could be some mistakes in my hazelcast.xml preferences, cause we are just starting to use Hazelcast in our project.</li>
  </ol>
  
  <p>Any suggestions about?</p>