On the importance of empirical performance testing

Twice recently I thought I had an opportunity to improve performance in my WPF application. Twice I have been wrong and only realized this because I actually tested performance before and after the change.

Example 1:
I have a WPF page with eight combo boxes. I populate the combo boxes from lookup tables in the database. When I initialize the page I populate the combo boxes one at a time. This is fairly common practice.

It occurred to me that as the combo boxes are not dependent on each other I could populate them asynchronously and wait until they had all loaded before continuing. Theoretically this would mean that this section of code would only take as long as the loading of the slowest combo box.

I performed before and after performance tests using a Stopwatch object and found that the single-threaded synchronous code executed in 1.485 seconds on average and the asynchronous code executed in 1.820 seconds on average. In addition, the asynchronous code is less robust because I have to keep track of incomplete asynchronous requests. It became obvious that the original synchronous code was better so I kept it.

Example 2:
I have a requirement to display a datagrid of documents and to display the document number in black if the document has no errors or warnings, blue if it only has warnings, and red if it has any errors. The documents are in a table called GLDocument and the errors are in a linked table called GLDocumentErrors. There is a bit field in GLDocumentError called IsError which is true if the GLDocumentError is an error and false if it is a warning.

My original SQL had three separate subqueries, one to detect each condition.

SELECT D.ID,
  CASE (SELECT COUNT(*) FROM GLDocumentError E WHERE E.GLDocumentID=D.ID) WHEN 0 THEN 0 ELSE 1 END AS HasAnyErrors,
  CASE (SELECT COUNT(*) FROM GLDocumentError E WHERE E.GLDocumentID=D.ID AND IsError=1) WHEN 0 THEN 0 ELSE 1 END AS HasErrors,
  CASE (SELECT COUNT(*) FROM GLDocumentError E WHERE E.GLDocumentID=D.ID AND IsError=0) WHEN 0 THEN 0 ELSE 1 END AS HasWarnings
  FROM GLDocument AS D

It occurred to me that I can get the results I needed with a single subquery which should be a lot faster. By dividing the GLDocumentError row count into the sum of IsError I will get DBNull if there are no GLDocumentError records, 0 if there are only warnings, and > 0 if there are any errors. I just have to cast the IsError from a bit to an float so that I can SUM it and the division result will be a float too. The simplified SQL looks like this...

SELECT D.ID,
  (SELECT SUM(CAST(IsError AS float))/COUNT(*) FROM GLDocumentError E WHERE E.GLDocumentID=D.ID) AS ErrorProportion
  FROM GLDocument AS D

Because this only has one instead of three subqueries it should be a lot faster right? So I SET STATISTICS TIME ON and let rip. Here are the surprising results...

-- For the three subquery SQL
(139160 row(s) affected)
SQL Server Execution Times:
CPU time = 782 ms, elapsed time = 519 ms.

-- For the one subquery SQL
(139160 row(s) affected)
SQL Server Execution Times:
CPU time = 2033 ms, elapsed time = 2755 ms.

 It appears all that CASTing and float division is more expensive than three almost identical subqueries. If you notice, the CPU time of the first query is more than the elapsed time. This tells me the query is being spread across multiple CPUs which accounts for the speed. The second query is probably executing on only one CPU.

So the moral of the tale is that you should always look before you leap!