Представьте: вы написали код, покрыли его тестами, запустили их локально — тесты успешно прошли. Вы загрузили изменения в репозиторий, пайплайн успешно завершился. Самое время расслабиться и приступить к новым задачам. Но не тут-то было!
Спустя некоторое время в CI/CD падает тест. Вы запускаете тесты локально — они проходят успешно. Вы снова запускаете пайплайн в CI/CD — и тесты снова проходят. Однако через какое-то время ситуация повторяется.
Знакомая картина? Значит, вы уже сталкивались с flaky-тестами.
Flaky-тесты — это тесты, которые могут как успешно пройти, так и упасть без каких-либо изменений в коде.
По работе я довольно часто сталкиваюсь с flaky-тестами. Иногда удаётся поймать падение при локальном прогоне тестов. Иногда причина становится ясной по полученной ошибке. Иногда мы можем проанализировать логи и найти источник проблемы.
Но бывает, что тесты падают только в CI/CD: ошибка ничего не объясняет, а логи превышают лимиты и не сохраняются полностью. Такая ситуация особенно часто возникает при написании интеграционных тестов для сложных многошаговых процессов, работающих с большим объёмом данных.
«Ах, если бы можно было вставить assert прямо в код, чтобы ловить ошибки там, где они возникают», — подумал я. В принципе, мы иногда действительно добавляем проверки (assertions) в сам код — например, для проверки параметров методов на null.
Но, конечно, мы не знаем заранее, какое конкретное значение должна иметь переменная в конкретный момент времени. Кроме того, добавление множества assertions сделало бы код практически нечитаемым.
Тогда мне пришла в голову идея: а что если сделать небольшую утилиту, которая позволяла бы вставлять в код лямбду из теста? Как-бы, заминировать код. Это могло бы выглядеть примерно так:
В коде:
inlineAssert("step1", i, status);В тесте:
on("step1").check((int i, Status status) -> {
// проверки
});
myClass.myMethod();Конечно, для этого придётся добавить в код несколько дополнительных строк, которые сами по себе никак не будут влиять на выполнение программы — они нужны будут только для тестов. Но ничего страшного: мы ведь уже добавляем в код логи!
Минуточку...
Для логирования мы используем SLF4J, который сам по себе ничего не логирует, а делегирует вызовы методов, например, в Logback. Точно так же он может делегировать вызовы любому другому провайдеру — например, нашей утилите, в которой мы сможем выполнять необходимые проверки.
Это примерно аналогично тому, как если бы мы использовали Mockito, чтобы создать Spy для логгера.
Так у меня и родилась идея утилиты JMina.
Возможности JMina:
Перехватывать вызовы методов логирования SLF4J по имени логгера, уровню логирования, маркеру и сообщению — в любых комбинациях.
Проверять передаваемые параметры на равенство заданным значениям.
Использовать лямбду для проверки параметров.
Вызывать исключения при выполнении определённых логов.
Проверять, что все ожидаемые логи были вызваны.
Рассмотрим, как это работает на простейшем примере — вычислении корней квадратного уравнения.
Алгоритм состоит из двух шагов: сначала вычисляется дискриминант, затем, на основе дискриминанта, находятся сами корни. Ошибка может произойти на любом из этих шагов. Чтобы понять, на каком именно этапе возникла проблема, добавим в код логирование значения дискриминанта.
public class QuadraticEquation {
private final Logger log = LoggerFactory.getLogger(QuadraticEquation.class);
public List<Double> solve(double a, double b, double c) {
double discriminant = b * b - 4 * a * c;
log.debug("discriminant: {}", discriminant); // Log the discriminant value to verify it during test execution
if (discriminant < 0) {
return Collections.emptyList();
} else {
List<Double> roots = new ArrayList<>();
if (discriminant > 0) {
roots.add((-b - sqrt(discriminant)) / (2 * a));
roots.add((-b + sqrt(discriminant)) / (2 * a));
} else {
roots.add(-b / (2 * a));
}
return roots;
}
}
}
А в тесте добавим проверку его значения.
public class QuadraticEquationTest {
@Test
public void testSolve() {
// Verify discriminant value inside the solve method
Mina
.on(QuadraticEquation.class, DEBUG, "discriminant: {}")
.check((Double discriminant) -> assertEquals(9, discriminant));
// Run our code
List<Double> roots = new QuadraticEquation().solve(1, -1, -2);
// Verify that all logs were called
Mina.assertAllCalled();
// Verify roots
assertEquals(-1, roots.get(0));
assertEquals(2, roots.get(1));
}
@AfterEach
public void clean() {
// Don't forget to clean-up context after each test
Mina.clean();
}
}
Теперь, если на этапе вычисления дискриминанта будет получено неправильное значение, тест упадёт с ошибкой. Причём stack trace укажет именно на то место в коде, где произошла ошибка. Таким образом мы сможем быстро найти проблему и исправить её.
На что ещё способна JMina?
Если мы тестируем успешный сценарий (success path), то, скорее всего, не ожидаем появления сообщений об ошибках. И если такое сообщение будет залогировано, мы можем сразу остановить выполнение теста и выбросить исключение.
Mina.on(ERROR).exception();Flaky-тесты могут отнимать массу времени и сил, особенно когда ошибки проявляются только в CI/CD, а логи оказываются неполными или бесполезными. Чтобы упростить отладку и повысить надёжность тестов, я разработал утилиту JMina — лёгкое, но мощное решение для перехвата и проверки логов прямо в процессе выполнения кода.
С помощью JMina можно оперативно находить ошибки там, где они возникают, проверять ключевые этапы работы системы и мгновенно останавливать тесты при появлении неожиданных проблем. Эта утилита уже помогает мне делать тестирование стабильнее и эффективнее — надеюсь, она будет полезна и вам.
P.S. Наиболее частые причины flaky-тестов (по моему опыту):
Влияние других тестов в Pipeline.
Некоторые тесты могут переопределять Bean'ы с помощью Mock'ов, менять настройки или оставлять грязные данные. И далеко не все тесты корректно очищают изменения после себя.Scheduled tasks.
Задачи, запускаемые по расписанию, могут начать выполняться во время прохождения тестов и повлиять на результат. Рекомендую отключать планировщики в тестовой среде.Неправильная работа со временем.
Некоторые тесты могут проходить или падать в зависимости от текущего времени. Чаще всего проблемы возникают около полуночи, в первый и последний день месяца или года.Race condition.
Неприятная проблема: иногда крайне сложно понять, что именно произошло. Но лучше, чтобы у вас падали тесты, а не продакшн.Отсутствие сортировки там, где она требуется. При работе с небольшими таблицами в базе данных строки часто возвращаются в порядке вставки или в порядке материального индекса. Но если явная сортировка не указана в запросе, СУБД не гарантирует порядок строк.
