SQL: Qu'est-ce qui ralentit les INSERT si ce n'est pas le CPU ou les IO?

19

Nous avons une base de données pour un produit lourd en écriture. Nous venons d'acheter une nouvelle machine serveur avec un SSD pour vous aider. À notre grande surprise, les insertions n'étaient pas plus rapides que sur notre ancienne machine avec un stockage beaucoup plus lent. Lors de l'analyse comparative, nous avons remarqué que le taux d'E / S présenté par le processus SQL Server était très faible.

Par exemple, j'ai exécuté le script trouvé sur cette page , sauf que j'ai ajouté un BEGIN TRAN et un COMMIT autour de la boucle. Au mieux, je pouvais voir l'utilisation du disque atteindre 7 Mo / s, tandis que le processeur atteignait à peine 5%. Le serveur a 64 Go installés et en utilise 10. La durée totale d'exécution était de 2 minutes 15 secondes pour le premier appel à environ 1 minute pour les appels suivants. La base de données est en récupération simple et était inactive pendant le test. J'ai laissé tomber la table entre chaque appel.

Pourquoi un script aussi simple est-il si lent? Le matériel est à peine utilisé du tout. Les deux outils dédiés d'analyse comparative des disques et SQLIO indiquent que le SSD fonctionne correctement avec des vitesses allant jusqu'à 500 Mo / s pour la lecture et l'écriture. Je comprends que les écritures aléatoires sont plus lentes que les écritures séquentielles, mais je m'attendrais à ce qu'une simple insertion comme celle-ci, dans une table sans indexation en cluster, soit beaucoup plus rapide.

En fin de compte, notre scénario est beaucoup plus complexe, mais je pense que je dois d'abord comprendre un cas simple. En résumé, notre application supprime les anciennes données, puis utilise SqlBulkCopy pour copier les nouvelles données dans les tables de transfert, effectue un filtrage et enfin utilise MERGE et / ou INSERT INTO selon les cas pour copier les données dans les tables finales.

-> EDIT 1: J'ai suivi la procédure liée par Martin Smith, et j'ai obtenu le résultat suivant:

[Wait Type]  [Wait Count] [Total Wait (ms)] [T. Resource Wait (ms)] [T. Signal Wait (ms)]
NETWORK_IO          5008              46735                 46587        148
LOGBUFFER           901               5994                  5977         17
PAGELATCH_UP        40                866                   865          1
SOS_SCHEDULER_YIELD 53279             219                   121          98
WRITELOG            5                 145                   145          0
PAGEIOLATCH_UP      4                 58                    58           0
LATCH_SH            5                 0                     0            0

Je trouve cela bizarre NETWORK_IO prend la plupart du temps, étant donné qu'il n'y a aucun résultat à afficher et aucune donnée à transférer ailleurs que dans les fichiers SQL. Le type NETWORK_IO inclut-il tous les E / S?

-> EDIT 2: J'ai créé un disque RAM de 20 Go et monté une base de données à partir de là. Le meilleur temps que j'ai eu sur le SSD est de 48 secondes, avec le disque RAM, il est tombé à 37 secondes. NETWORK_IO est toujours la plus grande attente. La vitesse d'écriture maximale sur le disque RAM était d'environ 250 Mo / s alors qu'il est capable de faire plusieurs gigaoctets par seconde. Il n'utilisait toujours pas beaucoup de CPU, alors qu'est-ce qui retarde SQL?

Djof
la source
3
cela NETWORK_IOpourrait provenir des 3 millions de messages "1 ligne (s) affectée (s)" renvoyés. Avez-vous essayé d'ajouter SET NOCOUNT ONau script?
Martin Smith
Oui, j'ai ajouté le NOCOUNT.
Djof
2
Étrange. Je n'attendrais pas grand-chose à l'activité de réseau alors. Avez-vous supprimé les anciens fichiers d'événements étendus entre les exécutions? Le script qui les lit utilise un caractère générique EE_WaitStats*.xelafin que les anciens contaminent vos résultats.
Martin Smith
Bon appel, je mettrai à jour les résultats demain.
Djof

Réponses:

9

Je sais que c'est une vieille question, mais cela pourrait encore aider les chercheurs et c'est un problème qui apparaît de temps en temps.

La principale raison pour laquelle vous atteignez un plafond de performances sans voir aucun goulot d'étranglement de ressources est que vous avez atteint la limite de ce qui est possible de traiter dans un seul thread de session. La boucle n'est pas traitée en parallèle, mais toutes les insertions sont effectuées en série.

