9

Scenario: SQL Server 2014 (v12.0.4100.1)

.NET Service runs this query:

SELECT name, base_object_name 
FROM sys.synonyms 
WHERE schema_id IN (SELECT schema_id 
                    FROM sys.schemas 
                    WHERE name = N'XXXX')
ORDER BY name

...which returns about 6500 rows but it often times out after 3+ minutes. The XXXX above is not 'dbo'.

If I run this query in SSMS as UserA, the query returns in less than a second.

When run as UserB (which is how the .NET service connects), the query takes 3-6 minutes, and has the CPU% at 25% (of a 4 cores) the entire time.

UserA is a Domain Login in the sysadmin role.

UserB is a SQL Login with:

EXEC sp_addrolemember N'db_datareader', N'UserB'
EXEC sp_addrolemember N'db_datawriter', N'UserB'
EXEC sp_addrolemember N'db_ddladmin', N'UserB'
GRANT EXECUTE TO [UserB]
GRANT CREATE SCHEMA TO [UserB]
GRANT VIEW DEFINITION TO [UserB]

I can duplicate this in SSMS by wrapping the above SQL in an Execute as...Revert block, so the .NET code is out of the picture.

The execution plan looks the same. I diff'ed the XML and there are only minor differences (CompileTime, CompileCPU, CompileMemory).

IO Stats all show no physical reads:

Table 'sysobjvalues'. Scan count 0, logical reads 19970, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Workfile'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'sysschobjs'. Scan count 1, logical reads 9122, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'sysclsobjs'. Scan count 0, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

XEvent waits status (for a ~3min query) are:

+---------------------+------------+----------------------+------------------------------+-----------------------------+
|      Wait Type      | Wait Count | Total Wait Time (ms) | Total Resource Wait Time (ms) | Total Signal Wait Time (ms) |
+---------------------+------------+----------------------+-------------------------------+-----------------------------+
| SOS_SCHEDULER_YIELD |      37300 |                  427 |                            20 |                         407 |
| NETWORK_IO          |          5 |                   26 |                            26 |                           0 |
| IO_COMPLETION       |          3 |                    1 |                             1 |                           0 |
+---------------------+------------+----------------------+-------------------------------+-----------------------------+

If I rewrite the query (in SSMS, I don't have access to the App Code) to

declare @id int 
SELECT @id=schema_id FROM sys.schemas WHERE name = N'XXXX'
SELECT a.name, base_object_name FROM sys.synonyms a
WHERE schema_id = @id
ORDER BY name

then UserB runs at the same (fast) speed as UserA.

If I add db_owner to UserB, then, again, the query runs < 1 sec.

Schema created via this template:

DECLARE @TranName VARCHAR(20)
SELECT @TranName = 'MyTransaction'

BEGIN TRANSACTION @TranName
GO

IF NOT EXISTS (SELECT SCHEMA_NAME FROM INFORMATION_SCHEMA.SCHEMATA
        WHERE SCHEMA_NAME = '{1}')
BEGIN
    EXEC('CREATE SCHEMA [{1}]')
    EXEC sp_addextendedproperty @name='User', @value='{0}', @level0type=N'Schema', @level0name=N'{1}'
END
GO

{2}

COMMIT TRANSACTION MyTransaction;
GO

And {2} is, I believe, a list of Synonyms created in that schema.

Query Profile at two points into the query:

enter image description here

enter image description here

I've opened a ticket with Microsoft.

Also, we tried adding UserB to db_owner, and then DENYing all of the privileges we know that are associated with db_owner. The result is a fast query. Either we missed something (entirely possible), or there is a special check for the db_owner role.

0

3 Answers 3

6

You may want to re-write your query as follows (I'm using dbo rather than XXXX so that I do find some synonyms on my testing database). This is similar to the re-write you found to be more efficient, but avoids the need to declare a variable and use two queries.

SELECT name, base_object_name 
FROM sys.synonyms 
WHERE schema_id = SCHEMA_ID(N'dbo')
ORDER BY name

This yields a plan like the following:

enter image description here

One very interesting thing about the Filter operator in this plan is that it has a predicate that performs an internal has_access() check. This filter removes any objects that the current account does not have sufficient permissions to see. However, this check is short-circuited (i.e., completes much more quickly) if you are a member of the db_owner role, which may explain the performance differences you are seeing.

enter image description here

Here is the query plan for your original query. Notice that all synonyms on the database (1,126 in my case, but likely many more in your case) pass through the very expensive has_access() filter, even though only 2 synonyms match the schema. By using the simplified query above, we can ensure that has_access() is only invoked for the synonyms that match your query rather than for all synonyms in the database.

enter image description here


Using sys.dm_exec_query_profiles to explore further

As Martin suggests, we can confirm that the has_access() check is a significant bottleneck by using sys.dm_exec_query_profiles on SQL Server 2014+. If I run the following query using a db_owner account on a database with ~700K objects, the query takes ~500ms:

SELECT COUNT(*)
FROM sys.objects

When run with an account that is not a db_owner, this same query takes about eight minutes! Running with actual plan on and using a p_queryProgress procedure that I wrote to help parse sys.dm_exec_query_profiles output more easily, we can see that almost all of the processing time is spent on the Filter operator that is performing the has_access() check:

enter image description here

9
  • TokenAndPermUserStore issue? In which case this KB article could help support.microsoft.com/en-gb/kb/955644 Apr 13, 2016 at 20:24
  • @MartinSmith Very interesting, I wasn't aware of the access check cache bucket count and access check cache quota configuration options previously. Will have to play around with those a bit. Apr 13, 2016 at 20:32
  • I'm not certain that this cache is relevant to the case here. I just remember it causing problems in the past. Apr 13, 2016 at 20:34
  • 1
    @MartinSmith While those settings didn't have an impact, there is something interesting going on with the cache. It seems like the cache's existence is detrimental. E.g., if I run WHILE(1=1) BEGIN DBCC FREESYSTEMCACHE ('TokenAndPermUserStore') WAITFOR DELAY '00:00:05' END in a loop forever, the query completes in under 2 minutes vs. 8 minutes typically. Apr 13, 2016 at 21:30
  • 1
    Thanks everyone - the response back from Microsoft echos the comments above, and a query rewrite is the best solution. It turns out that has_access() has a short-circuit at the beginning to test for db_owner or sysadmin and that resulted in the big time difference.
    – James
    Apr 27, 2016 at 20:04
0

If this is still live - we've had the same problem - it appears that if you are either the dbo or a sysadmin then any access to sys.objects (or anything like that) - then it's instantaneous with no checks against individual objects.

if it's a lowly db_datareader then it has to check each object in turn... it's hidden in the query plan as these behave more like functions than views/tables

the plan looks the same, but it's doing different things behind the hood

-2

Using trace flag 9481 seems to resolve this issue for me.

The CE (Cardinality Estimator) in 2014 (compat 120) changed from 2012 and 2008, and using TF 9481 forces use of the 2012 CE.

See The SQL 2014 Cardinality Estimator Eats Bad TSQL for Breakfast by Kendra Little.

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.