From 54e813615d88956eee6c76730935282066f58f05 Mon Sep 17 00:00:00 2001 From: Matthias Andreas Benkard Date: Wed, 3 Jul 2024 06:13:26 +0200 Subject: Generate JSON by hand. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This improves performance further. Before: Benchmark Mode Cnt Score Error Units FormatterBenchmark.massivelyStructuredLogRecord thrpt 10 137879.001 ± 30467.644 ops/s FormatterBenchmark.simpleLogRecord thrpt 10 896085.217 ± 249890.421 ops/s FormatterBenchmark.structuredLogRecord thrpt 10 553428.807 ± 194787.754 ops/s After: Benchmark Mode Cnt Score Error Units FormatterBenchmark.massivelyStructuredLogRecord thrpt 10 220855.729 ± 56336.321 ops/s FormatterBenchmark.simpleLogRecord thrpt 10 4456647.085 ± 1041546.047 ops/s FormatterBenchmark.structuredLogRecord thrpt 10 1500896.509 ± 543358.587 ops/s There is also a new benchmark: FormatterBenchmark.nestedLogRecord thrpt 10 878620.441 ± 297024.983 ops/s Change-Id: If3e323b133f8e3e3ff29431a92d1b1e500f9b8b2 --- .../jsonlogging/FormatterBenchmark.java | 8 ++ .../googlecloud/jsonlogging/FormatterTest.java | 89 +++++++++++++++++----- 2 files changed, 76 insertions(+), 21 deletions(-) (limited to 'core/src/test') diff --git a/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterBenchmark.java b/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterBenchmark.java index 4900a01..78291c1 100644 --- a/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterBenchmark.java +++ b/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterBenchmark.java @@ -14,6 +14,7 @@ public class FormatterBenchmark { private ExtLogRecord simpleLogRecord; private ExtLogRecord structuredLogRecord; private ExtLogRecord massivelyStructuredLogRecord; + private ExtLogRecord nestedLogRecord; private Formatter formatter; @Setup @@ -21,6 +22,7 @@ public class FormatterBenchmark { simpleLogRecord = FormatterTest.makeSimpleRecord(); structuredLogRecord = FormatterTest.makeStructuredRecord(); massivelyStructuredLogRecord = FormatterTest.makeMassivelyStructuredRecord(); + nestedLogRecord = FormatterTest.makeNestedRecord(); formatter = new Formatter(List.of(), List.of()); } @@ -39,4 +41,10 @@ public class FormatterBenchmark { var f = formatter.format(massivelyStructuredLogRecord); blackhole.consume(f); } + + @Benchmark + public void nestedLogRecord(Blackhole blackhole) { + var f = formatter.format(nestedLogRecord); + blackhole.consume(f); + } } diff --git a/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterTest.java b/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterTest.java index 6d40b15..16fc537 100644 --- a/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterTest.java +++ b/core/src/test/java/eu/mulk/quarkus/googlecloud/jsonlogging/FormatterTest.java @@ -23,14 +23,14 @@ class FormatterTest { assertLinesMatch( List.of( "\\{" - + "\"message\":\"Hello, world!\"," - + "\"severity\":\"INFO\"," - + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}," + "\"logging.googleapis.com/sourceLocation\":" + "\\{\"file\":\"ReflectionUtils.java\"," + "\"line\":\"\\d+\"," + "\"function\":\"org.junit.platform.commons.util.ReflectionUtils.invokeMethod\"" - + "\\}" + + "\\}," + + "\"message\":\"Hello, world!\"," + + "\"severity\":\"INFO\"," + + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}" + "\\}\n"), List.of(formattingResult)); } @@ -68,19 +68,19 @@ class FormatterTest { List.of( "\\{" + "\"logging.googleapis.com/labels\":\\{\"a\":\"b\",\"requestId\":\"123\"\\}," - + "\"message\":\"Hello, world!\"," - + "\"severity\":\"INFO\"," - + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}," + + "\"traceId\":\"39f9a49a9567a8bd7087b708f8932550\"," + + "\"spanId\":\"c7431b14630b633d\"," + + "\"one\":1," + + "\"two\":2.0," + + "\"yes\":true," + "\"logging.googleapis.com/sourceLocation\":" + "\\{\"file\":\"ReflectionUtils.java\"," + "\"line\":\"\\d+\"," + "\"function\":\"org.junit.platform.commons.util.ReflectionUtils.invokeMethod\"" + "\\}," - + "\"traceId\":\"39f9a49a9567a8bd7087b708f8932550\"," - + "\"spanId\":\"c7431b14630b633d\"," - + "\"one\":1," - + "\"two\":2.0," - + "\"yes\":true" + + "\"message\":\"Hello, world!\"," + + "\"severity\":\"INFO\"," + + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}" + "\\}\n"), List.of(formattingResult)); } @@ -105,21 +105,21 @@ class FormatterTest { assertLinesMatch( List.of( "\\{" - + "\"message\":\"Hello, world!\"," - + "\"severity\":\"INFO\"," - + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}," - + "\"logging.googleapis.com/sourceLocation\":" - + "\\{\"file\":\"ReflectionUtils.java\"," - + "\"line\":\"\\d+\"," - + "\"function\":\"org.junit.platform.commons.util.ReflectionUtils.invokeMethod\"" - + "\\}," + "\"int-0\":0,\"int-1\":1,\"int-2\":2,\"int-3\":3,\"int-4\":4,\"int-5\":5,\"int-6\":6,\"int-7\":7,\"int-8\":8,\"int-9\":9," + "\"double-10\":10.0,\"double-11\":11.0,\"double-12\":12.0,\"double-13\":13.0,\"double-14\":14.0," + "\"double-15\":15.0,\"double-16\":16.0,\"double-17\":17.0,\"double-18\":18.0,\"double-19\":19.0," + "\"boolean-20\":true,\"boolean-21\":false,\"boolean-22\":true,\"boolean-23\":false,\"boolean-24\":true," + "\"boolean-25\":false,\"boolean-26\":true,\"boolean-27\":false,\"boolean-28\":true,\"boolean-29\":false," + "\"string-30\":\"30\",\"string-31\":\"31\",\"string-32\":\"32\",\"string-33\":\"33\",\"string-34\":\"34\"," - + "\"string-35\":\"35\",\"string-36\":\"36\",\"string-37\":\"37\",\"string-38\":\"38\",\"string-39\":\"39\"" + + "\"string-35\":\"35\",\"string-36\":\"36\",\"string-37\":\"37\",\"string-38\":\"38\",\"string-39\":\"39\"," + + "\"logging.googleapis.com/sourceLocation\":" + + "\\{\"file\":\"ReflectionUtils.java\"," + + "\"line\":\"\\d+\"," + + "\"function\":\"org.junit.platform.commons.util.ReflectionUtils.invokeMethod\"" + + "\\}," + + "\"message\":\"Hello, world!\"," + + "\"severity\":\"INFO\"," + + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}" + "\\}\n"), List.of(formattingResult)); } @@ -148,4 +148,51 @@ class FormatterTest { }); return logRecord; } + + @Test + void nestedRecord() { + var logRecord = makeNestedRecord(); + + var formatter = new Formatter(List.of(), List.of()); + var formattingResult = formatter.format(logRecord); + assertLinesMatch( + List.of( + "\\{" + + "\"anObject\":\\{\"a\":\"b\\\\nc\\\\nd\\\\u0000\\\\u0001\\\\u0002e\"\\}," + + "\"anArray\":\\[1,2,3\\]," + + "\"anArrayOfObjects\":\\[" + + "\\{\"a\":1,\"b\":2\\}," + + "\\{\"b\":2,\"c\":3\\}," + + "\\{\"c\":3,\"d\":4\\}" + + "\\]," + + "\"logging.googleapis.com/sourceLocation\":" + + "\\{\"file\":\"ReflectionUtils.java\"," + + "\"line\":\"\\d+\"," + + "\"function\":\"org.junit.platform.commons.util.ReflectionUtils.invokeMethod\"" + + "\\}," + + "\"message\":\"Hello, world!\"," + + "\"severity\":\"INFO\"," + + "\"timestamp\":\\{\"seconds\":\\d+,\"nanos\":\\d+\\}" + + "\\}\n"), + List.of(formattingResult)); + } + + static ExtLogRecord makeNestedRecord() { + var logRecord = makeSimpleRecord(); + logRecord.setParameters( + new Object[] { + (StructuredParameter) + () -> + JSON.createObjectBuilder() + .add("anObject", JSON.createObjectBuilder().add("a", "b\nc\nd\0\1\2e")) + .add("anArray", JSON.createArrayBuilder().add(1).add(2).add(3)) + .add( + "anArrayOfObjects", + JSON.createArrayBuilder() + .add(JSON.createObjectBuilder().add("a", 1).add("b", 2)) + .add(JSON.createObjectBuilder().add("b", 2).add("c", 3)) + .add(JSON.createObjectBuilder().add("c", 3).add("d", 4))) + }); + return logRecord; + } } -- cgit v1.2.3