9

Using Tests

Everything in this book until now has been about using TDD to design and build a unit test library. While that has been valuable, it’s been a bootstrap project where we’ve used TDD to help create a tool for TDD.

This chapter is different. For the first time, we’re going to use TDD to create something that will use a unit test library just like any other project you’ll be working on. This will still be a library that’s intended to be used by other projects. We’re going to create a logging library, and we’re going to use TDD and the unit test library to reach the following goals:

  • Create a design that’s easy to use
  • Improve the quality of the code
  • Refactor the design as needed while maintaining confidence in the code
  • Create tests that help capture the requirements and document the usage of the library

The approach should be familiar by now. We’ll start out simple and get something working, before enhancing the design and adding new features. Each step will start with tests that will drive the design so that we can reach the goals.

We’ll first think about why we are building a logging library. This is important to set the overall direction of the project. Then we’ll explore how TDD will help us and what the ideal logging library would look like. And then, we’ll start building the logging library.

At the end of this chapter, you’ll have a simple logging library that you can use in your projects. But even more important is the skill you’ll gain by seeing exactly how to use TDD in a real project.

Technical requirements

All code in this chapter uses standard C++ that builds on any modern C++ 20 or later compiler and Standard Library. The code uses the testing library from the previous chapters and will start a new project.

You can find all the code for this chapter in the following GitHub repository:

https://github.com/PacktPublishing/Test-Driven-Development-with-CPP

Why build a logging library?

There are already lots of choices available in other libraries for logging. So why build another logging library? Isn’t this supposed to be a book about TDD?

This is a practical book that shows you how to use TDD in your own projects. And one of the best ways to do that is to use TDD to build a project. We needed a project for this book, and I thought that a logging library would be perfect because we can start out simple and enhance it along the way. A logging library is useful and practical in itself, which also fits the theme of this book.

If you already have your own logging library or are using one you found elsewhere, then this book will still help you to better understand how it works. And you’ll also benefit from the process of building a logging library so that you can apply the same process to your own project.

But we’re not going to settle for a logging library that does what all the other logging libraries do. Following a TDD approach, we need to have a good idea of how something will be used. We approach problems from a user’s point of view.

We’re going to approach this as if we were building micro-services. Instead of building a software solution as one giant application that does everything needed, a micro-service architecture builds smaller applications that accept requests, perform some desired service, and return the results. One service can sometimes call other services to perform its function.

There are many benefits to an architecture such as this that this book will not go into. This architecture is being used to give us a specific use in mind as we employ TDD to design a logging library that will be uniquely suited to a micro-service environment.

Without a focus on and knowledge of the specific user that will need the software you are designing, you face the risk of designing something that doesn’t meet the needs of that user. Our user for this book will be a software developer who is writing micro-services and needs to log what the services do. That’s the type of focus I encourage you to get to when designing your own software. Because without the focus just described, we might have jumped right into a logging library that does what most other logging libraries do. Our micro-service developer would look at a general-purpose logging library and find nothing special about it.

Our goal instead is for that same micro-service developer to look at our logging library and immediately see the benefits and want to start using it. The next section will show how TDD benefits the most from an awareness of who will be using the logging library.

How will TDD help build a logging library?

The biggest benefit we’ll get from using TDD to build a logging library is the customer focus. It’s easy to make assumptions about how something should be designed, especially when there are already many common solutions that do something similar.

It’s like a trail that’s easy to follow. The trail might take you someplace you want to go or maybe nearby. And if the destination is vague or unknown, then a trail becomes even easier to follow. But if you know exactly where you want to go, then you can follow a trail when convenient and leave the trail when it no longer takes you where you want to go.

TDD encourages us to think about how we want to use the software that we’re building. This, in turn, lets us customize the solution to best fit our needs. In other words, it lets us know when to leave the trail and start a new path.

We also benefit from having tests that can verify the behavior of the software because building software is not like walking along a path one time. We don’t start at the beginning and walk directly to the destination or final software that we want to build.

Instead, we refine the path. It’s more like starting with a map and drawing a rough path to the destination. Maybe the path aligns with known and existing paths, and maybe not. Once we have the rough path drawn, we refine it by adding more details. Sometimes the details might make us change our path. By the time we’re done, we’ve walked the path so many times we’ve lost count.

