none
Problème étrange de performance (INSERT) sous SQL serveur 2008 R2 RRS feed

  • Discussion générale

  • Bonjour à tous,

    J'ai un problème de performance un peu étrange sur certains serveurs de production récent que je n'ai pas sur mes serveurs de tests.

    Un processus faisant énormément d'INSERT consécutifs semble tourner au ralenti sur sur certains serveurs de production (très récent).
    Ce même processus sur mon portable avec un SQL SERVEUR local est plus rapide !

    En comparant les informations du moniteur d'activité SQL entre un serveur SQL qui fonctionne bien et ceux posant un problème de performance je remarque ceci :
    • Attente de ressources : tout est ok sauf la ligne Logging qui a un temps d'attente en ms/s très important sur les serveurs SQL posant problème.
    • Aucun problème au niveau du Buffer I/O

    Questions : 
    - à quoi correspond exactement cette catégorie d'attente Logging ?
    - que chercher ?
    - que vérifier ?
    jeudi 6 décembre 2012 17:14

Toutes les réponses

  • Merci d'exécuter :

    use master
    GO
    declare @lastrestart datetime
    select @lastrestart =create_date from sys.databases where database_id=2
    select @lastrestart 'Date Dernier Redémarrage' ,DATEDIFF(dd, @lastrestart, GETDATE()) 'Uptime'
    GO
    
    WITH Waits AS
        (SELECT
            wait_type,
            wait_time_ms / 1000.0 AS WaitS,
            (wait_time_ms - signal_wait_time_ms) / 1000.0 AS ResourceS,
            signal_wait_time_ms / 1000.0 AS SignalS,
            waiting_tasks_count AS WaitCount,
            100.0 * wait_time_ms / SUM (wait_time_ms) OVER() AS Percentage,
            ROW_NUMBER() OVER(ORDER BY wait_time_ms DESC) AS RowNum
        FROM sys.dm_os_wait_stats
        WHERE wait_type NOT IN (
            'CLR_SEMAPHORE', 'LAZYWRITER_SLEEP', 'RESOURCE_QUEUE', 'SLEEP_TASK',
            'SLEEP_SYSTEMTASK', 'SQLTRACE_BUFFER_FLUSH', 'WAITFOR', 'LOGMGR_QUEUE',
            'CHECKPOINT_QUEUE', 'REQUEST_FOR_DEADLOCK_SEARCH', 'XE_TIMER_EVENT', 'BROKER_TO_FLUSH',
            'BROKER_TASK_STOP', 'CLR_MANUAL_EVENT', 'CLR_AUTO_EVENT', 'DISPATCHER_QUEUE_SEMAPHORE',
            'FT_IFTS_SCHEDULER_IDLE_WAIT', 'XE_DISPATCHER_WAIT', 'XE_DISPATCHER_JOIN', 'BROKER_EVENTHANDLER',
            'TRACEWRITE', 'FT_IFTSHC_MUTEX', 'SQLTRACE_INCREMENTAL_FLUSH_SLEEP',
            'BROKER_RECEIVE_WAITFOR', 'ONDEMAND_TASK_QUEUE', 'DBMIRROR_EVENTS_QUEUE',
            'DBMIRRORING_CMD', 'BROKER_TRANSMITTER', 'SQLTRACE_WAIT_ENTRIES',
            'SLEEP_BPOOL_FLUSH', 'SQLTRACE_LOCK')
        )
    SELECT
        W1.wait_type AS WaitType,
        CAST (W1.WaitS AS DECIMAL(14, 2)) AS Wait_S,
        CAST (W1.ResourceS AS DECIMAL(14, 2)) AS Resource_S,
        CAST (W1.SignalS AS DECIMAL(14, 2)) AS Signal_S,
        W1.WaitCount AS WaitCount,
        CAST (W1.Percentage AS DECIMAL(4, 2)) AS Percentage,
        CAST ((W1.WaitS / W1.WaitCount) AS DECIMAL (14, 4)) AS AvgWait_S,
        CAST ((W1.ResourceS / W1.WaitCount) AS DECIMAL (14, 4)) AS AvgRes_S,
        CAST ((W1.SignalS / W1.WaitCount) AS DECIMAL (14, 4)) AS AvgSig_S
    FROM Waits AS W1
        INNER JOIN Waits AS W2 ON W2.RowNum <= W1.RowNum
    GROUP BY W1.RowNum, W1.wait_type, W1.WaitS, W1.ResourceS, W1.SignalS, W1.WaitCount, W1.Percentage
    HAVING SUM (W2.Percentage) - W1.Percentage < 95; -- percentage threshold
    GO


    David B.

    mercredi 12 décembre 2012 16:38
  • Voici les résultat

    Date Dernier Redémarrage	Uptime
    2012-12-12 09:01:56.100	1

    WaitType	Wait_S	Resource_S	Signal_S	WaitCount	Percentage	AvgWait_S	AvgRes_S	AvgSig_S
    WRITELOG	569.50	566.33	3.17	117434	71.99	0.0048	0.0048	0.0000
    ASYNC_IO_COMPLETION	49.14	49.14	0.00	14	6.21	3.5103	3.5103	0.0000
    BACKUPBUFFER	38.11	36.06	2.05	5644	4.82	0.0068	0.0064	0.0004
    BACKUPIO	35.57	35.56	0.01	1183	4.50	0.0301	0.0301	0.0000
    LCK_M_S	23.98	23.98	0.00	4	3.03	5.9950	5.9950	0.0000
    PREEMPTIVE_OS_WRITEFILEGATHER	15.63	15.63	0.00	20	1.98	0.7817	0.7817	0.0000
    PAGEIOLATCH_SH	8.37	8.36	0.01	3223	1.06	0.0026	0.0026	0.0000
    ASYNC_NETWORK_IO	8.02	6.88	1.14	90499	1.01	0.0001	0.0001	0.0000
    PREEMPTIVE_OS_LIBRARYOPS	6.13	6.13	0.00	1	0.77	6.1280	6.1280	0.0000

    jeudi 13 décembre 2012 09:04
  • 1 jour seulement ce n'est pas énorme mais c'est déjà ça. Le problème s'est-il reproduit entre hier 09h01 et ce matin ?

    Pour valider le temps de service sur les journaux:

    SELECT  DB_NAME(vfs.database_id) AS database_name ,
            vfs.database_id ,
            vfs.FILE_ID ,
            io_stall_read_ms / NULLIF(num_of_reads, 0) AS avg_read_latency ,
            io_stall_write_ms / NULLIF(num_of_writes, 0)
                                                   AS avg_write_latency ,
            io_stall / NULLIF(num_of_reads + num_of_writes, 0)
                                                   AS avg_total_latency ,
            vfs.io_stall ,
            size_on_disk_bytes / 1024 / 1024. AS size_on_disk_mbytes ,
            physical_name
    FROM    sys.dm_io_virtual_file_stats(NULL, NULL) AS vfs
            JOIN sys.master_files AS mf ON vfs.database_id = mf.database_id
                                           AND vfs.FILE_ID = mf.FILE_ID
    WHERE mf.type_desc = 'LOG'
    ORDER BY avg_total_latency DESC 


    David B.

    jeudi 13 décembre 2012 09:19
  • Effectivement le serveur a été redémarré depuis le dernier traitement posant problème. Le données ne sont plus significatives.

    Je relance le traitement et je vous transmet des informations à jour demain.

    Cdt,

    Frédéric

    jeudi 13 décembre 2012 13:04
  • Voici les résultats (il n'y a que du WRITELOG !)

    Le traitement lancé hier à été comme d'habitude catastrophique (17 h de traitement )

    Date Dernier Redémarrage	Uptime
    2012-12-12 09:01:56.100	2

    WaitType	Wait_S	Resource_S	Signal_S	WaitCount	Percentage	AvgWait_S	AvgRes_S	AvgSig_S
    WRITELOG	39806.60	39516.83	289.77	8160625	97.49	0.0049	0.0048	0.0000
    database_name	database_id	FILE_ID	avg_read_latency	avg_write_latency	avg_total_latency	io_stall	size_on_disk_mbytes	physical_name
    msdb	4	2	10	22	20	2263	5.062500	H:\Mssql\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\MSDBLog.ldf
    ConnexionDMS	5	2	11	22	20	783	1.000000	H:\MSSQL\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\ConnexionDMS_1.ldf
    model	3	2	2	21	18	822	0.750000	H:\Mssql\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\modellog.ldf
    master	1	2	2	13	13	2350	1.250000	H:\Mssql\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\mastlog.ldf
    tempdb	2	2	4	8	8	2692	1.000000	H:\Mssql\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\templog.ldf
    Motoculture	6	2	1	4	4	33403726	500.000000	h:\\Mssql\\MSSQL10_50.MSSQLSERVER\\MSSQL\\data\\Motoculture.ldf

    Help

    vendredi 14 décembre 2012 08:38
  • - Les journaux sont-ils séparés des fichiers de données ?
    - Sont-ce des disques locaux / SAN ? Quel type de disques ?
    - Quel type de RAID ?
    - Si une baie SAN, quelle est la proportion du cache de chaque contrôleur IO dédiée aux écritures ?
    - ConnexionDMS est la base en question ?
    - 39806 secondes ~= 11 heures sur 17.


    David B.

    vendredi 14 décembre 2012 10:31
  • Et voir ausi du côté de ce wp de sqlcat http://msdn.microsoft.com/en-us/library/dd425070.aspx qui explique l'utilisation du TF610 pour accélérer les insert / select, vérifier les conditions d'utilisation avec le tableau "Summarizing Minimal Logging Conditions"

    David B.

    vendredi 14 décembre 2012 10:39
  • C'est quoi que tu appelles plus rapide sur ton pc ? En combien de temps ? Quel est le gain ?

    Quels environnements sur tes serveurs ? Virtuels ? CPU, RAM ...

    Vu les résultats des requêtes je ne vois pas vraiment de gros gros problèmes.

    ++


    MCDBA | MCITP SQL Server 2005 / SQL Server 2008 | LPI Linux 1


    vendredi 14 décembre 2012 11:23
    Modérateur
  • Tu peux nous donner également un comparatif des requêtes sur ton pc et sur le serveur qui pose problème en utilisant

    SET STATISTICS IO ON; SET STATISTICS TIME ON;

    ++


    MCDBA | MCITP SQL Server 2005 / SQL Server 2008 | LPI Linux 1

    vendredi 14 décembre 2012 11:35
    Modérateur
  • - Les journaux sont-ils séparés des fichiers de données ?
    - Sont-ce des disques locaux / SAN ? Quel type de disques ?
    - Quel type de RAID ?
    - Si une baie SAN, quelle est la proportion du cache de chaque contrôleur IO dédiée aux écritures ?
    - ConnexionDMS est la base en question ?
    - 39806 secondes ~= 11 heures sur 17.


    David B.

    Bonjour,

    Je suis le collegue de Frederic (Percapita).

    - Les journaux sont-ils séparés des fichiers de données ? 

    Non, ils ne sont pas séparés
    - Sont-ce des disques locaux / SAN ? Quel type de disques ? 

    C'est des disques locaus / SAS 15 000 trs
    - Quel type de RAID ? 

    C'est du RAID 1

    - ConnexionDMS est la base en question ? 

    Non, la base c'est "MOTOCULTURE"

    Pour Info : on fait du RECOVERY Simple.

    Merci pour votre aide

    Bobi

    vendredi 14 décembre 2012 15:14
  • Je pense que la première chose à faire serait de tester en séparant le fichier journal de la bdd monoculture du reste comme cela de loin.

    Voir également si le fichier de log est correctement dimensionné pour éviter les autogrowth.

    ++


    MCDBA | MCITP SQL Server 2005 / SQL Server 2008 | LPI Linux 1

    mardi 18 décembre 2012 23:14
    Modérateur
  • Bonjour,

    Nous changeons le type de votre question à « Discussion générale » parce que vous n’êtes pas revenu avec les informations sollicitées. Si vous avez plus de temps pour réexaminer la question et fournir plus d'informations, n'hésitez pas à modifier le type du thread à « Question ». Si le problème est résolu, s’il vous plaît partagez la solution avec nous afin que la réponse puisse être trouvée et utilisée par d'autres membres de la communauté ayant des questions similaires.

    Merci !

    Cordialement,


    Aurel BERA, Microsoft
    Microsoft propose ce service gratuitement, dans le but d'aider les utilisateurs et d'élargir les connaissances générales liées aux produits et technologies Microsoft. Ce contenu est fourni "tel quel" et il n'implique aucune responsabilité de la part de Microsoft.

    lundi 28 janvier 2013 15:22
    Modérateur
  • Tout a fait d'accord, j'ajouterais aussi comme l'a dit l'autre David le TF610.

    Ensuite, vos inserts sont fait de quelle manière ? Un bulk ou bien une transaction qui fait tous les inserts et qui commite ensuite ?

    Essayez d'avoir un commit tous les 10 000 enregs pour voir ce que ça donne.

    Quels sont les idx sur votre table ? Essayez de les désactiver el temps de l'insert. Ensuite, votre index cluster est sur quel type de colonne (s'il y en a un).

    Christophe


    Christophe LAPORTE - Independent Consultant & Trainer - SQL Server MVP-MCM

    mercredi 10 avril 2013 12:51