Simple summary logging of images pulled during execution

Author: rnorth

core/src/main/java/org/testcontainers/DockerClientFactory.java

@@ -326,7 +326,7 @@ private boolean checkMountableFile() {
     public void checkAndPullImage(DockerClient client, String image) {
         List<Image> images = client.listImagesCmd().withImageNameFilter(image).exec();
         if (images.isEmpty()) {
-            client.pullImageCmd(image).exec(new TimeLimitedLoggedPullImageResultCallback(log)).awaitCompletion();
+            client.pullImageCmd(image).exec(new TimeLimitedLoggedPullImageResultCallback(log , image)).awaitCompletion();
         }
     }
 

core/src/main/java/org/testcontainers/images/LoggedPullImageResultCallback.java

@@ -3,6 +3,7 @@
 import com.github.dockerjava.api.command.PullImageResultCallback;
 import com.github.dockerjava.api.model.PullResponseItem;
 import org.slf4j.Logger;
+import org.testcontainers.utility.ImagePullCountLogger;
 
 import java.io.Closeable;
 import java.time.Duration;
@@ -17,6 +18,7 @@
  */
 class LoggedPullImageResultCallback extends PullImageResultCallback {
     private final Logger logger;
+    private final String canonicalImageName;
 
     private final Set<String> allLayers = new HashSet<>();
     private final Set<String> downloadedLayers = new HashSet<>();
@@ -26,8 +28,9 @@ class LoggedPullImageResultCallback extends PullImageResultCallback {
     private boolean completed;
     private Instant start;
 
-    LoggedPullImageResultCallback(final Logger logger) {
+    LoggedPullImageResultCallback(final Logger logger, final String canonicalImageName) {
         this.logger = logger;
+        this.canonicalImageName = canonicalImageName;
     }
 
     @Override
@@ -109,6 +112,8 @@ public void onComplete() {
                 byteCountToDisplaySize(downloadedLayerSize),
                 byteCountToDisplaySize(downloadedLayerSize / duration));
         }
+
+        ImagePullCountLogger.instance().recordPull(canonicalImageName);
     }
 
     private long downloadedLayerSize() {

core/src/main/java/org/testcontainers/images/RemoteDockerImage.java

@@ -77,7 +77,7 @@ protected final String resolve() {
                     dockerClient
                         .pullImageCmd(imageName.getUnversionedPart())
                         .withTag(imageName.getVersionPart())
-                        .exec(new TimeLimitedLoggedPullImageResultCallback(logger))
+                        .exec(new TimeLimitedLoggedPullImageResultCallback(logger, imageName.asCanonicalNameString()))
                         .awaitCompletion();
 
                     LocalImagesCache.INSTANCE.refreshCache(imageName);

core/src/main/java/org/testcontainers/images/TimeLimitedLoggedPullImageResultCallback.java

@@ -41,8 +41,8 @@ public class TimeLimitedLoggedPullImageResultCallback extends LoggedPullImageRes
     // All threads that are 'awaiting' this pull
     private final Set<Thread> waitingThreads = new HashSet<>();
 
-    public TimeLimitedLoggedPullImageResultCallback(Logger logger) {
-        super(logger);
+    public TimeLimitedLoggedPullImageResultCallback(Logger logger, final String canonicalImageName) {
+        super(logger, canonicalImageName);
         this.logger = logger;
     }
 

core/src/main/java/org/testcontainers/utility/ImagePullCountLogger.java

@@ -0,0 +1,50 @@
+package org.testcontainers.utility;
+
+import com.google.common.annotations.VisibleForTesting;
+import lombok.extern.slf4j.Slf4j;
+
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.stream.Collectors;
+
+/**
+ * Simple utility to log which images have been pulled by {@link org.testcontainers.Testcontainers} and how many times.
+ */
+@Slf4j
+public class ImagePullCountLogger {
+
+    private static ImagePullCountLogger instance;
+    private final Map<String, AtomicInteger> pullCounters = new ConcurrentHashMap<>();
+
+    public synchronized static ImagePullCountLogger instance() {
+        if (instance == null) {
+            instance = new ImagePullCountLogger();
+            Runtime.getRuntime().addShutdownHook(new Thread(instance::logStatistics));
+        }
+
+        return instance;
+    }
+
+    @VisibleForTesting
+    ImagePullCountLogger() {
+
+    }
+
+    public void logStatistics() {
+        if (pullCounters.size() > 0) {
+            final String summary = pullCounters.entrySet().stream()
+                .map(it -> it.getKey() + (it.getValue().intValue() > 1 ? " (" + it.getValue() + " times)" : ""))
+                .sorted()
+                .collect(Collectors.joining("\n    ", "\n    ", "\n"));
+
+            log.info("Testcontainers pulled the following images during execution:{}", summary);
+        } else {
+            log.info("Testcontainers did not need to pull any images during execution");
+        }
+    }
+
+    public void recordPull(final String image) {
+        pullCounters.computeIfAbsent(image, __ -> new AtomicInteger()).incrementAndGet();
+    }
+}

core/src/test/java/org/testcontainers/utility/ImagePullCountLoggerTest.java

@@ -0,0 +1,67 @@
+package org.testcontainers.utility;
+
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.read.ListAppender;
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+import org.slf4j.LoggerFactory;
+
+import java.util.Optional;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
+
+public class ImagePullCountLoggerTest {
+
+    private ImagePullCountLogger underTest;
+    private ListAppender<ILoggingEvent> listAppender;
+    private Logger logger;
+
+    @Before
+    public void setUp() throws Exception {
+        logger = (Logger) LoggerFactory.getLogger(ImagePullCountLogger.class);
+        listAppender = new ListAppender<>();
+        logger.addAppender(listAppender);
+        listAppender.start();
+    }
+
+    @Test
+    public void testPullCountsLogged() {
+        underTest = new ImagePullCountLogger();
+
+        underTest.recordPull("imageA");
+        underTest.recordPull("imageA");
+        underTest.recordPull("imageB");
+        underTest.recordPull("imageC");
+
+        underTest.logStatistics();
+
+        assertEquals(1, listAppender.list.size());
+        final Optional<String> messages = listAppender.list.stream().map(ILoggingEvent::getFormattedMessage).findFirst();
+        assertTrue(messages.isPresent());
+        final String message = messages.get();
+        assertTrue(message.contains("imageA (2 times)\n"));
+        assertTrue(message.contains("imageB\n"));
+        assertTrue(message.contains("imageC\n"));
+    }
+
+    @Test
+    public void testNoPullsLogged() {
+        underTest = new ImagePullCountLogger();
+
+        underTest.logStatistics();
+
+        assertEquals(1, listAppender.list.size());
+        final Optional<String> messages = listAppender.list.stream().map(ILoggingEvent::getFormattedMessage).findFirst();
+        assertTrue(messages.isPresent());
+        final String message = messages.get();
+        assertEquals("Testcontainers did not need to pull any images during execution", message);
+    }
+
+    @After
+    public void tearDown() throws Exception {
+        logger.detachAppender(listAppender);
+    }
+}