TDD helps by guiding us to a simple solution first and verifying that it works. This is like the rough path initially drawn on the map. Each time we enhance and refine the solution, we have tests to make sure that we don’t break anything. This is like checking to make sure we are still on the path.

Sometimes, an enhancement results in the need for a design change. This is like discovering a river blocking our way that didn’t appear on the initial map. We need to go around it by finding a different place to cross. The path changes, but the need to stay on the new path remains. This is where the tests help us. We have a new design that fixes an unforeseen problem, but we can still use the existing tests to validate the new design. We have confidence in the new design because it fixes the unexpected problem while still performing as expected.

TDD will help increase the usage of the logging library by other projects by providing clear and documented examples of how to use the library. This would be like producing videos of walking along the path so that future travelers will know what to expect and whether they want to follow the path before starting. Given a choice between our fully documented and easy-to-follow examples versus a similar library that claims to offer the same results but without proof, most people will prefer our library. Over time, our solution will get even better as we incorporate feedback from users.

Let’s start by thinking about the destination we want. This would be the ideal logging library for our intended customers. What would that look like? This will form the first rough path that we’ll start to refine.

What would the ideal logging library look like?

When designing software, it’s good to remember that you don’t have to design something completely new if common solutions already meet your needs exactly. A new design that’s different just for the sake of being different is just going to confuse people. A new design that’s different because the existing designs don’t quite work and the differences solve a real need is good. So before we begin dreaming up new logging designs, let’s first look at common ideas and see if we really need something new.

To be completely thorough, we should also try to use what C++ already provides. Maybe that is enough and we don’t need a library. Let’s say we have the following code that tries to calculate the result of starting with 1 and doubling the value three times. The correct answer should be 8, but this code has a bug:

#include <iostream>
int main ()
{
    int result = 1;
    for (int i = 0; i <= 3; ++i)
    {
        result *= 2;
    }
    std::cout << "result=" << result << std::endl;
    return 0;
}

It prints a result of 16 instead of 8. You probably already see the problem, but let’s imagine that the code is a lot more complicated, and the problem was not obvious. As the code is currently written, we’ll go through the loop four times instead of just three times.

We could add extra output such as this to help find the problem:

    for (int i = 0; i <= 3; ++i)
    {
        std::cout << "entering loop" << std::endl;
        result *= 2;
    }

Which, when run, produces the following output:

entering loop

entering loop

entering loop

entering loop

result=16

The results clearly show that the loop was run four times instead of just three.

What we just did by adding extra text to the output that showed what was happening while running the code is the core of logging. Sure, we can add more features or do more. But the questions we need to ask are is this enough, and will this meet our needs?

Using std::cout is not enough and will not meet our needs for several reasons:

This simple example already used the console output to display the results. Normally, services should avoid sending text to the console because there won’t be anybody watching the screen for the results.

Even if the console was the desired destination for the program output, we shouldn’t mix the extra logging output with the regular output.

We could send the logging output to a different stream, such as std::cerr, but this is not a full solution. Is the logging output always an error? Maybe it helps us identify that our program is actually running correctly and that the problem must be somewhere else.

Logging extra information is useful, but not all the time. Sending output directly to std::cout doesn’t give us a way to turn it off without changing the source code and rebuilding.

And it would be nice if the logging output included extra information, such as the date and time. We could add this extra information, but then we’d have to add it every time we called std::cout to log information.

We’re making progress in the design because we’ve just eliminated one possible path. It’s always good to think about what you already have available before looking for a solution elsewhere.

What if we put the logging into a function and called that function instead of using std::cout directly? The code might look like this:

#include <fstream>
#include <iostream>
void log (std::string_view message)
{
    std::fstream logFile("application.log", std::ios::app);
    logFile << message << std::endl;
}
int main ()
{
    int result = 1;
    for (int i = 0; i <= 3; ++i)
    {
        log("entering loop");
        result *= 2;
    }
    std::cout << "result=" << result << std::endl;
    return 0;
}

This is a big improvement already. Even though the application is still using std::cout to display the result, we’re not adding to the noise with even more console output for logging. Now the logging output goes into a file. This also avoids mixing the logging with the regular results.

We could even add a check inside the log function to see if the message should be logged or ignored. And having everything wrapped up in a function would also make it easy to add common information such as the date and time.

