diff --git a/CHANGELOG.md b/CHANGELOG.md index 00be947d7..ec3443aaf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,7 @@ +## Naksha_2.1.5 + +- Fixed thread hanging issue fixed by avoiding indefinite locking in `FibLinearProbeTable.java` + ## Naksha_2.1.4 - Fixes: diff --git a/gradle.properties b/gradle.properties index b8604b519..9b66cc554 100644 --- a/gradle.properties +++ b/gradle.properties @@ -11,4 +11,4 @@ mavenPassword=YourPassword # - here-naksha-lib-core/NakshaVersion (static property: latest) # - here-naksha-lib-psql/resources/naksha_plpgsql.sql (method: naksha_version) # - here-naksha-app-service/src/main/resources/swagger/openapi.yaml (info.version property) -version=2.1.4 +version=2.1.5 diff --git a/here-naksha-app-service/src/main/resources/swagger/openapi.yaml b/here-naksha-app-service/src/main/resources/swagger/openapi.yaml index d7f80dce9..f3b01152a 100644 --- a/here-naksha-app-service/src/main/resources/swagger/openapi.yaml +++ b/here-naksha-app-service/src/main/resources/swagger/openapi.yaml @@ -12,7 +12,7 @@ servers: info: title: "Naksha Hub-API" description: "Naksha Hub-API is a REST API to provide simple access to geo data." - version: "2.1.4" + version: "2.1.5" security: - AccessToken: [ ] diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/AbstractTask.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/AbstractTask.java index b0c7c7503..949eb0476 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/AbstractTask.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/AbstractTask.java @@ -613,6 +613,9 @@ private void incInstanceLevelUsage(String actorId, long limit) { break; } // Failed, conflict, repeat + log.info( + "Concurrency conflict while incrementing instance level threadCount from {}. Will retry...", + threadCount); } } @@ -649,6 +652,9 @@ private void incActorLevelUsage(String actorId, long limit) { if (counter == null) { Long existing = actorUsageMap.putIfAbsent(actorId, 1L); if (existing != null) { + log.info( + "Concurrency conflict while initializing threadCount to 1 for actorId [{}]. Will retry...", + actorId); continue; // Repeat, conflict with other thread } return; @@ -669,6 +675,10 @@ private void incActorLevelUsage(String actorId, long limit) { break; } // Failed, conflict, repeat + log.info( + "Concurrency conflict while incrementing actor level threadCount from {} for actorId [{}]. Will retry...", + counter, + actorId); } } @@ -693,6 +703,9 @@ private void decActorLevelUsage(String actorId) { log.error("Invalid actor usage value for actor: " + actorId + " value: " + current); } if (!actorUsageMap.remove(actorId, current)) { + log.info( + "Concurrency conflict while removing actor level threadCount for actorId [{}]. Will retry...", + actorId); continue; } break; @@ -700,6 +713,10 @@ private void decActorLevelUsage(String actorId) { break; } // Failed, repeat, conflict with other thread + log.info( + "Concurrency conflict while decrementing actor level threadCount from {} for actorId [{}]. Will retry...", + current, + actorId); } } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/NakshaContext.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/NakshaContext.java index d1302cd25..ff3062dcb 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/NakshaContext.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/NakshaContext.java @@ -221,6 +221,7 @@ public long startNanos() { return newValue; } // Conflict, two threads seem to want to update the same key the same time! + logger.info("Concurrency conflict while updating attachment map for key {}", valueClass); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/storage/IStorage.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/storage/IStorage.java index f0313a810..c0043bc84 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/storage/IStorage.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/storage/IStorage.java @@ -32,6 +32,8 @@ import org.jetbrains.annotations.ApiStatus.AvailableSince; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Storage API to gain access to storages. @@ -39,6 +41,8 @@ @AvailableSince(NakshaVersion.v2_0_6) public interface IStorage extends AutoCloseable { + Logger logger = LoggerFactory.getLogger(IStorage.class); + /** * Initializes the storage, create the transaction table, install needed scripts and extensions. * @@ -191,10 +195,12 @@ default void close() { try { shutdown(null).get(); return; - } catch (InterruptedException ignore) { + } catch (InterruptedException ie) { + logger.warn("Exception while shutting down IStorage. ", ie); } catch (Exception e) { throw unchecked(e); } + logger.info("Unable to shutdown IStorage. Will retry..."); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/FibMap.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/FibMap.java index 904298d01..444fbbd96 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/FibMap.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/FibMap.java @@ -29,6 +29,8 @@ import java.util.List; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Functional implementation of a recursive, thread safe, growing map, based upon ) { Reference ref = (Reference) raw; entry = (ENTRY) ref.get(); - if (entry == null && lock.tryLock()) { + if (entry == null && (lock.isHeldByCurrentThread() || lock.tryLock())) { locked = true; array[i] = null; SIZE.getAndAdd(fibSet, -1L); diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/fib/FibSet.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/fib/FibSet.java index 7033ad47c..928e31af1 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/fib/FibSet.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/fib/FibSet.java @@ -37,6 +37,8 @@ import org.jetbrains.annotations.ApiStatus.AvailableSince; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * A recursive, thread safe, weak/soft/strong referencing set, based upon > { + private static final Logger logger = LoggerFactory.getLogger(FibSet.class); + /** * The empty array used by default, so that empty maps do not consume memory. */ @@ -452,6 +456,9 @@ ENTRY _execute( if (raw_entry == null) { if (!ARRAY.compareAndSet(array, index, ref, null)) { // Race condition, another thread modified the array slot. + logger.info( + "Concurrency conflict while initializing array value at index {}. Will retry...", + index); continue; } SIZE.getAndAdd(this, -1L); @@ -487,6 +494,7 @@ ENTRY _execute( return (ENTRY) entry; } // Race condition, other thread updated the reference concurrently. + logger.info("Concurrency conflict while setting array value at index {}. Will retry...", index); continue; } assert op == REMOVE; @@ -495,6 +503,7 @@ ENTRY _execute( return (ENTRY) entry; } // Race condition, other thread updated the reference concurrently. + logger.info("Concurrency conflict while nullifying array value at index {}. Will retry...", index); continue; } @@ -516,6 +525,7 @@ ENTRY _execute( return _execute(op, key, key_hash, refType, sub_array, depth + 1); } // Race condition, another thread modified concurrently. + logger.info("Concurrency conflict while setting array value at index {}. Will retry...", index); continue; } @@ -529,6 +539,7 @@ ENTRY _execute( return new_entry; } // Race condition, another thread modified concurrently. + logger.info("Concurrency conflict while setting array value at index {}. Will retry...", index); continue; } @@ -546,6 +557,7 @@ ENTRY _execute( return new_entry; } // Race condition, another thread modified concurrently. + logger.info("Concurrency conflict while initializing array value at index {}. Will retry...", index); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldBool.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldBool.java index f0a96c6c5..61e056c75 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldBool.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldBool.java @@ -23,9 +23,13 @@ import java.nio.ByteOrder; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public final class JsonFieldBool extends JsonField { + private static final Logger logger = LoggerFactory.getLogger(JsonFieldBool.class); + JsonFieldBool( @NotNull JsonClass jsonClass, @NotNull Field javaField, @@ -94,6 +98,7 @@ public boolean _compareAndSwap(@NotNull OBJECT object, Boolean expected, Boolean return true; } // We need to loop, because possibly some code modified bytes we're not interested in. + logger.info("Concurrency conflict while setting value at offset {}. Will retry...", offset); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldByte.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldByte.java index ce17f34b1..b84c07e0b 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldByte.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldByte.java @@ -23,9 +23,13 @@ import java.nio.ByteOrder; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public final class JsonFieldByte extends JsonField { + private static final Logger logger = LoggerFactory.getLogger(JsonFieldByte.class); + JsonFieldByte( @NotNull JsonClass jsonClass, @NotNull Field javaField, @@ -100,6 +104,7 @@ public boolean _compareAndSwap(@NotNull OBJECT object, Byte expected, Byte value return true; } // We need to loop, because possibly some code modified bytes we're not interested in. + logger.info("Concurrency conflict while setting value at offset {}. Will retry...", offset); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldChar.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldChar.java index fe42df8e9..72cb31fe2 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldChar.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldChar.java @@ -23,9 +23,13 @@ import java.nio.ByteOrder; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public final class JsonFieldChar extends JsonField { + private static final Logger logger = LoggerFactory.getLogger(JsonFieldChar.class); + JsonFieldChar( @NotNull JsonClass jsonClass, @NotNull Field javaField, @@ -101,6 +105,7 @@ public boolean _compareAndSwap(@NotNull OBJECT object, Character expected, Chara return true; } // We need to loop, because possibly some code modified bytes we're not interested in. + logger.info("Concurrency conflict while setting value at offset {}. Will retry...", offset); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldShort.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldShort.java index e47d7059b..408d78de6 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldShort.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonFieldShort.java @@ -23,9 +23,13 @@ import java.nio.ByteOrder; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public final class JsonFieldShort extends JsonField { + private static final Logger logger = LoggerFactory.getLogger(JsonFieldShort.class); + JsonFieldShort( @NotNull JsonClass jsonClass, @NotNull Field javaField, @@ -102,6 +106,7 @@ public boolean _compareAndSwap(@NotNull OBJECT object, Short expected, Short val return true; } // We need to loop, because possibly some code modified bytes we're not interested in. + logger.info("Concurrency conflict while setting value at offset {}. Will retry...", offset); } } diff --git a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonMap.java b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonMap.java index 9129ef13c..d689e1872 100644 --- a/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonMap.java +++ b/here-naksha-lib-core/src/main/java/com/here/naksha/lib/core/util/json/JsonMap.java @@ -42,6 +42,8 @@ import org.jetbrains.annotations.ApiStatus.AvailableSince; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * A map that uses {@link String} key and arbitrary values. The map is thread safe for concurrent @@ -55,6 +57,8 @@ public class JsonMap implements Map<@NotNull String, @Nullable Object>, Iterable> { + private static final Logger logger = LoggerFactory.getLogger(JsonMap.class); + /** * Create a new empty map. * @@ -278,6 +282,7 @@ public boolean containsKey(@Nullable Object key) { final Object result = FibMap.put(key, oldValue, newValue, true, rootMutable(), this::intern, this::conflict); if (result instanceof FibMapConflict) { + logger.info("Concurrency conflict while setting value for key {}. Will retry...", key); continue; } assert result == oldValue; @@ -305,6 +310,7 @@ public boolean containsKey(@Nullable Object key) { final Object result = FibMap.put(key, original, newValue, true, rootMutable(), this::intern, this::conflict); if (result instanceof FibMapConflict) { + logger.info("Concurrency conflict while setting value for key {}. Will retry...", key); continue; } assert result == original; @@ -339,6 +345,7 @@ public boolean containsKey(@Nullable Object key) { final Object result = FibMap.put(key, original, UNDEFINED, true, rootMutable(), this::intern, this::conflict); if (result instanceof FibMapConflict) { + logger.info("Concurrency conflict while removing value for key {}. Will retry...", key); continue; } assert result == UNDEFINED; @@ -350,6 +357,7 @@ public boolean containsKey(@Nullable Object key) { final Object result = FibMap.put(key, original, newValue, true, rootMutable(), this::intern, this::conflict); if (result instanceof FibMapConflict) { + logger.info("Concurrency conflict while setting value for key {}. Will retry...", key); continue; } assert result == original; @@ -468,6 +476,7 @@ public void clear() { SIZE.getAndAdd(this, -oldSize); return; } + logger.info("Concurrency conflict while clearing map. Will retry..."); } } diff --git a/here-naksha-lib-core/src/test/java/com/here/naksha/lib/core/util/fib/FibLinearProbeTableTest.java b/here-naksha-lib-core/src/test/java/com/here/naksha/lib/core/util/fib/FibLinearProbeTableTest.java index 1e93c2339..a78bcdf73 100644 --- a/here-naksha-lib-core/src/test/java/com/here/naksha/lib/core/util/fib/FibLinearProbeTableTest.java +++ b/here-naksha-lib-core/src/test/java/com/here/naksha/lib/core/util/fib/FibLinearProbeTableTest.java @@ -29,9 +29,16 @@ import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertNull; import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.fail; import java.lang.ref.SoftReference; import java.lang.ref.WeakReference; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.TimeoutException; import org.junit.jupiter.api.Test; class FibLinearProbeTableTest { @@ -151,4 +158,38 @@ void test_expansion() { assertEquals(TOTAL_SIZE - i, SET.size); } } + + @Test + void test_Lock() { + final FibSet> SET = new FibSet<>(FibMapEntry::new); + final FibLinearProbeTable> lpt = new FibLinearProbeTable<>(SET, 0); + + /** + * First we put 2 weak references to lpt, then we call gc() - in such scenario next GET call should remove + * all empty references, but to do this it has to acquire lock, and release it at the end. + */ + + lpt.execute(PUT, "foo", WEAK); + lpt.execute(PUT, "foo1", WEAK); + System.gc(); + lpt.execute(GET, "foo1", WEAK); + + // then + ExecutorService executor = Executors.newSingleThreadExecutor(); + Future future = executor.submit(() -> { + lpt.execute(PUT, "foo3", WEAK); + return "done"; + }); + + /** + * Now we try to put new value to lpt in another thread - if previous locks were not released it should + * throw timeout exception. + */ + try { + future.get(1, TimeUnit.SECONDS); + } catch (TimeoutException | InterruptedException | ExecutionException e) { + fail("lock not released! " + e); + } + executor.shutdownNow(); + } }