Tracking Properties in Unit Tests - Update 2: Finer-Grained Timeout

When creating unit tests, we come across blocks of code that appear to be difficult to test. But with some thought, we can come up with some interesting solutions. Previously, we took a look at a test helper class that allows us to track changes to properties.

In the last article, we improved our PropertyChangeTracker class so that it works when "all properties" are updated. This time, we'll look at adding a finer-grained timeout.

Articles in this Series
o Tracking Property Changes in Unit Tests
o Update 1: Supporting "All Properties"
o Update 2: Finer-Grained Timeout (this article)
o Update 3: Async Tests

Note: The completed code for this article is in the "Timeout" branch of the GitHub project: jeremybytes/property-change-tracker. (It has also been merged into the master branch with some other updates.)

The Problem: 1 Second Resolution
The shortcoming of our current property change tracker is with the maximum wait time in our "WaitForChange" method:

The parameter is an integer, and it represents seconds. This means that our minimum wait time is 1 second.

This is an *extremely* long time to wait in a unit test. We want our tests to run fast. The faster our tests run, the more frequently we will run them.

Right now we have 3 tests that look at the timeout. This means that we have a minimum of a 3 second runtime for our tests:

In fact, our total run time is 5 seconds:

This doesn't seem like a long run time. But we only have 9 tests here. Once our test suite has several hundred tests, we may be hitting the timeout a dozen times in those tests, and that significantly impacts the running time of our test suite.

Finer-Grained Timeout
Ideally, we want to have much more control over this timeout period. As a start, we'll update the "WaitForChange" method so that it uses milliseconds instead of seconds. This is pretty easy:

The calculations are pretty much the same (although I did refactor it a bit). The result is that our maximum wait (a.k.a. timeout) is now in milliseconds.

DateTime.Now vs. DateTime.UtcNow
Just a quick note: another change to this code is that we use "DateTime.UtcNow" instead of "DateTime.Now". This is a minor optimization.

In the framework code, it turns out that "DateTime.Now" makes a call to "DateTime.UtcNow" and then it adjusts for the local timezone. We can avoid that calculation by just using the UTC time. For practical purposes, this makes no difference in functionality*. But there is a very slight performance difference.

*Exception: We will run into an issue with "DateTime.Now" if we run the unit tests precisely during a Daylight Saving Time switch over.

Breaking Change
We just made a breaking change to our code. Previous calls to "WaitForChange" that used "1" as a parameter will now have a timeout of 1 millisecond instead of 1 second.

Here's one of our tests:

We can see the difference in our results:

Our tests still pass, but our timings are different. This would be an issue if we were testing asynchronous calls (which we'll add in a future article).

Test Fix
Fixing the test is easy, we just need to change the parameter:

Now we have a timeout of 100 milliseconds. When we update all of our tests, we see the results:

Our total run time is now 3 seconds:

And most of that 3 seconds is actually the test runner starting up. So we've accomplished our goal of having a finer-grained timeout for our tracker class.

But lets add one more option before we leave this code.

Overload with TimeSpan
In addition to the millisecond option, we'll add an overload to our "WaitForChange" method that accepts a TimeSpan as a parameter.

Here's our additional method:

The logic is pretty close to our other method, but now we aren't limited to millisecond resolution. We can create whatever timeout we would like.

Additional Unit Tests
To test this new method, we'll create some additional tests. Here is a new test that is in the "Standard Properties" tests (see previous article for details on the test suite):

In this test, we're looking at what happens when our "max wait" has expired (hence, the name of the test). In the set up, we create a TimeSpan that represents 60 milliseconds.

This test was added to the "CallerMemberName" and "nameof()" test classes as well.

Here are the results:

We can see the new results that have run times of "59 ms" each. Our total run time stays the same:

So now we have 2 ways of calling our "WaitForChange" method: with milliseconds or with a TimeSpan.

Coming Up: Additional Tests
We still need some additional tests. As mentioned previously, the primary purpose of our PropertyChangeTracker class is to help us test where we have asynchronous methods updating our properties. So far, all of our tests are synchronous code.

So we'll add some asynchronous tests to make sure that all of this code still works reliably. And with that, we can do some additional validation of the timeouts that we have in place.

Wrap Up
We want our unit tests to run fast. The code that we had limited how fast some of our tests could run. 1-second resolution was just too long to be practical. We could easily update this code to give us millisecond resolution; however, this was a breaking change so we need to update the calling code (in this case, in our tests).

In addition, we added an option to accept an arbitrary TimeSpan. This offers even more flexibility when we use the PropertyChangeTracker in our tests.

Our class is slowly becoming useful in a larger variety of situations. More to come.

Happy Coding!