Re #5: Some cleanups. Also added experimental test that records alloc…

…ations - results are mind blowing. Some improvements based on that test.
tkowalcz · Feb 7, 2021 · 93d1892 · 93d1892
1 parent 63ad557
commit 93d1892
Show file tree

Hide file tree

Showing 9 changed files with 142 additions and 29 deletions.
diff --git a/loki-log4j2-appender/pom.xml b/loki-log4j2-appender/pom.xml
@@ -1,4 +1,5 @@
-<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
+<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
 
     <modelVersion>4.0.0</modelVersion>
 
@@ -30,6 +31,19 @@
             <version>2.13.3</version>
         </dependency>
 
+        <dependency>
+            <groupId>io.dropwizard.metrics</groupId>
+            <artifactId>metrics-core</artifactId>
+            <version>4.1.17</version>
+            <scope>provided</scope>
+        </dependency>
+
+        <dependency>
+            <groupId>com.google.code.java-allocation-instrumenter</groupId>
+            <artifactId>java-allocation-instrumenter</artifactId>
+            <version>3.3.0</version>
+            <scope>test</scope>
+        </dependency>
         <dependency>
             <groupId>io.rest-assured</groupId>
             <artifactId>rest-assured</artifactId>
@@ -54,13 +68,6 @@
             <scope>test</scope>
         </dependency>
 
-        <dependency>
-            <groupId>io.dropwizard.metrics</groupId>
-            <artifactId>metrics-core</artifactId>
-            <version>4.1.17</version>
-            <scope>provided</scope>
-        </dependency>
-
         <!-- Testcontainers -->
         <dependency>
             <groupId>org.junit.jupiter</groupId>
@@ -93,4 +100,25 @@
             <scope>test</scope>
         </dependency>
     </dependencies>
+
+    <build>
+        <plugins>
+            <plugin>
+                <groupId>org.apache.maven.plugins</groupId>
+                <artifactId>maven-surefire-plugin</artifactId>
+                <configuration>
+                    <argLine>
+                        -javaagent:"${settings.localRepository}/com/google/code/java-allocation-instrumenter/java-allocation-instrumenter/3.3.0/java-allocation-instrumenter-3.3.0.jar"
+                    </argLine>
+                </configuration>
+                <dependencies>
+                    <dependency>
+                        <groupId>com.google.code.java-allocation-instrumenter</groupId>
+                        <artifactId>java-allocation-instrumenter</artifactId>
+                        <version>3.3.0</version>
+                    </dependency>
+                </dependencies>
+            </plugin>
+        </plugins>
+    </build>
 </project>
diff --git a/loki-log4j2-appender/src/main/java/pl/tkowalcz/tjahzi/log4j2/AppenderLogic.java b/loki-log4j2-appender/src/main/java/pl/tkowalcz/tjahzi/log4j2/AppenderLogic.java
@@ -9,7 +9,7 @@
 
 import java.io.Serializable;
 import java.nio.ByteBuffer;
-import java.util.Map;
+import java.util.Collections;
 import java.util.concurrent.TimeUnit;
 import java.util.function.BiConsumer;
 
