Remove SLF4J Profiler (#1002)

This was useful while we were working to optimise performance, but now I feel it's just clutter and can be safely removed.

Author: rnorth

core/build.gradle

@@ -73,7 +73,6 @@ project.tasks.check.dependsOn(jarFileTest)
 dependencies {
     compile 'junit:junit:4.12'
     compile 'org.slf4j:slf4j-api:1.7.25'
-    compile 'org.slf4j:slf4j-ext:1.7.25'
     compile 'org.jetbrains:annotations:15.0'
     compile 'javax.annotation:javax.annotation-api:1.3.1'
     compile 'org.apache.commons:commons-compress:1.18'

core/src/main/java/org/testcontainers/containers/DockerComposeContainer.java

@@ -13,7 +13,6 @@
 import org.junit.runners.model.Statement;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
-import org.slf4j.profiler.Profiler;
 import org.testcontainers.DockerClientFactory;
 import org.testcontainers.containers.output.OutputFrame;
 import org.testcontainers.containers.output.Slf4jLogConsumer;
@@ -140,10 +139,6 @@ public void finished(Description description) {
 
     @Override
     public void start() {
-        final Profiler profiler = new Profiler("Docker Compose container rule");
-        profiler.setLogger(logger());
-        profiler.start("Docker Compose container startup");
-
         synchronized (MUTEX) {
             registerContainersForShutdown();
             if (pull) {
@@ -155,7 +150,7 @@ public void start() {
             }
             applyScaling(); // scale before up, so that all scaled instances are available first for linking
             createServices();
-            startAmbassadorContainers(profiler);
+            startAmbassadorContainers();
             waitUntilServiceStarted();
         }
     }
@@ -243,10 +238,8 @@ private List<Container> listChildContainers() {
                 .collect(toList());
     }
 
-    private void startAmbassadorContainers(Profiler profiler) {
-        profiler.start("Ambassador container startup");
+    private void startAmbassadorContainers() {
         ambassadorContainer.start();
-        profiler.stop().log();
     }
 
     private Logger logger() {

core/src/main/java/org/testcontainers/containers/GenericContainer.java

@@ -3,22 +3,9 @@
 import com.github.dockerjava.api.DockerClient;
 import com.github.dockerjava.api.command.CreateContainerCmd;
 import com.github.dockerjava.api.command.InspectContainerResponse;
-import com.github.dockerjava.api.model.Bind;
-import com.github.dockerjava.api.model.ContainerNetwork;
-import com.github.dockerjava.api.model.ExposedPort;
-import com.github.dockerjava.api.model.HostConfig;
-import com.github.dockerjava.api.model.Info;
-import com.github.dockerjava.api.model.Link;
-import com.github.dockerjava.api.model.PortBinding;
-import com.github.dockerjava.api.model.Volume;
-import com.github.dockerjava.api.model.VolumesFrom;
+import com.github.dockerjava.api.model.*;
 import com.google.common.base.Strings;
-import lombok.AccessLevel;
-import lombok.Data;
-import lombok.EqualsAndHashCode;
-import lombok.NonNull;
-import lombok.Setter;
-import lombok.SneakyThrows;
+import lombok.*;
 import org.apache.commons.compress.archivers.tar.TarArchiveInputStream;
 import org.apache.commons.compress.archivers.tar.TarArchiveOutputStream;
 import org.apache.commons.compress.utils.IOUtils;
@@ -32,7 +19,6 @@
 import org.rnorth.ducttape.unreliables.Unreliables;
 import org.rnorth.visibleassertions.VisibleAssertions;
 import org.slf4j.Logger;
-import org.slf4j.profiler.Profiler;
 import org.testcontainers.DockerClientFactory;
 import org.testcontainers.containers.output.FrameConsumerResultCallback;
 import org.testcontainers.containers.output.OutputFrame;
@@ -51,25 +37,11 @@
 import org.testcontainers.lifecycle.TestLifecycleAware;
 import org.testcontainers.utility.*;
 
-import java.io.ByteArrayInputStream;
-import java.io.ByteArrayOutputStream;
-import java.io.File;
-import java.io.FileOutputStream;
-import java.io.IOException;
-import java.io.InputStream;
+import java.io.*;
 import java.nio.charset.Charset;
 import java.nio.file.Path;
 import java.time.Duration;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Collections;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.LinkedHashSet;
-import java.util.List;
-import java.util.Map;
-import java.util.Optional;
-import java.util.Set;
+import java.util.*;
 import java.util.concurrent.Future;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicInteger;
@@ -229,11 +201,7 @@ public void start() {
     }
 
     protected void doStart() {
-        Profiler profiler = new Profiler("Container startup");
-        profiler.setLogger(logger());
-
         try {
-            profiler.start("Prepare container configuration and host configuration");
             configure();
 
             logger().debug("Starting container: {}", getDockerImageName());
@@ -242,24 +210,21 @@ protected void doStart() {
             AtomicInteger attempt = new AtomicInteger(0);
             Unreliables.retryUntilSuccess(startupAttempts, () -> {
                 logger().debug("Trying to start container: {} (attempt {}/{})", image.get(), attempt.incrementAndGet(), startupAttempts);
-                tryStart(profiler.startNested("Container startup attempt"));
+                tryStart();
                 return true;
             });
 
         } catch (Exception e) {
             throw new ContainerLaunchException("Container startup failed", e);
-        } finally {
-            profiler.stop().log();
         }
     }
 
-    private void tryStart(Profiler profiler) {
+    private void tryStart() {
         try {
             String dockerImageName = image.get();
             logger().debug("Starting container: {}", dockerImageName);
 
             logger().info("Creating container for image: {}", dockerImageName);
-            profiler.start("Create container");
             CreateContainerCmd createCommand = dockerClient.createContainerCmd(dockerImageName);
             applyConfiguration(createCommand);
 
@@ -272,7 +237,6 @@ private void tryStart(Profiler profiler) {
             containerIsCreated(containerId);
 
             logger().info("Starting container with ID: {}", containerId);
-            profiler.start("Start container");
             dockerClient.startContainerCmd(containerId).exec();
 
             // For all registered output consumers, start following as close to container startup as possible
@@ -281,22 +245,18 @@ private void tryStart(Profiler profiler) {
             logger().info("Container {} is starting: {}", dockerImageName, containerId);
 
             // Tell subclasses that we're starting
-            profiler.start("Inspecting container");
             containerInfo = dockerClient.inspectContainerCmd(containerId).exec();
             containerName = containerInfo.getName();
-            profiler.start("Call containerIsStarting on subclasses");
             containerIsStarting(containerInfo);
 
             // Wait until the container is running (may not be fully started)
-            profiler.start("Wait until container has started properly, or there's evidence it failed to start.");
 
             if (!this.startupCheckStrategy.waitUntilStartupSuccessful(dockerClient, containerId)) {
                 // Bail out, don't wait for the port to start listening.
                 // (Exception thrown here will be caught below and wrapped)
                 throw new IllegalStateException("Container did not start correctly.");
             }
 
-            profiler.start("Wait until container started properly");
             waitUntilContainerStarted();
 
             logger().info("Container {} started", dockerImageName);
@@ -321,8 +281,6 @@ private void tryStart(Profiler profiler) {
             }
 
             throw new ContainerLaunchException("Could not create/start container", e);
-        } finally {
-            profiler.stop();
         }
     }
 
@@ -455,7 +413,7 @@ public Set<Integer> getLivenessCheckPortNumbers() {
     private void applyConfiguration(CreateContainerCmd createCommand) {
         HostConfig hostConfig = buildHostConfig();
         createCommand.withHostConfig(hostConfig);
-        
+
         // Set up exposed ports (where there are no host port bindings defined)
         ExposedPort[] portArray = exposedPorts.stream()
                 .map(ExposedPort::new)
@@ -1166,7 +1124,7 @@ public SELF withStartupAttempts(int attempts) {
     }
 
     /**
-     * Allow low level modifications of {@link CreateContainerCmd} after it was pre-configured in {@link #tryStart(Profiler)}.
+     * Allow low level modifications of {@link CreateContainerCmd} after it was pre-configured in {@link #tryStart()}.
      * Invocation happens eagerly on a moment when container is created.
      * Warning: this does expose the underlying docker-java API so might change outside of our control.
      *

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

@@ -8,7 +8,6 @@
 import lombok.NonNull;
 import lombok.ToString;
 import org.slf4j.Logger;
-import org.slf4j.profiler.Profiler;
 import org.testcontainers.DockerClientFactory;
 import org.testcontainers.containers.ContainerFetchException;
 import org.testcontainers.utility.DockerImageName;
@@ -39,17 +38,10 @@ public RemoteDockerImage(@NonNull String repository, @NonNull String tag) {
 
     @Override
     protected final String resolve() {
-        Profiler profiler = new Profiler("Rule creation - prefetch image");
         Logger logger = DockerLoggerFactory.getLogger(imageName.toString());
-        profiler.setLogger(logger);
 
-        Profiler nested = profiler.startNested("Obtaining client");
         DockerClient dockerClient = DockerClientFactory.instance().client();
         try {
-            nested.stop();
-
-            profiler.start("Check local images");
-
             int attempts = 0;
             Exception lastException = null;
             while (true) {
@@ -83,7 +75,6 @@ protected final String resolve() {
                 // Log only on first attempt
                 if (attempts == 0) {
                     logger.info("Pulling docker image: {}. Please be patient; this may take some time but only needs to be done once.", imageName);
-                    profiler.start("Pull image");
                 }
 
                 if (attempts++ >= 3) {
@@ -109,8 +100,6 @@ protected final String resolve() {
             return imageName.toString();
         } catch (DockerClientException e) {
             throw new ContainerFetchException("Failed to get Docker client for " + imageName, e);
-        } finally {
-            profiler.stop().log();
         }
     }
 }

core/src/main/java/org/testcontainers/images/builder/ImageFromDockerfile.java

@@ -12,7 +12,6 @@
 import org.apache.commons.compress.archivers.tar.TarArchiveOutputStream;
 import org.apache.commons.lang.StringUtils;
 import org.slf4j.Logger;
-import org.slf4j.profiler.Profiler;
 import org.testcontainers.DockerClientFactory;
 import org.testcontainers.images.builder.traits.*;
 import org.testcontainers.utility.Base58;
@@ -90,9 +89,6 @@ public ImageFromDockerfile withFileFromTransferable(String path, Transferable tr
     protected final String resolve() {
         Logger logger = DockerLoggerFactory.getLogger(dockerImageName);
 
-        Profiler profiler = new Profiler("Rule creation - build image");
-        profiler.setLogger(logger);
-
         DockerClient dockerClient = DockerClientFactory.instance().client();
         try {
             if (deleteOnExit) {
@@ -116,16 +112,12 @@ public void onNext(BuildResponseItem item) {
             @Cleanup PipedInputStream in = new PipedInputStream();
             @Cleanup PipedOutputStream out = new PipedOutputStream(in);
 
-            profiler.start("Configure image");
             BuildImageCmd buildImageCmd = dockerClient.buildImageCmd(in);
             configure(buildImageCmd);
 
-            profiler.start("Build image");
             BuildImageResultCallback exec = buildImageCmd.exec(resultCallback);
 
             // To build an image, we have to send the context to Docker in TAR archive format
-            profiler.start("Send context as TAR");
-
             try (TarArchiveOutputStream tarArchive = new TarArchiveOutputStream(new GZIPOutputStream(out))) {
                 tarArchive.setLongFileMode(TarArchiveOutputStream.LONGFILE_POSIX);
 
@@ -137,14 +129,11 @@ public void onNext(BuildResponseItem item) {
                 tarArchive.finish();
             }
 
-            profiler.start("Wait for an image id");
             exec.awaitImageId();
 
             return dockerImageName;
         } catch(IOException e) {
             throw new RuntimeException("Can't close DockerClient", e);
-        } finally {
-            profiler.stop().log();
         }
     }
 

core/src/test/resources/logback-test.xml

@@ -20,8 +20,4 @@
     <logger name="io.netty" level="WARN" />
     <logger name="org.testcontainers.shaded" level="WARN"/>
 
-    <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
-        <Marker>PROFILER</Marker>
-        <OnMatch>DENY</OnMatch>
-    </turboFilter>
 </configuration>

modules/couchbase/src/test/resources/logback-test.xml

@@ -22,8 +22,4 @@
     <logger name="org.testcontainers.shaded" level="WARN"/>
     <logger name="com.zaxxer.hikari" level="INFO"/>
 
-    <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
-        <Marker>PROFILER</Marker>
-        <OnMatch>DENY</OnMatch>
-    </turboFilter>
-</configuration>
+</configuration>

modules/elasticsearch/src/test/resources/logback-test.xml

@@ -14,8 +14,4 @@
 
     <logger name="org.testcontainers.shaded" level="WARN"/>
 
-    <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
-        <Marker>PROFILER</Marker>
-        <OnMatch>DENY</OnMatch>
-    </turboFilter>
 </configuration>

modules/jdbc-test/src/test/resources/logback-test.xml

@@ -22,8 +22,4 @@
     <logger name="org.testcontainers.shaded" level="WARN"/>
     <logger name="com.zaxxer.hikari" level="INFO"/>
 
-    <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
-        <Marker>PROFILER</Marker>
-        <OnMatch>DENY</OnMatch>
-    </turboFilter>
-</configuration>
+</configuration>

modules/nginx/src/test/resources/logback-test.xml

@@ -22,8 +22,4 @@
     <logger name="org.testcontainers.shaded" level="WARN"/>
     <logger name="com.zaxxer.hikari" level="INFO"/>
 
-    <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
-        <Marker>PROFILER</Marker>
-        <OnMatch>DENY</OnMatch>
-    </turboFilter>
-</configuration>
+</configuration>