Устранение Race Condition в автотестах: от анализа логов до стабильного ожидания

Анатомия ошибки: чтение стектрейса и поиск точки отказа

java.lang.AssertionError: Статус талона отличен от ожидаемого. Ожидалось: 7 (DROPPED), фактически: 3 (CALLING).

Если вы пишете или поддерживаете автотесты, вы наверняка регулярно видите подобные красные строки в логах. Тест упал, сборка остановилась. Для новичка первая реакция — паника или желание перезапустить тест в надежде, что «само пройдёт» (и иногда, к сожалению, проходит, что делает ситуацию только хуже).

Первый шаг к стабильным тестам — научиться хладнокровно препарировать ошибку. Давайте разберём этот лог на составляющие и найдём точное место в коде, где всё пошло не так.

Шаг 1. Расшифровка сообщения об ошибке

Сообщение об ошибке (Error Message) — это диагноз. В нашем случае это AssertionError. Эта ошибка означает, что логика теста отработала без технических сбоев (никто не поделил на ноль и не обратился к пустой ссылке), но бизнес-проверка не сошлась с реальностью.

Вчитаемся в детали:

Ожидалось: 7 (DROPPED), фактически: 3 (CALLING)

Откуда взялись эти цифры? Заглянем в словарь нашего проекта — перечисление TicketStatusEnum. В нём зафиксированы все возможные состояния талона в системе:

CALLING(3) — талон вызывается.
DROPPED(7) — талон сброшен системой.

Тест ожидал, что после его действий талон получит статус 7 (сброшен). Но когда тест заглянул в базу данных, он увидел там статус 3 (вызывается). Система не перевела талон в нужное состояние.

Шаг 2. Чтение стектрейса (Stack Trace)

Поняв что пошло не так, нам нужно выяснить где это произошло. Для этого нужен стектрейс — простыня текста под сообщением об ошибке, которая пугает многих начинающих автоматизаторов.

Стектрейс — это просто история вызовов методов, записанная в обратном порядке. Самая верхняя строка — это место, где произошла авария. Строка ниже — метод, который вызвал аварийный метод, и так далее.

В логах нашего упавшего теста ключевыми будут эти три строки:

FeqsSuoDbSteps.assertLastTicketStatus(FeqsSuoDbSteps.java:62)
FeqsUiMainSteps.resetTicket(FeqsUiMainSteps.java:107)
FeqsUiMainSteps.resetTickets(FeqsUiMainSteps.java:116)

Как это прочитать? Мы начали выполнять массовый сброс талонов в методе resetTickets (строка 116). Внутри него для конкретного талона мы вызвали метод resetTicket (строка 107). А уже внутри него мы попытались проверить статус в БД через assertLastTicketStatus (строка 62) — и именно здесь тест разбился.

Шаг 3. Анализ точки отказа

Мы нашли точное место. Теперь нужно посмотреть на код вокруг 107-й строки, чтобы понять контекст.

@Step("Сбросить талон, находящийся на обслуживании")
public void resetTicket(TechnicalDepartmentEnum technicalDepartment, String ticketNumber) {
    Response response = feqsUiMainService.reset(getCookie(), technicalDepartment.getId());
    checkResponse(response, 200);
    checkSuccess(response);
    try {
        Thread.sleep(5000);
    } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
        throw new RuntimeException("Прервано ожидание перед сбросом талона", e);
    }
    // Строка 107:
    feqsSuoDbSteps.assertLastTicketStatus(technicalDepartment.getId(), ticketNumber, DROPPED);
}

Давайте восстановим хронологию событий в этом методе:

Мы отправляем API-запрос на сброс талона (feqsUiMainService.reset).
Мы проверяем, что сервер ответил нам HTTP-статусом 200 (ОК).
Мы замираем и ждём ровно 5 секунд с помощью Thread.sleep(5000).
Мы идём в базу данных и проверяем, что статус стал DROPPED.

Здесь кроется главная подсказка. API-запрос выполнился успешно (иначе тест упал бы раньше, на проверке ответа сервера). Мы честно подождали 5 секунд. Но база данных всё равно вернула нам старый статус CALLING.

Мы нашли точку отказа и поняли контекст. Наш тест столкнулся с классической проблемой асинхронных систем: мы попросили систему сделать работу, подождали фиксированное время, но система не успела. В следующей главе мы разберём, почему жёсткие паузы вроде Thread.sleep — это бомба замедленного действия, и познакомимся с понятием Race Condition.

