keycloak-aplcache
Changes
testsuite/performance/README.md 1(+1 -0)
testsuite/performance/tests/pom.xml 1(+1 -0)
Details
testsuite/performance/README.md 1(+1 -0)
diff --git a/testsuite/performance/README.md b/testsuite/performance/README.md
index 5987c57..fdd93d7 100644
--- a/testsuite/performance/README.md
+++ b/testsuite/performance/README.md
@@ -146,6 +146,7 @@ Usage: `mvn verify -Ptest[,cluster] [-DtestParameter=value]`.
| `warmUpPeriod` | Period with steady number of users intended for the system under test to warm up. (seconds) | `0` |
| `measurementPeriod` | A measurement period after the system is warmed up. (seconds) | `30` |
| `rampDownASAP` | When `true` the test will be checking for ramp-down condition after each *scenario step*. When `false` the check will be done only at the end of a *scenario iteration*. | `false` |
+| `filterResults` | Whether to filter out requests which are outside of the `measurementPeriod`. | `false` |
| `pace` | A dynamic pause after each *scenario iteration*. For example if the pace is 30s and one scenario iteration takes only 20s, the simulation will wait additional 10s before continuing to the next iteration. | `0` |
| `userThinkTime` | Pause between individual scenario steps. | `5` |
| `refreshTokenPeriod`| Period after which token should be refreshed. | `10` |
testsuite/performance/tests/pom.xml 1(+1 -0)
diff --git a/testsuite/performance/tests/pom.xml b/testsuite/performance/tests/pom.xml
index 117bd80..37bb52b 100644
--- a/testsuite/performance/tests/pom.xml
+++ b/testsuite/performance/tests/pom.xml
@@ -278,6 +278,7 @@
<include>keycloak.DemoSimulation2</include>
</includes-->
<jvmArgs>
+ <param>-Dproject.build.directory=${project.build.directory}</param>
<param>-Dkeycloak.server.uris=${keycloak.frontend.servers}</param>
<param>-DnumOfRealms=${numOfRealms}</param>
<param>-DusersPerRealm=${usersPerRealm}</param>
diff --git a/testsuite/performance/tests/src/main/java/org/keycloak/performance/log/LogProcessor.java b/testsuite/performance/tests/src/main/java/org/keycloak/performance/log/LogProcessor.java
index 7c6a5ec..da835f2 100644
--- a/testsuite/performance/tests/src/main/java/org/keycloak/performance/log/LogProcessor.java
+++ b/testsuite/performance/tests/src/main/java/org/keycloak/performance/log/LogProcessor.java
@@ -5,13 +5,19 @@ import java.io.File;
import java.io.FileInputStream;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
+import java.io.FileReader;
import java.io.IOException;
import java.io.InputStreamReader;
import java.io.OutputStreamWriter;
import java.io.PrintWriter;
+import java.io.Reader;
+import java.io.Writer;
import java.nio.charset.Charset;
+import java.nio.file.Files;
import java.util.ArrayList;
+import java.util.Arrays;
import java.util.HashMap;
+import java.util.HashSet;
import java.util.LinkedHashMap;
import java.util.LinkedHashSet;
import java.util.Map;
@@ -29,6 +35,7 @@ public class LogProcessor {
static boolean INLAYED_INCLUDED = false;
static boolean OUTLAYED_INCLUDED = false;
+ static boolean COMPLETE_SESSIONS = false;
File simulationLogFile;
String lastRequestLabel;
@@ -56,6 +63,25 @@ public class LogProcessor {
simulationLogFile = new File(logFilePath);
}
+ public LogProcessor(Class simulationClass) {
+ this(getLatestSimulationLogDir(getSimulationId(simulationClass)).getAbsoluteFile().toString() + "/simulation.log");
+ }
+
+ public static String getSimulationId(Class simulationClass) {
+ return simulationClass.getSimpleName().toLowerCase();
+ }
+
+ private static File getLatestSimulationLogDir(String simulationId) {
+ String buildDirPath = System.getProperty("project.build.directory", "target");
+ String resultsDirPath = System.getProperty("gatling.core.directory.results", buildDirPath + "/gatling");
+ File resultsDir = new File(resultsDirPath);
+
+ return Arrays.stream(resultsDir.listFiles((dir, name) -> name.startsWith(simulationId)))
+ .sorted((a, b) -> -a.compareTo(b))
+ .findFirst()
+ .orElseThrow(() -> new IllegalStateException("Latest simulation.log not found."));
+ }
+
public Stats stats() throws IOException {
Stats stats = new Stats();
@@ -125,15 +151,55 @@ public class LogProcessor {
currentIterations.put(scenario, 1 + currentIterations.getOrDefault(scenario, 1));
}
+ public void filterLog(long start, long end) throws IOException {
+ filterLog(start, end, INLAYED_INCLUDED, OUTLAYED_INCLUDED, COMPLETE_SESSIONS);
+ }
+
+ public void filterLog(long start, long end, boolean inlayedIncluded, boolean outlayedIncluded, boolean completeSessions) throws IOException {
+ INLAYED_INCLUDED = inlayedIncluded;
+ OUTLAYED_INCLUDED = outlayedIncluded;
+ COMPLETE_SESSIONS = completeSessions;
+
+ System.out.println(String.format("Filtering %s/%s \nINLAYED_INCLUDED: %s \nOUTLAYED_INCLUDED: %s \nCOMPLETE_SESSIONS: %s",
+ simulationLogFile.getParentFile().getName(), simulationLogFile.getName(), INLAYED_INCLUDED, OUTLAYED_INCLUDED, COMPLETE_SESSIONS));
+
+ File simulationLogFileFiltered = new File(simulationLogFile.getAbsoluteFile() + ".filtered");
+ File simulationLogFileUnfiltered = new File(simulationLogFile.getAbsoluteFile() + ".unfiltered");
+
+ PrintWriter out = new PrintWriter(new OutputStreamWriter(new FileOutputStream(simulationLogFileFiltered), "utf-8"));
+ copyPartialLog(out, start, end);
+
+ simulationLogFile.renameTo(simulationLogFileUnfiltered);
+ simulationLogFileFiltered.renameTo(simulationLogFile);
+ }
+
public void copyPartialLog(PrintWriter output, long start, long end) throws IOException {
+ File tmpFile = null, headFile = null;
+ PrintWriter tmp = null, startHead = null;
+ HashMap<String, LogLine> starts = new HashMap<>();
+ HashSet<String> actives = new HashSet<>();
+
+ if (COMPLETE_SESSIONS) {
+ tmp = output;
+ tmpFile = getTmpFile();
+ output = new PrintWriter(new OutputStreamWriter(new FileOutputStream(tmpFile), "utf-8"));
+
+ headFile = getTmpFile();
+ startHead = new PrintWriter(new OutputStreamWriter(new FileOutputStream(headFile), "utf-8"));
+ }
+
LogReader reader = new LogReader(simulationLogFile);
try {
LogLine line;
while ((line = reader.readLine()) != null) {
if (line.type() == LogLine.Type.RUN) {
- output.println(line.rawLine());
+ if (COMPLETE_SESSIONS) {
+ startHead.println(line.rawLine());
+ } else {
+ output.println(line.rawLine());
+ }
continue;
}
@@ -149,13 +215,73 @@ public class LogProcessor {
} else if (INLAYED_INCLUDED && endTime >= start && endTime < end) {
output.println(line.rawLine());
}
+
+ if (COMPLETE_SESSIONS) {
+ if (line.type() == LogLine.Type.USER_START) {
+ if (startTime < end) {
+ starts.put(line.userId(), line);
+ }
+ } else if (line.type() == LogLine.Type.USER_END) {
+ if (endTime < start) {
+ starts.remove(line.userId());
+ } else if (endTime >= start && endTime < end) {
+ LogLine sline = starts.remove(line.userId());
+ if (sline != null) {
+ startHead.println(sline.rawLine());
+ }
+ actives.remove(line.userId());
+ } else if (endTime >= end) {
+ boolean was = actives.remove(line.userId());
+ if (was) {
+ output.println(line.rawLine());
+ }
+ }
+ } else if (line.type() == LogLine.Type.REQUEST) {
+ if ((startTime >= start && startTime < end) || (endTime >= start && endTime < end)) {
+ LogLine sline = starts.remove(line.userId());
+ if (sline != null) {
+ startHead.println(sline.rawLine());
+ }
+ actives.add(line.userId());
+ }
+ }
+ }
}
} finally {
reader.close();
output.flush();
+
+ if (COMPLETE_SESSIONS) {
+ startHead.close();
+ output.close();
+
+
+ BufferedReader tmpIn = new BufferedReader(new FileReader(headFile));
+ copyStream(tmpIn, tmp);
+
+ tmpIn = new BufferedReader(new FileReader(tmpFile));
+ copyStream(tmpIn, tmp);
+
+ tmp.flush();
+
+ Files.delete(headFile.toPath());
+ Files.delete(tmpFile.toPath());
+ }
+ }
+ }
+
+ private static void copyStream(Reader reader, Writer writer) throws IOException {
+ char [] buff = new char[16 * 1024];
+ int rc;
+ while ((rc = reader.read(buff)) != -1) {
+ writer.write(buff, 0, rc);
}
}
+ private File getTmpFile() throws IOException {
+ return Files.createTempFile("perftest", ".log").toFile();
+ }
+
public void setLastRequestLabel(String lastRequestLabel) {
this.lastRequestLabel = lastRequestLabel;
}
@@ -333,7 +459,7 @@ public class LogProcessor {
start = Long.parseLong(cols[4]);
end = Long.parseLong(cols[5]);
} else {
- throw new RuntimeException("Unknow log entry type: " + cols[3]);
+ throw new RuntimeException("Unknow log entry type: " + cols[2]);
}
return this;
@@ -407,6 +533,11 @@ public class LogProcessor {
}
endMillis = Long.valueOf(args[++i]);
break;
+ case "--completeSessions":
+ //INLAYED_INCLUDED = true;
+ OUTLAYED_INCLUDED = true;
+ COMPLETE_SESSIONS = true;
+ break;
case "--lastRequest":
if (i == args.length - 1) {
throw new RuntimeException("Argument " + arg + " requires a LABEL");
diff --git a/testsuite/performance/tests/src/main/java/org/keycloak/performance/TestConfig.java b/testsuite/performance/tests/src/main/java/org/keycloak/performance/TestConfig.java
index bbb896d..6d7d5d7 100644
--- a/testsuite/performance/tests/src/main/java/org/keycloak/performance/TestConfig.java
+++ b/testsuite/performance/tests/src/main/java/org/keycloak/performance/TestConfig.java
@@ -60,6 +60,7 @@ public class TestConfig {
public static final int warmUpPeriod = Integer.getInteger("warmUpPeriod", 0);
public static final int measurementPeriod = Integer.getInteger("measurementPeriod", 30);
public static final boolean rampDownASAP = Boolean.getBoolean("rampDownASAP"); // check for rampdown condition after each scenario step
+ public static final boolean filterResults = Boolean.getBoolean("filterResults"); // filter out results outside of measurementPeriod
public static final int pace = Integer.getInteger("pace", 0); // additional dynamic "pause buffer" between scenario loops
public static final int userThinkTime = Integer.getInteger("userThinkTime", 0);
public static final int refreshTokenPeriod = Integer.getInteger("refreshTokenPeriod", 0);
@@ -122,10 +123,11 @@ public class TestConfig {
+ " warmUpPeriod: %s\n"
+ " measurementPeriod: %s\n"
+ " rampDownASAP: %s\n"
+ + " filterResults: %s\n"
+ " pace: %s\n"
+ " userThinkTime: %s\n"
+ " refreshTokenPeriod: %s",
- runUsers, rampUpPeriod, warmUpPeriod, measurementPeriod, rampDownASAP, pace, userThinkTime, refreshTokenPeriod
+ runUsers, rampUpPeriod, warmUpPeriod, measurementPeriod, rampDownASAP, filterResults, pace, userThinkTime, refreshTokenPeriod
);
}
diff --git a/testsuite/performance/tests/src/test/scala/keycloak/AdminConsoleSimulation.scala b/testsuite/performance/tests/src/test/scala/keycloak/AdminConsoleSimulation.scala
index 77b9778..8ddb9a9 100644
--- a/testsuite/performance/tests/src/test/scala/keycloak/AdminConsoleSimulation.scala
+++ b/testsuite/performance/tests/src/test/scala/keycloak/AdminConsoleSimulation.scala
@@ -99,4 +99,9 @@ class AdminConsoleSimulation extends Simulation {
setUp(adminScenario
.inject(rampUsers(TestConfig.runUsers) over TestConfig.rampUpPeriod)
.protocols(httpProtocol))
+
+ after {
+ filterResults(getClass)
+ }
+
}
diff --git a/testsuite/performance/tests/src/test/scala/keycloak/BasicOIDCSimulation.scala b/testsuite/performance/tests/src/test/scala/keycloak/BasicOIDCSimulation.scala
index 140da33..20e2f93 100644
--- a/testsuite/performance/tests/src/test/scala/keycloak/BasicOIDCSimulation.scala
+++ b/testsuite/performance/tests/src/test/scala/keycloak/BasicOIDCSimulation.scala
@@ -59,4 +59,8 @@ class BasicOIDCSimulation extends Simulation {
.inject(rampUsers(TestConfig.runUsers) over TestConfig.rampUpPeriod)
.protocols(httpDefault))
+ after {
+ filterResults(getClass)
+ }
+
}
diff --git a/testsuite/performance/tests/src/test/scala/keycloak/CommonScenarioBuilder.scala b/testsuite/performance/tests/src/test/scala/keycloak/CommonScenarioBuilder.scala
index 18a1b0f..39cc1a7 100644
--- a/testsuite/performance/tests/src/test/scala/keycloak/CommonScenarioBuilder.scala
+++ b/testsuite/performance/tests/src/test/scala/keycloak/CommonScenarioBuilder.scala
@@ -4,6 +4,7 @@ import io.gatling.core.Predef._
import io.gatling.http.Predef._
import org.keycloak.gatling.Predef._
import keycloak.BasicOIDCScenarioBuilder._
+import org.keycloak.performance.log.LogProcessor
import java.util.concurrent.atomic.AtomicInteger
@@ -27,5 +28,14 @@ object CommonScenarioBuilder {
System.currentTimeMillis < TestConfig.measurementEndTime
}
+ def filterResults(clazz: Class[_]) = {
+ if (TestConfig.filterResults) {
+ new LogProcessor(clazz).filterLog(
+ TestConfig.measurementStartTime,
+ TestConfig.measurementEndTime,
+ false, true, true)
+ }
+ }
+
}