Is the ideal solution just a function?

Not really, because we also need to configure the logging. The code just shown was very simple and used a fixed log filename. And other features are missing that will improve the logging experience, for example:

  • The code currently opens and closes the log file for each message.
  • There is an assumption that the message should go to a file. Maybe we want the message to go somewhere else or to a file, in addition to somewhere else.
  • The message is a single text string.
  • The code does not handle multiple threads trying to log messages at the same time.
  • The log function makes the main application wait until the log message has been written before the application can proceed.
  • We haven’t added anything specific to our desired customer, the micro-service developer, such as the ability to filter messages.

What we have is a good start, confirming that there are enough requirements to justify the need for a library.

Looking at other similar solutions is also a good idea, and there are many. One well-known logging library comes from the Boost C++ libraries and is called Boost.Log. This library allows you to start logging to the console in a simple way. And the library is extensible and fast. It’s also big. Even though it starts out simple, I’ve spent days reading through the documentation. One thing leads to another and before I knew it, I was learning about other technologies that the logging library uses.

While the Boost.Log library might start out simple, it can quickly require you to learn a lot more than expected. I’d like to create something that stays simple to use. Our ideal logging library should start out simple to use and hide any necessary complexity so that the user is not buried in options. We’re not trying to build a logging library that can do everything. We have a specific user in mind and will use TDD to focus on the needs of that micro-service developer.

The next section will begin the process of creating a logging library. Before we begin writing tests, we’ll need to create a new project, which the next section explains.

Starting a project using TDD

Now that we’ve determined that a logging library is a good idea and is justified, it’s time to start a new project. Let’s start with the log function from the previous section and create a new project. The log function looks like this:

void log (std::string_view message)
{
    std::fstream logFile("application.log", std::ios::app);
    logFile << message << std::endl;
}

Where will we put this log function, and what will the test project structure look like? In the earlier chapters, we tested the unit test library. This is the first time we’ll be using the unit test library as something outside the actual project we’re working on. The project structure will look like this:

MereMemo project root folder
    MereTDD folder
        Test.h
    MereMemo folder
        Log.h
        tests folder
            main.cpp
            Construction.cpp

The new structure uses a containing folder called the MereMemo project root folder. Like the unit test library is called MereTDD, I decided to continue the theme with the word mere and call the logging library MereMemo. Other choices were already in use, and the word memo represents the idea of writing something down to remember it.

You can see that inside the root folder is a folder called MereTDD with only the Test.h file. We no longer need to include the tests for the unit test library. We’re going to use the unit test library now instead of developing it further. If we ever do need to make changes to the unit test library, then we’ll go back to the previous project that contains the tests for the unit test library.

The project root folder gives us a place to put both the unit test library header file in its own folder and the logging library also in its own folder.

Inside the MereMemo folder is a file called Log.h. This is where we’ll put the log function. And there is also a folder called tests, which will contain the unit tests for the logging library. Inside the tests folder is where we will find the main.cpp file and all the other unit test files. For now, there is just one unit test file called Construction.cpp, which is empty and doesn’t contain any tests yet.

I should also mention that you don’t need to put the MereTDD folder inside your project root folder like this. You can put it anywhere you want. This is like installing the unit test library on your computer. Since the unit test library is really just a single header file, there isn’t anything that needs to be installed. The header file just needs to exist somewhere on your computer in a convenient place so that you know the path. We’ll need to add the path to the project settings in your development tools so that the compiler knows where to find Test.h. I’ll explain more about this step in just a moment.

We need the usual include guards in Log.h, and after putting the log function inside, then Log.h should look like this:

#ifndef MEREMEMO_LOG_H
#define MEREMEMO_LOG_H
#include <fstream>
#include <iostream>
#include <string_view>
namespace MereMemo
{
inline void log (std::string_view message)
{
    std::fstream logFile("application.log", std::ios::app);
    logFile << message << std::endl;
}
} // namespace MereMemo
#endif // MEREMEMO_LOG_H

The log function now needs to be inline since it is in its own header file and could be included multiple times in a project.

We can mostly copy the contents of main.cpp from the unit test library project and use it to run the unit tests for the logging library project too. We need to make a minor change to how we include Test.h, though. The main.cpp file should look like the following example:

