DECRYPTBYKEY is slower on SQL Server 2014 than SQL Server 2012

Question

We have been using symmetric keys for encryption / decryption on some instances of SQL Server 2012 for several years. We recently installed several new instances of SQL Server 2014 and ran into some performance issues that decrypted data on SQL Server 2014 installations.

Consider a table that looks like this:

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

And keys and certificates are created as follows:

 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 90,000 lines, article_id is a five-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 applied all available fixes, we tried to use different instances of SQL Server 2012 and SQL Server 2014 with different settings, such as ssd disks, RAM disks, etc.

We tried the query locally on SQL Server and remote.

The plans and execution 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 so bad on SQL Server 2014? What changed?

Answer 1

Edit: I just noticed that there is a FIX blog article : a query that uses the DECRYPTBYKEY function takes a lot of time in SQL Server 2014 , but I installed it and does not seem to change the original output below.

The following code runs in both SQL Server 2012 (11.0.5343.0) and 2014 (RTM) on a Quadro (Intel Core i5-2320) X64 desktop computer 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 look at this in Process Explorer

2012

2014

Two things immediately become apparent.

The 2012 version uses fewer processors and maximizes one core. Version 2014 uses more than one core and has significantly greater activity in kernel mode (red)

The window "threads" of the process explorer shows

2012

One thread monopolizes the scheduler.

2014

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

Tracking the 2014 process shows that SQL Server and these two threads are confronted with many context switches (tracing done at a different time than the previous screenshot, which is different for the thread identifiers)

Tracking two processes using the Windows Performance Toolkit shows some significant differences in time spent in different modules.

2012

2014

At the moment I'm not sure why the 2014 version reports 25% of the CPU in this view versus 30% in others, but in any case it is easy to understand that the time spent on ntoskrnl.exe has increased dramatically between versions, and now 60% of the time used in code in this module. Of course, the time taken to complete the encryption has been reduced accordingly.

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

So, it looks like 2014 has additional logic to stop this intimidation of the scheduler, and it often shuts down, as shown by the additional elements below.

(compared to 2012)

Attempting to perform the following operation 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 (processor time = 2344 ms, elapsed time = 2383 ms.)

It is clearly seen that while the wait type PREEMPTIVE_OS_CRYPTOPS exists in 2012, it is not used in this case.

Instead, it looks as if the scheduler is more or less monopolizing the request (although it still gives voluntarily at the end of its 4 ms quantum - 4 * 597 = 2388)

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

While for 2014, every call to the ENCRYPTBYKEY function encounters this type of wait, in which case (in combination with context switches) it adds 8.2 seconds to the total elapsed time.

Call stacks for some longer kernel calls are highlighted below.

I also tried another experiment

2014 - SQL Server Associated with a Single Processor

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

Timing here fell somewhere between 2012 and non-affiliate 2014, when the code ran on several different cores.