Dans mon cas, il faut 36 secondes pour insérer 3 millions de lignes. Cela signifie 36/30000000 = 0,000012 seconde par ligne. C'est assez rapide. Sur mon système, il suffit simplement de 0,000012 pour passer par toutes les étapes nécessaires.

La seule façon de le faire plus rapidement est de démarrer une deuxième session en parallèle.

Si je démarre 2 sessions en parallèle, les deux font 15 millions d'inserts. Les deux finissent en 18 secondes. Je pourrais évoluer davantage, mais ma configuration de test actuelle atteint 95% de CPU avec deux sessions parallèles, donc faire 3 fausserait les résultats puisque je frapperais un goulot d'étranglement CPU.

Si je démarre 2 sessions parallèles en insérant chacune 3 millions de lignes, elles se terminent toutes les deux en 39 secondes. ce qui fait maintenant 6 millions de lignes en 39 secondes.

D'accord, cela nous laisse toujours avec l'attente NETWORK_IO qui apparaît.

Les attentes NETWORK_IO sont ajoutées par le fait que vous utilisez des événements étendus pour les tracer. Dans mon cas, l'insert prend 36 secondes (en moyenne). Lorsque vous utilisez la méthode d'événement étendu (à partir du lien ci-dessus dans le tout premier commentaire), voici ce qui est enregistré:

Wait Type             Wait Count  Total Wait Time (ms) Total Resource Wait Time (ms) Total Signal Wait Time (ms)
NETWORK_IO            3455        68808                68802                         6
PAGEIOLATCH_SH        3           64                   64                            0
PAGEIOLATCH_UP        12          58                   58                            0
WRITE_COMPLETION      8           15                   15                            0
WRITELOG              3           9                    9                             0
PAGELATCH_UP          2           4                    4                             0
SOS_SCHEDULER_YIELD   32277       1                    0                             1
IO_COMPLETION         8           0                    0                             0
LATCH_SH              3           0                    0                             0
LOGBUFFER             1           0                    0                             0

Vous pouvez voir que 68 secondes de NETWORK_IO sont enregistrées. Mais comme la boucle d'insertion est une action à thread unique qui a pris 36 secondes, cela ne peut pas être le cas. (Oui, plusieurs threads sont utilisés, mais les opérations sont en série, jamais en parallèle, vous ne pouvez donc pas cumuler plus de temps d'attente que la durée totale de la requête)

Si je n'utilise pas les événements étendus mais seulement les DMV de statistiques d'attente sur une instance silencieuse (avec juste moi exécutant l'insertion) j'obtiens ceci:

Wait Type                   Wait Count  Total Wait Time (ms)  Total Resource Wait Time (ms) Signal Resource Wait Time (ms)
SOS_SCHEDULER_YIELD             8873                 0.21                                    0.01                                    0.20
PAGEIOLATCH_UP                  3                    0.02                                    0.02                                    0.00
PREEMPTIVE_OS_AUTHENTICATIONOPS 17                   0.02                                    0.02                                    0.00
PAGEIOLATCH_SH                  1                    0.00                                    0.00                                    0.00

Ainsi, le NETWORK_IO que vous voyiez dans le journal des événements étendu n'était pas lié à votre boucle d'insertion. (Si vous n'activiez pas nocount, vous auriez d'énormes attentes d'E / S sur le réseau asynchrone, +1 Martin)

Cependant, je ne sais pas pourquoi le NETWORK_IO apparaît dans la trace d'événements étendue. Bien sûr, l'écriture dans un fichier asynchrone cible des événements accumule ASYNC_NETWORK_IO, mais cela se fait sûrement sur un SPID différent de celui sur lequel nous filtrons. Je pourrais poser cette question comme une nouvelle question moi-même)

Edward Dortland
la source
1
"vous atteignez un plafond de performances sans voir aucun goulot d'étranglement de ressources parce que vous avez atteint la limite de ce qui est possible de traiter dans un seul thread de session": vous décrivez un goulot d'étranglement CPU à 100% (sur un cœur). S'il n'y a pas goulot d' étranglement, le système va aller plus vite, donc quelque chose d' autre doit être en jeu.
Remus Rusanu
Votre réponse est très instructive Edward. Il semble que le parallélisme soit la solution à notre problème sur lequel nous travaillons déjà, bien qu'il nécessite des modifications de la disposition de notre base de données. Cependant, comme Remus, je suis toujours curieux de savoir pourquoi la machine ne semble pas utiliser toutes (d'un) ressources CPU ou disque.
Djof
9