#include <MereTDD/Test.h>
#include <iostream>
int main ()
{
    return MereTDD::runTests(std::cout);
}

You can see that we now include Test.h using angle brackets instead of quotation marks. This is because Test.h is not directly part of the logging library; it’s now a file being included from another project. The best way to include files from other projects or libraries is to keep them separate in their own folders and change your project settings in your development tools to tell the compiler where to find the files needed.

For my development work, I’m using the CodeLite integrated development environment (IDE), and the project settings are available by right-clicking on the project and choosing the Settings menu option. Inside the pop-up dialog, there is a section for the compiler settings. And on the compiler settings page, there’s an option to specify the include paths. CodeLight has some predefined paths that can be used to identify things such as the path to the current project. I set the include paths to look like this:

.;$(ProjectPath)

The include paths are separated by semicolons. You can see there are two paths specified. The first is a single dot, which means to look for included files in the current folder. This is how the project-specific include files that use quotation marks are found. But I also added a path with the special syntax using the dollar sign and parentheses, which tells CodeLite to look in the project root folder for additional include files. What actually happens is that CodeLite interprets the paths, including its special predefined paths, such as ProjectPath, and sends the real filesystem paths to the compiler. The compiler doesn’t know anything about ProjectPath, parentheses, or dollar signs.

If you decide to place the unit test library somewhere else on your computer, you will need to add the full path instead of using ProjectPath. And if you’re using a different IDE instead of CodeLite, then the process will be similar. All IDEs have their own way of specifying the include paths to be used by the compiler. The settings are almost always in a settings dialog that you can open from the project.

With all this setup and project configuration work done, it’s time to start writing some tests, beginning in the next section.

Logging and confirming the first message

Now that we have a project ready, we can begin writing some tests and designing the logging library. We already created an empty unit tests file called Construction.cpp. I like to start with some simple tests that ensure classes can be constructed. We can also use this to make sure that simple functions can be called. This section will focus on creating a single test to log our first message and confirm that it all works.

We already have the log function from earlier, which opens a file and appends a message. Let’s add a test that calls log and writes something. The following example shows how to edit Construction.cpp to add the first test:

#include "../Log.h"
#include <MereTDD/Test.h>
TEST("Simple message can be logged")
{
    MereMemo::log("simple");
}

Because we’re testing the logging library, we need to include Log.h, which is found in the parent directory where Construction.cpp is located. We use quotation marks for Log.h because it’s in the same project. Later, if you want to use the logging library for your own project, you’ll just need to put Log.h in a known location and include it with angle brackets, just like how we now include Test.h with angle brackets.

The single test just calls the log function. This really just reorganizes the code we started in this chapter by creating a real project and using tests instead of directly writing code in main. Building and running the project shows the following output to the console:

Running 1 test suites
--------------- Suite: Single Tests
------- Test: Simple message can be logged
Passed
-----------------------------------
Tests passed: 1
Tests failed: 0

The single test ran and passed. But it will pass no matter what as long as it doesn’t throw an exception. That’s because we don’t have any confirmations in the test. The real output that we’re interested in doesn’t even appear in the console. Instead, it all goes to the log file called application.log. When I run the project from the CodeLite IDE, it shows a similar output. But it seems that CodeLite runs the code from a temporary folder. Other IDEs also do something similar, and it can be hard sometimes to keep up with the temporary locations. So instead, you might want to use your IDE to build the project and then open a separate terminal window to run the test application manually. This way, you are in full control over where the application is run and have a window open that you can use to examine the log file that gets created.

My application gets built in a folder called Debug, and the contents of that folder after building contain the executable file and the object files that are used to create the final executable. There is no file called application.log until the test application project is run. Once the project is run, the application.log file can be printed to the console like this:

$ cat application.log 
simple

At the $ prompt, the cat command is used to display the contents of the application.log file, which contains a single line with a simple message. If we run the project again, then we’ll append new content to the same log file, which looks like this:

$ cat application.log 
simple
simple

After running the application twice, we get two messages in the log file. Both messages are identical, which is going to make it hard to determine whether anything new was added to the log file or not. We need a way to create unique messages and then a way to verify that a particular message is found in the log file. This will let us add a confirmation to the test to verify that a message was logged without needing to manually examine the log file each time the test is run.