@@ -56,7 +56,7 @@ public void accept(LogEvent event, ByteBuffer byteBuffer) {
 
         logger.log(
                 event.getTimeMillis(),
-                Map.of(),
+                Collections.emptyMap(),
                 logLevelLabel,
                 logLevel,
                 byteBuffer

diff --git a/loki-log4j2-appender/src/test/java/pl/tkowalcz/tjahzi/log4j2/AllocationTest.java b/loki-log4j2-appender/src/test/java/pl/tkowalcz/tjahzi/log4j2/AllocationTest.java
@@ -0,0 +1,79 @@
+package pl.tkowalcz.tjahzi.log4j2;
+
+import com.google.monitoring.runtime.instrumentation.AllocationRecorder;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.junit.jupiter.api.Disabled;
+import org.junit.jupiter.api.Test;
+import org.testcontainers.containers.BindMode;
+import org.testcontainers.containers.GenericContainer;
+import org.testcontainers.containers.wait.strategy.Wait;
+import org.testcontainers.junit.jupiter.Container;
+import org.testcontainers.junit.jupiter.Testcontainers;
+import org.testcontainers.shaded.com.google.common.util.concurrent.Uninterruptibles;
+
+import java.net.URI;
+import java.net.URISyntaxException;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicLong;
+
+@Testcontainers
+public class AllocationTest {
+
+    @Container
+    public GenericContainer loki = new GenericContainer("grafana/loki:latest")
+            .withCommand("-config.file=/etc/loki-config.yaml")
+            .withClasspathResourceMapping("loki-config.yaml",
+                    "/etc/loki-config.yaml",
+                    BindMode.READ_ONLY)
+            .waitingFor(
+                    Wait.forHttp("/ready")
+                            .forPort(3100)
+            )
+            .withExposedPorts(3100);
+
+    @Test
+    @Disabled
+    void shouldSendData() throws URISyntaxException {
+        AtomicLong allocatedMemory = new AtomicLong();
+        Runtime.getRuntime().addShutdownHook(new Thread(() -> System.out.println("allocatedMemory = " + allocatedMemory)));
+
+        // Given
+        System.setProperty("loki.host", loki.getHost());
+        System.setProperty("loki.port", loki.getFirstMappedPort().toString());
+
+        URI uri = getClass()
+                .getClassLoader()
+                .getResource("basic-appender-test-log4j2-configuration.xml")
+                .toURI();
+
+        ((org.apache.logging.log4j.core.LoggerContext) LogManager.getContext(false))
+                .setConfigLocation(uri);
+
+        String logLine = "Cupcake ipsum dolor sit amet cake wafer. " +
+                "Souffle jelly beans biscuit topping. " +
+                "Danish bonbon gummies powder caramels. ";
+
+        Logger logger = LogManager.getLogger(pl.tkowalcz.tjahzi.log4j2.LokiAppenderTest.class);
+
+        // When
+        for (int i = 0; i < 1000; i++) {
+            logger.info(logLine);
+            Uninterruptibles.sleepUninterruptibly(10, TimeUnit.MILLISECONDS);
+        }
+
+        AllocationRecorder.addSampler((count, desc, newObj, size) -> {
+            if (!desc.startsWith("java/time")) {
+                allocatedMemory.addAndGet(size);
+            }
+        });
+
+        for (int i = 0; i < 1000; i++) {
+            logger.info(logLine);
+            Uninterruptibles.sleepUninterruptibly(10, TimeUnit.MILLISECONDS);
+        }
+
+        // Then
+
+    }
+}
diff --git a/loki-log4j2-appender/src/test/resources/basic-appender-test-log4j2-configuration.xml b/loki-log4j2-appender/src/test/resources/basic-appender-test-log4j2-configuration.xml
@@ -13,7 +13,7 @@
 
             <ThresholdFilter level="ALL"/>
             <PatternLayout>
-                <Pattern>%X{tid} [%t] %d{MM-dd HH:mm:ss.SSS} %5p %c{1} - %m%n%exception{full}</Pattern>
+                <Pattern>%X{tid} [%t] %d{DEFAULT} %5p %c{1} - %m%n%exception{full}</Pattern>
             </PatternLayout>
 
             <Header name="server" value="127.0.0.1"/>

diff --git a/tjahzi-core/src/main/java/pl/tkowalcz/tjahzi/LogBufferAgent.java b/tjahzi-core/src/main/java/pl/tkowalcz/tjahzi/LogBufferAgent.java
@@ -43,7 +43,10 @@ public LogBufferAgent(
         this.httpClient = httpClient;
 
         this.outputBuffer = new OutputBuffer(PooledByteBufAllocator.DEFAULT.buffer());
-        this.logBufferTranscoder = new LogBufferTranscoder(staticLabels);
+        this.logBufferTranscoder = new LogBufferTranscoder(
+                staticLabels,
+                logBuffer.buffer()
+        );
     }
 
     @Override

diff --git a/tjahzi-core/src/main/java/pl/tkowalcz/tjahzi/LogBufferTranscoder.java b/tjahzi-core/src/main/java/pl/tkowalcz/tjahzi/LogBufferTranscoder.java
@@ -5,6 +5,7 @@
 import io.netty.util.internal.StringUtil;
 import javolution.text.TextBuilder;
 import org.agrona.DirectBuffer;
+import org.agrona.concurrent.AtomicBuffer;
 import pl.tkowalcz.tjahzi.http.TextBuilders;
 
 import java.nio.ByteBuffer;
@@ -15,13 +16,18 @@ public class LogBufferTranscoder {
     private final Map<String, String> staticLabels;
     private final String staticLabelsString;
 
-    public LogBufferTranscoder(Map<String, String> staticLabels) {
+    private final ByteBuf logLineHolder;
+
+    public LogBufferTranscoder(Map<String, String> staticLabels, AtomicBuffer buffer) {
         this.staticLabels = staticLabels;
         this.staticLabelsString = buildLabelsStringIncludingStatic(
                 staticLabels,
                 StringUtil.EMPTY_STRING,
                 TextBuilders.threadLocal().append("{ ")
         ).toString();
+
+        ByteBuffer byteBuffer = buffer.byteBuffer();
+        logLineHolder = Unpooled.wrappedBuffer(byteBuffer);
     }
 
     public void deserializeIntoByteBuf(DirectBuffer buffer, int index, OutputBuffer outputBuffer) {
@@ -43,11 +49,8 @@ public void deserializeIntoByteBuf(DirectBuffer buffer, int index, OutputBuffer
                 labelsBuilder
         );
 
-        ByteBuffer byteBuffer = buffer.byteBuffer();
-        ByteBuf logLine = Unpooled.wrappedBuffer(byteBuffer)
-                .readerIndex(index);
-
-        outputBuffer.addLogLine(actualLabels, timestamp, logLine);
+        logLineHolder.readerIndex(index);
+        outputBuffer.addLogLine(actualLabels, timestamp, logLineHolder);
     }
 
     private int readLabels(
@@ -78,13 +81,11 @@ private static CharSequence buildLabelsStringIncludingStatic(
         }
 
         staticLabels.forEach((key, value) -> {
-//            if (!labels.containsKey(key)) {
             labels.append(key)
                     .append("=")
                     .append("\"")
                     .append(value)
                     .append("\",");
-//            }
         });
 
         labels.setCharAt(labels.length() - 1, '}');

diff --git a/tjahzi-core/src/test/java/pl/tkowalcz/thjazi/protobuf/ProtobufDeserializer.java b/tjahzi-core/src/test/java/pl/tkowalcz/thjazi/protobuf/ProtobufDeserializer.java
@@ -20,14 +20,16 @@ public class ProtobufDeserializer {
 
     @Test
     void shouldDeserialize() throws IOException {
-        ManyToOneRingBuffer logBuffer = new ManyToOneRingBuffer(
-                new UnsafeBuffer(
-                        ByteBuffer.wrap(
-                                new byte[1024 + RingBufferDescriptor.TRAILER_LENGTH]
-                        )
+        UnsafeBuffer buffer = new UnsafeBuffer(
+                ByteBuffer.wrap(
+                        new byte[1024 + RingBufferDescriptor.TRAILER_LENGTH]
                 )
         );
 
+        ManyToOneRingBuffer logBuffer = new ManyToOneRingBuffer(
+                buffer
+        );
+
         LogBufferSerializer serializer = new LogBufferSerializer(logBuffer.buffer());
         serializer.writeTo(
                 0,
@@ -38,7 +40,7 @@ void shouldDeserialize() throws IOException {
                 ByteBuffer.wrap("Test".getBytes())
         );
 
-        LogBufferTranscoder deserializer = new LogBufferTranscoder(Map.of());
+        LogBufferTranscoder deserializer = new LogBufferTranscoder(Map.of(), buffer);
         OutputBuffer outputBuffer = new OutputBuffer(PooledByteBufAllocator.DEFAULT.buffer());
         deserializer.deserializeIntoByteBuf(
                 logBuffer.buffer(),

diff --git a/tjahzi-core/src/test/java/pl/tkowalcz/tjahzi/LogBufferSerializerDeserializerTest.java b/tjahzi-core/src/test/java/pl/tkowalcz/tjahzi/LogBufferSerializerDeserializerTest.java
@@ -96,7 +96,7 @@ void shouldSerializeMessage(
         // Then
         OutputBuffer outputBuffer = new OutputBuffer(PooledByteBufAllocator.DEFAULT.buffer());
 
-        LogBufferTranscoder deserializer = new LogBufferTranscoder(Map.of());
+        LogBufferTranscoder deserializer = new LogBufferTranscoder(Map.of(), buffer);
         deserializer.deserializeIntoByteBuf(
                 buffer,
                 0,

diff --git a/tjahzi-core/src/test/java/pl/tkowalcz/tjahzi/LogBufferTranscoderTest.java b/tjahzi-core/src/test/java/pl/tkowalcz/tjahzi/LogBufferTranscoderTest.java
@@ -55,7 +55,7 @@ void shouldDeserializeMessageAndAddStaticLabels(
         OutputBuffer outputBuffer = new OutputBuffer(PooledByteBufAllocator.DEFAULT.buffer());
 
         // When
-        LogBufferTranscoder deserializer = new LogBufferTranscoder(staticLabels);
+        LogBufferTranscoder deserializer = new LogBufferTranscoder(staticLabels, buffer);
         deserializer.deserializeIntoByteBuf(
                 buffer,
                 0,
@@ -122,7 +122,7 @@ void shouldOverrideStaticLabelsWithIncoming() throws InvalidProtocolBufferExcept
         OutputBuffer outputBuffer = new OutputBuffer(PooledByteBufAllocator.DEFAULT.buffer());
 
         // When
-        LogBufferTranscoder deserializer = new LogBufferTranscoder(staticLabels);
+        LogBufferTranscoder deserializer = new LogBufferTranscoder(staticLabels, buffer);
         deserializer.deserializeIntoByteBuf(
                 buffer,
                 0,