From 136a26b7da5f6cd7424cb515a71447ba4df05859 Mon Sep 17 00:00:00 2001 From: Brandon Arp Date: Thu, 5 Jun 2025 12:36:39 -0700 Subject: [PATCH 1/2] feat: Add Pekko ActorContext serialization to structured logs --- config/logback-console.xml | 1 + config/logback.xml | 1 + pom.xml | 6 + .../module/pekko/ActorContextSerializer.java | 43 ++++++ .../module/pekko/PekkoLoggingModule.java | 15 +- .../pekko/TimerSchedulerSerializer.java | 57 ++++++++ .../metrics/mad/PeriodWorker.java | 2 +- src/main/resources/logback.xml | 1 + .../metrics/mad/PekkoLoggingModuleTest.java | 137 ++++++++++++++++++ .../steno/TestLoggerFactory.java | 36 +++++ .../com/arpnetworking/steno/package-info.java | 23 +++ .../mad/PekkoLoggingModeuleTest.expected | 1 + .../metrics/mad/PekkoLoggingModuleTest.xml | 33 +++++ src/test/resources/logback-perf.xml | 1 + src/test/resources/logback-test.xml | 1 + 15 files changed, 351 insertions(+), 7 deletions(-) create mode 100644 src/main/java/com/arpnetworking/configuration/jackson/module/pekko/ActorContextSerializer.java create mode 100644 src/main/java/com/arpnetworking/configuration/jackson/module/pekko/TimerSchedulerSerializer.java create mode 100644 src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java create mode 100644 src/test/java/com/arpnetworking/steno/TestLoggerFactory.java create mode 100644 src/test/java/com/arpnetworking/steno/package-info.java create mode 100644 src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModeuleTest.expected create mode 100644 src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.xml diff --git a/config/logback-console.xml b/config/logback-console.xml index eb6c4b68..17ec16c3 100644 --- a/config/logback-console.xml +++ b/config/logback-console.xml @@ -22,6 +22,7 @@ + true diff --git a/config/logback.xml b/config/logback.xml index 796820c2..60fd6288 100644 --- a/config/logback.xml +++ b/config/logback.xml @@ -32,6 +32,7 @@ + true diff --git a/pom.xml b/pom.xml index f58421ab..ac2f70e1 100644 --- a/pom.xml +++ b/pom.xml @@ -528,6 +528,7 @@ io.netty:netty-common:jar:* + ch.qos.logback:logback-core:jar:* @@ -546,6 +547,11 @@ logback-classic ${logback.version} + + ch.qos.logback + logback-core + ${logback.version} + com.arpnetworking.logback logback-steno diff --git a/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/ActorContextSerializer.java b/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/ActorContextSerializer.java new file mode 100644 index 00000000..8bd52a61 --- /dev/null +++ b/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/ActorContextSerializer.java @@ -0,0 +1,43 @@ +/* + * Copyright 2025 Brandon Arp + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.arpnetworking.configuration.jackson.module.pekko; + +import com.fasterxml.jackson.core.JsonGenerator; +import com.fasterxml.jackson.databind.JsonSerializer; +import com.fasterxml.jackson.databind.SerializerProvider; +import org.apache.pekko.actor.ActorContext; + +import java.io.IOException; + +/** + * Serializer for a Pekko timer message. + * + * @author Brandon Arp (brandon dot arp at inscopemetrics dot com) + */ +public final class ActorContextSerializer extends JsonSerializer { + @Override + public void serialize( + final ActorContext context, + final JsonGenerator jsonGenerator, + final SerializerProvider serializerProvider) + throws IOException { + jsonGenerator.writeStartObject(); + jsonGenerator.writeObjectField("type", context.getClass().getTypeName()); + jsonGenerator.writeObjectField("self", context.self()); + jsonGenerator.writeObjectField("sender", context.sender()); + jsonGenerator.writeEndObject(); + } +} diff --git a/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/PekkoLoggingModule.java b/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/PekkoLoggingModule.java index 2f1ee545..135771f0 100644 --- a/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/PekkoLoggingModule.java +++ b/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/PekkoLoggingModule.java @@ -16,6 +16,7 @@ package com.arpnetworking.configuration.jackson.module.pekko; import com.fasterxml.jackson.databind.module.SimpleModule; +import org.apache.pekko.actor.ActorContext; import org.apache.pekko.actor.ActorRef; import org.apache.pekko.actor.LocalActorRef; import org.apache.pekko.actor.TimerSchedulerImpl; @@ -37,12 +38,14 @@ public PekkoLoggingModule() { } @Override public void setupModule(final SetupContext context) { - addSerializer(ActorRef.class, new ActorRefLoggingSerializer()); - addSerializer(LocalActorRef.class, new ActorRefLoggingSerializer()); - addSerializer(TimerSchedulerImpl.TimerMsg.class, new TimerMessageSerializer()); - addSerializer(TimerSchedulerImpl.InfluenceReceiveTimeoutTimerMsg.class, new TimerMessageSerializer()); - addSerializer(TimerSchedulerImpl.NotInfluenceReceiveTimeoutTimerMsg.class, new TimerMessageSerializer()); - super.setupModule(context); + addSerializer(ActorRef.class, new ActorRefLoggingSerializer()); + addSerializer(LocalActorRef.class, new ActorRefLoggingSerializer()); + addSerializer(TimerSchedulerImpl.TimerMsg.class, new TimerMessageSerializer()); + addSerializer(TimerSchedulerImpl.InfluenceReceiveTimeoutTimerMsg.class, new TimerMessageSerializer()); + addSerializer(TimerSchedulerImpl.NotInfluenceReceiveTimeoutTimerMsg.class, new TimerMessageSerializer()); + addSerializer(TimerSchedulerImpl.class, new TimerSchedulerSerializer()); + addSerializer(ActorContext.class, new ActorContextSerializer()); + super.setupModule(context); } @Serial diff --git a/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/TimerSchedulerSerializer.java b/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/TimerSchedulerSerializer.java new file mode 100644 index 00000000..41c3a923 --- /dev/null +++ b/src/main/java/com/arpnetworking/configuration/jackson/module/pekko/TimerSchedulerSerializer.java @@ -0,0 +1,57 @@ +/* + * Copyright 2025 Brandon Arp + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.arpnetworking.configuration.jackson.module.pekko; + +import com.fasterxml.jackson.core.JsonGenerator; +import com.fasterxml.jackson.databind.JsonSerializer; +import com.fasterxml.jackson.databind.SerializerProvider; +import org.apache.pekko.actor.TimerSchedulerImpl; + +import java.io.IOException; +import java.io.InvalidObjectException; +import java.lang.reflect.Field; + +/** + * Serializer for a Pekko timer message. + * + * @author Brandon Arp (brandon dot arp at inscopemetrics dot com) + */ +public final class TimerSchedulerSerializer extends JsonSerializer { + @Override + public void serialize( + final TimerSchedulerImpl timerScheduler, + final JsonGenerator jsonGenerator, + final SerializerProvider serializerProvider) + throws IOException { + jsonGenerator.writeStartObject(); + jsonGenerator.writeObjectField("type", timerScheduler.getClass().getTypeName()); + try { + jsonGenerator.writeObjectField("key", CTX.get(timerScheduler)); + } catch (final IllegalAccessException e) { + throw new InvalidObjectException("Unable to access context field"); + } + jsonGenerator.writeEndObject(); + } + private static final Field CTX; + static { + try { + CTX = TimerSchedulerImpl.class.getDeclaredField("ctx"); + CTX.setAccessible(true); + } catch (final NoSuchFieldException e) { + throw new RuntimeException(e); + } + } +} diff --git a/src/main/java/com/arpnetworking/metrics/mad/PeriodWorker.java b/src/main/java/com/arpnetworking/metrics/mad/PeriodWorker.java index 9acd6b13..52956294 100644 --- a/src/main/java/com/arpnetworking/metrics/mad/PeriodWorker.java +++ b/src/main/java/com/arpnetworking/metrics/mad/PeriodWorker.java @@ -167,7 +167,7 @@ private void checkForIdle() { private void shutdown(final Aggregator.PeriodWorkerShutdown shutdown) { timers().cancelAll(); - self().tell(PoisonPill.getInstance(), self()); + timers().startSingleTimer("SELF_SHUTDOWN", PoisonPill.getInstance(), Duration.ofSeconds(5)); } private void scheduleRotation(final ZonedDateTime now) { diff --git a/src/main/resources/logback.xml b/src/main/resources/logback.xml index 6bfe06c6..8c5f6e8c 100644 --- a/src/main/resources/logback.xml +++ b/src/main/resources/logback.xml @@ -30,6 +30,7 @@ %date %t [%level] %logger : %message %ex%n + diff --git a/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java b/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java new file mode 100644 index 00000000..1186e8c7 --- /dev/null +++ b/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java @@ -0,0 +1,137 @@ +/* + * Copyright 2025 Brandon Arp + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.arpnetworking.metrics.mad; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.joran.JoranConfigurator; +import ch.qos.logback.classic.util.LogbackMDCAdapter; +import ch.qos.logback.core.joran.spi.JoranException; +import com.arpnetworking.steno.Logger; +import com.arpnetworking.steno.TestLoggerFactory; +import org.apache.pekko.actor.AbstractActor; +import org.apache.pekko.actor.ActorRef; +import org.apache.pekko.actor.ActorSystem; +import org.apache.pekko.actor.Props; +import org.apache.pekko.actor.Terminated; +import org.junit.After; +import org.junit.Assert; +import org.junit.Before; +import org.junit.Test; + +import java.io.File; +import java.io.IOException; +import java.net.URISyntaxException; +import java.net.URL; +import java.nio.file.Files; +import java.nio.file.Paths; +import java.util.concurrent.CompletionStage; +import java.util.concurrent.TimeUnit; + +/** + * Unit test class for verifying the functionality and integration of the AkkaLoggingModule. + * This class tests various aspects of logging and actor-based communication within an Akka-based + * system using Logback as the logging backend. + * + * @author Brandon Arp (brandon dot arp at inscopemetrics dot io) + */ +public class PekkoLoggingModuleTest { + /** + * Sets up the test environment by initializing the required components. + * This method is executed before each test, ensuring a fresh setup. + * + * The setup process includes the following: + * - Creation of an Akka {@link ActorSystem} instance. + * - Loading the specific XML configuration file corresponding to the test class. + * - Initializing and configuring a Logback {@link LoggerContext}. + * - Setting up the {@link JoranConfigurator} to parse the configuration file. + * - Resetting and associating a {@link LogbackMDCAdapter} instance with the LoggerContext. + * + * If an error occurs during the configuration process using the JoranConfigurator, + * a {@link RuntimeException} is thrown, encapsulating the underlying {@link JoranException}. + * + * The initialized {@link ActorSystem} and {@link LoggerContext} serve as the foundation for + * executing tests that involve logging and actor-based messaging. + */ + @Before + public void setUp() { + _actorSystem = ActorSystem.create(); + final URL configuration = getClass().getResource( + this.getClass().getSimpleName() + ".xml"); + _loggerContext = new LoggerContext(); + final JoranConfigurator configurator = new JoranConfigurator(); + configurator.setContext(_loggerContext); + _loggerContext.reset(); + final LogbackMDCAdapter mdcAdapter = new LogbackMDCAdapter(); + _loggerContext.setMDCAdapter(mdcAdapter); + try { + configurator.doConfigure(configuration); + } catch (final JoranException e) { + throw new RuntimeException(e); + } + } + + @After + public void tearDown() throws Exception { + final CompletionStage terminated = _actorSystem.getWhenTerminated(); + _actorSystem.terminate(); + terminated.toCompletableFuture().get(10, TimeUnit.SECONDS); + } + + @Test + public void testLoggingActorRefs() { + final ActorRef actorRef = _actorSystem.actorOf(Props.create(SimpleActor.class, SimpleActor::new)); + getLogger().info() + .setMessage("LoggingActorRefs") + .addData("actorRef", actorRef) + .log(); + } + + protected void assertOutput() { + final URL expectedResource = getClass().getResource( + getClass().getSimpleName() + ".expected"); + final File actualFile = new File("target/integration-test-logs/" + this.getClass().getSimpleName() + ".log"); + final String actualOutput; + try { + actualOutput = Files.readString(actualFile.toPath()); + } catch (final IOException e) { + throw new RuntimeException(e); + } + try { + assertOutput(Files.readString(Paths.get(expectedResource.toURI())), actualOutput); + } catch (final IOException | URISyntaxException e) { + Assert.fail("Failed with exception: " + e); + } + } + + protected void assertOutput(final String expected, final String actual) { + Assert.assertEquals(expected, actual); + } + + protected Logger getLogger() { + return TestLoggerFactory.getLogger(_loggerContext.getLogger(ch.qos.logback.classic.Logger.ROOT_LOGGER_NAME)); + } + + private ActorSystem _actorSystem; + private LoggerContext _loggerContext; + + static class SimpleActor extends AbstractActor { + + @Override + public Receive createReceive() { + return receiveBuilder().build(); + } + } +} diff --git a/src/test/java/com/arpnetworking/steno/TestLoggerFactory.java b/src/test/java/com/arpnetworking/steno/TestLoggerFactory.java new file mode 100644 index 00000000..70162440 --- /dev/null +++ b/src/test/java/com/arpnetworking/steno/TestLoggerFactory.java @@ -0,0 +1,36 @@ +/* + * Copyright 2015 Groupon.com + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.arpnetworking.steno; + +/** + * Wraps a {@link org.slf4j.Logger} instance in a {@link com.arpnetwoprking.steno.Logger} instance. + * + * @author Ville Koskela (ville dot koskela at inscopemetrics dot io) + */ +public final class TestLoggerFactory { + + /** + * Return a Steno {@link Logger} around a {@link org.slf4j.Logger} instance. + * + * @param logger The {@link org.slf4j.Logger} instance. + * @return Steno {@link Logger} instance. + */ + public static Logger getLogger(final org.slf4j.Logger logger) { + return new Logger(logger); + } + + private TestLoggerFactory() {} +} diff --git a/src/test/java/com/arpnetworking/steno/package-info.java b/src/test/java/com/arpnetworking/steno/package-info.java new file mode 100644 index 00000000..524e08f1 --- /dev/null +++ b/src/test/java/com/arpnetworking/steno/package-info.java @@ -0,0 +1,23 @@ +/* + * Copyright 2025 Brandon Arp + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +@ParametersAreNonnullByDefault +@ReturnValuesAreNonnullByDefault +package com.arpnetworking.steno; + +import com.arpnetworking.commons.javax.annotation.ReturnValuesAreNonnullByDefault; + +import javax.annotation.ParametersAreNonnullByDefault; diff --git a/src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModeuleTest.expected b/src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModeuleTest.expected new file mode 100644 index 00000000..c75763bb --- /dev/null +++ b/src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModeuleTest.expected @@ -0,0 +1 @@ +fail the test \ No newline at end of file diff --git a/src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.xml b/src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.xml new file mode 100644 index 00000000..a3c0dd18 --- /dev/null +++ b/src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.xml @@ -0,0 +1,33 @@ + + + + + target/test-logs/AkkaLoggingModuleTest.log + false + + true + true + true + + + + + + + + + diff --git a/src/test/resources/logback-perf.xml b/src/test/resources/logback-perf.xml index e7402b38..242bccf5 100644 --- a/src/test/resources/logback-perf.xml +++ b/src/test/resources/logback-perf.xml @@ -21,6 +21,7 @@ %relative %date %t [%level] %logger : %message %ex%n + diff --git a/src/test/resources/logback-test.xml b/src/test/resources/logback-test.xml index dc82cdd7..22ca4dd6 100644 --- a/src/test/resources/logback-test.xml +++ b/src/test/resources/logback-test.xml @@ -21,6 +21,7 @@ %relative %date %t [%level] %logger : %message %ex%n + From 51182170becc85f92d0c6ed9b43eafde1e706ae0 Mon Sep 17 00:00:00 2001 From: Brandon Arp Date: Thu, 5 Jun 2025 13:27:50 -0700 Subject: [PATCH 2/2] fix tests --- .../metrics/mad/PekkoLoggingModuleTest.java | 18 +++++++++++++++--- .../mad/PekkoLoggingModeuleTest.expected | 1 - .../mad/PekkoLoggingModuleTest.expected | 1 + .../metrics/mad/PekkoLoggingModuleTest.xml | 2 +- 4 files changed, 17 insertions(+), 5 deletions(-) delete mode 100644 src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModeuleTest.expected create mode 100644 src/test/resources/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.expected diff --git a/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java b/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java index 1186e8c7..1c41d7f6 100644 --- a/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java +++ b/src/test/java/com/arpnetworking/metrics/mad/PekkoLoggingModuleTest.java @@ -92,17 +92,18 @@ public void tearDown() throws Exception { @Test public void testLoggingActorRefs() { - final ActorRef actorRef = _actorSystem.actorOf(Props.create(SimpleActor.class, SimpleActor::new)); + final ActorRef actorRef = _actorSystem.actorOf(Props.create(SimpleActor.class, SimpleActor::new), "simple-actor"); getLogger().info() .setMessage("LoggingActorRefs") .addData("actorRef", actorRef) .log(); + assertOutput(); } protected void assertOutput() { final URL expectedResource = getClass().getResource( getClass().getSimpleName() + ".expected"); - final File actualFile = new File("target/integration-test-logs/" + this.getClass().getSimpleName() + ".log"); + final File actualFile = new File("target/test-logs/" + this.getClass().getSimpleName() + ".log"); final String actualOutput; try { actualOutput = Files.readString(actualFile.toPath()); @@ -117,7 +118,18 @@ protected void assertOutput() { } protected void assertOutput(final String expected, final String actual) { - Assert.assertEquals(expected, actual); + Assert.assertEquals(expected.trim(), sanitizeOutput(actual.trim())); + } + + protected String sanitizeOutput(final String output) { + return output.replaceAll("\"time\":\"[^\"]+\"", "\"time\":\"