La consulta contra sys.schemas y sys.synonymous se ejecuta muy lentamente para un usuario

8

Escenario: SQL Server 2014 (v12.0.4100.1)

.NET Service ejecuta esta consulta:

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

... que devuelve alrededor de 6500 filas pero a menudo se agota después de más de 3 minutos. Lo XXXXanterior no es 'dbo'.

Si ejecuto esta consulta en SSMS como UsuarioA, la consulta vuelve en menos de un segundo.

Cuando se ejecuta como UserB (que es cómo se conecta el servicio .NET), la consulta demora de 3 a 6 minutos y tiene el% de CPU al 25% (de 4 núcleos) todo el tiempo.

UserA es un inicio de sesión de dominio en el rol sysadmin

UserB es un inicio de sesión SQL con:

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]

Puedo duplicar esto en SSMS envolviendo el SQL anterior en un Execute as...Revertbloque, por lo que el código .NET está fuera de la imagen.

El plan de ejecución se ve igual. Difundí el XML y solo hay pequeñas diferencias (CompileTime, CompileCPU, CompileMemory).

Todas las estadísticas de IO no muestran lecturas físicas:

Tabla 'sysobjvalues'. Cuenta de escaneo 0, lecturas lógicas 19970, lecturas físicas 0, lecturas de lectura anticipada 0, lecturas lógicas lob 0, lecturas físicas lob 0, lecturas de lectura lob 0.
Tabla 'Archivo de trabajo'. Recuento de exploración 0, lecturas lógicas 0, lecturas físicas 0, lecturas de lectura anticipada 0, lecturas lógicas lob 0, lecturas físicas lob 0, lecturas de lectura lob 0.
Mesa 'Mesa de trabajo'. Recuento de exploración 0, lecturas lógicas 0, lecturas físicas 0, lecturas de lectura anticipada 0, lecturas lógicas lob 0, lecturas físicas lob 0, lecturas de lectura lob 0.
Tabla 'sysschobjs'. Cuenta de escaneo 1, lecturas lógicas 9122, lecturas físicas 0, lecturas de lectura anticipada 0, lecturas lógicas lob 0, lecturas físicas lob 0, lecturas de lectura lob 0.
Tabla 'sysclsobjs'. Cuenta de escaneo 0, lecturas lógicas 2, lecturas físicas 0, lecturas de lectura anticipada 0, lecturas lógicas lob 0, lecturas físicas lob 0, lecturas lob de lectura anticipada 0.

Los estados de espera de XEvent (para una consulta de ~ 3 minutos) son:

+ --------------------- + ------------ + -------------- -------- + ------------------------------ + ---------- ------------------- +
El | Esperar tipo | Espera cuenta | Tiempo de espera total (ms) | Tiempo total de espera de recursos (ms) | Tiempo de espera de señal total (ms) |
+ --------------------- + ------------ + -------------- -------- + ------------------------------- + --------- -------------------- +
El | SOS_SCHEDULER_YIELD | 37300 | 427 20 | 407
El | NETWORK_IO | 5 | 26 | 26 | 0 |
El | IO_COMPLETION | 3 | 1 | 1 | 0 |
+ --------------------- + ------------ + -------------- -------- + ------------------------------- + --------- -------------------- +

Si reescribo la consulta (en SSMS, no tengo acceso al Código de la aplicación) para

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

entonces UserB se ejecuta a la misma velocidad (rápida) que UserA.

Si agrego db_owneral usuario B, entonces, nuevamente, la consulta se ejecuta <1 seg.

Esquema creado a través de esta plantilla:

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

Y creo que {2} es una lista de sinónimos creados en ese esquema.

Perfil de consulta en dos puntos de la consulta:

ingrese la descripción de la imagen aquí

ingrese la descripción de la imagen aquí

Abrí un boleto con Microsoft.

Además, intentamos agregar UserB a db_owner, y luego incorporar DENYtodos los privilegios con los que sabemos que están asociados db_owner. El resultado es una consulta rápida. O nos perdimos algo (completamente posible), o hay una verificación especial para el db_ownerpapel.

