DECRYPTBYKEY slower on SQL Server 2014 than SQL Server 2012

Question

We have been using symmetric keys for encryption/decryption on some SQL Server 2012 instances for a few years. We recently installed some new instances of SQL Server 2014 and came across some performance issues decrypting the data on SQL Server 2014 installations.

Consider a table looking like this:

CREATE TABLE [dbo].[tblCertTest](
[article_id_enc] [varbinary](100) NOT NULL,
[article_id] [int] NULL
) ON [PRIMARY]

And keys and certificates created like this:

CREATE MASTER KEY ENCRYPTION BY PASSWORD = 'Passwrrrrd12'

CREATE CERTIFICATE MyCertificateName
WITH SUBJECT = 'A label for this certificate'

CREATE SYMMETRIC KEY MySymmetricKeyName WITH
IDENTITY_VALUE = 'a fairly secure name',
ALGORITHM = AES_256,
KEY_SOURCE = 'a very secure strong password or phrase'
ENCRYPTION BY CERTIFICATE MyCertificateName;

Our data set has about 90000 rows, article_id is a 5 digit number. A bit simplified, article_id_enc is encrypted with the following command:

update tblCertTest set article_id_enc = ENCRYPTBYKEY(KEY_GUID('MySymmetricKeyName'),convert(varbinary(100), article_id))

We have applied all available hotfixes, we've tried with different instances of both SQL Server 2012 and SQL Server 2014 with different setups like ssd disks, ram disks etc.

We have tried the query locally on the SQL Server and remote.

Execution plans and indexes are the same on all servers.

This SELECT statement takes about 50 ms on any SQL Server 2012 server, including simple development machines. On any SQL Server 2014 server (including really powerful ones) the query takes at least 1500 ms.

OPEN SYMMETRIC KEY MySymmetricKeyName
DECRYPTION BY CERTIFICATE MyCertificateName

SELECT CONVERT(int, DecryptByKey(article_id_enc))
FROM dbo.tblCertTest

Any suggestions on why the query is performing so bad on SQL Server 2014? What's changed?

Answer 1

Edit: I just noticed that there is a KB article FIX: A query that uses the DECRYPTBYKEY function takes a long time in SQL Server 2014 but I have that installed and it doesn't appear to change the original conclusions below.

Running the following code in both SQL Server 2012 (11.0.5343.0) and 2014 (RTM) on a quadcore (Intel Core i5-2320) X64 desktop machine running Windows 10.

OPEN SYMMETRIC KEY MySymmetricKeyName DECRYPTION BY CERTIFICATE MyCertificateName;

DECLARE @B VARBINARY(100);

WITH t
     AS (SELECT ROW_NUMBER() OVER (ORDER BY @@SPID) AS article_id
         FROM   sys.all_objects o1,
                sys.all_objects o2,
                sys.all_objects o3,
                sys.all_objects o4)
SELECT @B = ENCRYPTBYKEY(KEY_GUID('MySymmetricKeyName'), CONVERT(VARBINARY(100), article_id))
FROM   t 

And looking at it in Process Explorer

2012

2014

Two things become immediately apparent.

The 2012 version is using less CPU and is maxing out a single core. The 2014 version is using more than a single core and has significantly more kernel-mode activity (red)

The Process Explorer "threads" window shows

2012

A single thread is monopolizing the scheduler.

2014

Here the work is being performed by two threads (thread 3212 is running the idle task sqldk.dll!SOS_Scheduler::Idle).

Tracing the 2014 process shows that SQL Server and these two threads encounter a lot of context switches (trace taken at different time than previous screen shot hence differing thread ids)

Tracing the two processes with Windows Performance Toolkit shows some significant differences in time spent in different Modules

2012

2014

I'm not sure at the moment why the 2014 version reports 25% CPU in this view vs 30% in others but anyway it is readily apparent that time spent in ntoskrnl.exe has increased dramatically between versions and now 60% of time is spent in code in that module. Time spent performing the encryption has of course dropped correspondingly.

And attaching the VS code profiler the 2012 version looks like this and the 2014 like this.

So it looks as though 2014 has additional logic to stop this hogging the scheduler and it gets switched off more frequently as highlighted by the additional items below.

(Compared with 2012)

Trying the following in both versions to perform the operation 1 million times...

SET STATISTICS TIME ON;

DECLARE @B VARBINARY(100);

OPEN SYMMETRIC KEY MySymmetricKeyName DECRYPTION BY CERTIFICATE MyCertificateName;

DBCC SQLPERF("sys.dm_os_wait_stats", CLEAR);

WITH t
     AS (SELECT ROW_NUMBER() OVER (ORDER BY @@SPID) AS article_id
         FROM   master..spt_values v1,
                master..spt_values v2
         WHERE  v1.type = 'P'
                AND v2.type = 'P'
                AND v1.number BETWEEN 1 AND 1000
                AND v2.number BETWEEN 1 AND 1000)
SELECT @B = ENCRYPTBYKEY(KEY_GUID('MySymmetricKeyName'), CONVERT(VARBINARY(100), article_id))
FROM   t

SELECT *
FROM   sys.dm_os_wait_stats
WHERE  wait_type IN ( 'PREEMPTIVE_OS_CRYPTOPS', 'SOS_SCHEDULER_YIELD' ); 

2012 (CPU time = 2344 ms, elapsed time = 2383 ms.)

It can clearly be seen that whilst the PREEMPTIVE_OS_CRYPTOPS wait type does exist in 2012 it is not used in this case.

Instead it looks as though the query more or less monopolises the scheduler (though still yielding voluntarily at the end of its 4 ms quantum - 4 * 597 = 2388)

2014 ( CPU time = 8188 ms, elapsed time = 10569 ms.)

Whereas for 2014 every invocation of the ENCRYPTBYKEY function encounters this wait type and in this case it (combined with the context switches) added 8.2 seconds to overall elapsed time.

The call stacks for some of the more time consuming kernel calls are highlighted below.

I also tried one other experiment

2014 - SQL Server affinitised to single CPU

(CPU time = 4500 ms, elapsed time = 6648 ms.)

Timings here fell somewhere in between the 2012 performance and the 2014 non affinitised performance where the code executed across multiple different cores.