|
|
|
|
@@ -4,6 +4,16 @@
|
|
|
|
|
|
|
|
|
|
package io.airbyte.cdk.extensions;
|
|
|
|
|
|
|
|
|
|
import static java.util.concurrent.TimeUnit.DAYS;
|
|
|
|
|
import static java.util.concurrent.TimeUnit.HOURS;
|
|
|
|
|
import static java.util.concurrent.TimeUnit.MICROSECONDS;
|
|
|
|
|
import static java.util.concurrent.TimeUnit.MILLISECONDS;
|
|
|
|
|
import static java.util.concurrent.TimeUnit.MINUTES;
|
|
|
|
|
import static java.util.concurrent.TimeUnit.NANOSECONDS;
|
|
|
|
|
import static java.util.concurrent.TimeUnit.SECONDS;
|
|
|
|
|
import static java.util.regex.Pattern.CASE_INSENSITIVE;
|
|
|
|
|
import static java.util.regex.Pattern.UNICODE_CASE;
|
|
|
|
|
|
|
|
|
|
import java.lang.reflect.Constructor;
|
|
|
|
|
import java.lang.reflect.InvocationHandler;
|
|
|
|
|
import java.lang.reflect.Method;
|
|
|
|
|
@@ -11,19 +21,23 @@ import java.lang.reflect.Modifier;
|
|
|
|
|
import java.lang.reflect.Proxy;
|
|
|
|
|
import java.time.Duration;
|
|
|
|
|
import java.time.Instant;
|
|
|
|
|
import java.time.format.DateTimeParseException;
|
|
|
|
|
import java.util.Collections;
|
|
|
|
|
import java.util.HashMap;
|
|
|
|
|
import java.util.LinkedList;
|
|
|
|
|
import java.util.List;
|
|
|
|
|
import java.util.Locale;
|
|
|
|
|
import java.util.Map;
|
|
|
|
|
import java.util.concurrent.ConcurrentHashMap;
|
|
|
|
|
import java.util.concurrent.ExecutorService;
|
|
|
|
|
import java.util.Timer;
|
|
|
|
|
import java.util.TimerTask;
|
|
|
|
|
import java.util.concurrent.TimeUnit;
|
|
|
|
|
import java.util.concurrent.TimeoutException;
|
|
|
|
|
import java.util.regex.Matcher;
|
|
|
|
|
import java.util.regex.Pattern;
|
|
|
|
|
import org.apache.commons.lang3.StringUtils;
|
|
|
|
|
import org.apache.commons.lang3.exception.ExceptionUtils;
|
|
|
|
|
import org.apache.commons.lang3.time.DurationFormatUtils;
|
|
|
|
|
import org.junit.jupiter.api.Assertions;
|
|
|
|
|
import org.junit.jupiter.api.Timeout;
|
|
|
|
|
import org.junit.jupiter.api.Timeout.ThreadMode;
|
|
|
|
|
import org.junit.jupiter.api.extension.DynamicTestInvocationContext;
|
|
|
|
|
import org.junit.jupiter.api.extension.ExtensionContext;
|
|
|
|
|
import org.junit.jupiter.api.extension.InvocationInterceptor;
|
|
|
|
|
@@ -41,13 +55,11 @@ import org.slf4j.LoggerFactory;
|
|
|
|
|
*/
|
|
|
|
|
public class LoggingInvocationInterceptor implements InvocationInterceptor {
|
|
|
|
|
|
|
|
|
|
private static final Duration DEFAULT_TIMEOUT = Duration.ofMinutes(5);
|
|
|
|
|
private static final Logger LOGGER = LoggerFactory.getLogger(LoggingInvocationInterceptor.class);
|
|
|
|
|
private static final String JUNIT_METHOD_EXECUTION_TIMEOUT_PROPERTY_NAME = "JunitMethodExecutionTimeout";
|
|
|
|
|
|
|
|
|
|
private static final class LoggingInvocationInterceptorHandler implements InvocationHandler {
|
|
|
|
|
|
|
|
|
|
private static final Map<Integer, ExecutorService> executorByThread = new ConcurrentHashMap<>();
|
|
|
|
|
|
|
|
|
|
private static final Pattern methodPattern = Pattern.compile("intercept(.*)Method");
|
|
|
|
|
|
|
|
|
|
@Override
|
|
|
|
|
@@ -76,22 +88,33 @@ public class LoggingInvocationInterceptor implements InvocationInterceptor {
|
|
|
|
|
} else {
|
|
|
|
|
logLineSuffix = "execution of unknown intercepted call %s".formatted(methodName);
|
|
|
|
|
}
|
|
|
|
|
Thread currentThread = Thread.currentThread();
|
|
|
|
|
TimeoutInteruptor timeoutTask = new TimeoutInteruptor(currentThread);
|
|
|
|
|
Instant start = Instant.now();
|
|
|
|
|
try {
|
|
|
|
|
final Object retVal;
|
|
|
|
|
Duration timeout = getTimeout(invocationContext);
|
|
|
|
|
if (timeout != null) {
|
|
|
|
|
LOGGER.info("Junit starting {} with timeout of {}", logLineSuffix, DurationFormatUtils.formatDurationWords(timeout.toMillis(), true, true));
|
|
|
|
|
retVal = Assertions.assertTimeoutPreemptively(timeout, invocation::proceed);
|
|
|
|
|
new Timer("TimeoutTimer-" + currentThread.getName(), true).schedule(timeoutTask, timeout.toMillis());
|
|
|
|
|
} else {
|
|
|
|
|
LOGGER.warn("Junit starting {} with no timeout", logLineSuffix);
|
|
|
|
|
retVal = invocation.proceed();
|
|
|
|
|
}
|
|
|
|
|
retVal = invocation.proceed();
|
|
|
|
|
long elapsedMs = Duration.between(start, Instant.now()).toMillis();
|
|
|
|
|
LOGGER.info("Junit completed {} in {}", logLineSuffix, DurationFormatUtils.formatDurationWords(elapsedMs, true, true));
|
|
|
|
|
return retVal;
|
|
|
|
|
} catch (Throwable t) {
|
|
|
|
|
timeoutTask.cancel();
|
|
|
|
|
long elapsedMs = Duration.between(start, Instant.now()).toMillis();
|
|
|
|
|
if (timeoutTask.wasTriggered) {
|
|
|
|
|
Throwable t1 = t;
|
|
|
|
|
t = new TimeoutException(
|
|
|
|
|
"Execution was cancelled after %s. If you think your test should be given more time to complete, you can use the @Timeout annotation. If all the test of a connector are slow, "
|
|
|
|
|
+ " you can override the property 'JunitMethodExecutionTimeout' in your gradle.properties."
|
|
|
|
|
.formatted(DurationFormatUtils.formatDurationWords(elapsedMs, true, true)));
|
|
|
|
|
t.initCause(t1);
|
|
|
|
|
}
|
|
|
|
|
boolean belowCurrentCall = false;
|
|
|
|
|
List<String> stackToDisplay = new LinkedList<>();
|
|
|
|
|
for (String stackString : ExceptionUtils.getStackFrames(t)) {
|
|
|
|
|
@@ -110,25 +133,74 @@ public class LoggingInvocationInterceptor implements InvocationInterceptor {
|
|
|
|
|
LOGGER.error("Junit exception throw during {} after {}:\n{}", logLineSuffix, DurationFormatUtils.formatDurationWords(elapsedMs, true, true),
|
|
|
|
|
stackTrace);
|
|
|
|
|
throw t;
|
|
|
|
|
} finally {
|
|
|
|
|
timeoutTask.cancel();
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
private static class TimeoutInteruptor extends TimerTask {
|
|
|
|
|
|
|
|
|
|
private final Thread parentThread;
|
|
|
|
|
volatile boolean wasTriggered = false;
|
|
|
|
|
|
|
|
|
|
TimeoutInteruptor(Thread parentThread) {
|
|
|
|
|
this.parentThread = parentThread;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
@Override
|
|
|
|
|
public void run() {
|
|
|
|
|
wasTriggered = true;
|
|
|
|
|
parentThread.interrupt();
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
public boolean cancel() {
|
|
|
|
|
return super.cancel();
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
private static final Pattern PATTERN = Pattern.compile("([1-9]\\d*) *((?:[nμm]?s)|m|h|d)?",
|
|
|
|
|
CASE_INSENSITIVE | UNICODE_CASE);
|
|
|
|
|
private static final Map<String, TimeUnit> UNITS_BY_ABBREVIATION;
|
|
|
|
|
|
|
|
|
|
static {
|
|
|
|
|
Map<String, TimeUnit> unitsByAbbreviation = new HashMap<>();
|
|
|
|
|
unitsByAbbreviation.put("ns", NANOSECONDS);
|
|
|
|
|
unitsByAbbreviation.put("μs", MICROSECONDS);
|
|
|
|
|
unitsByAbbreviation.put("ms", MILLISECONDS);
|
|
|
|
|
unitsByAbbreviation.put("s", SECONDS);
|
|
|
|
|
unitsByAbbreviation.put("m", MINUTES);
|
|
|
|
|
unitsByAbbreviation.put("h", HOURS);
|
|
|
|
|
unitsByAbbreviation.put("d", DAYS);
|
|
|
|
|
UNITS_BY_ABBREVIATION = Collections.unmodifiableMap(unitsByAbbreviation);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
static Duration parseDuration(String text) throws DateTimeParseException {
|
|
|
|
|
Matcher matcher = PATTERN.matcher(text.trim());
|
|
|
|
|
if (matcher.matches()) {
|
|
|
|
|
long value = Long.parseLong(matcher.group(1));
|
|
|
|
|
String unitAbbreviation = matcher.group(2);
|
|
|
|
|
TimeUnit unit = unitAbbreviation == null ? SECONDS
|
|
|
|
|
: UNITS_BY_ABBREVIATION.get(unitAbbreviation.toLowerCase(Locale.ENGLISH));
|
|
|
|
|
return Duration.ofSeconds(unit.toSeconds(value));
|
|
|
|
|
}
|
|
|
|
|
throw new DateTimeParseException("Timeout duration is not in the expected format (<number> [ns|μs|ms|s|m|h|d])",
|
|
|
|
|
text, 0);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
private static Duration getTimeout(ReflectiveInvocationContext<Method> invocationContext) {
|
|
|
|
|
Duration timeout = DEFAULT_TIMEOUT;
|
|
|
|
|
Duration timeout = null;
|
|
|
|
|
if (invocationContext.getExecutable()instanceof Method m) {
|
|
|
|
|
Timeout timeoutAnnotation = m.getAnnotation(Timeout.class);
|
|
|
|
|
if (timeoutAnnotation == null) {
|
|
|
|
|
timeoutAnnotation = invocationContext.getTargetClass().getAnnotation(Timeout.class);
|
|
|
|
|
}
|
|
|
|
|
if (timeoutAnnotation != null) {
|
|
|
|
|
if (timeoutAnnotation.threadMode() == ThreadMode.SAME_THREAD) {
|
|
|
|
|
return null;
|
|
|
|
|
}
|
|
|
|
|
timeout = Duration.ofMillis(timeoutAnnotation.unit().toMillis(timeoutAnnotation.value()));
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
if (timeout.compareTo(Duration.ofHours(1)) > 0) {
|
|
|
|
|
return DEFAULT_TIMEOUT;
|
|
|
|
|
if (timeout == null) {
|
|
|
|
|
timeout = parseDuration(System.getProperty(JUNIT_METHOD_EXECUTION_TIMEOUT_PROPERTY_NAME));
|
|
|
|
|
}
|
|
|
|
|
return timeout;
|
|
|
|
|
}
|
|
|
|
|
|