Vote utilisateur: 5 / 5

Etoiles activesEtoiles activesEtoiles activesEtoiles activesEtoiles actives
 

Suite à un audit de performance chez une entreprise qui cherchait à améliorer les performances MSSQL Server (SSDE 2008 SE 64 bits sur W2K8R2) pour son application CRM (SugarCRM), j'ai constaté un comportement au premier abord étrange sur la gestion des chaînes unicode sur le SGBD de microsoft...
Le consultant spécialiste de l'application (SugarCRM) me fit remarqué que des requêtes très simples à priori n'avaient pas la performance attendue.
En étudiant de près une requête type j'ai constaté un effet étonnant concernant l'utilisation de filtres avec une chaîne unicode : colonne1=N'machaine' alors que la colonne que l'on cherche à filtrer est de type varchar (et non nvarchar).

La requête qui m'a posé problème était une requête très simple d'une durée de 200ms environ. Pas de problème de performance avec 200ms par requête me direz vous, sauf que cette requête était lancée plusieurs dixaines de fois pour certains écrans.

Voici la requête :

 

SELECT 
acc.id, acc.name, con_reports_to.first_name, con_reports_to.last_name
FROM
contacts
LEFT JOIN accounts_contacts a_c ON a_c.contact_id = N'1A9C0C58A81C4195B854739635E435D5' AND a_c.deleted=0
LEFT JOIN accounts acc ON a_c.account_id = acc.id AND acc.deleted=0
LEFT JOIN contacts con_reports_to ON con_reports_to.id = contacts.reports_to_id
WHERE
contacts.id = N'1A9C0C58A81C4195B854739635E435D5'
 

 

On notera sur cette requête les prédicats=N'1A9C0C58A81C4195B854739635E435D5'. Le N qui préfixe la chaîne indique au moteur relationnel de sql server qu'il s'agit d'une chaîne de caractère unicode. Or les colonnes sur lesquelles portent les filtres ne sont pas en nvarchar mais en varchar.En observant les statistiques et le plan d'éxécution on observe ceci :

 

Statistiques du client avec chaine unicode En lançant le requête trois fois de suite, le temps serveur reste bloqué à 203 ms
Plan d'éxécution de la requête

Le plan d'éxécution commence à livrer quelques indices.

Le cout de la requête est concentré sur 2 opérations d'Index Scan sur un index de la table Contact et sur l'index cluster de la table accounts_contacts.

Statistiques coté serveur
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
 
(1ligne(s) affecte(s))




Table 'contacts'. 
Nombre d'analyses 1, 
lectures logiques 1114, 
lectures physiques 0, 
lectures anticipes 0, 
lectures logiques de donnes d'objets volumineux 0, 
lectures physiques de donnes d'objets volumineux 0, 
lectures anticipes de donnes d'objets volumineux 0.




Table 'accounts'. 
Nombre d'analyses 0, 
lectures logiques 3, 
lectures physiques 0, 
lectures anticipes 0, 
lectures logiques de donnes d'objets volumineux 0, 
lectures physiques de donnes d'objets volumineux 0, 
lectures anticipes de donnes d'objets volumineux 0.




Table 'accounts_contacts'. 
Nombre d'analyses 1, 
lectures logiques 2864, 
lectures physiques 0, 
lectures anticipes 0, 
lectures logiques de donnes d'objets volumineux 0, 
lectures physiques de donnes d'objets volumineux 0, 
lectures anticipes de donnes d'objets volumineux 0.




(1ligne(s) affecte(s))




SQL Server \endash Temps d'excution: 
, Temps UC = 219ms, temps coul = 248ms.




Temps d'analyse et de compilation de SQL Server : 
, Temps UC = 0ms, temps coul = 0ms.
 

Les statistiques IO nous montre que les opérations de scan d'index réalisent un grand nombre de lectures logiques (en mémoire).