Other tests might need the ability to generate unique messages and then verify the contents of the log file, and we might want to put these other tests in different test.cpp files. So that means we should add a helper file to write the required code so that it can be shared with other tests in other files.

A common name for a helper file like this is Util. It seems like every project has Util.h and Util.cpp, and this is why. It’s a good place to put useful code that can be shared throughout a project.

What would the test look like if we had these helper functions? Change Construction.cpp to look like the following screenshot:

#include "../Log.h"
#include "Util.h"
#include <MereTDD/Test.h>
TEST("Simple message can be logged")
{
    std::string message = "simple ";
    message += Util::randomString();
    MereMemo::log(message);
    bool result = Util::isTextInFile(message,          "application.log");
    CONFIRM_TRUE(result);
}

We need to include Util.h, and then we can make the message unique by appending a random string we get from calling randomString. The full message is stored in a variable so that we can use it when logging and verifying. After logging the message, we call the other new function, isTextInFile, to verify.

One problem with this test is the need to specify the log filename. Right now, the log filename is hardcoded in the log function. We’re not going to fix the log filename problem right away. With TDD, we take things one step at a time. If you have an issue tracking system, adding the log filename problem to the tracking system will make sure it isn’t forgotten.

Now that we have an idea of how the utility functions will be used, let’s add both utility files to the project in the tests folder and add a couple of function declarations in Util.h like this:

#ifndef MEREMEMO_TESTS_UTIL_H
#define MEREMEMO_TESTS_UTIL_H
#include <string>
#include <string_view>
struct Util
{
    static std::string randomString ();
    static bool isTextInFile (
        std::string_view text,
        std::string_view fileName);
};
#endif // MEREMEMO_TESTS_UTIL_H

The first function will let us generate a random string that we can use to make the messages unique. There’s always a possibility that we’ll get duplicate strings, which could cause us to think that a log file contains a new log message when, in fact, we see a previous message that used the same random string. In practice, this shouldn’t be a problem because we won’t just be logging random strings. We’ll be adding random strings to other text that will be unique for each test.

When I was originally developing this code, I used the same text for many of the tests. The random number added to the end makes each message unique. Or, at least, I didn’t notice any duplicate messages. The tests all worked great until I got to Chapter 15, How to Test With Multiple Threads, and added 150 new messages in a single test. The problem wasn’t due to multiple threads. The problem was always a possibility and didn’t appear until the extra messages increased the probability of duplicate messages. We’re going to avoid the problem by using unique base message text for each test.

The second function will let us confirm that some text actually exists in a file, and we can use this to verify that a particular message exists in the log file.

I like to make functions like this static methods in a struct. This helps to make sure that the implementations match the declarations in the header file. The implementation goes in Util.cpp like this:

#include "Util.h"
#include <fstream>
#include <random>
std::string Util::randomString ()
{
    return "1";
}
bool Util::isTextInFile (
    std::string_view text,
    std::string_view fileName)
{
    return false;
}

The implementations don’t do anything other than return for now. But this lets us build and verify that the test fails.

Why would we want to make sure that the test fails?

Because it helps to validate a passing result once we actually implement the functions. A failure ensures that the test is written correctly and can catch a failure. Once we implement the helper functions, then the test will pass, and we can be sure that the pass is coming from the helper implementation and not just a test that will always pass anyway.

The following screenshot shows the expected failure when running the project:

Running 1 test suites
--------------- Suite: Single Tests
------- Test: Simple message can be logged
Failed confirm on line 15
    Expected: true
-----------------------------------
Tests passed: 0
Tests failed: 1

Even though a manual check of the application.log file shows that the expected message did get written to the end of the log file:

$ cat application.log 
simple
simple
simple 1

Let’s fix the randomString function now to ensure we can get unique messages logged. We’ll need to include chrono to be able to set up a random number generator with a seed based on the current time. The following code snippet shows the relevant code in Util.cpp:

#include <chrono>
#include <fstream>
#include <random>
std::string Util::randomString ()
{
    static bool firstCall = true;
    static std::mt19937 rng;
    if (firstCall)
    {
        // We only need to set the seed once.
        firstCall = false;
        unsigned int seed = static_cast<int>(
            std::chrono::system_clock::now().
            time_since_epoch().count());
        rng.seed(seed);
    }
    std::uniform_int_distribution<std::mt19937::result_type> dist(1, 10000);
    return std::to_string(dist(rng));
}

