Twoje unit testy przemówią! Czyli jak poprawić komunikaty testów.

Czytelność komunikatów logowanych podczas niepowodzenia unit testów często jest bardzo niskiej jakości. Sam wcześniej nie zwracałem na to zbytniej uwagi. Dziś uważam, że to błąd! Gdy testy świecą się na zielono, to w zasadzie problem nie istnieje. Gdy zaś na czerwono, wtedy zaczynają się schody. Najczęściej po prostu sięgamy od razu do kodu i szukamy przyczyny próbując jednocześnie odczytać “zaszyfrowane” wartości z logów failującego testu. A gdyby tak te logi mogłyby być czytelne nawet dla laika? Z pewnością ułatwiłoby to wszystkim pracę :)

Enum jak enigma

W unit testach porównujemy różnego rodzaju zmienne wynikowe z oczekiwanymi. Jeśli są to zmienne typu liczbowego to zazwyczaj ich odczytanie nie stanowi problemu. Inaczej dzieje się w przypadku typów wyliczeniowych. Nie zawsze pamiętamy co ich reprezentacja liczbowa oznacza. Dla przykładu mamy poniższy test.

TEST_F(SceneItemFactoryTests, create_OneObject_ReturnCorrectSceneItem)
{
    SceneItemFactoryTestable factory{};

    auto resultObject{ factory.create(SceneItemType::PLAYER, { 40.5F, 7.9F }, 45.0F) };

    EXPECT_EQ(0, resultObject.id);
    EXPECT_EQ(SceneItemType::WEAPON, resultObject.type); // Celowo podana zła wartość enum
}

A oto wynik naszego unit testu:

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:34: Failure
Expected equality of these values:
  expectedType
    Which is: 4-byte object <01-00 00-00>
  resultObject.type
    Which is: 4-byte object <00-00 00-00>

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

No cóż możemy sobie sprawdzić co oznacza 1 i 0, niemniej przyznać trzeba, że średnio ten komunikat jest czytelny. Musimy sięgnąć do kodu i to sprawdzić. Spróbujmy zmienić rodzaj asercji na EXPECT_THAT. Oto wynik:

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:35: Failure
Value of: resultObject.type
Expected: is equal to 4-byte object <01-00 00-00>
  Actual: 4-byte object <00-00 00-00> (of type SceneItemType)

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

Jest trochę lepiej, już teraz wiemy przynajmniej jakiego typu są wartości: (of type SceneItemType). Niemniej wciąż ten log niewiele pomaga. Co możemy zrobić? Dodać operator« ! Operator ten należy zdefiniować w tym samym pliku, w którym znajduje się nasz enum.

inline auto operator<<(std::ostream* os, const SceneItemType& type) -> std::ostream&
{
    std::string typeStr{};
    switch(type)
    {
        case SceneItemType::PLAYER:
            typeStr = "PLAYER";
            break;
        case SceneItemType::WEAPON:
            typeStr = "WEAPON";
            break;
    }

    os << typeStr;
    return os;
}

Taki zabieg pozwala Google Test użyć go w swoich asercjach. Gdy asercja nie przechodzi, GTest przeszukuje naszą bazę kodu w poszukiwaniu narzędzi umożliwiających wypisanie wartości parametrów asercji w formie tekstowej. Jeśli zdefiniujemy dla porównywanego typu, asercje Google Test użyje jej do budowy swoich logów.

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:35: Failure
Value of: resultObject.type
Expected: is equal to WEAPON
  Actual: PLAYER (of type SceneItemType)

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

Teraz zdecydowanie, dokładnie wiadomo co się wydarzyło w teście. Nasza testowana fabryka utworzyła obiekt typu PLAYER, a miała stworzyć WEAPON ;) W tym miejscu muszę wspomnieć o jeszcze jednym sposobie uzyskania podobnego efektu. Można zdefiniować funkcję PrintTo. Jest to specjalna metoda Google Test, która działa w zasadzie tak samo. Plusem może okazać się brak ingerencji w kod produkcyjny. Jeśli to dla kogoś problem warto zainteresować się tematem. Poniżej odpowiednik naszego operatora w wersji PrintTo.

inline auto PrintTo(const SceneItemType& type, std::ostream* os) -> void
{
    std::string typeStr{};
    switch(type)
    {
        case SceneItemType::PLAYER:
            typeStr = "PLAYER";
            break;
        case SceneItemType::WEAPON:
            typeStr = "WEAPON";
            break;
    }

    os << typeStr;
}

