diff --git a/docker/Dockerfile b/docker/Dockerfile index 228f44cec9..f527f26232 100644 --- a/docker/Dockerfile +++ b/docker/Dockerfile @@ -330,16 +330,6 @@ RUN cd /tmp \ USER seluser WORKDIR /home/seluser -#========== -# Selenium -#========== -# Layer size: medium: 21.23 MB -ENV SEL_MAJOR_VER="${selenium-server.major-minor.version}" \ - SEL_PATCH_LEVEL_VER="${selenium-server.patch-level.version}" -ENV SEL_VER="${SEL_MAJOR_VER}.${SEL_PATCH_LEVEL_VER}" -RUN export SELBASE="https://selenium-release.storage.googleapis.com" \ - && export SELPATH="${SEL_MAJOR_VER}/selenium-server-standalone-${SEL_VER}.jar" \ - && wget -nv ${SELBASE}/${SELPATH} #========== # Zalenium @@ -383,7 +373,7 @@ COPY zalenium.sh \ index.html \ zalando.ico \ logging_info.properties \ - logging_fine.properties \ + logging_debug.properties \ logback.xml \ /home/seluser/ COPY scm-source.json / diff --git a/docs/_posts/2000-01-05-docker.md b/docs/_posts/2000-01-05-docker.md index f4a6e59fb0..f6959d1d06 100644 --- a/docs/_posts/2000-01-05-docker.md +++ b/docs/_posts/2000-01-05-docker.md @@ -471,6 +471,11 @@ you can explicitly tell Zalenium which version you are using via `-e DOCKER=17.0 false Enables LogLevel.FINE. + + --logJson + false + Output logs in json format + --seleniumImageName "elgalu/selenium" diff --git a/pom.xml b/pom.xml index e9250cd9e1..58a6da11ad 100644 --- a/pom.xml +++ b/pom.xml @@ -57,7 +57,9 @@ 3.1.0 6.14.2 1.7.25 + 5.0 1.8 + 1.2.3 1.8 3.7.0 3.0.2 @@ -112,11 +114,36 @@ + + ch.qos.logback + logback-core + ${ch.qos.logback.version} + + + ch.qos.logback + logback-classic + ${ch.qos.logback.version} + + + ch.qos.logback + logback-access + ${ch.qos.logback.version} + org.slf4j - slf4j-log4j12 + jul-to-slf4j ${slf4j.version} + + org.slf4j + slf4j-simple + ${slf4j.version} + + + net.logstash.logback + logstash-logback-encoder + ${logstash-logback-encoder.version} + io.fabric8 openshift-server-mock @@ -198,7 +225,7 @@ src/main/resources logging_info.properties - logging_fine.properties + logging_debug.properties logback.xml @@ -260,32 +287,7 @@ - - org.seleniumhq.selenium:* - com.beust:* - net.bytebuddy:* - - org.w3c.css:* - net.sourceforge.cssparser:* - net.sourceforge.htmlunit:* - org.eclipse.jetty:* - org.eclipse.jetty.websocket:* - commons-codec:* - commons-io:* - commons-logging:* - commons-net:* - com.google.guava:* - com.google.code.findbugs:* - com.google.errorprone:* - com.google.j2objc:* - org.codehaus.mojo:* - org.apache.httpcomponents:* - net.jcip:* - xalan:* - xerces:* - xml-apis:* - org.yaml:* - + diff --git a/scripts/zalenium.sh b/scripts/zalenium.sh index 44ea69dfe8..b509f94d42 100755 --- a/scripts/zalenium.sh +++ b/scripts/zalenium.sh @@ -7,7 +7,6 @@ CHROME_CONTAINERS=1 FIREFOX_CONTAINERS=1 DESIRED_CONTAINERS=2 MAX_DOCKER_SELENIUM_CONTAINERS=10 -SELENIUM_ARTIFACT="$(pwd)/selenium-server-standalone-${selenium-server.major-minor.version}.${selenium-server.patch-level.version}.jar" ZALENIUM_ARTIFACT="$(pwd)/${project.build.finalName}.jar" DEPRECATED_PARAMETERS=false SAUCE_LABS_ENABLED=false @@ -21,6 +20,7 @@ SEND_ANONYMOUS_USAGE_INFO=true START_TUNNEL=false DEBUG_ENABLED=false KEEP_ONLY_FAILED_TESTS=false +LOG_JSON=false NEW_SESSION_WAIT_TIMEOUT=${NEW_SESSION_WAIT_TIMEOUT:-300000} GA_TRACKING_ID="UA-88441352-3" @@ -284,13 +284,6 @@ StartUp() fi fi - log "Running additional checks..." - if [ ! -f ${SELENIUM_ARTIFACT} ]; - then - echo "Selenium JAR not present, exiting start script." - exit 2 - fi - if [ ! -f ${ZALENIUM_ARTIFACT} ]; then echo "Zalenium JAR not present, exiting start script." @@ -423,13 +416,20 @@ StartUp() DEBUG_MODE=info if [ "$DEBUG_ENABLED" = true ]; then - DEBUG_MODE=fine + DEBUG_MODE=debug DEBUG_FLAG=-debug fi - java ${ZALENIUM_EXTRA_JVM_PARAMS} -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ - -Dlogback.configurationFile=logback.xml \ - -cp ${SELENIUM_ARTIFACT}:${ZALENIUM_ARTIFACT} org.openqa.grid.selenium.GridLauncherV3 \ + LOGBACK_APPENDER=STDOUT + + if [ "$LOG_JSON" == true ]; then + LOGBACK_APPENDER=JSON + fi + + java ${ZALENIUM_EXTRA_JVM_PARAMS} -Dlogback.loglevel=${DEBUG_MODE} \ + -Dlogback.appender=${LOGBACK_APPENDER} \ + -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ + -cp ${ZALENIUM_ARTIFACT} org.openqa.grid.selenium.GridLauncherV3 \ -role hub -port 4445 -newSessionWaitTimeout ${NEW_SESSION_WAIT_TIMEOUT} \ -servlet de.zalando.ep.zalenium.servlet.LivePreviewServlet \ -servlet de.zalando.ep.zalenium.servlet.ZaleniumConsoleServlet \ @@ -452,8 +452,9 @@ StartUp() echo "Starting DockerSeleniumStarter node..." - java -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ - -jar ${SELENIUM_ARTIFACT} -role node -hub http://localhost:4444/grid/register \ + java -Dlogback.loglevel=${DEBUG_MODE} -Dlogback.appender=${LOGBACK_APPENDER} \ + -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ + -cp ${ZALENIUM_ARTIFACT} org.openqa.grid.selenium.GridLauncherV3 -role node -hub http://localhost:4444/grid/register \ -registerCycle 0 -proxy de.zalando.ep.zalenium.proxy.DockerSeleniumStarterRemoteProxy \ -nodePolling 90000 -port 30000 ${DEBUG_FLAG} & echo $! > ${PID_PATH_DOCKER_SELENIUM_NODE} @@ -477,8 +478,9 @@ StartUp() if [ "$SAUCE_LABS_ENABLED" = true ]; then echo "Starting Sauce Labs node..." - java -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ - -jar ${SELENIUM_ARTIFACT} -role node -hub http://localhost:4444/grid/register \ + java -Dlogback.loglevel=${DEBUG_MODE} -Dlogback.appender=${LOGBACK_APPENDER} \ + -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ + -cp ${ZALENIUM_ARTIFACT} org.openqa.grid.selenium.GridLauncherV3 -role node -hub http://localhost:4444/grid/register \ -registerCycle 0 -proxy de.zalando.ep.zalenium.proxy.SauceLabsRemoteProxy \ -nodePolling 90000 -port 30001 ${DEBUG_FLAG} & echo $! > ${PID_PATH_SAUCE_LABS_NODE} @@ -504,8 +506,9 @@ StartUp() if [ "$BROWSER_STACK_ENABLED" = true ]; then echo "Starting Browser Stack node..." - java -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ - -jar ${SELENIUM_ARTIFACT} -role node -hub http://localhost:4444/grid/register \ + java -Dlogback.loglevel=${DEBUG_MODE} -Dlogback.appender=${LOGBACK_APPENDER} \ + -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ + -cp ${ZALENIUM_ARTIFACT} org.openqa.grid.selenium.GridLauncherV3 -role node -hub http://localhost:4444/grid/register \ -registerCycle 0 -proxy de.zalando.ep.zalenium.proxy.BrowserStackRemoteProxy \ -nodePolling 90000 -port 30002 ${DEBUG_FLAG} & echo $! > ${PID_PATH_BROWSER_STACK_NODE} @@ -530,8 +533,9 @@ StartUp() if [ "$TESTINGBOT_ENABLED" = true ]; then echo "Starting TestingBot node..." - java -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ - -jar ${SELENIUM_ARTIFACT} -role node -hub http://localhost:4444/grid/register \ + java -Dlogback.loglevel=${DEBUG_MODE} -Dlogback.appender=${LOGBACK_APPENDER} \ + -Djava.util.logging.config.file=logging_${DEBUG_MODE}.properties \ + -cp ${ZALENIUM_ARTIFACT} org.openqa.grid.selenium.GridLauncherV3 -role node -hub http://localhost:4444/grid/register \ -registerCycle 0 -proxy de.zalando.ep.zalenium.proxy.TestingBotRemoteProxy \ -nodePolling 90000 -port 30003 ${DEBUG_FLAG} & echo $! > ${PID_PATH_TESTINGBOT_NODE} @@ -769,6 +773,7 @@ function usage() echo -e "\t --timeZone -> Sets the time zone in the containers. Defaults to \"Europe/Berlin\"" echo -e "\t --sendAnonymousUsageInfo -> Collects anonymous usage of the tool. Defaults to 'true'" echo -e "\t --debugEnabled -> enables LogLevel.FINE. Defaults to 'false'" + echo -e "\t --logJson -> output logs in json format. Defaults to 'false'" echo -e "\t --seleniumImageName -> enables overriding of the Docker selenium image to use. Defaults to \"elgalu/selenium\"" echo -e "\t --gridUser -> allows you to specify a user to enable basic auth protection, --gridPassword must be provided also." echo -e "\t --gridPassword -> allows you to specify a password to enable basic auth protection, --gridUser must be provided also." @@ -848,6 +853,9 @@ case ${SCRIPT_ACTION} in --debugEnabled) DEBUG_ENABLED=${VALUE} ;; + --logJson) + LOG_JSON=${VALUE} + ;; --seleniumImageName) SELENIUM_IMAGE_NAME=${VALUE} ;; diff --git a/src/main/java/de/zalando/ep/zalenium/container/DockerContainerClient.java b/src/main/java/de/zalando/ep/zalenium/container/DockerContainerClient.java index b195cd6841..ec95b18980 100644 --- a/src/main/java/de/zalando/ep/zalenium/container/DockerContainerClient.java +++ b/src/main/java/de/zalando/ep/zalenium/container/DockerContainerClient.java @@ -28,8 +28,10 @@ import java.util.Map; import java.util.Optional; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import java.util.stream.Collectors; import de.zalando.ep.zalenium.proxy.DockerSeleniumStarterRemoteProxy; @@ -58,7 +60,7 @@ public class DockerContainerClient implements ContainerClient { }; private static final Environment defaultEnvironment = new Environment(); private static Environment env = defaultEnvironment; - private final Logger logger = Logger.getLogger(DockerContainerClient.class.getName()); + private final Logger logger = LoggerFactory.getLogger(DockerContainerClient.class.getName()); private final GoogleAnalyticsApi ga = new GoogleAnalyticsApi(); private DockerClient dockerClient = new DefaultDockerClient("unix:///var/run/docker.sock"); private String nodeId; @@ -91,7 +93,7 @@ private String getContainerId(String containerName) { try { containerList = dockerClient.listContainers(DockerClient.ListContainersParam.allContainers()); } catch (DockerException | InterruptedException e) { - logger.log(Level.FINE, nodeId + " Error while getting containerId", e); + logger.debug(nodeId + " Error while getting containerId", e); ga.trackException(e); } @@ -104,7 +106,7 @@ public InputStream copyFiles(String containerId, String folderName) { try { return dockerClient.archiveContainer(containerId, folderName); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Something happened while copying the folder " + folderName + ", " + + logger.warn(nodeId + " Something happened while copying the folder " + folderName + ", " + "most of the time it is an issue while closing the input/output stream, which is usually OK.", e); } return null; @@ -114,7 +116,7 @@ public void stopContainer(String containerId) { try { dockerClient.stopContainer(containerId, 5); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while stopping the container", e); + logger.warn(nodeId + " Error while stopping the container", e); ga.trackException(e); } } @@ -126,18 +128,18 @@ public void executeCommand(String containerId, String[] command, boolean waitFor DockerClient.ExecCreateParam.attachStdout(), DockerClient.ExecCreateParam.attachStderr(), DockerClient.ExecCreateParam.attachStdin()); final LogStream output = dockerClient.execStart(execCreation.id()); - logger.log(Level.INFO, () -> String.format("%s %s", nodeId, Arrays.toString(command))); + logger.info(String.format("%s %s", nodeId, Arrays.toString(command))); if (waitForExecution) { try { String commandOutput = output.readFully(); - logger.log(Level.FINE, () -> String.format("%s %s", nodeId, commandOutput)); + logger.debug(String.format("%s %s", nodeId, commandOutput)); } catch (Exception e) { - logger.log(Level.FINE, nodeId + " Error while executing the output.readFully()", e); + logger.debug(nodeId + " Error while executing the output.readFully()", e); ga.trackException(e); } } } catch (DockerException | InterruptedException e) { - logger.log(Level.FINE, nodeId + " Error while executing the command", e); + logger.debug(nodeId + " Error while executing the command", e); ga.trackException(e); } } @@ -147,7 +149,7 @@ public String getLatestDownloadedImage(String imageName) { try { images = dockerClient.listImages(DockerClient.ListImagesParam.byName(imageName)); if (images.isEmpty()) { - logger.log(Level.SEVERE, nodeId + " A downloaded docker-selenium image was not found!"); + logger.error(nodeId + " A downloaded docker-selenium image was not found!"); return imageName; } for (int i = images.size() - 1; i >= 0; i--) { @@ -158,7 +160,7 @@ public String getLatestDownloadedImage(String imageName) { images.sort((o1, o2) -> o2.created().compareTo(o1.created())); return images.get(0).repoTags().get(0); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while executing the command", e); + logger.warn(nodeId + " Error while executing the command", e); ga.trackException(e); } return imageName; @@ -175,7 +177,7 @@ public int getRunningContainers(String image) { } return numberOfDockerSeleniumContainers; } catch (InterruptedException | DockerException e) { - logger.log(Level.WARNING, nodeId + " Error while getting number of running containers", e); + logger.warn(nodeId + " Error while getting number of running containers", e); ga.trackException(e); } return 0; @@ -210,7 +212,7 @@ public ContainerCreationStatus createContainer(String zaleniumContainerName, Str String hostName = dockerClient.info().name(); extraHosts.add(String.format("%s:%s", hostName, "127.0.1.0")); } catch (DockerException | InterruptedException e) { - logger.log(Level.FINE, nodeId + " Error while getting host name", e); + logger.debug(nodeId + " Error while getting host name", e); } } @@ -256,7 +258,7 @@ public ContainerCreationStatus createContainer(String zaleniumContainerName, Str } } } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while checking (and pulling) if the image is present", e); + logger.warn(nodeId + " Error while checking (and pulling) if the image is present", e); ga.trackException(e); } @@ -265,7 +267,7 @@ public ContainerCreationStatus createContainer(String zaleniumContainerName, Str dockerClient.startContainer(container.id()); return new ContainerCreationStatus(true, containerName, nodePort); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while starting a new container", e); + logger.warn(nodeId + " Error while starting a new container", e); ga.trackException(e); return new ContainerCreationStatus(false); } @@ -293,7 +295,7 @@ private void loadSeleniumContainerLabels() { seleniumContainerLabels.put(split[0], split[1]); } } catch (Exception e) { - logger.log(Level.WARNING, nodeId + " Error while retrieving the added labels for the Selenium containers.", e); + logger.warn(nodeId + " Error while retrieving the added labels for the Selenium containers.", e); ga.trackException(e); } } @@ -318,7 +320,7 @@ private void loadIsZaleniumPrivileged(String zaleniumContainerName) { containerInfo = dockerClient.inspectContainer(containerId); isZaleniumPrivileged = containerInfo.hostConfig().privileged(); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while getting value to check if Zalenium is running in privileged mode.", e); + logger.warn(nodeId + " Error while getting value to check if Zalenium is running in privileged mode.", e); ga.trackException(e); } } @@ -336,7 +338,7 @@ private void loadMountedFolders(String zaleniumContainerName) { try { containerInfo = dockerClient.inspectContainer(containerId); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while getting mounted folders and env vars.", e); + logger.warn(nodeId + " Error while getting mounted folders and env vars.", e); ga.trackException(e); } @@ -393,7 +395,7 @@ private synchronized List getContainerExtraHosts(String zaleniumContaine containerInfo = dockerClient.inspectContainer(containerId); zaleniumExtraHosts = containerInfo.hostConfig().extraHosts(); } catch (DockerException | InterruptedException e) { - logger.log(Level.WARNING, nodeId + " Error while getting Zalenium extra hosts.", e); + logger.warn(nodeId + " Error while getting Zalenium extra hosts.", e); ga.trackException(e); } return Optional.ofNullable(zaleniumExtraHosts).orElse(DEFAULT_DOCKER_EXTRA_HOSTS); @@ -433,7 +435,7 @@ private synchronized String getZaleniumNetwork(String zaleniumContainerName) { } } } catch (DockerException | InterruptedException e) { - logger.log(Level.FINE, nodeId + " Error while getting Zalenium network.", e); + logger.debug(nodeId + " Error while getting Zalenium network.", e); ga.trackException(e); } zaleniumNetwork = DEFAULT_DOCKER_NETWORK_MODE; @@ -454,7 +456,7 @@ public String getContainerIp(String containerName) { } return containerInfo.networkSettings().ipAddress(); } catch (DockerException | InterruptedException e) { - logger.log(Level.FINE, nodeId + " Error while getting the container IP.", e); + logger.debug(nodeId + " Error while getting the container IP.", e); ga.trackException(e); } return null; diff --git a/src/main/java/de/zalando/ep/zalenium/container/kubernetes/KubernetesContainerClient.java b/src/main/java/de/zalando/ep/zalenium/container/kubernetes/KubernetesContainerClient.java index 264056d387..2fca82fbe6 100755 --- a/src/main/java/de/zalando/ep/zalenium/container/kubernetes/KubernetesContainerClient.java +++ b/src/main/java/de/zalando/ep/zalenium/container/kubernetes/KubernetesContainerClient.java @@ -16,8 +16,10 @@ import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Function; import java.util.function.Supplier; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import java.util.stream.Collectors; import org.apache.commons.lang.StringUtils; @@ -46,7 +48,7 @@ public class KubernetesContainerClient implements ContainerClient { "/dev/shm" }; - private static final Logger logger = Logger.getLogger(KubernetesContainerClient.class.getName()); + private static final Logger logger = LoggerFactory.getLogger(KubernetesContainerClient.class.getName()); private KubernetesClient client; @@ -71,7 +73,7 @@ public class KubernetesContainerClient implements ContainerClient { public KubernetesContainerClient(Environment environment, Function createDoneablePod, KubernetesClient client) { - logger.log(Level.INFO, "Initialising Kubernetes support"); + logger.info("Initialising Kubernetes support"); this.environment = environment; this.createDoneablePod = createDoneablePod; @@ -98,7 +100,7 @@ public KubernetesContainerClient(Environment environment, buildResourceMaps(); - logger.log(Level.INFO, + logger.info( "Kubernetes support initialised.\n" + "\tPod name: {0}\n" + "\tapp label: {1}\n" @@ -108,7 +110,7 @@ public KubernetesContainerClient(Environment environment, new Object[] {hostname, appName, zaleniumAppName, seleniumPodLimits.toString(), seleniumPodRequests.toString() }); } catch (Exception e) { - logger.log(Level.WARNING, "Error initialising Kubernetes support.", e); + logger.warn("Error initialising Kubernetes support.", e); } } @@ -224,7 +226,7 @@ public void executeCommand(String containerId, String[] command, boolean waitFor final CountDownLatch latch = new CountDownLatch(1); ByteArrayOutputStream baos = new ByteArrayOutputStream(); - logger.log(Level.INFO, () -> String.format("%s %s", containerId, Arrays.toString(command))); + logger.info(String.format("%s %s", containerId, Arrays.toString(command))); ExecWatch exec = client.pods().withName(containerId).writingOutput(baos).writingError(baos).usingListener(new ExecListener() { @Override @@ -234,7 +236,7 @@ public void onOpen(Response response) { @Override public void onFailure(Throwable t, Response response) { - logger.log(Level.SEVERE, t, () -> String.format("%s Failed to execute command %s", containerId, Arrays.toString(command))); + logger.error(String.format("%s Failed to execute command %s", containerId, Arrays.toString(command)), t); latch.countDown(); } @@ -250,12 +252,12 @@ public void onClose(int code, try { latch.await(); } catch (InterruptedException e) { - logger.log(Level.SEVERE, e, () -> String.format("%s Failed to execute command %s", containerId, Arrays.toString(command))); + logger.error(String.format("%s Failed to execute command %s", containerId, Arrays.toString(command)), e); } finally { exec.close(); } - logger.log(Level.INFO, () -> String.format("%s %s", containerId, baos.toString())); + logger.info(String.format("%s %s", containerId, baos.toString())); return null; }; @@ -279,7 +281,8 @@ public String getLatestDownloadedImage(String imageName) { @Override public int getRunningContainers(String image) { PodList list = client.pods().withLabels(createdByZaleniumMap).list(); - logger.log(Level.FINE, "Pods in the list " + list.getItems().size()); + logger.debug("Pods in the list " + list.getItems().size()); + int count=0; for (Pod pod : list.getItems()) { String phase = pod.getStatus().getPhase(); @@ -342,7 +345,7 @@ public String getContainerIp(String containerName) { Pod pod = client.pods().withName(containerName).get(); if (pod != null) { String podIP = pod.getStatus().getPodIP(); - logger.log(Level.FINE, String.format("Pod %s, IP -> %s", containerName, podIP)); + logger.debug(String.format("Pod %s, IP -> %s", containerName, podIP)); return podIP; } else { @@ -351,7 +354,7 @@ public String getContainerIp(String containerName) { } private void deleteSeleniumPods() { - logger.log(Level.INFO, "About to clean up any left over selenium pods created by Zalenium"); + logger.info("About to clean up any left over selenium pods created by Zalenium"); client.pods().withLabels(createdByZaleniumMap).delete(); } @@ -387,7 +390,7 @@ public ContainerClientRegistration registerNode(String zaleniumContainerName, UR registration.setNoVncPort(noVncPortInt); } else { - logger.log(Level.WARNING, "{0} Couldn't find NOVNC_PORT, live preview will not work.", containerId); + logger.warn("{0} Couldn't find NOVNC_PORT, live preview will not work.", containerId); } registration.setIpAddress(currentPod.getStatus().getPodIP()); @@ -424,9 +427,7 @@ public void onOpen(Response response) { @Override public void onFailure(Throwable t, Response response) { - logger.log(Level.SEVERE, - t, - () -> String.format("%s Failed to execute command %s", containerId, Arrays.toString(command))); + logger.error(String.format("%s Failed to execute command %s", containerId, Arrays.toString(command)), t); } @Override @@ -438,7 +439,7 @@ public void onClose(int code, boolean isClosed = closedResource.getAndSet(true); boolean hasErrors = stderr.size() > 0; if (!isClosed && hasErrors) { - logger.log(Level.SEVERE,() -> String.format("%s Copy files command failed with:\n\tcommand: %s\n\t stderr:\n%s", + logger.error(String.format("%s Copy files command failed with:\n\tcommand: %s\n\t stderr:\n%s", containerId, Arrays.toString(command), stderr.toString())); @@ -451,9 +452,7 @@ public void waitForInputStreamToConnect() { this.openLatch.await(); } catch (InterruptedException e) { - logger.log(Level.SEVERE, - e, - () -> String.format("%s Failed to execute command %s", containerId, Arrays.toString(command))); + logger.error( String.format("%s Failed to execute command %s", containerId, Arrays.toString(command)), e); } } } diff --git a/src/main/java/de/zalando/ep/zalenium/dashboard/Dashboard.java b/src/main/java/de/zalando/ep/zalenium/dashboard/Dashboard.java index 380168d677..95c394002c 100644 --- a/src/main/java/de/zalando/ep/zalenium/dashboard/Dashboard.java +++ b/src/main/java/de/zalando/ep/zalenium/dashboard/Dashboard.java @@ -15,8 +15,10 @@ import java.util.ArrayList; import java.util.List; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import static java.nio.charset.StandardCharsets.*; @@ -39,7 +41,7 @@ public class Dashboard { private static final String ZALANDO_ICO = "zalando.ico"; private static final String CSS_FOLDER = "/css"; private static final String JS_FOLDER = "/js"; - private static final Logger LOGGER = Logger.getLogger(Dashboard.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(Dashboard.class.getName()); private static List executedTestsInformation = new ArrayList<>(); private static CommonProxyUtilities commonProxyUtilities = new CommonProxyUtilities(); private static int executedTests = 0; @@ -107,8 +109,8 @@ public static synchronized void updateDashboard(TestInformation testInformation) executedTestsWithVideo++; } - LOGGER.log(Level.FINE, "Test count: " + executedTests); - LOGGER.log(Level.FINE, "Test count with video: " + executedTestsWithVideo); + LOGGER.debug("Test count: " + executedTests); + LOGGER.debug("Test count with video: " + executedTestsWithVideo); JsonObject testQuantities = new JsonObject(); testQuantities.addProperty(EXECUTED_TESTS_FIELD, executedTests); testQuantities.addProperty(EXECUTED_TESTS_WITH_VIDEO_FIELD, executedTestsWithVideo); @@ -136,7 +138,7 @@ public static synchronized void updateDashboard(TestInformation testInformation) } executedTestsInformation.add(testInformation); } catch (IOException e) { - LOGGER.log(Level.WARNING, "Error while updating the dashboard.", e); + LOGGER.warn("Error while updating the dashboard.", e); } } @@ -172,7 +174,7 @@ public static void synchronizeExecutedTestsValues(File testCountFile) { executedTests = Integer.parseInt(executedTestsInFile); executedTestsWithVideo = Integer.parseInt(executedTestsWithVideoInFile); } catch (Exception e) { - LOGGER.log(Level.WARNING, e.toString(), e); + LOGGER.warn(e.toString(), e); } } else { executedTests = 0; @@ -192,7 +194,7 @@ public static void loadTestInformationFromFile() { } } } catch (Exception e) { - LOGGER.log(Level.WARNING, e.toString(), e); + LOGGER.warn(e.toString(), e); } } @@ -205,7 +207,7 @@ public static void dumpTestInformationToFile() { FileUtils.writeStringToFile(testInformationFile, gson.toJson(executedTestsInformation), UTF_8); } } catch (Exception e) { - LOGGER.log(Level.WARNING, e.toString(), e); + LOGGER.warn(e.toString(), e); } } diff --git a/src/main/java/de/zalando/ep/zalenium/dashboard/DashboardCleanupServlet.java b/src/main/java/de/zalando/ep/zalenium/dashboard/DashboardCleanupServlet.java index 4c27f500eb..f29c06df21 100644 --- a/src/main/java/de/zalando/ep/zalenium/dashboard/DashboardCleanupServlet.java +++ b/src/main/java/de/zalando/ep/zalenium/dashboard/DashboardCleanupServlet.java @@ -3,8 +3,10 @@ import java.io.ByteArrayInputStream; import java.io.IOException; import java.io.InputStream; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; @@ -19,7 +21,7 @@ public class DashboardCleanupServlet extends RegistryBasedServlet { private static final String DO_CLEANUP_ALL = "doCleanupAll"; private static final long serialVersionUID = 1L; - private static final Logger LOGGER = Logger.getLogger(DashboardCleanupServlet.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(DashboardCleanupServlet.class.getName()); @SuppressWarnings("unused") public DashboardCleanupServlet() { @@ -45,7 +47,7 @@ protected void process(HttpServletRequest request, HttpServletResponse response) try { action = request.getParameter("action"); } catch (Exception e) { - LOGGER.log(Level.FINE, e.toString(), e); + LOGGER.debug(e.toString(), e); } String resultMsg; diff --git a/src/main/java/de/zalando/ep/zalenium/matcher/DockerSeleniumCapabilityMatcher.java b/src/main/java/de/zalando/ep/zalenium/matcher/DockerSeleniumCapabilityMatcher.java index 68a273e893..85763bea2a 100644 --- a/src/main/java/de/zalando/ep/zalenium/matcher/DockerSeleniumCapabilityMatcher.java +++ b/src/main/java/de/zalando/ep/zalenium/matcher/DockerSeleniumCapabilityMatcher.java @@ -12,8 +12,10 @@ import java.util.List; import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class DockerSeleniumCapabilityMatcher extends DefaultCapabilityMatcher { private static final List ZALENIUM_CUSTOM_CAPABILITIES_NO_PREFIX = Arrays.asList( @@ -29,7 +31,7 @@ public class DockerSeleniumCapabilityMatcher extends DefaultCapabilityMatcher { private static String chromeVersion = null; private static String firefoxVersion = null; private static AtomicBoolean browserVersionsFetched = new AtomicBoolean(false); - private final Logger logger = Logger.getLogger(DockerSeleniumCapabilityMatcher.class.getName()); + private final Logger logger = LoggerFactory.getLogger(DockerSeleniumCapabilityMatcher.class.getName()); private DefaultRemoteProxy proxy; public DockerSeleniumCapabilityMatcher(DefaultRemoteProxy defaultRemoteProxy) { @@ -39,11 +41,11 @@ public DockerSeleniumCapabilityMatcher(DefaultRemoteProxy defaultRemoteProxy) { @Override public boolean matches(Map nodeCapability, Map requestedCapability) { - logger.log(Level.FINE, ()-> String.format("Validating %s in node with capabilities %s", requestedCapability, + logger.debug(String.format("Validating %s in node with capabilities %s", requestedCapability, nodeCapability)); if (!requestedCapability.containsKey(CapabilityType.BROWSER_NAME)) { - logger.log(Level.FINE, () -> String.format("%s Capability %s does not contain %s key, a docker-selenium " + + logger.debug(String.format("%s Capability %s does not contain %s key, a docker-selenium " + "node cannot be started without it", proxy.getId(), requestedCapability, CapabilityType.BROWSER_NAME)); return false; } diff --git a/src/main/java/de/zalando/ep/zalenium/matcher/ZaleniumCapabilityMatcher.java b/src/main/java/de/zalando/ep/zalenium/matcher/ZaleniumCapabilityMatcher.java index 6de73a700e..817a06a137 100644 --- a/src/main/java/de/zalando/ep/zalenium/matcher/ZaleniumCapabilityMatcher.java +++ b/src/main/java/de/zalando/ep/zalenium/matcher/ZaleniumCapabilityMatcher.java @@ -6,8 +6,10 @@ import org.openqa.grid.selenium.proxy.DefaultRemoteProxy; import java.util.Map; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * The purpose of this class is to check if the capabilities cannot be supplied by docker-selenium so they can be just @@ -16,7 +18,7 @@ public class ZaleniumCapabilityMatcher extends DefaultCapabilityMatcher { - private static final Logger logger = Logger.getLogger(ZaleniumCapabilityMatcher.class.getName()); + private static final Logger logger = LoggerFactory.getLogger(ZaleniumCapabilityMatcher.class.getName()); private DefaultRemoteProxy proxy; @@ -27,13 +29,13 @@ public ZaleniumCapabilityMatcher(DefaultRemoteProxy defaultRemoteProxy) { @Override public boolean matches(Map nodeCapability, Map requestedCapability) { - logger.log(Level.FINE, ()-> String.format("Validating %s in node with capabilities %s", requestedCapability, + logger.debug(String.format("Validating %s in node with capabilities %s", requestedCapability, nodeCapability)); for (RemoteProxy remoteProxy : proxy.getRegistry().getAllProxies()) { if ((remoteProxy instanceof DockerSeleniumStarterRemoteProxy) && remoteProxy.hasCapability(requestedCapability)) { - logger.log(Level.FINE, "Capability supported by docker-selenium, should not be processed by " + + logger.debug("Capability supported by docker-selenium, should not be processed by " + "a Cloud Testing Provider: {0}", requestedCapability); return false; } diff --git a/src/main/java/de/zalando/ep/zalenium/proxy/BrowserStackRemoteProxy.java b/src/main/java/de/zalando/ep/zalenium/proxy/BrowserStackRemoteProxy.java index 9a3751debb..849185e237 100644 --- a/src/main/java/de/zalando/ep/zalenium/proxy/BrowserStackRemoteProxy.java +++ b/src/main/java/de/zalando/ep/zalenium/proxy/BrowserStackRemoteProxy.java @@ -10,8 +10,10 @@ import java.util.ArrayList; import java.util.List; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /* This class should work in a similar way as its sibling, SauceLabsRemoteProxy @@ -21,7 +23,7 @@ public class BrowserStackRemoteProxy extends CloudTestingRemoteProxy { private static final String BROWSER_STACK_URL = "http://hub-cloud.browserstack.com:80"; private static final String BROWSER_STACK_ACCOUNT_INFO = "https://www.browserstack.com/automate/plan.json"; - private static final Logger logger = Logger.getLogger(BrowserStackRemoteProxy.class.getName()); + private static final Logger logger = LoggerFactory.getLogger(BrowserStackRemoteProxy.class.getName()); private static final String BROWSER_STACK_USER = getEnv().getStringEnvVariable("BROWSER_STACK_USER", ""); private static final String BROWSER_STACK_KEY = getEnv().getStringEnvVariable("BROWSER_STACK_KEY", ""); private static final String BROWSER_STACK_PROXY_NAME = "BrowserStack"; @@ -43,11 +45,11 @@ private static RegistrationRequest updateBSCapabilities(RegistrationRequest regi } else { browserStackAccountConcurrency = bsAccountInfo.getAsJsonObject().get("parallel_sessions_max_allowed").getAsInt(); } - logger.log(Level.INFO, logMessage); + logger.info(logMessage); return addCapabilitiesToRegistrationRequest(registrationRequest, browserStackAccountConcurrency, BROWSER_STACK_PROXY_NAME); } catch (Exception e) { - logger.log(Level.SEVERE, e.toString(), e); + logger.error(e.toString(), e); getGa().trackException(e); } return addCapabilitiesToRegistrationRequest(registrationRequest, 1, BROWSER_STACK_PROXY_NAME); diff --git a/src/main/java/de/zalando/ep/zalenium/proxy/CloudTestingRemoteProxy.java b/src/main/java/de/zalando/ep/zalenium/proxy/CloudTestingRemoteProxy.java index 2ef9f4ee68..35aa8234bb 100644 --- a/src/main/java/de/zalando/ep/zalenium/proxy/CloudTestingRemoteProxy.java +++ b/src/main/java/de/zalando/ep/zalenium/proxy/CloudTestingRemoteProxy.java @@ -40,8 +40,10 @@ import java.net.URL; import java.nio.charset.StandardCharsets; import java.util.Map; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; @SuppressWarnings("WeakerAccess") @ManagedService(description = "CloudTesting TestSlots") @@ -51,7 +53,7 @@ public class CloudTestingRemoteProxy extends DefaultRemoteProxy { public static final long DEFAULT_MAX_TEST_IDLE_TIME_SECS = 90L; @VisibleForTesting public static boolean addToDashboardCalled = false; - private static final Logger logger = Logger.getLogger(CloudTestingRemoteProxy.class.getName()); + private static final Logger logger = LoggerFactory.getLogger(CloudTestingRemoteProxy.class.getName()); private static final GoogleAnalyticsApi defaultGA = new GoogleAnalyticsApi(); private static final CommonProxyUtilities defaultCommonProxyUtilities = new CommonProxyUtilities(); private static final Environment defaultEnvironment = new Environment(); @@ -134,8 +136,8 @@ public TestSession getNewSession(Map requestedCapability) { if (!hasCapability(requestedCapability)) { return null; } - logger.log(Level.INFO, () ->"Test will be forwarded to " + getProxyName() + ", " + requestedCapability); - logger.log(Level.INFO, () ->"Currently using " + getNumberOfSessions() + " paralell sessions towards " + getProxyName() + ". Attempt to start one more."); + logger.info("Test will be forwarded to " + getProxyName() + ", " + requestedCapability); + logger.info("Currently using " + getNumberOfSessions() + " paralell sessions towards " + getProxyName() + ". Attempt to start one more."); return super.getNewSession(requestedCapability); } @@ -155,7 +157,7 @@ public void beforeCommand(TestSession session, HttpServletRequest request, HttpS try { seleniumRequest.setBody(jsonObject.toString()); } catch (UnsupportedEncodingException e) { - logger.log(Level.SEVERE, () ->"Error while setting the body request in " + getProxyName() + logger.error("Error while setting the body request in " + getProxyName() + ", " + jsonObject.toString()); } } @@ -254,7 +256,7 @@ public void addTestToDashboard(String seleniumSessionId, boolean testCompleted) Dashboard.updateDashboard(testInformation); addToDashboardCalled = true; } catch (Exception e) { - logger.log(Level.SEVERE, e.toString(), e); + logger.error(e.toString(), e); } }, "CloudTestingRemoteProxy addTestToDashboard seleniumSessionId [" + seleniumSessionId + "] testCompleted [" + testCompleted + "]").start(); @@ -282,7 +284,7 @@ public URL getRemoteHost() { try { return new URL(getCloudTestingServiceUrl()); } catch (MalformedURLException e) { - logger.log(Level.SEVERE, e.toString(), e); + logger.error(e.toString(), e); getGa().trackException(e); } return null; @@ -295,7 +297,7 @@ private void createFeatureNotImplementedFile(String logsFolderPath) { String textToWrite = String.format("Feature not implemented for %s, we are happy to receive PRs", getProxyName()); FileUtils.writeStringToFile(notImplemented, textToWrite, StandardCharsets.UTF_8); } catch (IOException e) { - logger.log(Level.INFO, e.toString(), e); + logger.info(e.toString(), e); } } @@ -346,7 +348,7 @@ public void terminateIdleSessions() { executionTime); addTestToDashboard(testSlot.getSession().getExternalKey().getKey(), false); getRegistry().forceRelease(testSlot, SessionTerminationReason.ORPHAN); - logger.log(Level.INFO, getProxyName() + " Releasing slot and terminating session due to inactivity."); + logger.info(getProxyName() + " Releasing slot and terminating session due to inactivity."); } } } @@ -379,7 +381,7 @@ public void run() { try { Thread.sleep(getSleepTimeBetweenChecks()); } catch (InterruptedException e) { - logger.log(Level.FINE, cloudProxy.getProxyName() + " Error while sleeping the thread.", e); + logger.debug(cloudProxy.getProxyName() + " Error while sleeping the thread.", e); return; } } diff --git a/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumRemoteProxy.java b/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumRemoteProxy.java index 7a6d52e9e4..b2c7e4cf2f 100644 --- a/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumRemoteProxy.java +++ b/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumRemoteProxy.java @@ -40,8 +40,10 @@ import java.io.OutputStream; import java.util.Map; import java.util.Optional; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /* The implementation of this class was inspired on https://gist.github.com/krmahadevan/4649607 @@ -59,7 +61,7 @@ public class DockerSeleniumRemoteProxy extends DefaultRemoteProxy { @VisibleForTesting public static final boolean DEFAULT_VIDEO_RECORDING_ENABLED = true; private static final String ZALENIUM_KEEP_ONLY_FAILED_TESTS = "ZALENIUM_KEEP_ONLY_FAILED_TESTS"; - private static final Logger LOGGER = Logger.getLogger(DockerSeleniumRemoteProxy.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(DockerSeleniumRemoteProxy.class.getName()); private static final int DEFAULT_MAX_TEST_SESSIONS = 1; private static final boolean DEFAULT_KEEP_ONLY_FAILED_TESTS = false; private static final Environment defaultEnvironment = new Environment(); @@ -155,14 +157,14 @@ public TestSession getNewSession(Map requestedCapability) { } if (!requestedCapability.containsKey(CapabilityType.BROWSER_NAME)) { - LOGGER.log(Level.FINE, () -> String.format("%s Capability %s does not contain %s key, a browser test cannot " + + LOGGER.debug(String.format("%s Capability %s does not contain %s key, a browser test cannot " + "start without it.", getId(), requestedCapability, CapabilityType.BROWSER_NAME)); return null; } if (!this.isBusy() && increaseCounter()) { TestSession newSession = super.getNewSession(requestedCapability); - LOGGER.log(Level.FINE, getId() + " Creating session for: " + requestedCapability.toString()); + LOGGER.debug(getId() + " Creating session for: " + requestedCapability.toString()); String browserName = requestedCapability.get(CapabilityType.BROWSER_NAME).toString(); testName = getCapability(requestedCapability, ZaleniumCapabilityType.TEST_NAME, ""); if (testName.isEmpty()) { @@ -194,7 +196,7 @@ public TestSession getNewSession(Map requestedCapability) { maxTestIdleTimeSecs = getConfiguredIdleTimeout(requestedCapability); return newSession; } - LOGGER.log(Level.FINE, "{0} No more sessions allowed", getId()); + LOGGER.debug("{0} No more sessions allowed", getId()); return null; } @@ -213,8 +215,8 @@ private long getConfiguredIdleTimeout(Map requestedCapability) { configuredIdleTimeout = Long.valueOf(String.valueOf(idleTimeout)); } catch (Exception e) { configuredIdleTimeout = DEFAULT_MAX_TEST_IDLE_TIME_SECS; - LOGGER.log(Level.WARNING, getId() + " " + e.toString()); - LOGGER.log(Level.FINE, getId() + " " + e.toString(), e); + LOGGER.warn(getId() + " " + e.toString()); + LOGGER.debug(getId() + " " + e.toString(), e); } if (configuredIdleTimeout <= 0) { configuredIdleTimeout = DEFAULT_MAX_TEST_IDLE_TIME_SECS; @@ -225,12 +227,11 @@ private long getConfiguredIdleTimeout(Map requestedCapability) { @Override public void beforeCommand(TestSession session, HttpServletRequest request, HttpServletResponse response) { super.beforeCommand(session, request, response); - LOGGER.log(Level.FINE, - getId() + " lastCommand: " + request.getMethod() + " - " + request.getPathInfo() + " executing..."); + LOGGER.debug(getId() + " lastCommand: " + request.getMethod() + " - " + request.getPathInfo() + " executing..."); if (request instanceof WebDriverRequest && "POST".equalsIgnoreCase(request.getMethod())) { WebDriverRequest seleniumRequest = (WebDriverRequest) request; if (seleniumRequest.getPathInfo().endsWith("cookie")) { - LOGGER.log(Level.FINE, getId() + " Checking for cookies..." + seleniumRequest.getBody()); + LOGGER.debug(getId() + " Checking for cookies..." + seleniumRequest.getBody()); JsonElement bodyRequest = new JsonParser().parse(seleniumRequest.getBody()); JsonObject cookie = bodyRequest.getAsJsonObject().getAsJsonObject("cookie"); JsonObject emptyName = new JsonObject(); @@ -259,8 +260,7 @@ public void beforeCommand(TestSession session, HttpServletRequest request, HttpS @Override public void afterCommand(TestSession session, HttpServletRequest request, HttpServletResponse response) { super.afterCommand(session, request, response); - LOGGER.log(Level.FINE, - getId() + " lastCommand: " + request.getMethod() + " - " + request.getPathInfo() + " executed."); + LOGGER.debug(getId() + " lastCommand: " + request.getMethod() + " - " + request.getPathInfo() + " executed."); if (request instanceof WebDriverRequest && "POST".equalsIgnoreCase(request.getMethod())) { WebDriverRequest seleniumRequest = (WebDriverRequest) request; if (RequestType.START_SESSION.equals(seleniumRequest.getRequestType())) { @@ -269,8 +269,7 @@ public void afterCommand(TestSession session, HttpServletRequest request, HttpSe if (session.getSlot().getProxy() instanceof DockerSeleniumRemoteProxy) { remoteName = ((DockerSeleniumRemoteProxy)session.getSlot().getProxy()).getRegistration().getContainerId(); } - LOGGER.log(Level.INFO, - String.format("Test session started with internal key %s and external key %s assigned to remote %s.", + LOGGER.info(String.format("Test session started with internal key %s and external key %s assigned to remote %s.", session.getInternalKey(), session.getExternalKey().getKey(), remoteName)); @@ -291,21 +290,21 @@ public void afterSession(TestSession session) { stopPolling(); if (isTestSessionLimitReached()) { String message = String.format("%s AFTER_SESSION command received. Node should shutdown soon...", getId()); - LOGGER.log(Level.INFO, message); + LOGGER.info(message); shutdownNode(false); } else { String message = String.format( "%s AFTER_SESSION command received. Cleaning up node for reuse, used %s of max %s", getId(), getAmountOfExecutedTests(), maxTestSessions); - LOGGER.log(Level.INFO, message); + LOGGER.info(message); cleanupNode(false); // Enabling polling again since the node is still alive. startPolling(); } } } catch (Exception e) { - LOGGER.log(Level.WARNING, getId() + " " + e.toString(), e); + LOGGER.warn(getId() + " " + e.toString(), e); } finally { super.afterSession(session); } @@ -410,12 +409,12 @@ protected void videoRecording(final DockerSeleniumContainerAction action) { try { processContainerAction(action, getContainerId()); } catch (Exception e) { - LOGGER.log(Level.SEVERE, getId() + e.toString(), e); + LOGGER.error(getId() + e.toString(), e); ga.trackException(e); } } else { String message = String.format("%s %s: Video recording is disabled", getId(), action.getContainerAction()); - LOGGER.log(Level.INFO, message); + LOGGER.info(message); } } @@ -485,17 +484,17 @@ void copyVideos(final String containerId) { IOUtils.copy(tarStream, outputStream); outputStream.close(); videoWasCopied = true; - LOGGER.log(Level.INFO, "{0} Video file copied to: {1}/{2}", new Object[]{getId(), + LOGGER.info("{0} Video file copied to: {1}/{2}", new Object[]{getId(), testInformation.getVideoFolderPath(), testInformation.getFileName()}); } } catch (IOException e) { // This error happens in k8s, but the file is ok, nevertheless the size is not accurate boolean isPipeClosed = e.getMessage().toLowerCase().contains("pipe closed"); if (ContainerFactory.getIsKubernetes().get() && isPipeClosed) { - LOGGER.log(Level.INFO, "{0} Video file copied to: {1}/{2}", new Object[]{getId(), + LOGGER.info("{0} Video file copied to: {1}/{2}", new Object[]{getId(), testInformation.getVideoFolderPath(), testInformation.getFileName()}); } else { - LOGGER.log(Level.WARNING, getId() + " Error while copying the video", e); + LOGGER.warn(getId() + " Error while copying the video", e); } ga.trackException(e); } finally { @@ -525,14 +524,14 @@ void copyLogs(final String containerId) { IOUtils.copy(tarStream, outputStream); outputStream.close(); } - LOGGER.log(Level.INFO, "{0} Logs copied to: {1}", new Object[]{getId(), testInformation.getLogsFolderPath()}); + LOGGER.info("{0} Logs copied to: {1}", new Object[]{getId(), testInformation.getLogsFolderPath()}); } catch (IOException e) { // This error happens in k8s, but the file is ok, nevertheless the size is not accurate boolean isPipeClosed = e.getMessage().toLowerCase().contains("pipe closed"); if (ContainerFactory.getIsKubernetes().get() && isPipeClosed) { - LOGGER.log(Level.INFO, "{0} Logs copied to: {1}", new Object[]{getId(), testInformation.getLogsFolderPath()}); + LOGGER.info("{0} Logs copied to: {1}", new Object[]{getId(), testInformation.getLogsFolderPath()}); } else { - LOGGER.log(Level.WARNING, getId() + " Error while copying the logs", e); + LOGGER.warn(getId() + " Error while copying the logs", e); } ga.trackException(e); } @@ -637,7 +636,7 @@ public void run() { */ if (dockerSeleniumRemoteProxy.isTestIdle()) { dockerSeleniumRemoteProxy.testInformation.setTestStatus(TestInformation.TestStatus.TIMEOUT); - LOGGER.log(Level.INFO, dockerSeleniumRemoteProxy.getId() + + LOGGER.info(dockerSeleniumRemoteProxy.getId() + " Shutting down node due to test inactivity"); dockerSeleniumRemoteProxy.shutdownNode(true); return; @@ -645,7 +644,7 @@ public void run() { try { Thread.sleep(getSleepTimeBetweenChecks()); } catch (InterruptedException e) { - LOGGER.log(Level.FINEST, dockerSeleniumRemoteProxy.getId() + " Error while sleeping the " + + LOGGER.info(dockerSeleniumRemoteProxy.getId() + " Error while sleeping the " + "thread, stopping thread execution.", e); return; } diff --git a/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumStarterRemoteProxy.java b/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumStarterRemoteProxy.java index b8342cdb28..2ee77391d9 100644 --- a/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumStarterRemoteProxy.java +++ b/src/main/java/de/zalando/ep/zalenium/proxy/DockerSeleniumStarterRemoteProxy.java @@ -47,8 +47,10 @@ import java.util.concurrent.ThreadFactory; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * The idea of this proxy instance is: @@ -88,7 +90,7 @@ public class DockerSeleniumStarterRemoteProxy extends DefaultRemoteProxy impleme static final String DEFAULT_SELENIUM_NODE_PARAMS = ""; private static final String DEFAULT_ZALENIUM_CONTAINER_NAME = "zalenium"; private static final String ZALENIUM_CONTAINER_NAME = "ZALENIUM_CONTAINER_NAME"; - private static final Logger LOGGER = Logger.getLogger(DockerSeleniumStarterRemoteProxy.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(DockerSeleniumStarterRemoteProxy.class.getName()); private static final String DEFAULT_DOCKER_SELENIUM_IMAGE = "elgalu/selenium"; private static final String ZALENIUM_SELENIUM_IMAGE_NAME = "ZALENIUM_SELENIUM_IMAGE_NAME"; private static final int LOWER_PORT_BOUNDARY = 40000; @@ -290,7 +292,7 @@ public static TimeZone getConfiguredTimeZone() { public static void setConfiguredTimeZone(String configuredTimeZone) { if (!Arrays.asList(TimeZone.getAvailableIDs()).contains(configuredTimeZone)) { - LOGGER.log(Level.WARNING, () -> String.format("%s is not a real time zone.", configuredTimeZone)); + LOGGER.warn(String.format("%s is not a real time zone.", configuredTimeZone)); DockerSeleniumStarterRemoteProxy.configuredTimeZone = DEFAULT_TZ; } else { DockerSeleniumStarterRemoteProxy.configuredTimeZone = TimeZone.getTimeZone(configuredTimeZone); @@ -326,12 +328,12 @@ public HtmlRenderer getHtmlRender() { public TestSession getNewSession(Map requestedCapability) { if (!hasCapability(requestedCapability)) { - LOGGER.log(Level.FINE, LOGGING_PREFIX + "Capability not supported {0}", requestedCapability); + LOGGER.debug(LOGGING_PREFIX + "Capability not supported {0}", requestedCapability); return null; } if (!requestedCapability.containsKey(CapabilityType.BROWSER_NAME)) { - LOGGER.log(Level.FINE, () -> String.format("%s Capability %s does not contain %s key, a docker-selenium " + + LOGGER.debug(String.format("%s Capability %s does not contain %s key, a docker-selenium " + "node cannot be started without it", LOGGING_PREFIX, requestedCapability, CapabilityType.BROWSER_NAME)); return null; } @@ -346,21 +348,21 @@ public TestSession getNewSession(Map requestedCapability) { Reusing nodes, rejecting requests when a node is cleaning up and will be ready again soon. */ if (nodesAvailable(requestedCapability)) { - LOGGER.log(Level.FINE, LOGGING_PREFIX + "A node is coming up soon for {0}, won't start a new node yet.", + LOGGER.debug(LOGGING_PREFIX + "A node is coming up soon for {0}, won't start a new node yet.", requestedCapability); return null; } // Checking if this request has been processed based on its id, contents, and attempts if (hasRequestBeenProcessed(requestedCapability)) { - LOGGER.log(Level.FINE, LOGGING_PREFIX + "Request {0}, has been processed and it is waiting for a node.", + LOGGER.debug(LOGGING_PREFIX + "Request {0}, has been processed and it is waiting for a node.", requestedCapability); return null; } ProcessedCapabilities processedCapabilities = new ProcessedCapabilities(requestedCapability, System.identityHashCode(requestedCapability)); processedCapabilitiesList.add(processedCapabilities); - LOGGER.log(Level.INFO, LOGGING_PREFIX + "Starting new node for {0}.", requestedCapability); + LOGGER.debug(LOGGING_PREFIX + "Starting new node for {0}.", requestedCapability); poolExecutor.execute(() -> startDockerSeleniumContainer(timeZone, screenSize)); cleanProcessedCapabilities(); @@ -371,9 +373,9 @@ private boolean hasRequestBeenProcessed(Map requestedCapability) int requestedCapabilityHashCode = System.identityHashCode(requestedCapability); for (ProcessedCapabilities processedCapability : processedCapabilitiesList) { - LOGGER.log(Level.FINE, LOGGING_PREFIX + "System.identityHashCode(requestedCapability) -> " + LOGGER.debug(LOGGING_PREFIX + "System.identityHashCode(requestedCapability) -> " + System.identityHashCode(requestedCapability) + ", " + requestedCapability); - LOGGER.log(Level.FINE, LOGGING_PREFIX + "processedCapability.getIdentityHashCode() -> " + LOGGER.debug(LOGGING_PREFIX + "processedCapability.getIdentityHashCode() -> " + processedCapability.getIdentityHashCode() + ", " + processedCapability.getRequestedCapability()); if (processedCapability.getIdentityHashCode() == requestedCapabilityHashCode) { @@ -384,7 +386,7 @@ private boolean hasRequestBeenProcessed(Map requestedCapability) if (processedTimes >= 30) { processedCapability.setProcessedTimes(1); - LOGGER.log(Level.INFO, LOGGING_PREFIX + "Request has waited 30 attempts for a node, something " + + LOGGER.info(LOGGING_PREFIX + "Request has waited 30 attempts for a node, something " + "went wrong with the previous attempts, creating a new node for {0}.", requestedCapability); return false; } @@ -469,19 +471,19 @@ public boolean startDockerSeleniumContainer(TimeZone timeZone, Dimension screenS if (creationStatus.isCreated() && checkContainerStatus(creationStatus)) { return true; } else { - LOGGER.log(Level.FINE, String.format("%sContainer creation failed, retrying...", LOGGING_PREFIX)); + LOGGER.debug(String.format("%sContainer creation failed, retrying...", LOGGING_PREFIX)); } } else { - LOGGER.log(Level.INFO, String.format("%sNo container was created, will try again in a moment...", + LOGGER.info(String.format("%sNo container was created, will try again in a moment...", LOGGING_PREFIX)); try { Thread.sleep(10000); } catch (InterruptedException e) { - LOGGER.log(Level.FINE, "Exception while making a pause during container creation.", e); + LOGGER.debug("Exception while making a pause during container creation.", e); } } } - LOGGER.log(Level.INFO, String.format("%sNo container was created after 3 attempts, will wait until request is " + + LOGGER.info(String.format("%sNo container was created after 3 attempts, will wait until request is " + "processed again...", LOGGING_PREFIX)); return false; } @@ -508,21 +510,21 @@ private boolean checkContainerStatus(ContainerCreationStatus creationStatus) { String status = IOUtils.toString(statusUrl, StandardCharsets.UTF_8); String successMessage = "\"Node is running\""; if (status.contains(successMessage)) { - LOGGER.log(Level.INFO, String.format("%sContainer %s is up after ~%s seconds...", + LOGGER.info(String.format("%sContainer %s is up after ~%s seconds...", LOGGING_PREFIX, createdContainerName, i * (sleepInterval / 1000))); return true; } } catch (IOException e) { - LOGGER.log(Level.FINE, "Error while getting node status, probably the node is still starting up..."); + LOGGER.debug("Error while getting node status, probably the node is still starting up..."); } } catch (MalformedURLException | InterruptedException e) { - LOGGER.log(Level.WARNING, "Malformed status url.", e); + LOGGER.warn("Malformed status url.", e); } } String message = String.format("%sContainer %s took longer than 60 seconds to be up and ready, this might be " + "a signal that you have reached the hardware limits for the number of concurrent threads " + "that you want to execute.", LOGGING_PREFIX, createdContainerName); - LOGGER.log(Level.INFO, message); + LOGGER.info(message); return false; } @@ -563,19 +565,19 @@ private Map buildEnvVars(TimeZone timeZone, Dimension screenSize private void createContainersOnStartup() { int containersToCreate = getDesiredContainersOnStartup() > getMaxDockerSeleniumContainers() ? getMaxDockerSeleniumContainers() : getDesiredContainersOnStartup(); - LOGGER.log(Level.INFO, String.format("%s Setting up %s nodes...", LOGGING_PREFIX, getDesiredContainersOnStartup())); + LOGGER.info(String.format("%s Setting up %s nodes...", LOGGING_PREFIX, getDesiredContainersOnStartup())); // Thread.sleep() is to avoid having containers starting at the same time for (int i = 0; i < containersToCreate; i++) { new Thread(() -> { try { Thread.sleep(RandomUtils.nextInt(1, (containersToCreate / 2) + 1) * sleepIntervalMultiplier); } catch (InterruptedException e) { - LOGGER.log(Level.WARNING, getId() + " Error sleeping before starting a container", e); + LOGGER.warn(getId() + " Error sleeping before starting a container", e); } startDockerSeleniumContainer(getConfiguredTimeZone(), getConfiguredScreenSize(), true); }, "DockerSeleniumStarterRemoteProxy createContainersOnStartup #" + i).start(); } - LOGGER.log(Level.INFO, String.format("%s containers were created, it will take a bit more until all get registered.", containersToCreate)); + LOGGER.info(String.format("%s containers were created, it will take a bit more until all get registered.", containersToCreate)); } /* @@ -596,11 +598,11 @@ private Dimension getConfiguredScreenResolutionFromCapabilities(Map 0 && screenHeight > 0) { screenSize = new Dimension(screenWidth, screenHeight); } else { - LOGGER.log(Level.FINE, "One of the values provided for screenResolution is negative, " + + LOGGER.debug("One of the values provided for screenResolution is negative, " + "defaults will be used. Passed value -> " + screenResolution); } } catch (Exception e) { - LOGGER.log(Level.FINE, "Values provided for screenResolution are not valid integers or " + + LOGGER.debug("Values provided for screenResolution are not valid integers or " + "either the width or the height is missing, defaults will be used. Passed value -> " + screenResolution); } @@ -630,7 +632,7 @@ private TimeZone getConfiguredTimeZoneFromCapabilities(Map reque private boolean nodesAvailable(Map requestedCapability) { if (!waitForAvailableNodes) { - LOGGER.log(Level.FINE, LOGGING_PREFIX + "Not waiting for available slots, creating nodes when possible."); + LOGGER.debug(LOGGING_PREFIX + "Not waiting for available slots, creating nodes when possible."); return false; } for (RemoteProxy remoteProxy : this.getRegistry().getAllProxies()) { @@ -639,12 +641,12 @@ private boolean nodesAvailable(Map requestedCapability) { // If a node is cleaning up it will be available soon // It is faster and more resource wise to wait for the node to be ready if (proxy.isCleaningUpBeforeNextSession() && proxy.hasCapability(requestedCapability)) { - LOGGER.log(Level.FINE, LOGGING_PREFIX + "A node is coming up to handle this request."); + LOGGER.debug(LOGGING_PREFIX + "A node is coming up to handle this request."); return true; } } } - LOGGER.log(Level.FINE, LOGGING_PREFIX + "No slots available, a new node will be created."); + LOGGER.debug(LOGGING_PREFIX + "No slots available, a new node will be created."); return false; } @@ -652,15 +654,15 @@ private boolean validateAmountOfDockerSeleniumContainers() { try { int numberOfDockerSeleniumContainers = containerClient.getRunningContainers(getDockerSeleniumImageName()); if (numberOfDockerSeleniumContainers >= getMaxDockerSeleniumContainers()) { - LOGGER.log(Level.WARNING, LOGGING_PREFIX + "Max. number of docker-selenium containers has been reached, " + + LOGGER.warn(LOGGING_PREFIX + "Max. number of docker-selenium containers has been reached, " + "no more will be created until the number decreases below {0}.", getMaxDockerSeleniumContainers()); return false; } - LOGGER.log(Level.FINE, () -> String.format("%s %s docker-selenium containers running", LOGGING_PREFIX, + LOGGER.debug(String.format("%s %s docker-selenium containers running", LOGGING_PREFIX, numberOfDockerSeleniumContainers)); return true; } catch (Exception e) { - LOGGER.log(Level.SEVERE, LOGGING_PREFIX + e.toString(), e); + LOGGER.error(LOGGING_PREFIX + e.toString(), e); ga.trackException(e); } return false; @@ -679,7 +681,7 @@ If the list size is this big (~9800), it means that almost all ports have been u synchronized (allocatedPorts){ if (allocatedPorts.size() > (upperBoundary - lowerBoundary - 200)) { allocatedPorts.clear(); - LOGGER.log(Level.INFO, () -> LOGGING_PREFIX + "Cleaning allocated ports list."); + LOGGER.info(LOGGING_PREFIX + "Cleaning allocated ports list."); } for (int portNumber = lowerBoundary; portNumber <= upperBoundary; portNumber++) { int noVncPortNumber = portNumber + NO_VNC_PORT_GAP; diff --git a/src/main/java/de/zalando/ep/zalenium/proxy/SauceLabsRemoteProxy.java b/src/main/java/de/zalando/ep/zalenium/proxy/SauceLabsRemoteProxy.java index f2b785e6fe..f1d5d75624 100644 --- a/src/main/java/de/zalando/ep/zalenium/proxy/SauceLabsRemoteProxy.java +++ b/src/main/java/de/zalando/ep/zalenium/proxy/SauceLabsRemoteProxy.java @@ -10,8 +10,10 @@ import java.util.ArrayList; import java.util.List; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /* Almost all concepts and ideas for this part of the implementation are taken from the open source project seen here: @@ -24,7 +26,7 @@ public class SauceLabsRemoteProxy extends CloudTestingRemoteProxy { private static final String SAUCE_LABS_USER_NAME = getEnv().getStringEnvVariable("SAUCE_USERNAME", ""); private static final String SAUCE_LABS_ACCESS_KEY = getEnv().getStringEnvVariable("SAUCE_ACCESS_KEY", ""); private static final String SAUCE_LABS_URL = "http://ondemand.saucelabs.com:80"; - private static final Logger LOGGER = Logger.getLogger(SauceLabsRemoteProxy.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(SauceLabsRemoteProxy.class.getName()); private static final String SAUCE_LABS_PROXY_NAME = "SauceLabs"; public SauceLabsRemoteProxy(RegistrationRequest request, GridRegistry registry) { @@ -46,11 +48,11 @@ static RegistrationRequest updateSLCapabilities(RegistrationRequest registration sauceLabsAccountConcurrency = slAccountInfo.getAsJsonObject().getAsJsonObject("concurrency_limit"). get("overall").getAsInt(); } - LOGGER.log(Level.INFO, logMessage); + LOGGER.info(logMessage); return addCapabilitiesToRegistrationRequest(registrationRequest, sauceLabsAccountConcurrency, SAUCE_LABS_PROXY_NAME); } catch (Exception e) { - LOGGER.log(Level.SEVERE, e.toString(), e); + LOGGER.warn(e.toString(), e); getGa().trackException(e); } return addCapabilitiesToRegistrationRequest(registrationRequest, 1, SAUCE_LABS_PROXY_NAME); diff --git a/src/main/java/de/zalando/ep/zalenium/proxy/TestingBotRemoteProxy.java b/src/main/java/de/zalando/ep/zalenium/proxy/TestingBotRemoteProxy.java index d82b386f68..2d01b59f8a 100644 --- a/src/main/java/de/zalando/ep/zalenium/proxy/TestingBotRemoteProxy.java +++ b/src/main/java/de/zalando/ep/zalenium/proxy/TestingBotRemoteProxy.java @@ -10,8 +10,10 @@ import java.util.ArrayList; import java.util.List; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /* This class should work in a similar way as its sibling, SauceLabsRemoteProxy @@ -23,7 +25,7 @@ public class TestingBotRemoteProxy extends CloudTestingRemoteProxy { private static final String TESTINGBOT_ACCOUNT_INFO = "https://api.testingbot.com/v1/user"; private static final String TESTINGBOT_KEY = getEnv().getStringEnvVariable("TESTINGBOT_KEY", ""); private static final String TESTINGBOT_SECRET = getEnv().getStringEnvVariable("TESTINGBOT_SECRET", ""); - private static final Logger logger = Logger.getLogger(TestingBotRemoteProxy.class.getName()); + private static final Logger logger = LoggerFactory.getLogger(TestingBotRemoteProxy.class.getName()); private static final String TESTINGBOT_PROXY_NAME = "TestingBot"; public TestingBotRemoteProxy(RegistrationRequest request, GridRegistry registry) { @@ -43,11 +45,11 @@ private static RegistrationRequest updateTBCapabilities(RegistrationRequest regi } else { testingBotAccountConcurrency = testingBotAccountInfo.getAsJsonObject().get("max_concurrent").getAsInt(); } - logger.log(Level.INFO, logMessage); + logger.info(logMessage); return addCapabilitiesToRegistrationRequest(registrationRequest, testingBotAccountConcurrency, TESTINGBOT_PROXY_NAME); } catch (Exception e) { - logger.log(Level.SEVERE, e.toString(), e); + logger.error(e.toString(), e); getGa().trackException(e); } return addCapabilitiesToRegistrationRequest(registrationRequest, 1, TESTINGBOT_PROXY_NAME); @@ -117,7 +119,7 @@ public TestInformation getTestInformation(String seleniumSessionId) { try { Thread.sleep(1000 * 5); } catch (InterruptedException e) { - logger.log(Level.FINE, e.toString(), e); + logger.debug(e.toString(), e); } } } diff --git a/src/main/java/de/zalando/ep/zalenium/registry/ZaleniumRegistry.java b/src/main/java/de/zalando/ep/zalenium/registry/ZaleniumRegistry.java index 45e0de2be7..6e88576d2c 100644 --- a/src/main/java/de/zalando/ep/zalenium/registry/ZaleniumRegistry.java +++ b/src/main/java/de/zalando/ep/zalenium/registry/ZaleniumRegistry.java @@ -27,8 +27,10 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.locks.Condition; import java.util.concurrent.locks.ReentrantLock; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Kernel of the grid. Keeps track of what's happening, what's free/used and assigns resources to @@ -36,7 +38,7 @@ */ @ThreadSafe public class ZaleniumRegistry extends BaseGridRegistry implements GridRegistry { - private static final Logger LOG = Logger.getLogger(ZaleniumRegistry.class.getName()); + private static final Logger LOG = LoggerFactory.getLogger(ZaleniumRegistry.class.getName()); // lock for anything modifying the tests session currently running on this // registry. private final ReentrantLock lock = new ReentrantLock(); @@ -138,7 +140,7 @@ public void removeIfPresent(RemoteProxy proxy) { // an empty TestSlot list, which doesn't figure into the proxy equivalence check. Since we want to free up // those test sessions, we need to operate on that original object. if (proxies.contains(proxy)) { - LOG.warning(String.format( + LOG.warn(String.format( "Cleaning up stale test sessions on the unregistered node %s", proxy)); final RemoteProxy p = proxies.remove(proxy); @@ -200,7 +202,7 @@ private void assignRequestToProxy() { } catch (InterruptedException e) { LOG.info("Shutting down registry."); } catch (Throwable t) { - LOG.log(Level.SEVERE, "Unhandled exception in Matcher thread.", t); + LOG.error("Unhandled exception in Matcher thread.", t); } } @@ -215,8 +217,7 @@ private boolean takeRequestHandler(RequestHandler handler) { remoteName = ((DockerSeleniumRemoteProxy)session.getSlot().getProxy()).getRegistration().getContainerId(); } long timeToAssignProxy = System.currentTimeMillis() - handler.getRequest().getCreationTime(); - LOG.log(Level.INFO, - String.format("Test session with internal key %s assigned to remote (%s) after %s seconds (%s ms).", + LOG.info(String.format("Test session with internal key %s assigned to remote (%s) after %s seconds (%s ms).", session.getInternalKey(), remoteName, timeToAssignProxy / 1000, @@ -255,7 +256,7 @@ private void release(String internalKey, SessionTerminationReason reason) { release(session1, reason); return; } - LOG.warning("Tried to release session with internal key " + internalKey + + LOG.warn("Tried to release session with internal key " + internalKey + " but couldn't find it."); } @@ -273,7 +274,7 @@ public void add(RemoteProxy proxy) { removeIfPresent(proxy); if (registeringProxies.contains(proxy)) { - LOG.warning(String.format("Proxy '%s' is already queued for registration.", proxy)); + LOG.warn(String.format("Proxy '%s' is already queued for registration.", proxy)); return; } @@ -290,7 +291,7 @@ public void add(RemoteProxy proxy) { ((RegistrationListener) proxy).beforeRegistration(); } } catch (Throwable t) { - LOG.severe("Error running the registration listener on " + proxy + ", " + t.getMessage()); + LOG.error("Error running the registration listener on " + proxy + ", " + t.getMessage()); t.printStackTrace(); listenerOk = false; } @@ -390,13 +391,13 @@ public Set getActiveSessions() { * @see GridRegistry#getProxyById(String) */ public RemoteProxy getProxyById(String id) { - LOG.log(Level.FINE, "Getting proxy " + id); + LOG.debug("Getting proxy " + id); return proxies.getProxyById(id); } protected static class UncaughtExceptionHandler implements Thread.UncaughtExceptionHandler { public void uncaughtException(Thread t, Throwable e) { - LOG.log(Level.SEVERE, "Matcher thread dying due to unhandled exception.", e); + LOG.debug("Matcher thread dying due to unhandled exception.", e); } } @@ -422,4 +423,4 @@ public void run() { } -} \ No newline at end of file +} diff --git a/src/main/java/de/zalando/ep/zalenium/servlet/LivePreviewServlet.java b/src/main/java/de/zalando/ep/zalenium/servlet/LivePreviewServlet.java index b9e9f6c14f..8c01a8a1d6 100644 --- a/src/main/java/de/zalando/ep/zalenium/servlet/LivePreviewServlet.java +++ b/src/main/java/de/zalando/ep/zalenium/servlet/LivePreviewServlet.java @@ -25,12 +25,14 @@ import java.util.List; import java.util.Map; import java.util.Optional; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class LivePreviewServlet extends RegistryBasedServlet { - private static final Logger LOGGER = Logger.getLogger(LivePreviewServlet.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(LivePreviewServlet.class.getName()); @SuppressWarnings("unused") public LivePreviewServlet(){ @@ -46,7 +48,7 @@ protected void doGet(HttpServletRequest request, HttpServletResponse response) { try { process(request, response); } catch (Exception e) { - LOGGER.log(Level.SEVERE, e.toString(), e); + LOGGER.error(e.toString(), e); } } @@ -55,7 +57,7 @@ protected void doPost(HttpServletRequest request, HttpServletResponse response) try { process(request, response); } catch (Exception e) { - LOGGER.log(Level.SEVERE, e.toString(), e); + LOGGER.error(e.toString(), e); } } @@ -70,7 +72,7 @@ protected void process(HttpServletRequest request, HttpServletResponse response) refresh = Optional.ofNullable(request.getParameter("refresh")).orElse(refresh); testBuild = Optional.ofNullable(request.getParameter("build")).orElse(testBuild); } catch (Exception e) { - LOGGER.log(Level.FINE, e.toString(), e); + LOGGER.debug(e.toString(), e); } List nodes = new ArrayList<>(); diff --git a/src/main/java/de/zalando/ep/zalenium/servlet/VncAuthenticationServlet.java b/src/main/java/de/zalando/ep/zalenium/servlet/VncAuthenticationServlet.java index 5aa7164ef5..5dcba44e65 100644 --- a/src/main/java/de/zalando/ep/zalenium/servlet/VncAuthenticationServlet.java +++ b/src/main/java/de/zalando/ep/zalenium/servlet/VncAuthenticationServlet.java @@ -3,8 +3,10 @@ import java.net.URI; import java.net.URISyntaxException; import java.util.Optional; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import java.util.regex.Matcher; import java.util.regex.Pattern; import java.util.stream.Stream; @@ -31,7 +33,7 @@ public class VncAuthenticationServlet extends RegistryBasedServlet { private static Pattern VNC_REGEX = Pattern.compile("^\\/vnc\\/host\\/(?[^\\/]+)\\/port\\/(?\\d+)\\/"); private static Pattern WEB_SOCKET_REGEX = Pattern.compile("^\\/proxy\\/(?[^:]+):(?\\d+)\\/websockify"); - private static final Logger LOGGER = Logger.getLogger(VncAuthenticationServlet.class.getName()); + private static final Logger LOGGER = LoggerFactory.getLogger(VncAuthenticationServlet.class.getName()); public VncAuthenticationServlet() { super(null); @@ -46,7 +48,7 @@ protected void doGet(HttpServletRequest req, HttpServletResponse resp) { try { authenticate(req, resp); } catch (Exception e) { - LOGGER.log(Level.SEVERE, e.toString(), e); + LOGGER.error(e.toString(), e); } } @@ -55,7 +57,7 @@ protected void doPost(HttpServletRequest req, HttpServletResponse resp) { try { authenticate(req, resp); } catch (Exception e) { - LOGGER.log(Level.SEVERE, e.toString(), e); + LOGGER.error(e.toString(), e); } } @@ -64,7 +66,7 @@ protected void doHead(HttpServletRequest req, HttpServletResponse resp) { try { authenticate(req, resp); } catch (Exception e) { - LOGGER.log(Level.SEVERE, e.toString(), e); + LOGGER.error(e.toString(), e); } } @@ -76,7 +78,7 @@ private void authenticate(HttpServletRequest request, HttpServletResponse respon try { return Optional.of(new URI(s).getPath()); } catch (URISyntaxException e) { - LOGGER.log(Level.SEVERE, "Failed to parse url [" + s + "]", e); + LOGGER.error("Failed to parse url [" + s + "]", e); return Optional.empty(); } }); diff --git a/src/main/java/de/zalando/ep/zalenium/servlet/renderer/TemplateRenderer.java b/src/main/java/de/zalando/ep/zalenium/servlet/renderer/TemplateRenderer.java index 73db2ab0d4..9eb6f619a5 100644 --- a/src/main/java/de/zalando/ep/zalenium/servlet/renderer/TemplateRenderer.java +++ b/src/main/java/de/zalando/ep/zalenium/servlet/renderer/TemplateRenderer.java @@ -7,12 +7,14 @@ import java.io.InputStream; import java.nio.charset.StandardCharsets; import java.util.Map; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; @SuppressWarnings("WeakerAccess") public class TemplateRenderer { - private final Logger logger = Logger.getLogger(LivePreviewServlet.class.getName()); + private final Logger logger = LoggerFactory.getLogger(LivePreviewServlet.class.getName()); private String templateFile; private String templateContents; @@ -28,7 +30,7 @@ private void loadTemplate() { templateContents = IOUtils.toString(inputStream, StandardCharsets.UTF_8); } catch (IOException e) { templateContents = ""; - logger.log(Level.SEVERE, e.toString(), e); + logger.error(e.toString(), e); } } } diff --git a/src/main/java/de/zalando/ep/zalenium/util/CommonProxyUtilities.java b/src/main/java/de/zalando/ep/zalenium/util/CommonProxyUtilities.java index 333b6f30be..031111a3d3 100644 --- a/src/main/java/de/zalando/ep/zalenium/util/CommonProxyUtilities.java +++ b/src/main/java/de/zalando/ep/zalenium/util/CommonProxyUtilities.java @@ -17,12 +17,14 @@ import java.text.DateFormat; import java.text.SimpleDateFormat; import java.util.Date; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class CommonProxyUtilities { - private static final Logger LOG = Logger.getLogger(CommonProxyUtilities.class.getName()); + private static final Logger LOG = LoggerFactory.getLogger(CommonProxyUtilities.class.getName()); /* Reading a JSON with DockerSelenium capabilities from a given URL @@ -47,15 +49,15 @@ public JsonElement readJSONFromUrl(String jsonUrl, String user, String password) return new JsonParser().parse(jsonText); } catch (Exception e) { currentAttempts++; - LOG.log(Level.SEVERE, e.toString(), e); + LOG.error(e.toString(), e); if (currentAttempts >= maxAttempts) { - LOG.log(Level.SEVERE, e.toString(), e); + LOG.error(e.toString(), e); } else { - LOG.log(Level.INFO, "Trying download once again from " + jsonUrl); + LOG.info("Trying download once again from " + jsonUrl); try { Thread.sleep(1000 * 5); } catch (InterruptedException iE) { - LOG.log(Level.FINE, iE.toString(), iE); + LOG.debug(iE.toString(), iE); } } } @@ -69,7 +71,7 @@ public String currentLocalPath() { .getLocation().toURI().getPath()); return jarLocation.getParent(); } catch (URISyntaxException e) { - LOG.log(Level.SEVERE, e.toString(), e); + LOG.error(e.toString(), e); } return null; } @@ -118,19 +120,19 @@ public void downloadFile(String fileUrl, String fileNameWithFullPath, String use fos.close(); //End download code currentAttempts = maxAttempts + 1; - LOG.log(Level.INFO, "File downloaded to " + fileNameWithFullPath); + LOG.info("File downloaded to " + fileNameWithFullPath); } catch (IOException e) { // Catching this exception generally means that the file was not ready, so we try again. currentAttempts++; if (currentAttempts >= maxAttempts) { - LOG.log(Level.SEVERE, e.toString(), e); + LOG.info(e.toString(), e); } else { - LOG.log(Level.INFO, "Trying download once again from " + fileUrl); + LOG.info("Trying download once again from " + fileUrl); Thread.sleep(currentAttempts * 5 * 1000); } } catch (Exception e) { currentAttempts = maxAttempts + 1; - LOG.log(Level.SEVERE, e.toString(), e); + LOG.error(e.toString(), e); } } } @@ -153,11 +155,11 @@ public void convertFlvFileToMP4(TestInformation testInformation) { try { int exitValue = defaultExecutor.execute(commandLine); if (exitValue != 0) { - LOG.log(Level.WARNING, () -> "File " + flvVideoFile + " could not be converted to MP4. Exit value: " + + LOG.warn("File " + flvVideoFile + " could not be converted to MP4. Exit value: " + exitValue); } } catch (IOException e) { - LOG.log(Level.SEVERE, e.toString(), e); + LOG.error(e.toString(), e); } // Deleting the FLV file diff --git a/src/main/java/de/zalando/ep/zalenium/util/Environment.java b/src/main/java/de/zalando/ep/zalenium/util/Environment.java index 8b15128120..d6e88ea1ca 100644 --- a/src/main/java/de/zalando/ep/zalenium/util/Environment.java +++ b/src/main/java/de/zalando/ep/zalenium/util/Environment.java @@ -2,12 +2,14 @@ import com.google.common.annotations.VisibleForTesting; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class Environment { - private final Logger logger = Logger.getLogger(Environment.class.getName()); + private final Logger logger = LoggerFactory.getLogger(Environment.class.getName()); private static final String ENV_VAR_IS_NOT_SET = "Env. variable %s value is not set, falling back to default: %s"; private static final String ENV_VAR_IS_NOT_A_VALID_DATA_TYPE = "Env. variable %s is not a valid %s"; @@ -22,12 +24,12 @@ public int getIntEnvVariable(String envVariableName, int defaultValue) { try { return Integer.parseInt(getEnvVariable(envVariableName)); } catch (Exception e) { - logger.log(Level.WARNING, String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "integer")); - logger.log(Level.FINE, String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "integer"), e); + logger.warn(String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "integer")); + logger.debug(String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "integer"), e); return defaultValue; } } else { - logger.log(Level.FINE, () -> String.format(ENV_VAR_IS_NOT_SET, envVariableName, defaultValue)); + logger.debug(String.format(ENV_VAR_IS_NOT_SET, envVariableName, defaultValue)); return defaultValue; } } @@ -37,12 +39,12 @@ public String getStringEnvVariable(String envVariableName, String defaultValue) try { return String.valueOf(getEnvVariable(envVariableName)); } catch (Exception e) { - logger.log(Level.WARNING, String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "String")); - logger.log(Level.FINE, String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "String"), e); + logger.warn(String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "String")); + logger.debug(String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "String"), e); return defaultValue; } } else { - logger.log(Level.FINE, () -> String.format(ENV_VAR_IS_NOT_SET, envVariableName, defaultValue)); + logger.debug(String.format(ENV_VAR_IS_NOT_SET, envVariableName, defaultValue)); return defaultValue; } } @@ -53,11 +55,11 @@ public Boolean getBooleanEnvVariable(String envVariableName, Boolean defaultValu if("true".equalsIgnoreCase(var) || "false".equalsIgnoreCase(var)) { return Boolean.parseBoolean(var); } else{ - logger.log(Level.WARNING, String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "boolean")); + logger.warn(String.format(ENV_VAR_IS_NOT_A_VALID_DATA_TYPE, envVariableName, "boolean")); return defaultValue; } } else { - logger.log(Level.FINE, () -> String.format(ENV_VAR_IS_NOT_SET, envVariableName, defaultValue)); + logger.debug(String.format(ENV_VAR_IS_NOT_SET, envVariableName, defaultValue)); return defaultValue; } } diff --git a/src/main/java/de/zalando/ep/zalenium/util/GoogleAnalyticsApi.java b/src/main/java/de/zalando/ep/zalenium/util/GoogleAnalyticsApi.java index 2b24e6bbef..11aed65477 100644 --- a/src/main/java/de/zalando/ep/zalenium/util/GoogleAnalyticsApi.java +++ b/src/main/java/de/zalando/ep/zalenium/util/GoogleAnalyticsApi.java @@ -8,8 +8,10 @@ import org.apache.http.entity.ByteArrayEntity; import org.apache.http.impl.client.HttpClientBuilder; -import java.util.logging.Level; -import java.util.logging.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Small class to create hits in Google Analytics @@ -17,7 +19,7 @@ */ public class GoogleAnalyticsApi { - private final Logger logger = Logger.getLogger(GoogleAnalyticsApi.class.getName()); + private final Logger logger = LoggerFactory.getLogger(GoogleAnalyticsApi.class.getName()); private HttpClient httpClient; @@ -71,7 +73,7 @@ private void doPost(String payload) { httpPost.setEntity(httpEntity); httpClient.execute(httpPost); } catch (Exception e) { - logger.log(Level.FINE, e.getMessage(), e); + logger.debug(e.getMessage(), e); } }, "GoogleAnalytics doPost").start(); } diff --git a/src/main/resources/logback.xml b/src/main/resources/logback.xml index 122649fa4d..1242f07f4f 100644 --- a/src/main/resources/logback.xml +++ b/src/main/resources/logback.xml @@ -1,6 +1,13 @@ + + + + {"application":"zalenium"} + + + %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n @@ -11,7 +18,7 @@ - - + + - \ No newline at end of file + diff --git a/src/main/resources/logging_fine.properties b/src/main/resources/logging_debug.properties similarity index 97% rename from src/main/resources/logging_fine.properties rename to src/main/resources/logging_debug.properties index 0882646f0a..f8d22052d4 100644 --- a/src/main/resources/logging_fine.properties +++ b/src/main/resources/logging_debug.properties @@ -16,7 +16,7 @@ # By default we only configure a ConsoleHandler, which will only # show messages at the INFO and above levels. #handlers= java.util.logging.ConsoleHandler -handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler +handlers = org.slf4j.bridge.SLF4JBridgeHandler # To also add the FileHandler, use the following line instead. #handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler diff --git a/src/main/resources/logging_info.properties b/src/main/resources/logging_info.properties index 8881c626d5..984bc6c750 100644 --- a/src/main/resources/logging_info.properties +++ b/src/main/resources/logging_info.properties @@ -16,8 +16,7 @@ # By default we only configure a ConsoleHandler, which will only # show messages at the INFO and above levels. #handlers= java.util.logging.ConsoleHandler -handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler - +handlers = org.slf4j.bridge.SLF4JBridgeHandler # To also add the FileHandler, use the following line instead. #handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler