From 9d0fcc81db991d8b4e2b1bc8595e2cf612923910 Mon Sep 17 00:00:00 2001 From: Henry Kupty Date: Wed, 3 Jan 2024 11:58:37 +0100 Subject: [PATCH 1/3] test: Add test for logger storage correctness --- .../penna/core/logger/LoggerStorageTests.java | 72 +++++++++++++++++++ 1 file changed, 72 insertions(+) create mode 100644 penna-core/src/propertyTesting/java/penna/core/logger/LoggerStorageTests.java diff --git a/penna-core/src/propertyTesting/java/penna/core/logger/LoggerStorageTests.java b/penna-core/src/propertyTesting/java/penna/core/logger/LoggerStorageTests.java new file mode 100644 index 0000000..6164ffc --- /dev/null +++ b/penna-core/src/propertyTesting/java/penna/core/logger/LoggerStorageTests.java @@ -0,0 +1,72 @@ +package penna.core.logger; + +import net.jqwik.api.*; +import net.jqwik.api.constraints.Size; + +import java.util.List; + +class LoggerStorageTests { + + @Provide + Arbitrary> loggerNames() { + return + Arbitraries + .strings() + .alpha() + .ofMinLength(2) + .ofMaxLength(5) + .flatMap(prefix -> + Arbitraries + .strings() + .alpha() + .ofMinLength(3) + .ofMaxLength(10) + .list() + .ofMinSize(2) + .ofMaxSize(4) + .map(components -> { + var builder = new StringBuilder(prefix); + components.forEach(item -> builder.append(".").append(item)); + + return builder.toString(); + })) + .list(); + + } + + @Property + boolean uniqueLoggers(@ForAll("loggerNames") @Size(min = 5, max = 1024) List loggerNames) { + LoggerStorage storage = new LoggerStorage(); + return loggerNames.stream().reduce(true, + (acc, i) -> { + if (!acc) { + return false; + } + + return storage.getOrCreate(i).name.equals(i); + }, + Boolean::logicalAnd + ); + + } + + @Property + boolean sameLogger(@ForAll("loggerNames") @Size(min = 5, max = 1024) List loggerNames) { + LoggerStorage storage = new LoggerStorage(); + return loggerNames.stream().reduce(true, + (acc, i) -> { + if (!acc) { + return false; + } + + var logger1 = storage.getOrCreate(i); + var logger2 = storage.getOrCreate(i); + + return logger1.equals(logger2); + }, + Boolean::logicalAnd + ); + + } + +} From 7c85cbcdce3abdcb98c532b98f9f0c7740e9d0ba Mon Sep 17 00:00:00 2001 From: Henry Kupty Date: Wed, 3 Jan 2024 18:13:00 +0100 Subject: [PATCH 2/3] refactor: Ensure storage is correct --- .../java/penna/core/logger/LoggerStorage.java | 254 +++++++++++++----- 1 file changed, 191 insertions(+), 63 deletions(-) diff --git a/penna-core/src/main/java/penna/core/logger/LoggerStorage.java b/penna-core/src/main/java/penna/core/logger/LoggerStorage.java index 42abcf1..baef72f 100644 --- a/penna-core/src/main/java/penna/core/logger/LoggerStorage.java +++ b/penna-core/src/main/java/penna/core/logger/LoggerStorage.java @@ -4,7 +4,9 @@ import penna.api.config.Config; import penna.api.config.ConfigManager; +import java.util.ArrayDeque; import java.util.Arrays; +import java.util.Deque; import java.util.concurrent.atomic.AtomicReference; import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReentrantLock; @@ -17,6 +19,15 @@ * TST, instead of doing the traditional char-by-char trie/TST. *
*
+ * This TST can store two kinds of values: {@link PennaLogger} and {@link Config}. + * The loggers exist on some leaf nodes, as they're likely class names: `* -> io -> app -> controller -> MyController`, + * with `MyController` being a leaf object pointing to a {@link PennaLogger}. + *
+ * The {@link Config} references can live in the middle of the TST. For example `* -> io -> app -> controller` can hold + * a reference to a {@link Config} where the log level is {@link org.slf4j.event.Level#DEBUG} whereas the rest of the + * Logger references will be under {@link Config#getDefault()}, which is stored in the root of the TST. + *
+ *
* The logger storage exposes three public methods: *
* {@link LoggerStorage#getOrCreate(String)}: For retrieving an existing logger or creating a new one if none existent @@ -30,10 +41,77 @@ */ public class LoggerStorage { - private record NodeAndConfig( - ComponentNode node, - Config config - ) { + private static class Cursor { + public ComponentNode node; + public Config config; + public int index; + public int nextIndex; + public boolean isMatch; + public boolean earlyFinish; + public char[][] path; + private final int target; + + @SuppressWarnings("PMD.ArrayIsStoredDirectly") + public Cursor(ComponentNode node, char[]... path) { + this.path = path; + this.index = 0; + this.target = path.length; + this.isMatch = false; + this.earlyFinish = false; + setNode(node); + } + + private void setNode(ComponentNode node) { + if (node == null) { + this.earlyFinish = true; + return; + } + + Config cfg; + if ((cfg = node.configRef.get()) != null) { + this.config = cfg; + } + this.node = node; + + } + + /** + * Ensures the values are within the range of [-1, 1], then makes them an array-accessor by incrementing + * + * @param offset Diff between two characters + * @return a number in the range of [0, 2] + */ + private int normalize(int offset) { + return ((-offset >>> 31) - (offset >>> 31)) + 1; + } + + public boolean next() { + var key = path[index]; + nextIndex = normalize(Arrays.compare(key, node.component)); + index += (nextIndex & 0x1); + isMatch = nextIndex == 1; + if (index < target) setNode(node.children[nextIndex]); + return index < target && !earlyFinish; + } + + public boolean exactMatch() { + return index >= target && isMatch && !earlyFinish; + } + + public void createRemaining() { + for (; index < target; index++) { + node.lock.lock(); + try { + if (node.children[nextIndex] == null) { + node.children[nextIndex] = node.createChild(path[index]); + } + } finally { + node.lock.unlock(); + setNode(node.children[nextIndex]); + this.nextIndex = 1; + } + } + } } /** @@ -59,6 +137,13 @@ private record ComponentNode( ) { + /** + * Static factory for creating a node with the correct values. + * + * @param component the char-array representing that node + * @param config the configuration for that segment + * @return a new {@link ComponentNode} instance + */ static ComponentNode create(char[] component, Config config) { return new ComponentNode( component, @@ -69,6 +154,12 @@ static ComponentNode create(char[] component, Config config) { ); } + /** + * This is a convenience factory method for creating a child node. + * + * @param component The char-array representing that node. + * @return a new {@link ComponentNode} instance. + */ ComponentNode createChild(char... component) { return new ComponentNode( component, @@ -79,35 +170,63 @@ ComponentNode createChild(char... component) { ); } - Config updateConfig(ConfigManager.ConfigurationChange configurationChange) { + /** + * Updates a configuration value that is stored in a {@link ComponentNode#configRef}. + * + * @param configurationChange a {@link ConfigManager.ConfigurationChange} lambda. + * @return the updated configuration value. + */ + Config updateConfigReference(ConfigManager.ConfigurationChange configurationChange) { var cfg = configRef.getAcquire(); var updated = configurationChange.apply(cfg); configRef.setRelease(cfg); return updated; } - void replaceConfig(Config config) { + /** + * If this node contains a logger reference, updates its config. + * + * @param config the new configuration to be applied to that logger reference. + */ + void updateLoggerConfig(Config config) { + PennaLogger logger; + if ((logger = loggerRef.get()) != null) { + logger.updateConfig(config); + } + } + + /** + * Set (or replace if existing) the configuration reference for this node. + * + * @param config the new configuration to be held by this node. + */ + void replaceConfigReference(Config config) { configRef.set(config); } + /** + * Removes any configuration reference associated with this node. + */ void unsetConfig() { configRef.set(null); } } + /** + * The root of the TST. This is a special node that doesn't have any component, therefore all children of this node will + * live on the left children. + */ private final ComponentNode root = ComponentNode.create(new char[]{}, Config.getDefault()); /** - * Ensures the values are within the range of [-1, 1] + * Transforms a FQ string into an array of components, being each component an array of chars. + * For example, the string `io.app.controller.MyController` becomes + * `[[i,o],[a,p,p],[c,o,n,t,r,o,l,l,e,r],[M,y,C,o,n,t,r,o,l,l,e,r]]`. * - * @param offset Diff between two characters - * @return a number in the range of [-1, 1] + * @param key a FQ string, like the logger name. + * @return an array of char arrays containing the components of the name. */ - private int normalize(int offset) { - return (-offset >>> 31) - (offset >>> 31); - } - private char[][] componentsForLoggerName(String key) { char[] keyChars = key.toCharArray(); char[][] components = new char[16][]; @@ -128,44 +247,19 @@ private char[][] componentsForLoggerName(String key) { } - - private NodeAndConfig find(ComponentNode node, - char[]... key) { - int target = key.length - 1; - - int nodeIx; - int index = 0; - ComponentNode cursor = node; - Config cfg = null; - char[] chr; - - do { - chr = key[index]; - Config tmpCfg; - if ((tmpCfg = cursor.configRef.get()) != null) { - cfg = tmpCfg; - } - - nodeIx = normalize(Arrays.compare(chr, cursor.component)) + 1; - index = index + (nodeIx & 0x1); - if (cursor.children[nodeIx] == null) { - cursor.lock.lock(); - try { - if (cursor.children[nodeIx] == null) { - cursor.children[nodeIx] = cursor.createChild(key[index]); - } - } finally { - cursor.lock.unlock(); - } - } - cursor = cursor.children[nodeIx]; - } while (index != target); - return new NodeAndConfig(cursor, cfg); + private Cursor find(char[]... key) { + Cursor cursor = new Cursor(root, key); + while (cursor.next()) {} + return cursor; } public PennaLogger getOrCreate(@NotNull String key) { - var ret = find(root, componentsForLoggerName(key)); + var ret = find(componentsForLoggerName(key)); + + if (!ret.exactMatch()) { + ret.createRemaining(); + } PennaLogger logger = ret.node.loggerRef.getAcquire(); if (logger == null) { @@ -177,41 +271,75 @@ public PennaLogger getOrCreate(@NotNull String key) { } private void traverse(LoggerStorage.ComponentNode node, Config config) { + Deque nodes = new ArrayDeque<>(); + ComponentNode next; for (ComponentNode child : node.children) { if (child != null) { + nodes.push(child); + } + } - if (child.configRef.get() != null) { - return; - } - - PennaLogger logger; - if ((logger = child.loggerRef.get()) != null) { - logger.updateConfig(config); + while ((next = nodes.poll()) != null) { + if (next.configRef.get() != null) { + continue; + } + next.updateLoggerConfig(config); + for (ComponentNode child : next.children) { + if (child != null) { + nodes.push(child); } - - traverse(child, config); } } } + public void updateConfig( @NotNull String prefix, @NotNull ConfigManager.ConfigurationChange configurationChange) { - ComponentNode updatePoint = find(root, componentsForLoggerName(prefix)).node; - Config newConfig = updatePoint.updateConfig(configurationChange); - traverse(updatePoint, newConfig); + Cursor updatePoint = find(componentsForLoggerName(prefix)); + + if (!updatePoint.exactMatch()) { + // TODO handle correctly + return; + } + + Config newConfig = updatePoint.node.updateConfigReference(configurationChange); + updatePoint.node.updateLoggerConfig(newConfig); + var child = updatePoint.node.children[1]; // Only the middle child of the matched prefix should be traversed + if (child != null) { + child.updateLoggerConfig(newConfig); + traverse(child, newConfig); + } } public void replaceConfig(@NotNull String prefix, @NotNull Config newConfig) { - ComponentNode updatePoint = find(root, componentsForLoggerName(prefix)).node; - updatePoint.replaceConfig(newConfig); - traverse(updatePoint, newConfig); + Cursor cursor = find(componentsForLoggerName(prefix)); + + if (!cursor.exactMatch()) { + // TODO handle correctly + return; + } + + ComponentNode updatePoint = cursor.node; + + updatePoint.replaceConfigReference(newConfig); + updatePoint.updateLoggerConfig(newConfig); + var child = updatePoint.children[1]; // Only the middle child of the matched prefix should be traversed + if (child != null) { + child.updateLoggerConfig(newConfig); + traverse(child, newConfig); + } + } + + public void replaceConfig(@NotNull Config newConfig) { + root.replaceConfigReference(newConfig); + traverse(root, newConfig); } public void unsetConfigPoint(@NotNull String prefix) { - ComponentNode updatePoint = find(root, componentsForLoggerName(prefix)).node; + ComponentNode updatePoint = find(componentsForLoggerName(prefix)).node; updatePoint.unsetConfig(); } } \ No newline at end of file From 019f803af0a53df5ac88ba96f4a23caa14a760ae Mon Sep 17 00:00:00 2001 From: Henry Kupty Date: Wed, 3 Jan 2024 18:15:00 +0100 Subject: [PATCH 3/3] test: Expand logger storage tests --- .../penna/core/logger/LoggerStorageTests.java | 58 +++++++++++++++++++ 1 file changed, 58 insertions(+) diff --git a/penna-core/src/test/java/penna/core/logger/LoggerStorageTests.java b/penna-core/src/test/java/penna/core/logger/LoggerStorageTests.java index 623602f..428a2dd 100644 --- a/penna-core/src/test/java/penna/core/logger/LoggerStorageTests.java +++ b/penna-core/src/test/java/penna/core/logger/LoggerStorageTests.java @@ -1,6 +1,10 @@ package penna.core.logger; import org.junit.jupiter.api.Test; +import org.slf4j.event.Level; +import penna.api.config.Config; + +import java.util.List; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertSame; @@ -23,4 +27,58 @@ public void calling_getOrCreate_twice_does_not_create_duplicates() { assertSame(logger1, logger2); } + + + @Test + public void update_the_whole_tree_affects_leaf_objects() { + var cache = new LoggerStorage(); + var defaults = Config.getDefault(); + var logger1 = cache.getOrCreate("com.for.testing"); + var logger2 = cache.getOrCreate("com.for.testing.other"); + + assertEquals(defaults.level(), logger1.levelGuard.level()); + assertEquals(defaults.level(), logger2.levelGuard.level()); + + cache.replaceConfig(Config.withFields(Level.DEBUG)); + + assertEquals(Level.DEBUG, cache.getOrCreate("com.for.testing").levelGuard.level()); + assertEquals(Level.DEBUG, cache.getOrCreate("com.for.testing.other").levelGuard.level()); + } + + @Test + public void update_prefix_doesnt_change_all_only_descendants() { + var cache = new LoggerStorage(); + var defaults = Config.getDefault(); + var logger1 = cache.getOrCreate("com.for.testing"); + var logger2 = cache.getOrCreate("com.for.testing.other"); + var logger3 = cache.getOrCreate("com.for.unrelated"); + + assertEquals(defaults.level(), logger1.levelGuard.level()); + assertEquals(defaults.level(), logger2.levelGuard.level()); + assertEquals(defaults.level(), logger3.levelGuard.level()); + + cache.replaceConfig("com.for.testing", Config.withFields(Level.DEBUG)); + + assertEquals(Level.DEBUG, logger2.levelGuard.level()); + assertEquals(Level.DEBUG, logger1.levelGuard.level()); + assertEquals(defaults.level(), logger3.levelGuard.level()); + cache.replaceConfig("com.for.unrelated", Config.withFields(Level.WARN)); + + assertEquals(Level.DEBUG, logger2.levelGuard.level()); + assertEquals(Level.DEBUG, logger1.levelGuard.level()); + assertEquals(Level.WARN, logger3.levelGuard.level()); + } + + + @Test + public void we_always_get_the_right_logger() { + var cache = new LoggerStorage(); + var loggers = List.of( + "com.AAA.AAA", "com.AAA.AAA", "com.AAA.AAA", "io.aaa.zzz.AAA", "io.aaa.zzz" + ); + + for (var logger : loggers) { + assertEquals(cache.getOrCreate(logger).name, logger); + } + } }