James
fuente

Respuestas:

5

Es posible que desee volver a escribir su consulta de la siguiente manera (estoy usando en dbolugar de XXXXencontrar algunos sinónimos en mi base de datos de prueba). Esto es similar a la reescritura que consideró más eficiente, pero evita la necesidad de declarar una variable y usar dos consultas.

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

Esto produce un plan como el siguiente:

ingrese la descripción de la imagen aquí

Una cosa muy interesante sobre el Filteroperador en este plan es que tiene un predicado que realiza una has_access()verificación interna . Este filtro elimina cualquier objeto que la cuenta actual no tenga permisos suficientes para ver. Sin embargo, esta verificación está en cortocircuito (es decir, se completa mucho más rápidamente) si es miembro del db_ownerrol, lo que puede explicar las diferencias de rendimiento que está viendo.

ingrese la descripción de la imagen aquí

Aquí está el plan de consulta para su consulta original. Observe que todos los sinónimos en la base de datos ( 1,126en mi caso, pero probablemente muchos más en su caso) pasan por el has_access()filtro muy costoso , aunque solo los 2sinónimos coincidan con el esquema. Al utilizar la consulta simplificada anterior, podemos asegurar que has_access()solo se invoque para los sinónimos que coincidan con su consulta en lugar de para todos los sinónimos en la base de datos.

ingrese la descripción de la imagen aquí


Usando sys.dm_exec_query_profiles para explorar más a fondo

Como sugiere Martin, podemos confirmar que la verificación has_access () es un cuello de botella significativo al usar sys.dm_exec_query_profilesSQL Server 2014+. Si ejecuto la siguiente consulta usando una db_ownercuenta en una base de datos con ~ 700K objetos, la consulta toma ~500ms:

SELECT COUNT(*)
FROM sys.objects

Cuando se ejecuta con una cuenta que no es una db_owner, ¡esta misma consulta tarda unos ocho minutos! Al ejecutar el plan real y usar un procedimiento p_queryProgress que escribí para ayudar a analizar la sys.dm_exec_query_profilessalida más fácilmente, podemos ver que casi todo el tiempo de procesamiento se dedica al Filteroperador que realiza la has_access()verificación:

ingrese la descripción de la imagen aquí

Geoff Patterson
fuente
¿Problema de TokenAndPermUserStore? En cuyo caso este artículo de KB podría ayudar a support.microsoft.com/en-gb/kb/955644
Martin Smith
@MartinSmith muy interesante, no estaba al tanto de los access check cache bucket county access check cache quotalas opciones de configuración previamente. Tendrá que jugar un poco con ellos.
Geoff Patterson el
No estoy seguro de que este caché sea relevante para el caso aquí. Solo recuerdo que causó problemas en el pasado.
Martin Smith
1
@MartinSmith Si bien esas configuraciones no tuvieron impacto, hay algo interesante en el caché. Parece que la existencia del caché es perjudicial. Por ejemplo, si ejecuto WHILE(1=1) BEGIN DBCC FREESYSTEMCACHE ('TokenAndPermUserStore') WAITFOR DELAY '00:00:05' ENDun bucle para siempre, la consulta se completa en menos de 2 minutos frente a 8 minutos normalmente.
Geoff Patterson el
1
Gracias a todos: la respuesta de Microsoft refleja los comentarios anteriores, y una reescritura de consultas es la mejor solución. Resulta que has_access () tiene un cortocircuito al principio para probar db_owner o sysadmin y eso resultó en una gran diferencia horaria.
James
0

Si esto todavía está en vivo, hemos tenido el mismo problema, parece que si usted es el dbo o un administrador de sistemas, entonces cualquier acceso a sys.objects (o algo así), entonces es instantáneo sin controles contra objetos individuales.

si es un db_datareader humilde, entonces tiene que verificar cada objeto a su vez ... está oculto en el plan de consulta ya que estos se comportan más como funciones que vistas / tablas

el plan se ve igual, pero está haciendo cosas diferentes detrás del capó

Miguel
fuente