Because this uses random numbers, you’ll get different results each time. The test still fails, but after running the test application a couple more times, my application.log file looks like this:

$ cat application.log 
simple
simple
simple 1
simple 2030
simple 8731

The message is now somewhat unique, with a slight chance of duplicate log messages. That’s good enough for now, and we can move on to getting the verification function working. We’ve been keeping the log file between test application runs, so the new message is appended each time. A real test run to verify your code should start with a clean environment with no leftover files from a previous run.

I’m showing the code for both the random string and the verification without fully explaining everything. That’s because random numbers and file searches are needed but are not completely in scope for explaining TDD. It’s easy to get off topic by explaining all the details about random numbers or even searching text files for matching strings.

The implementation of the isTextInFile function looks like this:

bool Util::isTextInFile (
    std::string_view text,
    std::string_view fileName)
{
    std::ifstream logfile(fileName.data());
    std::string line;
    while (getline(logfile, line))
    {
        if (line.find(text) != std::string::npos)
        {
            return true;
        }
    }
    return false;
}

All this function does is open the log file, read each line, and try to find the text. If the text is found, then it returns true, and the function returns false if it cannot find the text in any line.

Building and running the project now shows the test passes like this:

Running 1 test suites
--------------- Suite: Single Tests
------- Test: Simple message can be logged
Passed
-----------------------------------
Tests passed: 1
Tests failed: 0

We now have a way to write log messages to a file and confirm that the message appears in the file. The code could be more efficient because, right now, it searches through the entire log file starting at the beginning when looking for the text. But our goal is not to write the best log file searching tool. The test log files will not likely grow too big, so a simple approach to searching should work well.

A log needs more than just messages to be useful. The following section will add timestamps to the messages, adding the minimum set of features needed for a logging library.

Adding timestamps

A single log file might provide some value with just messages, but recording the date and time of each log message makes it much more valuable. And once we start working with multiple log files from different micro-services, the need to order the log messages by time becomes critical.

It’s fairly simple to add timestamps. All we need to do is get the current time, format it into a standard timestamp that eliminates misunderstanding between the year, month, and day, and then send the timestamp to the log along with the message. The caller doesn’t need to do anything.

It’s also difficult to test directly to make sure it works. We can manually open the log file and see the timestamps; that will be enough for now. We’re not going to add any new tests for the timestamps.

All we need to do is modify Log.h so it looks like this:

#include <chrono>
#include <ctime>
#include <fstream>
#include <iomanip>
#include <iostream>
#include <string>
#include <string_view>
namespace MereMemo
{
inline void log (std::string_view message)
{
    auto const now = std::chrono::system_clock::now();
    std::time_t const tmNow =          std::chrono::system_clock::to_time_t(now);
    auto const ms = duration_cast<std::chrono::milliseconds>(
        now.time_since_epoch()) % 1000;
    std::fstream logFile("application.log", std::ios::app);
    logFile << std::put_time(std::gmtime(&tmNow),                "%Y-%m-%dT%H:%M:%S.")
               << std::setw(3) << std::setfill('0')                << std::to_string(ms.count())
               << " " << message << std::endl;
}

We need to include some new system headers, chrono, ctime, iomanip, and string. A better way to format dates and times involves a new system header file called format. Unfortunately, even though format is part of C++20, it’s still not widely implemented by most standard libraries. So this code uses a slightly older way to do the formatting that uses the standard put_time function.

We start by getting the system time. Then we need to convert the time to an older time format called time_t. Even though I often only mention time, I usually mean both time and date.

We want the timestamps to be fairly precise and just logging the time down to the seconds is not nearly precise enough. So, we need to cast the time to milliseconds and divide by 1,000 to get the fraction of a second we need.

The function continues to open the log file as before. But now, it calls put_time with the Coordinated Universal Time (UTC) or Greenwich Mean Time (GMT). Both terms mean almost the same thing for most practical purposes. GMT is an actual time zone, while UTC is a standard. They are normally the same and are used instead of local time to avoid issues with different time zones. By calling gmtime, we can ensure that logs generated on machines in different time zones will be ordered correctly because all the times refer to the same time zone.

If you’re using the Visual Studio tools from Microsoft, you’ll likely get an error with the use of gmtime. I mentioned this is an older solution, and some compilers will complain that gmtime could be unsafe. The recommended replacement is gmtime_s, but this replacement function requires some extra checks in the code to see if it is available. Other compilers might also complain about gmtime and normally tell you in the error message what needs to be done to fix the problem. The error message from Visual Studio says that if we want to use gmtime, we need to define _CRT_SECURE_NO_WARNINGS in the project settings under C++ preprocessor definitions.

The strange formatting involving percent signs and uppercase and lowercase letters tells put_time how to format the various elements of the date and time. We want to format the date and time according to the ISO-8601 standard. The most important part is that the standard says that the year comes first with four digits followed by the two-digit month, and then the two-digit day. Dashes are allowed between the numbers.

Without a standard like this, a date such as 10-07-12 could mean different dates to different people. Is that October 7, 2012? Or July 10, 2012? Or July 12, 2010? Or December 7, 2010? About the only thing we can all agree on is that the year is probably not 2007. Even using a four-digit year still leaves room for the month and day to get mixed up. By using ISO-8601, we all agree that the year is first, then the month, and then the day.

Next in the standard is the capital letter T. All this does is separate the date from the time portion. The time comes next and is much less confusing because we all agree that the hour comes first, then the minutes, and then the seconds. We put a dot after the seconds before displaying the fractional milliseconds.

After making these changes, deleting the old log file, and building and running the project a few times, we can see that the log file looks something like this:

$ cat application.log

2022-06-13T03:37:15.056 simple 8520

2022-06-13T03:37:17.288 simple 1187

2022-06-13T03:37:18.479 simple 2801

The only thing we’re not doing is including specific text in the timestamp that shows the time is UTC. We could add specific time zone information, but this should not be needed.

We have timestamps and can log a single string of text. The next section will let us log more than a single piece of text.

Constructing log messages with streams

Having a log function that accepts a single string to display is not the easiest function to use. Sometimes, we might want to log more information. We might also want to log different types and not just strings. This is where we can use the powerful streaming ability used extensively in C++.

We’re already using a stream inside the log function. All we need to do to give the full power of the stream to the caller is to stop sending the single message text to the stream inside the log function and instead return the stream itself to the caller. The caller will then be free to stream whatever is needed.

We can see what this will look like by first modifying the test; we have to use the log function as if it returned a stream. The modified test looks like this:

TEST("Simple message can be logged")
{
    std::string message = "simple ";
    message += Util::randomString();
    MereMemo::log() << message << " with more text.";
    bool result = Util::isTextInFile(message,          "application.log");
    CONFIRM_TRUE(result);
}

We now call the log function without any arguments. Instead of passing the message variable as an argument, we use the log function’s return value as a stream and directly send the message along with another piece of text to the stream.

Notice how we need to make sure to add a space before the second piece of text. This is to prevent the text from joining up with the message that comes before it. As with any stream, it’s up to the caller to ensure the text doesn’t run together.

There is a slight problem we need to work out. Previously, when we were handling the message inside the log function, we were able to add a newline to the end of the message. We still want log messages to appear on their own lines in the log file. But we also don’t want the caller to always have to remember to add a newline.

One of our goals is to make this logging library easy to use. Requiring each call to log to include a newline at the end makes the use tedious. So instead, a simple temporary solution is for the log function to add a newline to the beginning of each log message.

This has a strange side effect. The very first line in a log file will be empty. And the last line will not have a newline. But the overall effect is still that each log message will appear on its own line. And that’s the behavior that we want to keep. This temporary solution will be fixed properly in the following chapter.

The change to the log function in Log.h is also simple and looks like this:

inline std::fstream log ()
{
    auto const now = std::chrono::system_clock::now();
    std::time_t const tmNow =          std::chrono::system_clock::to_time_t(now);
    auto const ms = duration_cast<std::chrono::milliseconds>(
        now.time_since_epoch()) % 1000;
    std::fstream logFile("application.log", std::ios::app);
    logFile << std::endl
        << std::put_time(std::gmtime(&tmNow),         "%Y-%m-%dT%H:%M:%S.")
        << std::setw(3) << std::setfill('0')         << std::to_string(ms.count())
        << " ";
    return logFile;
}

Instead of returning void, this new version returns std::fstream. You can see that the first thing that gets sent to the log file stream is std::endl, which ensures each log message gets its own line in the log file. The entire idea of returning std::fstream is a temporary solution that will be enhanced in the next chapter.

Then, instead of sending a message to the stream, the function returns the stream after sending the timestamp. This lets the caller send whatever values are needed to the stream. An empty space is added after the timestamp to make sure that the timestamp doesn’t run into additional text that gets streamed by the caller.

An interesting thing to consider about the return type is what will happen to fstream once the function returns. We construct fstream inside the log function and then return the stream by value. Returning a stream by value was not possible before C++11, and we can do this only because we now have the ability to move the stream out of the log function. The code doesn’t need to do anything special to enable the move. It just works with modern C++. We will run into the move issue again in the next chapter when we fix the temporary solution with newlines.

Following TDD to design software encourages working solutions that get enhanced instead of trying to come up with a perfect design in the beginning. I can tell you from experience that it’s not possible to think of every little design issue ahead of time. Adjustments need to be made along the way, which tends to turn a perfect design into something less than it was. I like TDD because designs start with the end user in mind and the enhancements work around small issues such as our newline problem. The end result is better than what it was in the beginning. Following TDD lets the design stay true to the things that matter the most while being flexible where needed.

We still need to consider what happens to the stream once it leaves the log function. The test code is not storing the stream in a local variable, so it will get destroyed. But it will only get destroyed at the end of the expression in which it was created. Let’s say we call log, as follows:

