synchronized Olat resttemplate interception, add more debug-logging

This commit is contained in:
anhefti 2022-06-09 12:05:00 +02:00
parent 3e6efd3ccf
commit 774b52f93b
2 changed files with 59 additions and 11 deletions

View file

@ -8,8 +8,10 @@
package ch.ethz.seb.sebserver.gbl.async; package ch.ethz.seb.sebserver.gbl.async;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.Future; import java.util.concurrent.Future;
import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;
import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicInteger;
import java.util.function.Supplier; import java.util.function.Supplier;
@ -172,7 +174,7 @@ public final class CircuitBreaker<T> {
if (failing > this.maxFailingAttempts || currentBlockingTime > this.maxBlockingTime) { if (failing > this.maxFailingAttempts || currentBlockingTime > this.maxBlockingTime) {
// brake thought to HALF_OPEN state and return error // brake thought to HALF_OPEN state and return error
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug("Changing state from Open to Half Open and return cached value"); log.debug("Changing state from Open to Half Open");
} }
this.state = State.HALF_OPEN; this.state = State.HALF_OPEN;
@ -203,7 +205,7 @@ public final class CircuitBreaker<T> {
if (result.hasError()) { if (result.hasError()) {
// on fail go to OPEN state // on fail go to OPEN state
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug("Changing state from Half Open to Open and return cached value"); log.debug("Changing state from Half Open to Open");
} }
this.lastOpenTime = Utils.getMillisecondsNow(); this.lastOpenTime = Utils.getMillisecondsNow();
@ -214,7 +216,7 @@ public final class CircuitBreaker<T> {
} else { } else {
// on success go to CLOSED state // on success go to CLOSED state
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug("Changing state from Half Open to Closed and return value"); log.debug("Changing state from Half Open to Closed");
} }
this.state = State.CLOSED; this.state = State.CLOSED;
@ -248,9 +250,21 @@ public final class CircuitBreaker<T> {
private Result<T> attempt(final Supplier<T> supplier) { private Result<T> attempt(final Supplier<T> supplier) {
final Future<T> future = this.asyncRunner.runAsync(supplier); final Future<T> future = this.asyncRunner.runAsync(supplier);
try { try {
return Result.of(future.get(this.maxBlockingTime, TimeUnit.MILLISECONDS)); return Result.of(future.get(this.maxBlockingTime, TimeUnit.MILLISECONDS));
} catch (final Exception e) { } catch (final InterruptedException e) {
if (log.isDebugEnabled()) {
log.debug("Attempt interruption: {}, {}", e.getMessage(), this.state);
}
return Result.ofError(e);
} catch (final ExecutionException e) {
future.cancel(false);
if (log.isWarnEnabled()) {
log.warn("Attempt error: {}, {}", e.getMessage(), this.state);
}
return Result.ofError(e);
} catch (final TimeoutException e) {
future.cancel(false); future.cancel(false);
log.warn("Max blocking timeout exceeded: {}, {}", this.maxBlockingTime, this.state); log.warn("Max blocking timeout exceeded: {}, {}", this.maxBlockingTime, this.state);
return Result.ofError(e); return Result.ofError(e);

View file

@ -39,28 +39,58 @@ public class OlatLmsRestTemplate extends RestTemplate {
// Add X-OLAT-TOKEN request header to every request done using this RestTemplate // Add X-OLAT-TOKEN request header to every request done using this RestTemplate
this.getInterceptors().add(new ClientHttpRequestInterceptor() { this.getInterceptors().add(new ClientHttpRequestInterceptor() {
@Override @Override
public ClientHttpResponse intercept(final HttpRequest request, final byte[] body, public synchronized ClientHttpResponse intercept(
final HttpRequest request,
final byte[] body,
final ClientHttpRequestExecution execution) throws IOException { final ClientHttpRequestExecution execution) throws IOException {
// if there's no token, authenticate first // if there's no token, authenticate first
if (OlatLmsRestTemplate.this.token == null) { if (OlatLmsRestTemplate.this.token == null) {
authenticate(); authenticate();
} }
// when authenticating, just do a normal call // when authenticating, just do a normal call
else if (OlatLmsRestTemplate.this.token.equals("authenticating")) { else if (OlatLmsRestTemplate.this.token.equals("authenticating")) {
if (log.isDebugEnabled()) {
log.debug("OLAT [authentication call]: URL {}", request.getURI());
}
return execution.execute(request, body); return execution.execute(request, body);
} }
// otherwise, add the X-OLAT-TOKEN // otherwise, add the X-OLAT-TOKEN
request.getHeaders().set("accept", "application/json"); request.getHeaders().set("accept", "application/json");
request.getHeaders().set("X-OLAT-TOKEN", OlatLmsRestTemplate.this.token); request.getHeaders().set("X-OLAT-TOKEN", OlatLmsRestTemplate.this.token);
if (log.isDebugEnabled()) {
log.debug("OLAT [regular API call]: URL {}", request.getURI());
}
ClientHttpResponse response = execution.execute(request, body); ClientHttpResponse response = execution.execute(request, body);
log.debug("OLAT [regular API call] {} Headers: {}", response.getStatusCode(), response.getHeaders());
if (log.isDebugEnabled()) {
log.debug("OLAT [regular API call response] {} Headers: {}",
response.getStatusCode(),
response.getHeaders());
}
// If we get a 401, re-authenticate and try once more // If we get a 401, re-authenticate and try once more
if (response.getStatusCode() == HttpStatus.UNAUTHORIZED || if (response.getStatusCode() == HttpStatus.UNAUTHORIZED
response.getStatusCode() == HttpStatus.FORBIDDEN) { /* || response.getStatusCode() == HttpStatus.FORBIDDEN */) {
authenticate(); authenticate();
request.getHeaders().set("X-OLAT-TOKEN", OlatLmsRestTemplate.this.token); request.getHeaders().set("X-OLAT-TOKEN", OlatLmsRestTemplate.this.token);
if (log.isDebugEnabled()) {
log.debug("OLAT [retry API call]: URL {}", request.getURI());
}
response = execution.execute(request, body); response = execution.execute(request, body);
log.debug("OLAT [retry API call] {} Headers: {}", response.getStatusCode(), response.getHeaders());
if (log.isDebugEnabled()) {
log.debug("OLAT [retry API call response] {} Headers: {}",
response.getStatusCode(),
response.getHeaders());
}
} }
return response; return response;
} }
@ -76,11 +106,15 @@ public class OlatLmsRestTemplate extends RestTemplate {
credentials.put("password", this.details.getClientSecret()); credentials.put("password", this.details.getClientSecret());
final HttpHeaders httpHeaders = new HttpHeaders(); final HttpHeaders httpHeaders = new HttpHeaders();
httpHeaders.set("content-type", "application/json"); httpHeaders.set("content-type", "application/json");
final HttpEntity<Map<String,String>> requestEntity = new HttpEntity<>(credentials, httpHeaders); final HttpEntity<Map<String, String>> requestEntity = new HttpEntity<>(credentials, httpHeaders);
try { try {
final ResponseEntity<String> response = this.postForEntity(authUrl, requestEntity, String.class); final ResponseEntity<String> response = this.postForEntity(authUrl, requestEntity, String.class);
final HttpHeaders responseHeaders = response.getHeaders(); final HttpHeaders responseHeaders = response.getHeaders();
log.debug("OLAT [authenticate] {} Headers: {}", response.getStatusCode(), responseHeaders);
if (log.isDebugEnabled()) {
log.debug("OLAT [authenticated] {} Headers: {}", response.getStatusCode(), responseHeaders);
}
this.token = responseHeaders.getFirst("X-OLAT-TOKEN"); this.token = responseHeaders.getFirst("X-OLAT-TOKEN");
} catch (final Exception e) { } catch (final Exception e) {
this.token = null; this.token = null;