libre.sh/keycloak-scim
4
0
Fork 0
Code Issues 15 Pull requests Releases 1 Activity Actions

KEYCLOAK-5973 Filtering of Gatling results

Browse source
This commit is contained in:
Tomas Kyjovsky 2018-02-23 15:29:15 +01:00
parent d70e4740fc
commit 417c31bc0b
7 changed files with 157 additions and 3 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

1
testsuite/performance/README.md
View file

@ -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` |

1
testsuite/performance/tests/pom.xml
View file

@ -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>

4
testsuite/performance/tests/src/main/java/org/keycloak/performance/TestConfig.java
View file

@ -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
);
}

135
testsuite/performance/tests/src/main/java/org/keycloak/performance/log/LogProcessor.java
View file

@ -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");

5
testsuite/performance/tests/src/test/scala/keycloak/AdminConsoleSimulation.scala
View file

@ -99,4 +99,9 @@ class AdminConsoleSimulation extends Simulation {
setUp(adminScenario
.inject(rampUsers(TestConfig.runUsers) over TestConfig.rampUpPeriod)
.protocols(httpProtocol))
after {
filterResults(getClass)
}
}

4
testsuite/performance/tests/src/test/scala/keycloak/BasicOIDCSimulation.scala
View file

@ -59,4 +59,8 @@ class BasicOIDCSimulation extends Simulation {
.inject(rampUsers(TestConfig.runUsers) over TestConfig.rampUpPeriod)
.protocols(httpDefault))
after {
filterResults(getClass)
}
}

10
testsuite/performance/tests/src/test/scala/keycloak/CommonScenarioBuilder.scala
View file

@ -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)
}
}
}