enable logging for testing

Author: zhongkechen

.github/workflows/build.yml

@@ -57,5 +57,7 @@ jobs:
           java-version: ${{ matrix.java }}
           cache: maven
 
-      - name: Build and test
-        run: mvn -B install --file pom.xml
+      - name: Build
+        run: mvn -B install --file pom.xml -DskipTests
+      - name: Test
+        run: mvn -B test --file pom.xml -X -Dtest=DurableContextTest -Dorg.slf4j.simpleLogger.defaultLogLevel=DEBUG

sdk/pom.xml

@@ -56,6 +56,12 @@
             <artifactId>mockito-core</artifactId>
             <scope>test</scope>
         </dependency>
+        <dependency>
+            <groupId>org.slf4j</groupId>
+            <artifactId>slf4j-simple</artifactId>
+            <version>${slf4j.version}</version>
+            <scope>test</scope>
+        </dependency>
     </dependencies>
 
     <build>

sdk/src/main/java/com/amazonaws/lambda/durable/operation/BaseDurableOperation.java

@@ -135,6 +135,7 @@ private void validateCurrentThreadType() {
     protected Operation waitForOperationCompletion() {
 
         validateCurrentThreadType();
+        logger.info("Start waiting for operation to finish {} (Phaser: {})", getOperationId(), phaser);
 
         // register to prevent the state from advancing
         phaser.register();
@@ -147,14 +148,14 @@ protected Operation waitForOperationCompletion() {
             // Operation not done yet
             var context = executionManager.getCurrentContext();
             // Deregister current context - allows suspension
-            logger.debug(
+            logger.info(
                     "get() on {} attempting to deregister context: {}",
                     getType(),
                     executionManager.getCurrentContext().contextId());
             deregisterActiveThreadAndUnsetCurrentContext(context.contextId());
 
             // Block until operation completes
-            logger.trace("Waiting for operation to finish {} (Phaser: {})", getOperationId(), phaser);
+            logger.info("Waiting for operation to finish {} (Phaser: {})", getOperationId(), phaser);
             phaser.arriveAndAwaitAdvance();
 
             // Reactivate current context

sdk/src/test/java/com/amazonaws/lambda/durable/DurableContextTest.java

@@ -10,9 +10,12 @@
 import java.time.Duration;
 import java.util.List;
 import org.junit.jupiter.api.Test;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import software.amazon.awssdk.services.lambda.model.*;
 
 class DurableContextTest {
+    private static final Logger logger = LoggerFactory.getLogger(DurableContextTest.class);
 
     private DurableContext createTestContext() {
         var executionOp = Operation.builder()
@@ -39,6 +42,7 @@ private DurableContext createTestContext(List<Operation> initialOperations) {
 
     @Test
     void testContextCreation() {
+        logger.info("testContextCreation");
         var context = createTestContext();
 
         assertNotNull(context);
@@ -47,6 +51,7 @@ void testContextCreation() {
 
     @Test
     void testGetExecutionContext() {
+        logger.info("testGetExecutionContext");
         var context = createTestContext();
 
         var executionContext = context.getExecutionContext();
@@ -61,6 +66,7 @@ void testGetExecutionContext() {
 
     @Test
     void testStepExecution() {
+        logger.info("testStepExecution");
         var context = createTestContext();
 
         var result = context.step("test", String.class, () -> "Hello World");
@@ -70,6 +76,7 @@ void testStepExecution() {
 
     @Test
     void testStepReplay() {
+        logger.info("testStepReplay");
         // Create context with existing operation
         var existingOp = Operation.builder()
                 .id("1")
@@ -86,6 +93,7 @@ void testStepReplay() {
 
     @Test
     void testStepAsync() throws Exception {
+        logger.info("testStepAsync");
         var context = createTestContext();
 
         var future = context.stepAsync("async-test", String.class, () -> "Async Result");
@@ -96,6 +104,7 @@ void testStepAsync() throws Exception {
 
     @Test
     void testStepAsyncReplay() throws Exception {
+        logger.info("testStepAsyncReplay");
         // Create context with existing operation
         var existingOp = Operation.builder()
                 .id("1")
@@ -112,6 +121,7 @@ void testStepAsyncReplay() throws Exception {
 
     @Test
     void testWait() {
+        logger.info("testWait");
         var context = createTestContext();
 
         // Wait should throw SuspendExecutionException
@@ -122,6 +132,7 @@ void testWait() {
 
     @Test
     void testWaitReplay() {
+        logger.info("testWaitReplay");
         // Create context with completed wait operation
         var existingOp =
                 Operation.builder().id("1").status(OperationStatus.SUCCEEDED).build();
@@ -135,24 +146,29 @@ void testWaitReplay() {
 
     @Test
     void testCombinedSyncAsyncWait() throws Exception {
+        logger.info("testCombinedSyncAsyncWait");
         var context = createTestContext();
 
         // Execute sync step
         var syncResult = context.step("sync-step", String.class, () -> "Sync Done");
         assertEquals("Sync Done", syncResult);
+        logger.info("testCombinedSyncAsyncWait - Sync Done");
 
         // Execute async step
         var asyncFuture = context.stepAsync("async-step", Integer.class, () -> 42);
         assertEquals(42, asyncFuture.get());
+        logger.info("testCombinedSyncAsyncWait - Async Done");
 
         // Wait should suspend (throw exception)
         assertThrows(SuspendExecutionException.class, () -> {
             context.wait(Duration.ofSeconds(30));
+            logger.info("testCombinedSyncAsyncWait - Wait Done");
         });
     }
 
     @Test
     void testCombinedReplay() throws Exception {
+        logger.info("testCombinedReplay");
         // Create context with all operations completed
         var syncOp = Operation.builder()
                 .id("1")
@@ -183,6 +199,7 @@ void testCombinedReplay() throws Exception {
 
     @Test
     void testNamedWait() {
+        logger.info("testNamedWait");
         var ctx = createTestContext();
 
         // Named wait should throw SuspendExecutionException
@@ -203,6 +220,7 @@ void testNamedWait() {
 
     @Test
     void testStepWithTypeToken() {
+        logger.info("testStepWithTypeToken");
         var context = createTestContext();
 
         List<String> result = context.step("test-list", new TypeToken<List<String>>() {}, () -> List.of("a", "b", "c"));
@@ -214,6 +232,7 @@ void testStepWithTypeToken() {
 
     @Test
     void testStepWithTypeTokenReplay() {
+        logger.info("testStepWithTypeTokenReplay");
         // Create context with existing operation
         var existingOp = Operation.builder()
                 .id("1")
@@ -235,6 +254,7 @@ void testStepWithTypeTokenReplay() {
 
     @Test
     void testStepWithTypeTokenAndConfig() {
+        logger.info("testStepWithTypeTokenAndConfig");
         var context = createTestContext();
 
         List<Integer> result = context.step(
@@ -252,6 +272,7 @@ void testStepWithTypeTokenAndConfig() {
 
     @Test
     void testStepAsyncWithTypeToken() throws Exception {
+        logger.info("testStepAsyncWithTypeToken");
         var context = createTestContext();
 
         DurableFuture<List<String>> future =
@@ -265,6 +286,7 @@ void testStepAsyncWithTypeToken() throws Exception {
 
     @Test
     void testStepAsyncWithTypeTokenReplay() throws Exception {
+        logger.info("testStepAsyncWithTypeTokenReplay");
         // Create context with existing operation
         var existingOp = Operation.builder()
                 .id("1")
@@ -287,6 +309,7 @@ void testStepAsyncWithTypeTokenReplay() throws Exception {
 
     @Test
     void testStepAsyncWithTypeTokenAndConfig() throws Exception {
+        logger.info("testStepAsyncWithTypeTokenAndConfig");
         var context = createTestContext();
 
         DurableFuture<List<Integer>> future = context.stepAsync(