Oba rozwiązania muszą znajdować się w tej samej przestrzeni nazw, gdyż Google Test szuka operator« oraz PrintTo za pomocą ADL. Zauważ, że w instrukcji switch celowo pominąłem sekcję default. Dzięki temu, gdy w przyszłości dodasz nową wartość do enuma, kompilator przypomni Ci o konieczności aktualizacji również tego fragmentu kodu.

struct, czyli puchnące testy

W przypadku porównywania struktur możemy w każdej asercji sprawdzać pojedyncze jej pola.

TEST_F(SceneItemFactoryTests, create_OneObject_ReturnCorrectSceneItem)
{
    SceneItemFactoryTestable factory{};

    auto resultObject{ factory.create(SceneItemType::PLAYER, { 40.1F, 7.9F }, 45.0F) };

    EXPECT_THAT(resultObject.id, Eq(0));
    EXPECT_THAT(resultObject.type, Eq(SceneItemType::PLAYER));
    EXPECT_THAT(resultObject.position.x, FloatEq(40.5F)); // Sprawdzamy każde pole
    EXPECT_THAT(resultObject.position.y, FloatEq(7.9F)); // struktury Position osobno
    EXPECT_THAT(resultObject.rotation, FloatEq(45.0F));
}

Gdy struktura jest mała, może to być rozwiązanie całkiem ok. Jednak są na to lepsze metody. Jeżeli chcemy, aby jedna asercja porównywała całą strukturę musimy zdefiniować operator==. Dzięki temu Google Test użyje go automatyczne.

struct Position
{
    float x{ 0.0F };
    float y{ 0.0F };

    auto operator==(const Position& other) const -> bool
    {
        // Używamy std::abs i małej tolerancji (epsilon)
        constexpr auto eps{ 1e-5F };
        return std::abs(x - other.x) < eps and 
               std::abs(y - other.y) < eps;
    }

    // W C++20 wystarczy to, by działało EXPECT_THAT
    auto operator==(const Position&) const -> bool = default
};

Po dodaniu operatora porównania, nasz test wygląda następująco.

TEST_F(SceneItemFactoryTests, create_OneObject_ReturnCorrectSceneItem)
{
    SceneItemFactoryTestable factory{};

    auto resultObject{ factory.create(SceneItemType::PLAYER, { 40.1F, 7.9F }, 45.0F) };

    EXPECT_EQ(0, resultObject.id);
    EXPECT_THAT(resultObject.type, Eq(SceneItemType::PLAYER));
    EXPECT_THAT(resultObject.position, Eq(Position{ 40.5F, 7.9F })); // Jedna asercja na całą strukturę
    EXPECT_THAT(resultObject.rotation, FloatEq(45.0F));
}

Choć zdecydowanie, dodanie operatora pomaga w ograniczaniu rozmiaru naszego unit testu, to nie chroni on od pojawiających się oktetów, gdy asercja się nie powiedzie.

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:33: Failure
Value of: resultObject.position
Expected: is equal to 8-byte object <00-00 22-42 CD-CC FC-40>
  Actual: 8-byte object <66-66 20-42 CD-CC FC-40> (of type Position)

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

Innym rozwiązaniem może być utworzenie własnego matchera. Jedną z zasad pisania unit testów jest założenie, że nie powinniśmy zmieniać kodu produkcyjnego tylko ze względu na testy. Są oczywiście techniki jak Dependency Injection, które wpływają nieco na kod produkcyjny, ale w tej zasadzie bardziej chodzi o to, by nie oddawać API do naszej testowanej klasy, czy w tym przypadku struktury.

MATCHER_P2(PositionNear, expected, tolerance, "")
{
    const auto xDiff{ std::abs(arg.x - expected.x) };
    const auto yDiff{ std::abs(arg.y - expected.y) };

    *result_listener << "where x diff is " << xDiff << " and y diff is " << yDiff;

    return xDiff <= tolerance and yDiff <= tolerance;
}

Prawda, że elegancki? A teraz jak to wygląda w praktyce, czyli odświeżony test.

TEST_F(SceneItemFactoryTests, create_OneObject_ReturnCorrectSceneItem)
{
    SceneItemFactoryTestable factory{};

    auto resultObject{ factory.create(SceneItemType::PLAYER, { 40.1F, 7.9F }, 45.0F) };

    EXPECT_EQ(0, resultObject.id);
    EXPECT_THAT(resultObject.type, Eq(SceneItemType::PLAYER));
    EXPECT_THAT(resultObject.position, PositionNear(Position{ 40.5F, 7.9F }, 1e-5F)); // Użycie naszego matchera do porównywania struktury Position
    EXPECT_THAT(resultObject.rotation, FloatEq(45.0F));
}

