The insert time-out Story (Dramatically locked)

Introduction
Pour des besoins de tracabilité, notre logiciel maintient un table d'audit.
Cette dernière reçoit une copie de toutes les opérations effectuées sur les tables principales de la base de donnée.
A priori, il semble raisonnable de considérer que cette table ne soit utilisée que pour y ajouter des enregistrements.
Les opérations de lectures étant réservées uniquement à des tâches de maintenances et de vérifications (idéalement sur une copie de cette DB). Il n'est pas difficile de se rendre compte que cette table est, de par nature, très sollicitée.
Un jour, un développeur fort peu avisé s'est mis en tête d'aller y faire des lectures pour en sortir quelques historiques de modifications.
Cette solution rapide et confortable en temps de dévelopement, n'était pas des plus appropriées et cette option de faible qualité fut largement discutée à l'époque (en effet une table d'audit est destinée a grandir et à être purgée).
Malheureusement, pour des raisons historiques et économiques, cette solution fut maintenue en place malgré de vives protestations.
Résultat immédiat: il n'est pas possible de purger l'audit (parce que ce rapport d'historique est une exigeance).
Résulat aujourd'hui (après quelques années): la table fait 19 millions de records et nous cause beaucoup de tord.

Cas de figure
Passons de l'introduction au cas pratique... il nous aura fallut un certain temps pour comprendre que la table d'audit était notre problème.
L'application se comportait normalement... jusqu'il y a peu.
En effet, suivant les heures et les jours, pour une raison inexpliquée (jusqu'aujourdh'hui) les utilisateurs se plaignaient, de façon occasionnelle, d'un système extrêmement lent... la phase de login prenant quelques-fois plusieurs minutes.


Après investigation, nous avons constatés que l'écriture d'un nouvel enregistrement dans la table d'audit échouait après +/- 30 secondes (Time-Out on inserting record).
En poussant les investigations un peu plus loin à l'aide de Sql Profile, nous avons constaté que ces problèmes de Time-out concoïncidaient avec des requêtes de lecture de l'audit.
De là à tirer des conclusions hatives, il n'y a qu'un pas... reste cependant encore à identifier précisément le mécanisme pour y apporter une solution. 



Test pratique

SQL1 : Lecture de l'AuditTrail

select * from tblSSAudit
where ID_ObjectInstance 
between 181125 and 272175 --order by Audit_Date
Temps d'exécution: 49 sec.
Lors d'une lecture normale, il n'y a pas de système de locking particulier. Cependant, la table est grosse (19 millions d'enregistrement) et cela génère un Table Scan et enormément d'accès disques.
Voici le résultat d'un sp_lock durant la lecture:

SQL2: Insertion dans l'AuditTrail
declare @i int;
select @i=1
while @i < 10000
begin
insert into tblSSAudit (audit_comment) values ('Writing test '+Cast( @i as Varchar(10) ) )
print cast( GetDate() as Varchar(20) )+': insert value '+Cast(@i as Varchar(10) )
select @i = @i +1
end
Temps d'exécution: 7 Sec.
Cependant, durant la lecture de l'AuditTrail (SQL1) le temps d'exécution explose à 53 secondes.
Avec un peu de feeling, il n'est pas difficile de deviner que les INSERTs attendent la fin du processus de lecture.

SQL3: Examination des locks

Durant l'exécution de SQL1 (exécution active) et SQL2 (apparemment en pause), un troisième SQL (sp_lock) est exécuté sur la DB.
En voici le résultat:

• +/- 5000 locks!!
• Un lock IX (Intent Exlusive) sur la table d'audit (ce lock exclusif étant créé par les instructions INSERT).

Les essais
En lisant l'article de InformIT, la meilleure option était encore d'utiliser NOLOCK comme query hint lors de l'exécution des requêtes. Ce hint stipulant clairement a SqlServer qu'il ne fallait pas prévoir d'escalade de locking dans le cas de la lecture.

SQL 1 devenait donc:
select * from tblSSAudit with (NOLOCK)
where ID_ObjectInstance 
between 181125 and 272175 --order by Audit_Date
  
Essais avec NOLOCK

Les premiers essais ne furent pas concluant en ce sens que les inserts semblaient toujours attendre la fin de l'exécution du SELECT. Néanmoins, en un coup d'oeil sur SP_Lock permettait d'identifier une difference notable dans l'escalade des locking.

Par la suite, j'ai arrêté l'exécution de SQL2 après 10 secondes. J'ai constaté que ce dernier avait néanmoins inséré 796 records pendant l'exécution de SQL1.
Pour m'assurer d'une potientielle avancée, j'ai (1) retiré le query hint, (2) réexécuté SQL1 suivit de SQL2, (3) denouveau arrêter SQL2 après 10 seconds. 
Dans ce second test sans NOLOCK, SQL n'avait écrit aucun records!

Conclusion:
L'utilisation de NOLOCK durant la lecture de l'audit trail autorise toujours les insertions de records mais avec une performance catastrophique.
En effet, dans ce cas, la performance d'insertion passe de 1428 records/sec à 99 records/sec... soit un diminution de performance de 93%.
Si deux processus exécutent SQL1, dans ce cas, le performance d'insertion diminue encore (69 rec/sec).


Essais avec NOLOCK et READUNCOMMITTED
L'ajout de ReadUncommitted dans le query hint n'as pas modifié les performances de façon signification.
Ce n'est donc pas une option a considérer.


Solutions

A court terme:

Et bien, a très court terme, l'option de la requête SELECT avec l'option NOLOCK permet de maintenir un "service minimum". Cependant, cela ne fournira pas solution à long terme.

A long terme:

1. Trouver un moyen de décharger cette table pour la faire revenir dans des proportions plus raisonnable.
   Cependant, une analyse ultérieure à révélé que sur les 19 millions d'enregistrements, 12 millions étaient potentiellement exploitables et doivent donc rester accessible.
   
2. Résultat du point précédent: considérer le stockage des informations importantes dans une strucutre plus appropriée (le stockage de valeurs numériques étant moins couteuses en terme d'espace disque et par ailleurs indexable).
3. Partitionner la table (fonctionnalité de SQL 2005 enterprise) et stocker la partie/partition inactive dans un File-Group en lecture seule (cela évitera a SQL serveur de gérer inutilement des locks sur cette partition).
   

Références

Voici un article "Options Affecting SQL Server Locking Behavior" d'InformIT traitant du sujet.
Détail des valeurs retournée par sp_lock.