Skip to content

Commit

Permalink
KEYCLOAK-12838 DatasetLoader in performance swallows exceptions (keyc…
Browse files Browse the repository at this point in the history 
…loak#6708)
  • Loading branch information
@tkyjovsk
tkyjovsk authored Feb 6, 2020
1 parent 32fccfa commit a506115
Show file tree
Hide file tree
Showing 3 changed files with 49 additions and 38 deletions.
28 changes: 16 additions & 12 deletions testsuite/performance/tests/src/main/java/org/keycloak/performance/dataset/Creatable.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@

import java.io.IOException;
import javax.ws.rs.ClientErrorException;
import javax.ws.rs.WebApplicationException;
import javax.ws.rs.core.Response;
import static org.keycloak.admin.client.CreatedResponseUtil.getCreatedId;
import org.keycloak.admin.client.Keycloak;
Expand Down Expand Up @@ -32,7 +33,7 @@ public default void readAndSetId(Keycloak adminClient) {
public Response create(Keycloak adminClient);

public default boolean createCheckingForConflict(Keycloak adminClient) {
logger().trace("creating " + this);
logger().debug("Creating " + this);
boolean conflict = false;
try {
Response response = create(adminClient);
Expand All @@ -41,23 +42,26 @@ public default boolean createCheckingForConflict(Keycloak adminClient) {
} else {
String responseBody = response.readEntity(String.class);
response.close();
if (response.getStatus() == 409) { // some endpoints dont't throw exception on 409, throwing here
throw new ClientErrorException(HTTP_409_SUFFIX, response);
}
if (responseBody != null && !responseBody.isEmpty()) {
logger().trace(responseBody);
setRepresentation(EntityTemplate.OBJECT_MAPPER.readValue(responseBody, (Class<REP>) getRepresentation().getClass()));
} else {
setId(getCreatedId(response));
switch (response.getStatus()) {
case 201: // created
if (responseBody != null && !responseBody.isEmpty()) {
logger().trace(String.format("Response status: %s, body: %s", response.getStatus(), responseBody));
setRepresentation(EntityTemplate.OBJECT_MAPPER.readValue(responseBody, (Class<REP>) getRepresentation().getClass()));
} else {
setId(getCreatedId(response));
}
break;
case 409: // some client endpoints dont't throw exception on 409 response, throwing from here
throw new ClientErrorException(HTTP_409_SUFFIX, response);
default:
throw new RuntimeException(String.format("Error when creating entity %s.", this), new WebApplicationException(response));
}
}
} catch (ClientErrorException ex) {
if (ex.getResponse().getStatus() == 409) {
conflict = true;
logger().trace("entity already exists");
logger().debug(String.format("Entity %s already exists.", this));
readAndSetId(adminClient);
} else {
throw ex;
}
} catch (IOException ex) {
throw new RuntimeException(ex);
Expand Down
55 changes: 29 additions & 26 deletions ...suite/performance/tests/src/main/java/org/keycloak/performance/dataset/DatasetLoader.java
View file
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
package org.keycloak.performance.dataset;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.Date;
import java.util.Iterator;
import java.util.LinkedHashMap;
Expand Down Expand Up @@ -28,7 +30,7 @@ public class DatasetLoader implements Loggable {
private static final int QUEUE_TIMEOUT = Integer.parseInt(System.getProperty("queue.timeout", "60"));
private static final int THREADPOOL_SHUTDOWN_TIMEOUT = Integer.parseInt(System.getProperty("shutdown.timeout", "60"));

public static void main(String[] args) {
public static void main(String[] args) throws InterruptedException {
DatasetTemplate template = new DatasetTemplate();
template.validateConfiguration();
DatasetLoader loader = new DatasetLoader(template.produce(), DELETE);
Expand All @@ -49,6 +51,7 @@ public DatasetLoader(Dataset dataset, boolean delete) {
Validate.notNull(dataset);
this.dataset = dataset;
this.delete = delete;
logger().info(String.format("Opening %s admin clients.", TestConfig.numOfWorkers));
for (int i = 0; i < TestConfig.numOfWorkers; i++) {
adminClients.add(Keycloak.getInstance(
TestConfig.serverUrisIterator.next(),
Expand All @@ -59,7 +62,7 @@ public DatasetLoader(Dataset dataset, boolean delete) {
}
}

private void processDataset() {
private void processDataset() throws InterruptedException {
if (delete) {
logger().info("Deleting dataset.");
processEntities(dataset.realms());
Expand Down Expand Up @@ -92,9 +95,10 @@ private void processDataset() {
}
}

private void processEntities(Stream<? extends Updatable> stream) {
private void processEntities(Stream<? extends Updatable> stream) throws InterruptedException {
if (!errorReported()) {
Iterator<? extends Updatable> iterator = stream.iterator();
logger().debug("Creating thread pool.");
ExecutorService threadPool = Executors.newFixedThreadPool(TestConfig.numOfWorkers);
BlockingQueue<Updatable> queue = new LinkedBlockingQueue<>(TestConfig.numOfWorkers + 5);
try {
Expand All @@ -103,12 +107,10 @@ private void processEntities(Stream<? extends Updatable> stream) {
try {
if (queue.offer(iterator.next(), QUEUE_TIMEOUT, SECONDS)) {
threadPool.execute(() -> {
if (!errorReported()) {
try {

Updatable updatable = queue.take();
try {
Updatable updatable = queue.take();
if (!errorReported()) {
Keycloak adminClient = adminClients.take();

try {

if (delete) {
Expand All @@ -126,10 +128,9 @@ private void processEntities(Stream<? extends Updatable> stream) {
} finally {
adminClients.add(adminClient); // return client for reuse
}

} catch (Exception ex) {
reportError(ex);
}
} catch (Throwable ex) {
reportError(ex);
}
});
} else {
Expand All @@ -142,21 +143,18 @@ private void processEntities(Stream<? extends Updatable> stream) {
} catch (Exception ex) {
reportError(ex);
}
// shut down threadpool
if (errorReported()) {
logger().error("Exception thrown from executor service. Shutting down.");

logger().debug("Terminating thread pool.");
threadPool.shutdown();
threadPool.awaitTermination(THREADPOOL_SHUTDOWN_TIMEOUT, SECONDS);
if (!threadPool.isTerminated()) {
logger().error("Failed to terminate the thread pool. Attempting force shutdown.");
threadPool.shutdownNow();
throw new RuntimeException(error);
} else {
try {
threadPool.shutdown();
threadPool.awaitTermination(THREADPOOL_SHUTDOWN_TIMEOUT, SECONDS);
if (!threadPool.isTerminated()) {
throw new IllegalStateException("Executor service still not terminated.");
}
} catch (InterruptedException ex) {
throw new RuntimeException(ex);
}
}

if (errorReported()) {
closeAdminClients();
throw new Error(error);
}
}
}
Expand Down Expand Up @@ -192,11 +190,16 @@ private synchronized boolean errorReported() {

private synchronized void reportError(Throwable ex) {
logProcessedEntityCounts(true);
logger().error("Error occured: " + ex);

StringWriter sw = new StringWriter();
ex.printStackTrace(new PrintWriter(sw));

logger().error(String.format("Error occured in thread %s: %s", Thread.currentThread().getName(), sw.toString()));
this.error = ex;
}

public void closeAdminClients() {
logger().info("Closing admin clients.");
while (!adminClients.isEmpty()) {
adminClients.poll().close();
}
Expand Down
4 changes: 4 additions & 0 deletions testsuite/performance/tests/src/main/resources/logback.xml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,10 @@
<appender-ref ref="CONSOLE_MSG_ONLY" />
</logger>

<!--logging for dataset-->
<logger name="org.keycloak.performance.dataset" level="INFO" additivity="false">
<appender-ref ref="CONSOLE_MSG_ONLY" />
</logger>

<logger name="ch.qos.logback" level="WARN"/>

Expand Down

0 comments on commit a506115

Please sign in to comment.