Я давно хотел рассказать об этом, но не знал как. Не было подходящего примера, какой-то однозначной, наглядной ситуации. И вот недавно мне дали новый проект, в котором уже были написаны unit тесты и они работали, но был один нюанс, который портил всю картину.

По сути в этой публикации речь пойдет о функции done() в jest. Функция очень полезная, так как позволяет разработчику решать в какой момент будет закончен тест. Бывают ситуации, когда это действительно очень нужно. В новом проекте я столкнулся с такой задачей и решил просто описать то, как я её решил.

В нашем проекте, при запуске unit тестов, командой:

 yarn test:ci

, в конце выполнения появлялась ошибка error Command failed with exit code 1. Тесты были написаны на Jest в приложении на Angular 14.

Все тесты при этом были PASSED.

 error Command failed with exit code 1
error Command failed with exit code 1

В нашем случае под командой test:ci скрывалось следующее:

jest --ci --collectCoverage

Проверив оба параметра по отдельности, выяснилось, что источником ошибки является команда:

yarn jest --ci.

Ошибка не совсем очевидная и выяснить причину было довольно сложно. В интернете есть ссылка, посвященная этой проблеме: https://github.com/facebook/jest/issues/9324. Точного объяснения причины этой ошибки, на момент написания этой публикации, там не было, но было сказано, что ошибка исчезает, если добавить --maxWorkers=2. При добавлении этого параметра ошибка исчезала и у нас. Параметр maxWorkers ограничивает максимально число рабочих потоков, о чем можно прочитать тут - https://jestjs.io/ru/docs/cli. Конечно, такой способ позволяет избежать ошибки, но реально он её не исправляет.

Чтобы найти причину ошибки были перегружены функции console.error и console.warn в файле jest.setup.js, в проекте он назывался setup-jest.ts. Проблема в том, что если в коде есть вызов команды console.error и мы пишем unit тест на этот код, то при выполнении мы увидим в логе сообщение об ошибке и стэк до этой ошибки. В случае с unit тестом, это ожидаемое поведение, так как мы пишем тест, в котором проверяем, как поведет себя приложение в случае ошибочных данных или состояний. Отсюда сам тест будет отмечен как PASSED, но в логе будет сообщение об ошибке, которую мы и хотели получить в тесте. Такие сообщения, да ещё и со stack trace, затрудняли поиск реальных ошибок. Чтобы отделить "хорошие" ошибки от "плохих" я написал в файле setup-jest.ts код представленный ниже:

// Write info message when a `console.error` or `console.warn` happens
// by overriding the functions
const CONSOLE_FAIL_TYPES = ['error', 'warn'];

CONSOLE_FAIL_TYPES.forEach((type) => {
  console[type] = (...params: string[]) => {
    console.info(`console.${type}\n class: ${params[0]}\n message: ${params[1]}`);
  };
});

Идея написать такую перегрузку функций была взята отсюда: https://www.benmvp.com/blog/catch-warnings-jest-tests/

После добавления такой перегрузки, при запуске тестов, на одном из них стала появляться такая ошибка: Cannot log after tests are done. Did you forget to wait for something async in your test?

Ошибка говорит о том, что тест был завершен раньше, чем отработали все асинхронные конструкции.

Код этого теста:

it('just a test', async () => {
  ...
  for (const incorrectJson of toFail) {
    ...
    component.onCallFunc(incorrectJson);
    ...
    await waitForExpect(() => {
      expect(component['funcWithPromiseHandler']).toHaveBeenCalled();
    }, 5000);
    expect(component['funcWitchCalledInHandler']).toHaveBeenCalled();
  }
  expect(someService.importSomth).toHaveBeenCalledTimes(0);
});

Было решено переписать этот код на Promise и использовать функцию jest done(), чтобы явно завершить этот тест тогда, когда это нам нужно. О том как она работает можно узнать тут: https://jestjs.io/docs/asynchronous, в разделе Callbacks.

Переписанный код:

it('just a test', (done: any) => {
  ...
  let promiseArr: Promise<{}>[] = []
  for (const incorrectJson of toFail) {
    ...
    component.onCallFunc(incorrectJson);
    ...
    promiseArr.push(waitForExpect(() => {
      expect(component['funcWithPromiseHandler']).toHaveBeenCalled();
    }, 5000).finally( () => {
      expect(component['funcWitchCalledInHandler']).toHaveBeenCalled();
    }));
  }
  Promise.all(promiseArr).then( () => {
    expect(someService.importSomth).toHaveBeenCalledTimes(0);
    done();
  }).catch ( (er) => {
    done(er);
  })
});

После этого команда:

 yarn test:ci

стала выполняться без ошибок:

Заключение

В публикации говориться не только о функции done(). Из примера видно, что среди множества тестов ошибка была только в одном. Выловить эту ошибку получилось благодаря перегрузке console.error и console.warn. Думаю, что показанный в этой публикации подход к решению данной проблемы будет полезен не только в данном конкретном случае, но и в решении других не менее сложных и запутанных ситуациях, которые могут возникнуть при работе с jest.

Комментарии (7)


  1. funca
    18.01.2023 18:40

    Вы заметили, что в варианте с done тест выполняется быстрее (345 секунд против 419)?

    for { await waitForExpect(..) } запускает проверки строго последовательно - следующая стратует когда дождались результата предыдущей.

    for { waitForExpect(..) }; Promise.all() запускает все проверки практически одновременно, а потом ждет когда они все завершатся.

    Мне кажется такое преобразование, как минимум не эквивалентным, а может и ошибочным.


    1. alex_29 Автор
      18.01.2023 19:51

      Добрый вечер. А почему должно быть ошибочным? И в чем нарушение эквивалентности?


      1. aleksandy
        19.01.2023 07:03

        И в чем нарушение эквивалентности?

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

        Разве это не очевидно?


        1. alex_29 Автор
          19.01.2023 13:06

          Это unit тест для клиентской части веб приложения. Который проверяет, была ли вызванна та или иная функция. Т.е. он не проверяет внутреннее сосотояние объекта. Другой тест возможно проверяет их там 558, но не этот. Воторой момент - на клиенте, по возможности, все должно работать быстро и асинхронно, т.к. мы имеем дело с событиями, которые не обязательно вызываются последовательно. Отсюда, код клиентской части чаще всего асинхронный, хотя могут быть какие-то зависимости, но конечно же при написании юнит теста это проверяется. Суть текущего теста - просто подача входных значений из массива и проверка что определенные функции внутри кода вызываются или не вызываются при этом. Я не писал этот тест изначально, о чем сказанно в публикации. Но изменение async/await на Promise в юнит тесте точно никак не влияет на логику как самого теста, так и тестируемого кода в данном конкретном случае.


    1. alex_29 Автор
      18.01.2023 20:43

      345 секунд против 419 - это было на разных виртуальных машинах. Я просто версию до изменений развернул на одной виртуалке, а версию с изменениями на другой. Одна из виртуалок была довольно слабой, другая наоборот довольно сильной.


  1. DarthVictor
    19.01.2023 00:08

    Проблема в том, что если в коде есть вызов команды console.error и мы пишем unit тест на этот код, то при выполнении мы увидим в логе сообщение об ошибке и стэк до этой ошибки. В случае с unit тестом, это ожидаемое поведение,

    Не сказал бы, что это ожидаемое поведение. Я бы ожидал увидеть в логах CI только строки успешно завершенных тестов, а в самих тестах я бы ожидал увидеть моки логирования. Заодно и текст ошибок проще проверить.


    1. alex_29 Автор
      19.01.2023 13:15
      +1

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