Flaky tests
Что неприятнее «красного теста»? Тест, который то зелёный, то красный, и непонятно, почему. На нашей конференции Heisenbug 2017 Moscow Андрей Солнцев (Codeborne) рассказывал, из-за чего они могут возникать и как снижать их число. Примеры в его докладе такие, что прямо-таки кожей ощущаешь боль, возникавшую при столкновении с ними. А советы полезные — причём ознакомиться с ними стоит как тестировщикам, так и разработчикам. Есть и неожиданное: можно узнать, как порой можно разобраться в проблеме, если оторваться от экрана и поиграть с дочкой в кубики.
В итоге зрители высоко оценили доклад, и мы решили не просто опубликовать видеозапись, а ещё и сделать для Хабра текстовую версию доклада.
На мой взгляд, flaky-тесты — это самая актуальная тема в мире автоматизации. Потому что на вопрос «что вообще в мире делается, как у вас дела с автоматизацией?» все отвечают: «Стабильности нет! Падают наши тесты периодически».
Ты запустил у себя тест, он зелёный, ещё два дня зелёный, а потом раз и внезапно упал на Jenkins. Ты пытаешься это повторить, запускаешь, а он снова зелёный. И в итоге никогда не знаешь: это баг или это просто тест глюканул? И каждый раз надо разбираться.
Зачастую после ночного запуска тестов на Jenkins тестировщик сначала видит «30 тестов упало, надо изучить», но все знают, что происходит дальше…
Вы, конечно, догадались, какое неприличное слово замаскировано: «перезапущу». Мол, «сегодня неохота разбираться…» Вот так это обычно происходит, и это прямо беда.
Точной статистики нет, но я часто слышал от разных людей, что у них примерно 30% тестов — flaky. Грубо говоря, запускают тысячу, из них 300 периодически красные, и дальше руками проверяют, а на самом ли деле они упали.
Google пару лет выпустил статью: там сообщается, что у них 1,5% процента flaky-тестов, и рассказано, как они бьются за снижение их числа. Я могу чуть похвастаться и сказать, что в моём проекте в Codeborne сейчас 0,1%. Но на самом деле всё это плохо, даже 0,1%. Почему?
Возьмём 1,5%, это число кажется маленьким, но что оно значит на практике? Допустим, в проекте тысяча тестов. Это может значить, что в одном билде упало 15 тестов, в следующем 12, затем 18. И это ужасно плохо, потому что в этом случае почти все билды красные, и постоянно нужно проверять руками, правда это или нет.
И даже наш один промилле (0,1%) — всё равно плохо. Допустим, у нас 1000 тестов, тогда 0,1% означает, что регулярно один билд из десяти валится с 1-2 красными тестами. Вот реальная картина с нашего Jenkins, так и получается: при одном запуске упал один flaky-тест, при другом запуске другой.
Получается, ни дня без красного билда у нас не проходит. Так как много зелёного, вроде бы всё хорошо, но клиент вправе спросить нас: «Ребята, мы вам платим деньги, а вы нам постоянно красноту поставляете! Что за дела?»
Я бы на месте клиента был недоволен, и объяснять «вообще-то по отрасли это нормально, у всех всё красное» нехорошо, да? Поэтому, на мой взгляд, это очень актуальная проблема, и давайте вместе разбираться, как же с ней бороться.
Пример 1: классика
Для затравки — классический Selenium-скрипт:
Правильно, мы все хорошо знаем, что любая! Может сломаться абсолютно любая строчка, по совершенно разным причинам:
Первая строчка — медленный интернет, сервис упал, админы что-то не настроили.
Вторая строчка — элемент еще не успел отрисоваться, если он динамически отрисовывается.
Что может сломаться в третьей строчке? Тут для меня было неожиданно: я написал это тест для конференции, запустил локально, и он именно на третьей строчке свалился с вот такой ошибкой:
Это говорит, что элемент в этой точке некликабельный. Казалось бы, простая элементарная Google-форма. Секрет оказался в том, что во второй строке мы вбили слово, и пока мы его вводили, Google уже нашёл первые результаты, показал несколько первых результатов в таком поп-апчике, и они закрыли следующую кнопку. И это происходит не во всех браузерах и не всегда. У меня с этим скриптом такое происходило примерно один раз из пяти.
Четвёртая же строчка может упасть, например, потому что этот элемент отрисовывается динамически и еще не успел отрисоваться.
На этом примере хочу сказать, что, по моему опыту, 90% flaky-тестов имеют в основе одни и те же причины:
Вот этот тест проходит всегда. За счёт того, что методы setValue(), click() и shouldHave() — умные: если что-то не успело подрисоваться, они чуть-чуть ждут и пробуют ещё (это называется «умные ожидания»).
Если посмотреть чуть подробнее, то все эти should*-методы умные:
Пример 2: nbob
Итак, 90% проблем с flaky-тестами решаются с помощью Selenide. Но остаются 10% гораздо более изощрённых случаев со сложными запутанными причинами. Вот именно о них я и хочу сегодня поговорить, потому что это такая «серая область». Приведу один из примеров: flaky-тест, на который я сразу же наткнулся в новом проекте. На первый взгляд, этого просто не может случиться, вот это-то и интересно.
Тестировали приложение-клавиатуру для логина в киосках. Тест хотел залогиниться как юзер «bob», то есть в поле «логин» ввести три буквы: b-o-b. Для этого использовались кнопки на экране. Как правило, это срабатывало, но иногда тест падал, и в поле «логин» оставалось значение «nbob»:
Естественно, ломишься искать по коду, где у нас могло быть написано «nbob» — но в целом проекте этого вообще нет (ни в базе данных, ни в коде, ни даже в Excel-файлах). Как это возможно?
Смотрим подробнее код — казалось бы, всё просто, никаких загадок:
Так получилось, что буква N находилась посередине экрана, а функция click() как минимум в Chrome работает так: высчитывает центральную координату элемента и кликает в неё. Поскольку body — это большой элемент, она кликала в центр всего экрана.
И это падало не всегда. Кто знает, почему? На самом деле, я сам не до конца знаю. Возможно, из-за того, что окно браузера всё время открывалось разного размера, и это не всегда попадало в букву N.
В итоге расширяем список причин нестабильных тестов:
Пример 3: фантомные счета
Пример интересен тем, что тут совпало сразу всё, что только может совпасть.
Был тест, который проверял, что на этом экране должно быть 5 счетов.
Он, как правило, был зелёный, но иногда при непонятно каких условиях падал и говорил, что на экране не пять, а шесть счетов.
Я стал исследовать, откуда берётся лишний счёт. Абсолютно непонятно. Возник вопрос: может быть, у нас есть другой тест, который в ходе теста создает новый счёт? Оказалось, что да, есть такой LoansTest. А между ним и падающим AccountsTest (который ожидает пять счетов) может оказываться миллион каких-то других тестов.
Пытаемся понять, как же так: разве LoansTest, который создаёт счёт, не должен его удалять в конце? Смотрим его код — да, должен, в конце для этого есть функция After. Тогда, по идее, всё должно быть хорошо, в чём же проблема?
Может, тест его удаляет, но он остаётся где-то закэшированным? Смотрим продакшн-код, который грузит счета — в нём действительно есть аннотация @CacheFor, он кэширует счета на пять минут.
Возникает вопрос: но разве тест не должен был очистить этот кэш? Было бы логично, не может же быть такой косяк? Смотрим его код — да, он действительно очищает кэш перед каждым тестом. Что за дела? Тут уже теряешься, потому что гипотезы закончились: объект удаляется, кэш очищается, ёлки-палки, что же ещё может быть проблемой? Дальше стал уже просто лазать по коду, это заняло некоторое время, возможно, даже несколько дней. Пока я наконец не посмотрел в этот класс и суперкласс, и не нашёл там одну подозрительную вещь:
Кто-то уже заметил, да? Совершенно верно: и в дочернем, и в родительском классе есть метод с одним и тем же названием, и он не вызывает super.
И в Java это очень легко сделать: нажимаешь в IntelliJ IDEA или Eclipse сочетание Alt+Enter или Ctrl+Insert, он по умолчанию создаёт тебе метод setUp(), и не замечаешь, что он оверрайдит метод в суперклассе. То есть кэш все-таки не вызывался. Когда я увидел это, я был дико зол. Это сейчас мне радостно.
Давайте подытожим ещё раз: как это получилось, почему тест падал не всегда? Во-первых, он зависел от порядка этих двух тестов, они же всегда запускаются в случайном порядке. Ещё тест зависел от того, сколько времени прошло между ними. Счета кэшируются пять минут, если проходило больше, то тест был зелёный, а если меньше — падал, и такое случалось редко.
Расширяем список того, почему тесты могут быть нестабильны:
Пример 4: Время Java
Был тест, который работал на всех наших компьютерах и на нашем Jenkins, но иногда падал на Jenkins заказчика. Смотрим в тест, разбираемся, почему. Оказывается, падал, потому что при проверке «дата платежа должна быть сейчас или в прошлом» она оказывалась «в будущем».
Смотрим в код, вдруг при каких-то условиях мы можем поставить дату в будущем? Не можем: в единственном месте, где инициализируется время платежа, используется new Date(), а это всегда текущее время (в крайнем случае оно может оказаться в прошлом, если вдруг тест был очень медленным). Как такое вообще возможно? Долго бились головой, не могли понять.
А однажды заглянули в лог приложения. Отсюда первая мораль — очень полезно при исследовании тестов заглядывать в лог самого приложения. Поднимите руки, кто это делает. В общем, не большинство, увы. А там есть полезная информация: к примеру, request log, такой-то URL в такое время выполнился, выдал такой-то ответ.
Здесь есть кое-что подозрительное, заметили? Смотрим время: этот запрос обрабатывался минус три секунды. Как такое может быть? Долго бились, не могли понять. Наконец, когда у нас кончились теории, сделали тупое решение: в Jenkins написали простенький скрипт, который в цикле раз в секунду логирует текущее время. Запустили его. На следующий день, когда этот flaky-тест один раз ночью упал, стали смотреть выдержку из этого файла за то время, когда он упал:
Итак: 34 секунды, 35, 36, 37, 35, 39… Круто, что мы это нашли, но как это вообще возможно? Снова теории закончились, ещё два дня чесали голову. Это реально тот случай, когда Матрица шутит над тобой, да?
Пока наконец не стукнула в голову одна идея… И вот, что оказалось. В Linux есть сервис для синхронизации времени, который бегает на центральный сервер и спрашивает «а столько сейчас милисекунд?» И оказывается, на этом конкретном Jenkins было запущено два разных сервиса. Тест начал падать, когда на этом сервере обновили Ubuntu.
Там раньше был сконфигурирован ntp-сервис, который обращался на специальный банковский сервер и брал время оттуда. А с новой версией Ubuntu по умолчанию включался новый легковесный сервис, к примеру, systemd-timesyncd. И работали оба. Никто этого не заметил. Почему-то центральный банковский сервер и какой-то центральный Ubuntu-сервер выдавали ответ с разницей в 3 секунды. Естественно, эти два сервиса друг другу мешали. Где-то глубоко в документации Ubuntu сказано, что, конечно, не допускайте такой ситуации… Ну, спасибо за информацию 🙂
Кстати, заодно я узнал один интересный нюанс Java, который до этого, несмотря на мой многолетний опыт, не знал. Один из самых базовых методов в Java называется System.currentTimeMillis(), с помощью него обычно засекают время вызова чего-то, многие писали такой код:
На самом деле, в документации методов это написано, я же просто никогда не читал её. Я всю жизнь думал, что System.currentTimeMillis() и System.nanoTime() — одно и то же, только с разницей в миллион раз. А оказалось, что это принципиально разные вещи.
System.currentTimeMillis() возвращает реально текущую дату — сколько сейчас миллисекунд прошло с 1 января 1970-го. А System.nanoTime() — некий абстрактный счётчик, который не привязан к реальному времени: да, он гарантированно растёт каждую наносекунду на единичку, но он не связан с текущим временем, он может быть даже отрицательным. При старте JVM как-то случайным образом выбирается момент времени, и он начинает расти. Это для меня был сюрприз. Для вас тоже? Вот, не зря приехал.
Пример 5: Проклятие зелёной кнопки
Тут у нас тест заполняет некую форму, нажимает зелёную кнопку Confirm, и иногда не идёт дальше. Почему не идёт — непонятно.
Вбиваем четыре нуля и висим, не идём на следующую страничку. Клик происходит без ошибок. Я посмотрел всё: Ajaх-запросы, ожидание, таймауты, логи приложений, кэш — ничего не нашёл. Пока не появилась библиотека Video Recorder, написанная Сергеем Пироговым. Она позволяет, добавив в код одну аннотацию, записывать видео. Тогда я смог снять видео этого теста, посмотреть его в замедленном виде, и это наконец-то прояснило ситуацию, которую до видео я не мог разгадать несколько месяцев.
Прогресс-бар перекрыл кнопку на доли секунды, а клик сработал ровно в этот момент и попал по этому прогресс-бару. То есть прогресс-бар схавал клик и пропал! И его не будет видно ни на одном скриншоте, ни в одном логе, никогда не узнаешь, что произошло.
В принципе, это в каком-то смысле баг приложения: прогресс-бар появился, потому что приложение реально вылезает за край экрана, и если прокрутить, там оказывается куча полезных данных. Но пользователи на это не жаловались, потому что на большом экране всё помещалось, не помещалось только на маленьком.
Пример 6: почему зависает Chrome?
Детективное расследование длиной в два года, абсолютно реальный случай. Ситуация такая: наши тесты довольно часто были flaky и падали, и в стек-трейсах было видно, что Chrome зависает: не тест наш, а именно Chrome. В логах было видно «Build is running 36 hours. » Стали снимать тред-дампы и стак-трейсы — они показывают, что в тестах всё хорошо, зависает обращение к Chromedriver и, как правило, в момент закрытия (вызываем метод close, и этот метод ничего не делает, висит 36 часов). Если интресно, то стек-трейс выглядел так:
Пытались сделать всё, что только может прийти в голову:
Пытаемся повторить проблему: пишем цикл от 1 до 1000, в цикле просто открываем браузер, первую страничку в нашем приложении и закрываем. Написали такой цикл, и… бинго! Результат: проблема стала повторяться стабильно (правда, примерно через каждые 80 итераций)! Круто! Правда, это достижение долго ничего не давало. Запустил ты, дождался 80-й итерации, завис Chrome… а дальше что делать? Смотришь в стак-трейсы, дампы, логи — ничего полезного там нет. Developer Tools в Chrome, возможно, помог бы, но до сентября 2017-го вместе с Selenium эти тулы не работали (конфликтовали порты: запускаешь Chrome из Selenium, и DevTools не открываются). Долгое время не мог придумать, что сделать.
И тут в этой истории начинается сказочный момент. Однажды, после бесконечного количества попыток, я снова запустил эти тесты, он у меня снова на какой-то итерации вроде 56-й завис, я думаю «давай ещё что-нибудь покопаю» (правда, не знаю, куда ещё брейкпойнт поставить или какой-то лог добавить). В этот момент дочка предлагает поиграть в кубики, а у меня тут как раз тест завис. Я говорю «Подожди», она мне: «Ты что, не понял, у меня тут к у б и к и!»
Что поделать, с грустью оставил компьютер, пошёл играть в кубики… И вдруг, примерно через 20 минут, случайно бросаю взгляд на экран, и вижу совершенно неожиданную картину:
Что получается: идёт отсчёт, через сколько минут истечёт сессия, а я строю башню из кубиков, остаётся две, одна… сессия истекает, тест продолжается, бежит до конца и падает (элемента уже нет, сессия истекла).
Что получается: Chrome на самом деле не зависал, как мы думали всё это время, он всё это время что-то ждал. Когда сессия истекала, дожидался, шёл дальше. Чего именно ждал Chrome — абсолютно непонятно, чтобы это понять, пришлось перелопатить весь код методом бинарного поиска: выкидываешь половину JavaScript и HTML, снова пытаешься повторить 80 итераций — не зависло, о, значит, где-то там… В общем, экспериментальным путем поняли, что проблема вот здесь:
Был на всех наших страницах JavaScript — тот самый, который показывает окошко, что сессия истекает. Наверно, все JavaScript-программисты знают, что так делать не очень правильно: всё, что запускается в тегах
Александр Александров про тренды и технологии тестирования, про влияние Covid19 на рынок QA
Продолжу хвастаться статусом книги.
Онлайн-тренинги
Что пишут в блогах (EN)
Разделы портала
Про инструменты
Если тесты сбоят на ранее протестированном коде, то это явный признак того, что в коде появилась какая-то новая ошибка. Раньше тесты проходили успешно и код был правильный, сейчас тесты сбоят и код работает неправильно. Цель хорошего набора тестов заключается в том, чтобы сделать этот сигнал настолько ясным и чётко адресованным, насколько возможно.
Ненадёжные (flaky), то есть недетерминированные тесты ведут себя иначе. Они могут показать как положительный, так и отрицательный результат на одном и том же коде. Другими словами, сбой теста может означать, а может и не означать появление новой проблемы. И попытка воспроизвести ошибку путём перезапуска теста на той же версии кода может привести или не привести к успешному проходу теста. Мы рассматриваем такие тесты как ненадёжные, и в конце концов они теряют свою ценность. Если изначальная проблема — это недетерминизм в рабочем коде, то игнорирование теста означает игнорирование бага в продакшне.
Ненадёжные тесты в Google
В системе непрерывной интеграции Google работает около 4,2 млн тестов. Из них примерно 63 тыс. показывают непредсказуемый результат в течение недели. Хотя они представляют менее 2% от всех тестов, но всё равно ложатся серьёзным бременем на наших инженеров.
Если мы хотим починить ненадёжные тесты (и избежать написания новых), то прежде всего нужно понять их. Мы в Google собираем много данных по своим тестам: время выполнения, типы тестов, флаги выполнения и потребляемые ресурсы. Я изучил, как некоторые из этих данных коррелируют с надёжностью тестов. Думаю, что это исследование может помочь нам улучшить и сделать более стабильными методы тестирования. В подавляющем большинстве случаев, чем больше тест (по размеру бинарника, использованию RAM или количеству библиотек), тем менее он надёжен. В остальной статье обсудим некоторые из обнаруженных закономерностей.
Предыдущее обсуждение ненадёжных тестов см. в статье Джона Микко от мая 2016 года.
Размер теста — большие тесты менее надёжны
Чем больше тест, тем меньше надёжность
| Корреляция между метрикой и прогнозом ненадёжности теста | |
| Метрика | r2 |
| Бинарный размер | 0,82 |
| Используемая RAM | 0,76 |
Рассматриваемые здесь тесты — это по большей мере герметичные тесты, которые выдают сигнал успех/неудача. Бинарный размер и использование RAM хорошо коррелировали по всей выборке тестов, и между ними нет особой разницы. Так что речь не просто о том, что большие тесты скорее будут ненадёжными, а о постепенном уменьшении надёжности с увеличением теста.
Определённые инструменты коррелируют с частотой ненадёжных тестов
| Ненадёжность тестов при использовании некоторых из наших обычных тестовых инструментов | ||
| Категория | Доля ненадёжных | Доля от всех ненадёжных тестов |
| Все тесты | 1,65% | 100% |
| Java WebDriver | 10,45% | 20,3% |
| Python WebDriver | 18,72% | 4,0% |
| Внутренний инструмент интеграции | 14,94% | 10,6% |
| Эмулятор Android | 25,46% | 11,9% |
Все эти инструменты показывают процент ненадёжности выше среднего. А учитывая, что каждый пятый ненадёжный тест написан на Java WebDriver, становится понятно, почему люди на него жалуются. Но корреляция не означает наличия причинно-следственной связи. Зная результаты из предыдущего раздела, можно предположить, что некий иной фактор уменьшает надёжность тестов, а не просто инструмент.
Размер даёт лучший прогноз, чем инструменты
Можно совместить выбор инструмента и размер теста — и посмотреть, что важнее. Для каждого упомянутого инструмента я изолировал тесты, которые используют этот инструмент, и разделил их на группы по использованию памяти (RAM) и бинарному размеру, по такому же принципу, как и раньше. Затем рассчитал линию наилучшего объективного прогноза и насколько она коррелирует с данными (r2). Потом вычислил прогноз вероятности, что тест будет ненадёжным в самой маленькой группе [8] (которая уже покрывает 48% наших тестов), а также 90-й и 95-й процентиль по использованию RAM.
| Предсказанная вероятность ненадёжности по RAM и инструменту | ||||
| Категория | r2 | Наименьшая группа (48-й процентиль) | 90-й процентиль | 95-й процентиль |
| Все тесты | 0,76 | 1,5% | 5,3% | 9,2% |
| Java WebDriver | 0,70 | 2,6% | 6,8% | 11% |
| Python WebDriver | 0,65 | −2,0% | 2,4% | 6,8% |
| Внутренний инструмент интеграции | 0,80 | −1,9% | 3,1% | 8,1% |
| Эмулятор Android | 0,45 | 7,1% | 12% | 17% |
Эта таблица показывает результаты вычислений для RAM. Корреляция сильнее для всех инструментов, кроме эмулятора Android. Если игнорировать эмулятор, то разница в корреляции между инструментами при схожем использовании RAM будет в районе 4-5%. Разница между самым маленьким тестом и 95-м процентилем составляет 8-10%. Это один из самых полезных выводов нашего исследования: инструменты оказывают некое влияние, но использование RAM даёт гораздо большие отклонения по надёжности.
| Предсказанная вероятность ненадёжности по бинарному размеру и инструменту | ||||
| Категория | r2 | Наименьшая группа (33-й процентиль) | 90-й процентиль | 95-й процентиль |
| Все тесты | 0,82 | −4,4% | 4,5% | 9,0% |
| Java WebDriver | 0,81 | −0,7% | 14% | 21% |
| Python WebDriver | 0,61 | −0,9% | 11% | 17% |
| Внутренний инструмент интеграции | 0,80 | −1,8% | 10% | 17% |
| Эмулятор Android | 0,05 | 18% | 23% | 25% |
Для тестов в эмуляторе Android практически отсутствует корреляция между бинарным размером и ненадёжностью. Для других инструментов можно увидеть большую разницу прогноза ненадёжности между маленькими и большими тестами по по потреблению RAM; до 12 процентных пунктов. Но в то же время при сравнении тестов по бинарному размеру разница прогноза ненадёжности ещё больше: до 22 процентных пунктов. Это похоже на то, что мы видели при анализе использования RAM, и это ещё один важный вывод нашего исследования: бинарный размер важнее для отклонений в прогнозе ненадёжности, чем используемый инструмент.
Выбранный разработчиком размер теста коррелирует с ненадёжностью, но в Google недостаточно вариантов выбора размера, чтобы этот параметр действительно был полезен для прогноза.
Объективно измеренные показатели бинарного размера и использования RAM сильно коррелируют с надёжностью теста. Это непрерывная, а не ступенчатая функция. Последняя показала бы неожиданные скачки и означала бы, что в этих точках мы переходим от одного типа тестов к другому (например, от модульных тестов к системным или от системных тестов к интеграционным).
Тесты, написанные с помощью определённых инструментов, чаще дают непредсказуемый результат. Но это в основном можно объяснить бóльшим размером этих тестов. Сами по себе инструменты вносят небольшой вклад в эту разницу по надёжности.
Следует с осторожностью принимать решение о написании большого теста. Подумайте, какой код вы тестируете и как будет выглядеть минимальный тест для этого. И нужно очень осторожно писать большие тесты. Без дополнительных защитных мер есть большая вероятность, что вы сделаете тест с недетерминированным результатом, и такой тест придётся исправлять.
