Thursday, December 9, 2010

Ouch, 3-day bug!

Earlier I had posted on how to write tests for the Quantumbits ObservableList class by enabling a DispatcherCycler to essentially perform a "DoEvents" to hook up appropriate events.

This was all working just fine until one day after adding a more complete suite of tests for an implementation of an ObservableList I had a failing test. I had run the test successfully before so I took a quick look and re-run the test. It passed. I ran the suite again and it failed. I ran it several times as a suite and individually to see if it might be an intermittent problem but alone it always succeeded, as part of the suite it always failed. And it failed for a completely wrong reason.
        [Test]
        public void EnsureChangingRelativeDeltaUpdatesRemainingCorrectly()
        {
            var mortgageInterestList = new MortgageInterestList(new MortgageInterest.Initial(0.05m, DateTime.Today));
            var second = new MortgageInterest.Adjustment("+.5%", DateTime.Today.AddDays(2));
            var third = new MortgageInterest.Adjustment("+.2%", DateTime.Today.AddDays(3));
            mortgageInterestList.Add(second);
            mortgageInterestList.Add(third);
            new DispatcherCycler(mortgageInterestList.CurrentDispatcher).Cycle(); // * Failed here

            second.UpdateByAbsoluteOrRelativeValue("+.3%");
            new DispatcherCycler(mortgageInterestList.CurrentDispatcher).Cycle();
            Assert.AreEqual(0.05m, mortgageInterestList.SortedList.First().InterestRate, "First interest rate should not have changed.");
            Assert.AreEqual(0.053m, second.InterestRate, "Second interest rate was not updated.");
            Assert.AreEqual(0.055m, third.InterestRate, "Third interest rate was not updated.");
        }


The guts of the list in question contained a set of data that would be sorted in date-order. It contained an initial instance (which could have it's date adjusted) and had logic that basically asserted that "adjustment" instances could not be inserted before the initial item, or moved (date changed) prior to the initial item. The error behind the failing test indicated that the test was trying to move an item prior to the initial item, which it obviously wasn't. The test merely changes the value of one of the items which should update the later item. Debugging that failure it almost looked like the adjustments were being added to the collection before the initial item, which was completely impossible.

After staring this down for two evenings looking for bugs with my Dispatcher implementations within the Observable List and cycler, Dispatcher behaviour and multithreading, TDD.Net behaviour, etc. I decided to start looking for tests that were supposed to be replicating this behaviour.  Sure enough I did have tests for this behaviour:
        [Test]
        [ExpectedException(typeof(ArgumentException))]
        public void EnsureAdjustmentInterestRateCannotBeMovedBeforeInitialRate()
        {
            var mortgageInterestList = new MortgageInterestList(new MortgageInterest.Initial(1.25m, DateTime.Today.AddDays(1)));
            mortgageInterestList.Add(new MortgageInterest.Adjustment("+5%", DateTime.Today.AddDays(2)));
            new DispatcherCycler(mortgageInterestList.CurrentDispatcher).Cycle();
            mortgageInterestList.SortedList[1].EffectiveDate = DateTime.Today;
        }


I popped an [Ignore] attribute onto this test and re-ran the suite... All remaining tests pass! I re-enable the test and the other test fails once more. Now I'm seriously doing a WTF? but making progress.

Side Note: Notice now my Dispatcher cycler is accepting a dispatcher in it's constructer, rather than being a static helper using Dispatcher.CurrentDispatcher. I was chasing all kinds of ideas around whether Dispatcher actually was thread-safe, and whether I needed to ensure the Cycle call would use the same dispatcher as the list. I went through a LOT of trial and error to try and track this behaviour down...

Then I read up on Dispatcher and how it can capture unhandled exceptions. Since this test was waiting for an exception that would have been raised on the Dispatcher (UI) thread based on the nature of ObservableList I decided to see what happens if I handled the exception at the Dispatcher level. I added a text fixture setup implementation to handle unhandled exceptions:

            Dispatcher.CurrentDispatcher.UnhandledException += (sender, e) =>
                {
                    e.Handled = true;
                };

Re-running the tests I had different failures. Essentially the classes that were expecting the exception weren't receiving it... But the originally failing test was passing.

Finally I removed the fixture setup and tried the following:

        [Test]
        [ExpectedException(typeof(ArgumentException))]
        public void EnsureAdjustmentInterestRateCannotBeMovedBeforeInitialRate()
        {
            var mortgageInterestList = new MortgageInterestList(new MortgageInterest.Initial(1.25m, DateTime.Today.AddDays(1)));
            mortgageInterestList.Add(new MortgageInterest.Adjustment("+5%", DateTime.Today.AddDays(2)));
            new DispatcherCycler(mortgageInterestList.CurrentDispatcher).Cycle();
            DispatcherUnhandledExceptionEventHandler handler = (sender, e) =>
            {
                e.Handled = true;
            };
            mortgageInterestList.CurrentDispatcher.UnhandledException += handler;
            mortgageInterestList.SortedList[1].EffectiveDate = DateTime.Today;
            mortgageInterestList.CurrentDispatcher.UnhandledException -= handler;
        }


Sure enough all tests PASS! I was actually expecting the above test to fail since the dispatcher would not raise the ArgumentException that would be raised when the effective date was changed, such as was the case when I had this essentially in the Fixture setup. However, the ArgumentEception does get raised and handled.

I explicitly add and remove the delegate handler since this would be attaching a handler to a CurrentDispatcher on the executing thread. I don't want it to interfere beyond the scope of this test.

Actually, as I write this I want to be certain that other tests that might trigger an exception (as a test failure) or test the exception behaviour don't trip up other tests.

The code can be substituted so that the handler is assigned on test start up, and removed on test cleanup. Fortunately I have a base class wrapper for my nUnit implementation so this is a snap!

        private DispatcherUnhandledExceptionEventHandler _handler = (sender, e) =>
        {
            e.Handled = true;
        };

        public override void TestSetup()
        {
            base.TestSetup();
            Dispatcher.CurrentDispatcher.UnhandledException += _handler;
        }

        public override void TestTearDown()
        {
            base.TestTearDown();
            Dispatcher.CurrentDispatcher.UnhandledException -= _handler;
        }


And now all tests are covered to behave nicely with one another if the Dispatcher encounters an error. No messy hooks in individual test cases needed.

Damn that felt good to squish!