Природа Race Condition: почему Thread.sleep не гарантирует результат

5000 миллисекунд — это целая вечность для процессора, выполняющего миллиарды операций в секунду. В методе resetTicket автотест честно замирает на 5 секунд после отправки API-запроса на сброс талона. Но тест всё равно падает, утверждая, что статус талона в базе данных остался CALLING (3), хотя должен был измениться на DROPPED (7). Как система умудрилась не обновить статус за такое огромное время?

Секрет кроется в том, что автотест и тестируемая система живут в параллельных, независимых друг от друга потоках выполнения.

Когда вызывается feqsUiMainService.reset(), тест отправляет сетевой запрос и мгновенно переходит к следующей строке кода. Бэкенд принимает запрос и начинает свою работу: валидирует данные, открывает транзакцию в базе данных, обновляет связанные таблицы и, наконец, фиксирует изменения (commit).

Состояние гонки (Race Condition) — ошибка проектирования, при которой итоговый результат зависит от того, в каком порядке и с какой скоростью выполняются параллельные процессы.

IEEE Std 610.12-1990

В нашем случае соревнуются два бегуна: поток автотеста, который отсчитывает время и делает SELECT из базы, и поток бэкенда, который выполняет UPDATE этой же базы.

Рассмотрим, как распределяется время в неудачном сценарии:

Этап	Поток автотеста	Поток бэкенда (и БД)
$T_0$	Отправляет API-запрос на сброс	Принимает запрос
$T_1$	Входит в `Thread.sleep(5000)`	Начинает обработку бизнес-логики
$T_2$	...спит...	Ждёт освобождения пула соединений БД
$T_3$	Просыпается, запрашивает статус	Выполняет `UPDATE`, но транзакция ещё не закрыта
$T_4$	Получает старый статус 3. Падение!	Делает `COMMIT`. Статус меняется на 7

Жестко заданное ожидание через Thread.sleep() предполагает, что время обработки запроса бэкендом $t$ всегда строго меньше заданного таймаута: $t < 5$ сек.

В идеальных условиях локальной машины разработчика это условие выполняется: бэкенд справляется за 200 миллисекунд. Но автотесты запускаются на CI/CD серверах, где параллельно могут собираться другие проекты, база данных находится под нагрузкой, а сеть может испытывать микрозадержки. В таких условиях реальное время транзакции становится плавающим: $t_{min} \leq t \leq t_{max}$ .

Первым инстинктивным желанием при виде падающего теста становится увеличение времени сна: заменить 5000 на 10000. Это создает иллюзию стабильности, но порождает две новые проблемы.

Во-первых, тест становится неоправданно медленным. Если бэкенд обновил статус за 0.5 секунды, автотест всё равно будет слепо стоять на месте оставшиеся 9.5 секунд. В масштабах набора из сотен тестов это превращается в часы потерянного времени при каждом прогоне.

Во-вторых, это не устраняет саму природу гонки. Если база данных «моргнет» или попадет под тяжелый процесс бэкапа, транзакция может занять 11 секунд, и тест снова упадет.

Слепое ожидание не учитывает состояние внешней системы. Чтобы гарантировать стабильность автотеста и при этом не раздувать время его выполнения, поток должен не просто «спать», а активно наблюдать за изменениями в базе данных, задавая вопрос: «Статус уже обновился? А теперь?».

Этот подход требует перехода от статических пауз к динамическому опросу состояния.

Рефакторинг ожидания: внедрение динамического опроса (Polling) через EndureAwaitRunner

Рефакторинг ожидания: внедрение динамического опроса (Polling)

Ждать обновления данных в базе можно двумя способами: закрыть глаза ровно на пять секунд и надеяться, что транзакция успела завершиться, или проверять состояние каждую секунду, пока не получим нужный результат. Первый подход заставляет тесты падать при малейшей задержке сети. Второй — гарантирует стабильность и экономит время.

Чтобы разорвать зависимость от непредсказуемой скорости выполнения параллельных потоков, мы отказываемся от жестких пауз в пользу динамического опроса.

Polling (динамический опрос) — шаблон проектирования, при котором программа циклически проверяет выполнение заданного условия с определенным интервалом, пока условие не станет истинным или не истечет максимальное время ожидания.

Сравним два подхода на практике:

