From: Sébastien Lesaint Date: Tue, 22 Mar 2016 11:01:05 +0000 (+0100) Subject: SONAR-6732 fix ServerTest perf test confused by extra JVM X-Git-Tag: 5.5-M11~51 X-Git-Url: https://source.dussan.org/?a=commitdiff_plain;h=6b29d25a5aeb56e1e73d9e430829bca85c159805;p=sonarqube.git SONAR-6732 fix ServerTest perf test confused by extra JVM orchestrator is using the WS /api/server/index which does not wait for the Compute Engine in its own process to actually finish starting startup time and shutdown time are therefor incorrectly calculated. We now rely on logs to compute them correctly, until the WS is updated --- diff --git a/server/sonar-ce/src/main/java/org/sonar/ce/app/CeServer.java b/server/sonar-ce/src/main/java/org/sonar/ce/app/CeServer.java index 279081366e9..a09765d1d25 100644 --- a/server/sonar-ce/src/main/java/org/sonar/ce/app/CeServer.java +++ b/server/sonar-ce/src/main/java/org/sonar/ce/app/CeServer.java @@ -79,7 +79,7 @@ public class CeServer implements Monitored { /** * Can't be started as is. Needs to be bootstrapped by sonar-application */ - public static void main(String[] args) throws Exception { + public static void main(String[] args) { ProcessEntryPoint entryPoint = ProcessEntryPoint.createForArguments(args); Props props = entryPoint.getProps(); new ServerProcessLogging(PROCESS_NAME, LOG_LEVEL_PROPERTY).configure(props); @@ -188,6 +188,7 @@ public class CeServer implements Monitored { private void startup() { LOG.info("Compute Engine Server starting up..."); computeEngine.startup(); + LOG.info("Compute Engine Server is up"); } private void waitForStopSignal() { diff --git a/tests/perf/src/main/java/org/sonarsource/sonarqube/perf/ServerLogs.java b/tests/perf/src/main/java/org/sonarsource/sonarqube/perf/ServerLogs.java index 7bf90524153..bc85ad04ae9 100644 --- a/tests/perf/src/main/java/org/sonarsource/sonarqube/perf/ServerLogs.java +++ b/tests/perf/src/main/java/org/sonarsource/sonarqube/perf/ServerLogs.java @@ -29,7 +29,7 @@ import java.util.List; public class ServerLogs { - static Date extractDate(String line) { + public static Date extractDate(String line) { String pattern = "yyyy.MM.dd HH:mm:ss"; SimpleDateFormat format = new SimpleDateFormat(pattern); if (line.length() > 19) { diff --git a/tests/perf/src/test/java/org/sonarsource/sonarqube/perf/server/ServerTest.java b/tests/perf/src/test/java/org/sonarsource/sonarqube/perf/server/ServerTest.java index 36687d52c2d..2c89409013e 100644 --- a/tests/perf/src/test/java/org/sonarsource/sonarqube/perf/server/ServerTest.java +++ b/tests/perf/src/test/java/org/sonarsource/sonarqube/perf/server/ServerTest.java @@ -20,16 +20,22 @@ package org.sonarsource.sonarqube.perf.server; import com.sonar.orchestrator.Orchestrator; -import org.sonarsource.sonarqube.perf.PerfTestCase; -import org.sonarsource.sonarqube.perf.ServerLogs; import java.io.IOException; import java.util.Collections; import java.util.Date; import java.util.List; import org.apache.commons.io.FileUtils; +import org.junit.Rule; import org.junit.Test; +import org.junit.rules.Timeout; +import org.sonarsource.sonarqube.perf.PerfTestCase; +import org.sonarsource.sonarqube.perf.ServerLogs; public class ServerTest extends PerfTestCase { + private static final int TIMEOUT_3_MINUTES = 1000 * 60 * 3; + + @Rule + public Timeout timeout = new Timeout(TIMEOUT_3_MINUTES); // ES + TOMCAT @Test @@ -46,39 +52,60 @@ public class ServerTest extends PerfTestCase { .setServerProperty("sonar.web.javaOpts", defaultWebJavaOptions + " -Djava.security.egd=file:/dev/./urandom") .build(); try { - long startupDuration = start(orchestrator); - assertDurationAround(startupDuration, 41000); + ServerLogs.clear(orchestrator); + orchestrator.start(); + + // compare dates of first and last log + long firstLogDate = ServerLogs.extractFirstDate(readLogLines(orchestrator)).getTime(); + long startedAtDate = extractStartedAtDate(orchestrator); + assertDurationAround(startedAtDate - firstLogDate, 45000); + + ServerLogs.clear(orchestrator); + orchestrator.stop(); - long shutdownDuration = stop(orchestrator); - // can't use percent margins because logs are second-grained but not milliseconds - assertDurationLessThan(shutdownDuration, 4000); + List lines = readLogLines(orchestrator); + long firstStopLogDate = ServerLogs.extractFirstDate(lines).getTime(); + long stopDate = extractStopDate(lines); + assertDurationLessThan(stopDate - firstStopLogDate, 10000); } finally { orchestrator.stop(); } } - long start(Orchestrator orchestrator) throws IOException { - ServerLogs.clear(orchestrator); - orchestrator.start(); - return logsPeriod(orchestrator); + private static long extractStartedAtDate(Orchestrator orchestrator) throws IOException { + Date startedAtDate = extractStartedDate(readLogLines(orchestrator)); + // if SQ never starts, the test will fail with timeout + while (startedAtDate == null) { + try { + Thread.sleep(100); + startedAtDate = extractStartedDate(readLogLines(orchestrator)); + } catch (InterruptedException e) { + // ignored + } + } + return startedAtDate.getTime(); } - long stop(Orchestrator orchestrator) throws Exception { - ServerLogs.clear(orchestrator); - orchestrator.stop(); - return logsPeriod(orchestrator); + private static Date extractStartedDate(List lines) { + Collections.reverse(lines); + Date end = null; + for (String line : lines) { + if (line.contains("Compute Engine Server is up")) { + end = ServerLogs.extractDate(line); + break; + } + } + return end; } - private long logsPeriod(Orchestrator orchestrator) throws IOException { - // compare dates of first and last log - List lines = FileUtils.readLines(orchestrator.getServer().getLogs()); - if (lines.size() < 2) { - throw new IllegalStateException("Fail to estimate server shutdown or startup duration. Not enough logs."); - } - Date start = ServerLogs.extractFirstDate(lines); + private static long extractStopDate(List lines) throws IOException { Collections.reverse(lines); Date end = ServerLogs.extractFirstDate(lines); - return end.getTime() - start.getTime(); + return end.getTime(); + } + + private static List readLogLines(Orchestrator orchestrator) throws IOException { + return FileUtils.readLines(orchestrator.getServer().getLogs()); } }