No to czas na werdykt, czy nasze logi rzeczywiście poprawiły się dzięki temu zabiegowi?

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:43: Failure
Value of: resultObject.position
Expected: position near (expected: 8-byte object <00-00 22-42 CD-CC FC-40>, tolerance: 1e-05)
  Actual: 8-byte object <66-66 20-42 CD-CC FC-40> (of type Position), where x diff is 0.400002 and y diff is 0

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

No magiczne oktety wciąż się pojawiają. To dlatego, że tak naprawdę Google Test dalej nie wie w jaki sposób wyświetlić naszą strukturę Position. I tutaj wracamy się z powrotem do operatora wstawiania do strumienia: operator«.

inline auto operator<<(std::ostream& os, const Position& position) -> std::ostream&
{
    return os << "Position{ x: " << position.x << ", y: " << position.y << " }";
}

Po dodaniu takiego operatora nasze logi z testu wyglądają następująco.

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:43: Failure
Value of: resultObject.position
Expected: position near (expected: Position{ x: 40.5, y: 7.9 }, tolerance: 1e-05)
  Actual: Position{ x: 40.1, y: 7.9 } (of type Position), where x diff is 0.400002 and y diff is 0

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

Teraz można śmiało stwierdzić, że każdy będzie w stanie zrozumieć co dokładnie się wydarzyło i dlaczego test nie przechodzi. I dla porównania logi z testu z użyciem operator== zamiast matchera.

[ RUN      ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem
/usr/src/heisttown/src/Scene/Tests/SceneItemFactoryTests.cpp:33: Failure
Value of: resultObject.position
Expected: is equal to Position{ x: 40.5, y: 7.9 }
  Actual: Position{ x: 40.1, y: 7.9 } (of type Position)

[  FAILED  ] SceneItemFactoryTests.create_OneObject_ReturnCorrectSceneItem (0 ms)

To czy należy korzystać z operator== czy jednak z matchera to w zasadzie może zależeć od wielu czynników. Oba rozwiązania mają swoje wady i zalety. Tak jak to często w naszym zawodzie bywa, trzeba wybrać to rozwiązanie, które najbardziej pasuje do założeń naszego projektu, dobrych praktyk w naszym zespole, standardów kodzenia w naszej organizacji lub po prostu naszych preferencji :)

Kontenery

Podczas porównywania elementów dowolnego kontenera w C++ przy użyciu Google Test, najczęstszym problemem jest brak informacji, które elementy nie zgadzają się z ich oczekiwaną wartością. Mamy poniższy test.

TEST_F(OrderProcessorTest, getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad)
{
    OrderProcessor processor{};
    const std::vector<int> expected{ 1, 2, 3 };

    const auto result{ processor.getProcessedIds({ 3, 1, 2 }) };

    EXPECT_EQ(expected, result);
}

A oto wynik z konsoli.

[ RUN      ] OrderProcessorTest.getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad
/var/fpwork/tbiela/alps/testing/src/ut/vetControl/TiltCalculusTest.cpp:85: Failure
Expected equality of these values:
  expected
    Which is: { 1, 2, 3 }
  result
    Which is: { 3, 1, 2 }

[  FAILED  ] OrderProcessorTest.getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad (0 ms)

Jak widać w takim przypadku, gdy kontener zawiera niewielką ilość elementów, znalezienie różnicy nie bywa wymagające. Co innego, gdy taki std::vector zawiera ich znacznie więcej.

TEST_F(OrderProcessorTest, getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad)
{
    OrderProcessor processor{};
    const std::vector<int> expected{  1,  2,  3,  4,  5,  6,  7,  8,  9, 10,
                                     11, 12, 13, 14, 15, 16, 17, 18, 19, 20 };

    const auto result{ processor.getProcessedIds({  3,  1,  2,  4, 15, 20,  5,  7,  6,  8,
                                                   10, 11, 14, 13, 18, 19,  9, 12, 16, 17 }) };

    EXPECT_EQ(expected, result);
}

Znalezienie różnicy może być znacznie utrudnione.

[ RUN      ] OrderProcessorTest.getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad
/var/fpwork/tbiela/alps/testing/src/ut/vetControl/TiltCalculusTest.cpp:88: Failure
Expected equality of these values:
  expected
    Which is: { 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20 }
  result
    Which is: { 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 16, 15, 17, 18, 19, 20 }

[  FAILED  ] OrderProcessorTest.getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad (0 ms)