Характеристика	`Thread.sleep(5000)`	Polling
Время выполнения, если БД обновилась за 1 сек.	Ровно 5 секунд (впустую ждем еще 4)	~1 секунда (тест идет дальше)
Результат, если БД обновилась за 6 сек.	Падение теста (AssertionError)	Падение (если таймаут 5 сек.), но таймаут можно безопасно увеличить
Нагрузка на процессор	Поток блокируется полностью	Поток просыпается только для коротких проверок

Инструмент в нашем арсенале: EndureAwaitRunner

Нам не нужно писать цикл while и обрабатывать исключения вручную. В проекте уже есть готовая утилита для поллинга — EndureAwaitRunner. Если заглянуть в соседний метод resetTickets (строка 116), можно увидеть, как она применяется для ожидания исчезновения талона из очереди.

Мы используем этот же инструмент для нашей задачи. Конструкция состоит из трех ключевых параметров:

atMost(timeout, unit) — жесткий лимит времени. Если за это время условие не выполнится, тест упадет. Обозначим его как $T_{max}$ .
pollInterval(interval, unit) — частота проверок. Шаг времени $\Delta t$ между попытками.
execute(Runnable) — блок кода с проверкой (нашим ассертом).

Механика работы execute предельно проста: утилита запускает переданный код. Если код выбрасывает AssertionError (статус всё ещё CALLING), утилита перехватывает ошибку, ждет $\Delta t$ и пробует снова. Если код выполняется без ошибок (статус стал DROPPED), цикл немедленно прерывается, и тест продолжается.

Рефакторинг метода resetTicket

Вернемся к проблемному узлу в коде. Сейчас метод выглядит так:

@Step("Сбросить талон, находящийся на обслуживании")
public void resetTicket(TechnicalDepartmentEnum technicalDepartment, String ticketNumber) {
    Response response = feqsUiMainService.reset(getCookie(), technicalDepartment.getId());
    checkResponse(response, 200);
    checkSuccess(response);

    // Блокирующее ожидание — причина нестабильности
    try {
        Thread.sleep(5000);
    } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
        throw new RuntimeException("Прервано ожидание перед сбросом талона", e);
    }

    // Одноразовая проверка, которая падает, если БД не успела обновиться
    feqsSuoDbSteps.assertLastTicketStatus(technicalDepartment.getId(), ticketNumber, DROPPED);
}

Мы удаляем громоздкий блок try-catch с Thread.sleep и оборачиваем нашу проверку в endureRun(). Установим $T_{max} = 5$ секунд (сохраняем старый лимит, чтобы не увеличивать общее время прогона) и $\Delta t = 1$ секунда.

Обновленный код:

@Step("Сбросить талон, находящийся на обслуживании")
public void resetTicket(TechnicalDepartmentEnum technicalDepartment, String ticketNumber) {
    Response response = feqsUiMainService.reset(getCookie(), technicalDepartment.getId());
    checkResponse(response, 200);
    checkSuccess(response);

    // Динамический опрос состояния талона в БД
    endureRun().atMost(5, SECONDS)
               .pollInterval(1, SECONDS)
               .execute(() ->
                   feqsSuoDbSteps.assertLastTicketStatus(technicalDepartment.getId(), ticketNumber, DROPPED)
               );
}

Что изменилось архитектурно? Ранее assertLastTicketStatus был просто финальной точкой метода. Теперь он стал условием выхода из цикла ожидания.

Если API-запрос отработал быстро, и база данных зафиксировала статус 7 (DROPPED) за 500 миллисекунд, первая же проверка внутри execute пройдет успешно. Тест сэкономит 4.5 секунды и пойдет дальше. Если база данных будет под нагрузкой и статус обновится только через 3 секунды, тест сделает три неудачные попытки, на четвертую получит успех и также продолжит работу без падения.

Мы устранили Race Condition, сделав тест адаптивным к скорости работы бэкенда.

Валидация решения: проверка транзакционной целостности статуса в БД

Мы заменили жесткую пятисекундную паузу на динамический опрос (Polling). Тесты позеленели, а время их выполнения сократилось. Но значит ли это, что мы окончательно победили Race Condition, или нам просто повезло при текущем локальном запуске? Чтобы тест был по-настоящему стабильным, необходимо убедиться, что наш механизм опроса корректно синхронизируется с жизненным циклом базы данных.

Скрытая жизнь транзакции

Когда метод feqsUiMainService.reset() отправляет API-запрос на сброс талона и получает ответ 200 OK, это означает лишь одно: бэкенд принял команду в работу.