Enfin on observe que sur le temps d'éxécution totale de la requête (248 ms = temps de parse(0)+ temps d'execution(219+x) + temps client (15) + temps réseau(le reste)), le temps cpu représente la grande majorité du temps passé.

A ce stade je me pose plusieurs questions :

  • Pourquoi l'optimiseur choisit-il une opération en index scan alors qu'une opération en index seek aurait été plus performantes et plus logique ?
  • Pourquoi autant de cpu dépensée pourdes opérations de lectures logiques?

En analysant plus avant les opérations d'index scan on notera une petite subtilité : l'utilisation d'une conversion implicite (CONVERT_IMPLICITE). Les valeurs de la colonne sont converties en unicode avant d'être comparer à la chaîne de caractère (unicode elle aussi car préfixée par N').

Plan d'execution avec chaine unicode
StmtText
  |--Nested Loops(Left Outer Join, OUTER REFERENCES:([SugarCRM].[dbo].[contacts].[reports_to_id]) OPTIMIZED)
       |--Nested Loops(Left Outer Join, OUTER REFERENCES:([a_c].[account_id]) OPTIMIZED)
       |    |--Nested Loops(Left Outer Join)
       |    |    |--Index Scan(OBJECT:([SugarCRM].[dbo].[contacts].[idx_reports_to_id]),  
                     WHERE:(CONVERT_IMPLICIT(nvarchar(36),[SugarCRM].[dbo].[contacts].[id],0)=N'1A9C0C58A81C4195B854739635E435D5'))
       |    |    |--Nested Loops(Inner Join, OUTER REFERENCES:([a_c].[id]) OPTIMIZED)
       |    |         |--Index Scan(OBJECT:([SugarCRM].[dbo].[accounts_contacts].[idx_account_contact] AS [a_c]),  
                          WHERE:(CONVERT_IMPLICIT(nvarchar(36),[SugarCRM].[dbo].[accounts_contacts].[contact_id] AS [a_c].[contact_id],0)=N'1A9C0C58A81C4195B85473...'))
       |    |         |--Clustered Index Seek(OBJECT:([SugarCRM].[dbo].[accounts_contacts].[pk_accounts_contacts] AS [a_c]), SEEK:([a_c].[id]=[SugarCRM].[dbo].[...)
       |    |--Clustered Index Seek(OBJECT:([SugarCRM].[dbo].[accounts].[pk_accounts] AS [acc]), SEEK:([acc].[id]=[SugarCRM].[dbo].[accounts_contacts]. ...)
       |--Clustered Index Seek(OBJECT:([SugarCRM].[dbo].[contacts].[pk_contacts] AS [con_reports_to]), SEEK:([con_reports_to].[id]=[SugarCRM].[dbo].[)...)
  

 

C'est cette conversion qui consomme du cpu à outrance et qui implique de faire un index scan en balayant plusieurs milliers de pages et non un index seek.

Mais pourquoi diable une conversion de la colonne en nvarchar et pas plutôt une conversion de la chaîne passée en paramètre en varchar ?
Je pense personnellement que c'est un choix fait par les équipes du moteur sql serveur. Leur choix: honorer la demande de l'utilisateur. Il n'est pas possible en effet de convertir une chaine unicode dans un jeu de caractère "inférieur" (mono-byte), par contre l'inverse est possible.

Que ce passe-t il si on retire les prefixes N' devant les chaîne de caractère en filtre ?

Etudions le comportement de cette requête sans les chaînes unicode :

SELECT acc.id, acc.name, con_reports_to.first_name, con_reports_to.last_name
FROM contacts
LEFT JOIN accounts_contacts a_c ON a_c.contact_id = '1A9C0C58A81C4195B854739635E435D5' AND a_c.deleted=0
LEFT JOIN accounts acc ON a_c.account_id = acc.id AND acc.deleted=0
LEFT JOIN contacts con_reports_to ON con_reports_to.id = contacts.reports_to_id
WHERE contacts.id = '1A9C0C58A81C4195B854739635E435D5'
 

 

Statistiques du client sans les chaines unicode

Les temps n'ont rien à voir : la première éxécution est quasi instantané pour la réponse serveur (moins de 1ms).

200 fois plus rapide ! (voir plus)

Plan d'éxécution sans les chaines unicode Plus d'index scan mais bien des index seek
Statistiques serveur sans les chaines unicode
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
 
1ligne(s) affectée(s))




Table 'contacts'. 
Nombre d'analyses 0, 
lectures logiques 3, 
lectures physiques 0, 
lectures anticipées 0, 
lectures logiques de données d'objets volumineux 0, 
lectures physiques de données d'objets volumineux 0, 
lectures anticipées de données d'objets volumineux 0.




Table 'accounts'. 
Nombre d'analyses 0, 
lectures logiques 3, 
lectures physiques 0, 
lectures anticipées 0, 
lectures logiques de données d'objets volumineux 0, 
lectures physiques de données d'objets volumineux 0, 
lectures anticipées de données d'objets volumineux 0.




Table 'accounts_contacts'. 
Nombre d'analyses 1, 
lectures logiques 3, 
lectures physiques 0, 
lectures anticipées 0, 
lectures logiques de données d'objets volumineux 0, 
lectures physiques de données d'objets volumineux 0, 
lectures anticipées de données d'objets volumineux 0.




 SQL Server \endash Temps d'exécution: 
, Temps UC = 0ms, temps écoulé = 0ms.
Temps d'analyse et de compilation de SQL Server : 
, Temps UC = 0ms, temps écoulé = 0ms.
 
Les statistiques coté serveur confirment : l'opération d'index seek est beaucoup moins consommatrice en lecture logique que ne l'était l'opération d'index scan (3 lectures contre plusieurs milliers)

Le temps cpu est de moins de 1 ms.

 

Plan d'execution sans les chaines unicodes
StmtText
  |--Nested Loops(Left Outer Join, OUTER REFERENCES:([SugarCRM].[dbo].[contacts].[reports_to_id]) OPTIMIZED)
       |--Nested Loops(Left Outer Join, OUTER REFERENCES:([a_c].[account_id]) OPTIMIZED)
       |    |--Nested Loops(Left Outer Join)
       |    |    |--Clustered Index Seek(OBJECT:([SugarCRM].[dbo].[contacts].[pk_contacts]), SEEK:([SugarCRM].[dbo].[contacts].[id]='1A9C0C58A81C4195B854739635E435D5')...)
       |    |    |--Index Seek(OBJECT:([SugarCRM].[dbo].[accounts_contacts].[idx_contid_del_accid] AS [a_c]), SEEK:([a_c].[contact_id]='1A9C0C58A81C4195B854739635E435D5'...
       |    |--Clustered Index Seek(OBJECT:([SugarCRM].[dbo].[accounts].[pk_accounts] AS [acc]), SEEK:([acc].[id]=[SugarCRM].[dbo].[accounts_contacts].[account_id]...)...
       |--Clustered Index Seek(OBJECT:([SugarCRM].[dbo].[contacts].[pk_contacts] AS [con_reports_to]), SEEK:([con_reports_to].[id]=[SugarCRM].[dbo].[contacts].[reports_ ...)
  

 

--> Il n'y a plus de CONVERT_IMPLICIT.

Comment faire pour éviter que l'application de demande une recherche d'une chaine unicode sur un champ qui ne peut pas l'être puisque de type varchar ?

Le consultant SugarCRM a alors recherché dans les fichiers de génération T-SQL de l'outil. Un des fichiers, mssql_manager.php, contenait une expression régulière (prereg_match) qui positionnait systématiquement un N' devant les chaînes de type string. En retirant le N', le sql généré était alors conforme par rapport au type de données dans les tables et la performance des écrans fut améliorée.