diff --git a/src/main/java/ch/ethz/seb/sebserver/gbl/async/CircuitBreaker.java b/src/main/java/ch/ethz/seb/sebserver/gbl/async/CircuitBreaker.java index 2493bb23..b06385e6 100644 --- a/src/main/java/ch/ethz/seb/sebserver/gbl/async/CircuitBreaker.java +++ b/src/main/java/ch/ethz/seb/sebserver/gbl/async/CircuitBreaker.java @@ -8,8 +8,10 @@ package ch.ethz.seb.sebserver.gbl.async; +import java.util.concurrent.ExecutionException; import java.util.concurrent.Future; import java.util.concurrent.TimeUnit; +import java.util.concurrent.TimeoutException; import java.util.concurrent.atomic.AtomicInteger; import java.util.function.Supplier; @@ -172,7 +174,7 @@ public final class CircuitBreaker { if (failing > this.maxFailingAttempts || currentBlockingTime > this.maxBlockingTime) { // brake thought to HALF_OPEN state and return error 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; @@ -203,7 +205,7 @@ public final class CircuitBreaker { if (result.hasError()) { // on fail go to OPEN state 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(); @@ -214,7 +216,7 @@ public final class CircuitBreaker { } else { // on success go to CLOSED state 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; @@ -248,9 +250,21 @@ public final class CircuitBreaker { private Result attempt(final Supplier supplier) { final Future future = this.asyncRunner.runAsync(supplier); + try { 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); log.warn("Max blocking timeout exceeded: {}, {}", this.maxBlockingTime, this.state); return Result.ofError(e); diff --git a/src/main/java/ch/ethz/seb/sebserver/webservice/servicelayer/lms/impl/olat/OlatLmsRestTemplate.java b/src/main/java/ch/ethz/seb/sebserver/webservice/servicelayer/lms/impl/olat/OlatLmsRestTemplate.java index 3f67d36e..f244c1b5 100644 --- a/src/main/java/ch/ethz/seb/sebserver/webservice/servicelayer/lms/impl/olat/OlatLmsRestTemplate.java +++ b/src/main/java/ch/ethz/seb/sebserver/webservice/servicelayer/lms/impl/olat/OlatLmsRestTemplate.java @@ -39,28 +39,58 @@ public class OlatLmsRestTemplate extends RestTemplate { // Add X-OLAT-TOKEN request header to every request done using this RestTemplate this.getInterceptors().add(new ClientHttpRequestInterceptor() { @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 { + // if there's no token, authenticate first if (OlatLmsRestTemplate.this.token == null) { authenticate(); } // when authenticating, just do a normal call else if (OlatLmsRestTemplate.this.token.equals("authenticating")) { + + if (log.isDebugEnabled()) { + log.debug("OLAT [authentication call]: URL {}", request.getURI()); + } + return execution.execute(request, body); } // otherwise, add the X-OLAT-TOKEN request.getHeaders().set("accept", "application/json"); 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); - 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 (response.getStatusCode() == HttpStatus.UNAUTHORIZED || - response.getStatusCode() == HttpStatus.FORBIDDEN) { + if (response.getStatusCode() == HttpStatus.UNAUTHORIZED + /* || response.getStatusCode() == HttpStatus.FORBIDDEN */) { + authenticate(); 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); - 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; } @@ -76,11 +106,15 @@ public class OlatLmsRestTemplate extends RestTemplate { credentials.put("password", this.details.getClientSecret()); final HttpHeaders httpHeaders = new HttpHeaders(); httpHeaders.set("content-type", "application/json"); - final HttpEntity> requestEntity = new HttpEntity<>(credentials, httpHeaders); + final HttpEntity> requestEntity = new HttpEntity<>(credentials, httpHeaders); try { final ResponseEntity response = this.postForEntity(authUrl, requestEntity, String.class); 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"); } catch (final Exception e) { this.token = null;