En règle générale, vous commencez par regarder sys.dm_exec_requests, en particulier la wait_time, wait_typeet wait_resourcepour vos demandes INSERT. Cela vous donnera une indication claire de ce qui bloque votre INSERT. Les résultats indiqueront s'il y a conflit de verrouillage, événements de croissance de fichier, attente de vidage de journal, conflit d'allocation (se manifeste comme conflit de verrouillage de page PFS), etc., etc. Une fois que vous avez mesuré, mettez à jour votre question en conséquence. Je vous invite fortement à vous arrêter maintenant et à lire la méthodologie de dépannage des attentes et des files d'attente avant de continuer.

Remus Rusanu
la source
3

J'ai exécuté le script de test sur la page liée dans l'OP avec le BEGIN TRAN / COMMIT autour de la boucle. Sur ma machine, il a fallu 1:28 pour terminer la première fois.

J'ai ensuite déplacé ces deux commandes hors de la boucle:

SELECT @Random = ROUND(((@Upper - @Lower -1) * RAND() + @Lower), 0)
SET @InsertDate = DATEADD(dd, @Random, GETDATE())

Il s'est terminé en 28 secondes après cela.

Je ne sais pas exactement ce qui se passe, mais je suppose qu'il pourrait y avoir une sorte de sommeil dans le RAND()code, peut-être dans le cadre de l'algorithme qu'ils utilisent pour générer l'entropie (meilleurs nombres aléatoires).

FWIW, les SSD ne sont pas toujours la meilleure technologie pour les applications lourdes en écriture. Pour de meilleures performances, assurez-vous que votre journal de base de données se trouve sur une lettre de lecteur différente des données de base de données, le fichier journal est pré-développé à sa taille maximale et ne tronquez jamais le journal.

RickNZ
la source
Merci pour votre contribution RickNZ. Je n'ai pas obtenu de résultats plus rapides en déplaçant le code hors de la boucle. Attendez, j'ai remarqué que si vous l'exécutez plusieurs fois, cela devient plus rapide, c'est peut-être ce que vous avez vécu. Je sais que les SSD ne sont pas des balles d'argent, mais j'ai toujours l'impression que les performances ne sont pas ce qu'elles pourraient être.
Djof
1

Un autre DMV que j'utilise pour identifier la lenteur est sys.dm_os_waiting_tasks . Si votre requête n'est pas gourmande en CPU, vous pouvez trouver plus d'informations sur les attentes de ce DMV.

StanleyJohns
la source
0

Je vérifie la liste des événements d'attente pour SQL 2008 et je ne vois pas NETWORK_IO répertorié: http://technet.microsoft.com/en-us/library/ms179984(v=sql.100).aspx

Je pensais que NETWORK_IO venait maintenant d'être répertorié comme ASYNC_NETWORK_IO, donc je voulais vous demander si vous pouviez vérifier à nouveau votre version de SQL, car je suis simplement curieux de savoir comment / pourquoi cet événement d'attente apparaît pour cette version.

Quant à l'attente du réseau apparaissant du tout, oui, cela peut arriver même si vous travaillez sur un serveur autonome. Avez-vous vérifié les paramètres de vos cartes réseau? Je me demande si c'est un problème.

À la fin de la journée, il n'y a que quelques goulots d'étranglement de ressources possibles: mémoire, CPU, E / S disque, réseau et verrouillage. Vous avez indiqué que le processeur et les E / S ne sont pas le problème, et vous avez un événement d'attente de NETWORK_IO, donc je vous suggère de regarder ces cartes NIC en premier.

SQLRockstar
la source
1
Le NETWORK_IOs'affiche car l'OP utilise des événements étendus. Il n'a jamais été mis à joursys.dm_xe_map_values
Martin Smith
Je pense au même SQLRockstar, juste ce qui pourrait se passer. J'ai essayé de désactiver complètement les cartes réseau. Martin a souligné que certains anciens fichiers étaient peut-être toujours là. Je mettrai à jour les résultats demain pour voir si cela change quelque chose.
Djof
aussi, cela pourrait aider si nous pouvions voir les plans d'exécution des déclarations.
SQLRockstar