    MereMemo::log() << message << " with more text.";

The std::fstream that gets returned from the log function remains valid until the semicolon at the end of the line. The lifetime of the stream needs to remain valid so that we can continue to use it to send the message and the additional text.

Building and running the project a few times shows that the single test passes each time. And the log file contains the extra text, as displayed in the following screenshot:

$ cat application.log 
2022-06-13T05:01:56.308 simple 5586 with more text.
2022-06-13T05:02:02.281 simple 2381 with more text.
2022-06-13T05:02:05.621 simple 8099 with more text.

You can see the empty line at the beginning of the file. But each message is still on its own line, and the caller can now log other information. Let’s create a new test to make sure. The new test will look like the following example:

TEST("Complicated message can be logged")
{
    std::string message = "complicated ";
    message += Util::randomString();
    MereMemo::log() << message
        << " double=" << 3.14
        << " quoted=" << std::quoted("in quotes");
    bool result = Util::isTextInFile(message,     "application.log");
    CONFIRM_TRUE(result);
}

This new test logs a double literal value directly and even logs the result of calling the std::quoted function. The quoted function just puts quotation marks around what is given to it. Even though the text “in quotes” already looks like it has quotation marks, remember that these marks are for the compiler to know when the text begins and ends. The quotation marks in the source code are not actually part of the text, just like how the quotation marks from the other string literals such as “double=” don’t appear in the log message. But because we call std::quoted, we will get quotation marks in the output.

The interesting thing about std::quoted is that the return value can really only be used to send to a stream. The actual type is undefined by the C++ standard, and the only requirement is that it can be sent to a stream.

Building and running the project shows that both tests pass. The following example shows what the application.log file looks like after deleting it and running the tests a couple of times:

$ cat application.log

2022-06-13T05:47:36.973 simple 6706 with more text.

2022-06-13T05:47:36.975 complicated 1025 double=3.14 quoted="in quotes"

2022-06-13T05:47:39.489 simple 4411 with more text.

2022-06-13T05:47:39.495 complicated 9375 double=3.14 quoted="in quotes"

We now have the ability to create log messages with timestamps, save them to a log file, and can send whatever data we want to each log message. The usage is simple and intuitive for C++ developers who are already familiar with sending information to a stream such as std::cout.

Summary

In this chapter, you learned how to use the unit test library to begin a new project using TDD. Even though we only have two tests, we already have a working logging library that is easy to use and understandable by any C++ developer.

The two tests will help ensure we don’t break the simple design started in this chapter as we extend the logging library in later chapters. The next chapter, in particular, will extend the logging library to better fit the needs of our intended user, a micro-services developer. We’ll be adding the ability to tag log messages and then use the tags to enable powerful filtering options.

..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset
3.22.27.45