Aby poradzić sobie z tym problemem możemy zastosować matchera Pointwise w połączeniu z Eq(), oczywiście przy użyciu asercji EXPECT_THAT zamiast EXPECT_EQ. Tym razem widać znaczącą różnice w możliwościach tych dwóch typów asercji.

TEST_F(OrderProcessorTest, getProcessedIds_UnsortedIds_ReturnsSortedVector_Bad)
{
    OrderProcessor processor{};
    const std::vector<int> expected{  1,  2,  3,  4,  5,  6,  7,  8,  9, 10,
                                     11, 12, 13, 14, 15, 16, 17, 18, 19, 20 };

    const auto result{ processor.getProcessedIds({  3,  1,  2,  4, 15, 20,  5,  7,  6,  8,
                                                   10, 11, 14, 13, 18, 19,  9, 12, 16, 17 }) };

    EXPECT_THAT(result, Pointwise(Eq(), expected));
}

I wynik z konsoli.

Value of: result
Expected: contains 20 values, where each value and its corresponding value in { 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20 } are an equal pair
  Actual: { 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 16, 15, 17, 18, 19, 20 }, where the value pair (16, 15) at index #14 don't match

Nie tylko dostajemy numer indeksu niepasujących wartości ale również jakie one są. Jedynym minusem jest fakt, że zostajemy poinformowani tylko o pierwszej niepasującej parze wartości. Innym przypadkiem może być sytuacja, w której porównujemy kontener z elementami typu struktury lub klasy z operatorem porównania za pomocą pętli for. Wtedy możemy zastosować ciekawą właściwość makr asercji Google Test i potraktować je jak strumień wyjścia.

struct Product
{
    int id;
    std::string name;

    auto operator==(const Product& other) const -> bool
    {
        return id == other.id and name == other.name;
    }

    friend auto operator<<(std::ostream& os, const Product& product) -> std::ostream&
    {
        return os << "Product{ id: " << product.id << ", name: " << product.name << " }";
    }
};

class Warehouse
{
public:
    auto getProducts() const -> std::vector<Product>
    {
        return { Product{ 1, "Keyboard" }, Product{ 2, "Gamepad" } };
    }
};

TEST_F(WarehouseTest, getProducts_WhenInventoryNotEmpty_ReturnsAllItemsWithStreamInfo)
{
    const std::vector<Product> expectedItems{ Product{ 1, "Keyboard" }, Product{ 2, "Mouse" } };
    Warehouse warehouse{};

    const auto resultItems{ warehouse.getProducts() };

    ASSERT_THAT(resultItems.size(), Eq(expectedItems.size()));
    for (std::size_t idx{ 0 }; idx < resultItems.size(); ++idx)
    {
        EXPECT_THAT(resultItems.at(idx), Eq(expectedItems.at(idx)))
            << " mismatch at index: " << idx;
    }
}

A tak się prezentuje komunikat w konsoli.

[ RUN      ] WarehouseTest.getProducts_WhenInventoryNotEmpty_ReturnsAllItemsWithStreamInfo
/var/fpwork/tbiela/alps/testing/src/ut/vetControl/TiltCalculusTest.cpp:131: Failure
Value of: resultItems.at(idx)
Expected: is equal to Product{ id: 2, name: Mouse }
  Actual: Product{ id: 2, name: Gamepad } (of type Product)
 mismatch at index: 1

[  FAILED  ] WarehouseTest.getProducts_WhenInventoryNotEmpty_ReturnsAllItemsWithStreamInfo (0 ms)

Dzięki zastosowaniu operator«, widzimy co znajduje się w strukturach. Natomiast dzięki dodaniu komunikatu na końcu asercji mamy informację o tym, który element nie pasuje do wartości oczekiwanej.

Podsumowanie

Na ten moment to już wszystko ode mnie w temacie poprawy czytelności wyników testów. Jeśli natrafię na inne przypadki, gdzie testy nie są zbyt rozmowne to z pewnością postaram się zaprezentować nowe przykłady i dodam je do tego wpisu. Mam nadzieję, że przedstawiona tutaj treść pomoże Ci pisać nie tylko lepsze i bardziej skuteczne unit testy, ale również bardziej konkretne komunikaty, gdy testy failują. Jeśli masz inne przypadki, gdzie logi wyników testów bywają słabo pomocne opisz problem w komentarzu lub napisz do mnie bezpośrednio! Podziel się również swoją opinią na temat tego wpisu i ogólnie co myślisz o moim blogu. Chętnie dowiem się Twojej opinii! :)

Autor: Tadeusz Biela
Programista C++ | Entuzjasta TDD | Fan unit testów

LinkedIn