Same plan, markedly different performance!

A Simple PlanIn a previous post, I talked about how to store a number with leading zeros. This morning I came across an interesting function that could be used in SQL Server 2012 and higher to obtain the same result without using string concatenation. FORMATMESSAGE (MSDN page here) provides a mechanism to format a variable using zeros padding, exactly like our requirement!

The FORMATMESSAGE function follows the “C” convention for variable substitution used by the printf function. That is, a portion of the string starting with a space followed by a % symbol, then a “type” indicator such as “i” or “s” will be replaced by values passed into the function. See the RAISERROR page on MSDN for details about how the substitution works.

I thought, surely this function, being designed to provide the desired functionality, would be more efficient than the string concatenation method. I also added code to test the FORMAT function. Let’s take a look…

For this test, I’ve simplified the table from the prior post – this is the test-bed code:

USE tempdb;
GO
CHECKPOINT 5;
GO
DBCC FREEPROCCACHE;
DBCC FREESYSTEMCACHE ('ALL');
DBCC DROPCLEANBUFFERS;
GO

DROP TABLE #MyTestConcat;
DROP TABLE #MyTestFormatMessage;
DROP TABLE #MyTestFormat;
GO

CREATE TABLE #MyTestConcat
(
    ID INT NOT NULL
        PRIMARY KEY CLUSTERED
        IDENTITY(1,1)
    , IDPadded AS RIGHT('0000000000' + CONVERT(VARCHAR(10), ID), 10)
	, SomeData VARCHAR(1000)
)
GO
CREATE TABLE #MyTestFormatMessage
(
	ID INT NOT NULL
		PRIMARY KEY CLUSTERED
		IDENTITY(1,1)
	, IDPadded AS CONVERT(VARCHAR(10), (FORMATMESSAGE('%010i',ID)))
	, SomeData VARCHAR(1000)
);
GO
CREATE TABLE #MyTestFormat
(
    ID INT NOT NULL
        PRIMARY KEY CLUSTERED
        IDENTITY(1,1)
    , IDPadded AS FORMAT(ID, '0000000000')
	, SomeData VARCHAR(1000)
)
GO

INSERT INTO #MyTestConcat (SomeData)
SELECT TOP(1000000) o1.name + o2.name + o3.name
FROM sys.objects o1
	, sys.objects o2
	, sys.objects o3
ORDER BY o1.name
	, o2.name
	, o3.name;
GO

INSERT INTO #MyTestFormatMessage (SomeData)
SELECT TOP(1000000) o1.name + o2.name + o3.name
FROM sys.objects o1
	, sys.objects o2
	, sys.objects o3
ORDER BY o1.name
	, o2.name
	, o3.name;
GO

INSERT INTO #MyTestFormat (SomeData)
SELECT TOP(1000000) o1.name + o2.name + o3.name
FROM sys.objects o1
	, sys.objects o2
	, sys.objects o3
ORDER BY o1.name
	, o2.name
	, o3.name;
GO

SET STATISTICS IO, TIME ON;
GO
SELECT SUM(LEN(IDPadded))
FROM #MyTestConcat;
GO
SELECT SUM(LEN(IDPadded))
FROM #MyTestFormatMessage;
GO
SELECT SUM(LEN(IDPadded))
FROM #MyTestFormat;
GO
SET STATISTICS IO, TIME OFF;
GO

The plans for the three SELECT statements at the end are:

Plan #1

MyTest2Plan

MyTest3Plan

Cool! The plans are the same. Looks good so far. Next I used SET STATISTICS IO, TIME ON; to display I/O and duration statistics for each operation. The results of which are:

+----------------------+------------+----------------+----------------+--------------------+
|      TABLE NAME      | SCAN COUNT |  LOGICAL READS |  CPU TIME (MS) |  ELAPSED TIME (MS) |
+----------------------+------------+----------------+----------------+--------------------+
| #MyTestConcat        | 3          | 8053           |   342          |   262              |
| #MyTestFormatMessage | 3          | 8053           |  6552          |  3323              |
| #MyTestFormat        | 3          | 8053           | 27846          | 16783              |
+----------------------+------------+----------------+----------------+--------------------+

Oh. It appears the concatenating and truncating (#MyTestConcat) method is far-and-away the quickest method.

The takeaway for this is don’t just look at the execution plans when evaluating code for performance. Although execution plans are invaluable, they don’t tell you anything about how much time it actually takes to run.