В этот момент под капотом системы запускается асинхронный процесс. База данных открывает транзакцию, находит нужную запись и выполняет обновление: меняет статус талона с 3 (CALLING) на 7 (DROPPED). Эта операция занимает миллисекунды, но для потока автотеста она происходит в будущем времени.

Транзакционная целостность в контексте автотестов — это гарантия того, что проверяемые данные в базе полностью обновлены и зафиксированы (операция commit) до того, как тест попытается их прочитать и вынести вердикт.

Если тест обратится к базе до завершения транзакции (до commit), он прочитает старые данные. Именно поэтому старая реализация с Thread.sleep() периодически выдавала AssertionError: Ожидалось 7, фактически 3 — тест успевал «проснуться» и заглянуть в БД за мгновение до того, как транзакция была зафиксирована.

Интеграция проверки в цикл опроса

Чтобы гарантировать транзакционную целостность, нам нужно не просто «подождать перед проверкой», а сделать саму проверку БД частью цикла опроса. Утилита EndureAwaitRunner позволяет обернуть шаг валидации базы данных в повторяющийся блок.

Вот как выглядит финальный, стабильный код метода resetTicket:

@Step("Сбросить талон, находящийся на обслуживании")
public void resetTicket(TechnicalDepartmentEnum technicalDepartment, String ticketNumber) {
    // 1. Отправляем команду
    Response response = feqsUiMainService.reset(getCookie(), technicalDepartment.getId());
    checkResponse(response, 200);
    checkSuccess(response);

    // 2. Динамически ждем фиксации транзакции в БД
    endureRun().atMost(5, SECONDS)
               .pollInterval(1, SECONDS)
               .execute(() -> feqsSuoDbSteps.assertLastTicketStatus(
                       technicalDepartment.getId(),
                       ticketNumber,
                       DROPPED
               ));
}

Теперь assertLastTicketStatus выполняется внутри лямбда-выражения. Если на первой секунде статус в базе всё ещё 3 (CALLING), ассерт падает, но endureRun перехватывает эту ошибку и не «роняет» тест. Он ждет одну секунду и повторяет попытку. Как только транзакция в БД фиксируется и статус становится 7 (DROPPED), ассерт проходит успешно, и цикл опроса немедленно прерывается.

Математика стабильности

Динамический опрос переводит стабильность теста из категории вероятности в категорию математической гарантии. Обозначим две ключевые переменные: $T_{db}$ — реальное время выполнения и фиксации транзакции в базе данных. $T_{test}$ — время, которое автотест выделяет на ожидание результата.

Для успешного прохождения теста всегда должно выполняться условие: $T_{test} \geq T_{db}$

При использовании статического ожидания Thread.sleep(5000) мы жестко фиксировали $T_{test} = 5$ . Если из-за нагрузки на сервер $T_{db}$ возрастало до 6 секунд, тест гарантированно падал.

При использовании поллинга с atMost(5, SECONDS), $T_{test}$ становится динамическим. Тест адаптируется под скорость базы данных в каждом конкретном прогоне.

Сценарий сервера	Поведение Thread.sleep(5000)	Поведение EndureAwaitRunner
Быстрая БД ( $T_{db} = 0.5$ сек)	Тест ждет 5 сек. Потеряно 4.5 сек.	Тест ждет 1 сек (первый интервал). Идет дальше.
Средняя БД ( $T_{db} = 2.5$ сек)	Тест ждет 5 сек. Потеряно 2.5 сек.	Тест делает 3 попытки, завершается на 3-й секунде.
Нагруженная БД ( $T_{db} = 4.8$ сек)	Тест ждет 5 сек. Проходит на грани фола.	Тест делает 5 попыток, успешно завершается на 5-й секунде.

Итог сквозной задачи

Мы прошли полный путь устранения плавающего дефекта:

Расшифровали стектрейс и локализовали проблему в проверке assertLastTicketStatus.
Поняли, что корень зла — состояние гонки (Race Condition) между потоком теста и транзакцией базы данных.
Отказались от антипаттерна Thread.sleep, который либо тормозил прогон, либо не спасал от падений.
Внедрили динамический опрос (Polling), который гарантирует, что тест дождется транзакционной целостности данных, не потратив ни одной лишней секунды.

Теперь статус талона проверяется надежно, и ошибка Ожидалось: 7, фактически: 3 больше не потревожит CI/CD пайплайн.