Felsöka frågor som aldrig verkar slutföras i SQL Server

Artikel
07/30/2024

Den här artikeln beskriver felsökningsstegen för problemet där du har en fråga som aldrig verkar slutföras, eller så kan det ta många timmar eller dagar att slutföra den.

Vad är en oändlig fråga?

Det här dokumentet fokuserar på frågor som fortsätter att köras eller kompileras, dvs. deras CPU fortsätter att öka. Den gäller inte för frågor som blockeras eller väntar på en resurs som aldrig släpps (processorn förblir konstant eller ändras mycket lite).

Viktigt!

Om en fråga är kvar för att slutföra körningen slutförs den så småningom. Det kan ta bara några sekunder, eller så kan det ta flera dagar.

Termen never-ending används för att beskriva uppfattningen av en fråga som inte slutförs när frågan i själva verket slutförs.

Identifiera en oändlig fråga

Följ dessa steg för att identifiera om en fråga körs kontinuerligt eller fastnar på en flaskhals:

Kör följande fråga:

DECLARE @cntr int = 0

WHILE (@cntr < 3)
BEGIN
    SELECT TOP 10 s.session_id,
                    r.status,
                    r.wait_time,
                    r.wait_type,
                    r.wait_resource,
                    r.cpu_time,
                    r.logical_reads,
                    r.reads,
                    r.writes,
                    r.total_elapsed_time / (1000 * 60) 'Elaps M',
                    SUBSTRING(st.TEXT, (r.statement_start_offset / 2) + 1,
                    ((CASE r.statement_end_offset
                        WHEN -1 THEN DATALENGTH(st.TEXT)
                        ELSE r.statement_end_offset
                    END - r.statement_start_offset) / 2) + 1) AS statement_text,
                    COALESCE(QUOTENAME(DB_NAME(st.dbid)) + N'.' + QUOTENAME(OBJECT_SCHEMA_NAME(st.objectid, st.dbid)) 
                    + N'.' + QUOTENAME(OBJECT_NAME(st.objectid, st.dbid)), '') AS command_text,
                    r.command,
                    s.login_name,
                    s.host_name,
                    s.program_name,
                    s.last_request_end_time,
                    s.login_time,
                    r.open_transaction_count,
                    atrn.name as transaction_name,
                    atrn.transaction_id,
                    atrn.transaction_state
        FROM sys.dm_exec_sessions AS s
        JOIN sys.dm_exec_requests AS r ON r.session_id = s.session_id 
                CROSS APPLY sys.Dm_exec_sql_text(r.sql_handle) AS st
        LEFT JOIN (sys.dm_tran_session_transactions AS stran 
             JOIN sys.dm_tran_active_transactions AS atrn
                ON stran.transaction_id = atrn.transaction_id)
        ON stran.session_id =s.session_id
        WHERE r.session_id != @@SPID
        ORDER BY r.cpu_time DESC

    SET @cntr = @cntr + 1
WAITFOR DELAY '00:00:05'
END

Kontrollera exempelutdata.
- Felsökningsstegen i den här artikeln gäller särskilt när du ser utdata som liknar följande där processorn ökar proportionellt med den förflutna tiden, utan betydande väntetider. Det är viktigt att observera att ändringar i logical_reads inte är relevanta i det här fallet eftersom vissa CPU-bundna T-SQL-begäranden kanske inte gör några logiska läsningar alls (till exempel utför beräkningar eller en WHILE loop).
  
  session_id status cpu_time logical_reads wait_time wait_type
  
  56 körs 7038 101000 0 NULL
  
  56 körbar 12040 301000 0 NULL
  
  56 körs 17020 523000 0 NULL
- Den här artikeln är inte tillämplig om du ser ett väntescenario som liknar följande där processorn inte ändras eller ändras mycket lite, och sessionen väntar på en resurs.
  
  session_id status cpu_time logical_reads wait_time wait_type
  
  56 upphängd 0 3 8312 LCK_M_U
  
  56 upphängd 0 3 13318 LCK_M_U
  
  56 upphängd 0 5 18331 LCK_M_U
Mer information finns i Diagnostisera väntetider eller flaskhalsar.

session_id	status	cpu_time	logical_reads	wait_type
56	körs	7038	101000	NULL
56	körbar	12040	301000	NULL
56	körs	17020	523000	NULL

session_id	status	logical_reads	wait_time	wait_type
56	upphängd	3	8312	LCK_M_U
56	upphängd	3	13318	LCK_M_U
56	upphängd	5	18331	LCK_M_U

Lång kompileringstid

I sällsynta fall kan du observera att processorn ökar kontinuerligt med tiden, men det drivs inte av frågekörning. I stället kan den drivas av en alltför lång kompilering (parsning och kompilering av en fråga). I dessa fall kontrollerar du kolumnen transaction_name utdata och letar efter värdet sqlsource_transform. Det här transaktionsnamnet anger en kompilering.

Samla in diagnostikdata

Följ dessa steg för att samla in diagnostikdata med hjälp av SQL Server Management Studio (SSMS):

Samla in xml-koden för den uppskattade frågekörningsplanen .
Granska frågeplanen för att se om det finns några tydliga indikationer på var långsamheten kan komma ifrån. Vanliga exempel är:
- Tabell- eller indexgenomsökningar (titta på uppskattade rader).
- Kapslade loopar som drivs av en enorm datauppsättning i en yttre tabell.
- Kapslade loopar med en stor gren på den inre sidan av slingan.
- Tabellpooler.
- Funktioner i SELECT listan som tar lång tid att bearbeta varje rad.
Om frågan körs snabbt när som helst kan du samla in de "snabba" körningarna av den faktiska XML-körningsplanen som ska jämföras.

Den lätta infrastrukturen för frågeprofilering introducerades i dessa versioner av SQL Server. Det gör att du kan samla in faktisk statistik under körningen av en långsam fråga. Med den här felsökningsfunktionen kan du undersöka frågeoperatorer i en frågeplan vid körning och förstå var större delen av tiden spenderas i en fråga.

Följ dessa steg om du vill identifiera de långsamma stegen i frågan med hjälp av lightweight query execution statistics profileing infrastructure v1 (Profileringsinfrastruktur för enkel frågekörningsstatistik v1):

Kör följande kommandon för att aktivera query_thread_profile XEvent:

CREATE EVENT SESSION [NodePerfStats] ON SERVER
ADD EVENT sqlserver.query_thread_profile(
  ACTION(sqlos.scheduler_id,sqlserver.database_id,sqlserver.is_system,
    sqlserver.plan_handle,sqlserver.query_hash_signed,sqlserver.query_plan_hash_signed,
    sqlserver.server_instance_name,sqlserver.session_id,sqlserver.session_nt_username,
    sqlserver.sql_text))
ADD TARGET package0.ring_buffer(SET max_memory=(25600))
WITH (MAX_MEMORY=4096 KB,
  EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
  MAX_DISPATCH_LATENCY=30 SECONDS,
  MAX_EVENT_SIZE=0 KB,
  MEMORY_PARTITION_MODE=NONE,
  TRACK_CAUSALITY=OFF,
  STARTUP_STATE=OFF);

ALTER EVENT SESSION [NodePerfStats] ON SERVER STATE = START

Starta den berörda oändliga frågan från programmet.

Kör följande kommando flera gånger i minuten eller så för att kontrollera körningsstatistiken för körning för frågeplansoperatorerna:

SELECT CONVERT (varchar(30), getdate(), 126) as runtime,
            qp.session_id,
            convert(nvarchar(48), qp.physical_operator_name) as physical_operator_name,
            qp.row_count,
            qp.estimate_row_count,
            qp.node_id,
            req.cpu_time,
            req.total_elapsed_time,
            substring
            (REPLACE
            (REPLACE
                (SUBSTRING
                (SQLText.text
                , (req.statement_start_offset/2) + 1
                , (
                    (CASE statement_END_offset
                        WHEN -1
                        THEN DATALENGTH(SQLText.text)  
                        ELSE req.statement_END_offset
                        END
                        - req.statement_start_offset)/2) + 1)
            , CHAR(10), ' '), CHAR(13), ' '), 1, 512)  AS active_statement_text
FROM sys.dm_exec_query_profiles qp 
RIGHT OUTER JOIN sys.dm_exec_requests req
    ON qp.session_id = req.session_id
LEFT OUTER JOIN sys.dm_exec_sessions sess
    on req.session_id = sess.session_id
LEFT OUTER JOIN sys.dm_exec_connections conn on conn.session_id = req.session_id
OUTER APPLY sys.dm_exec_sql_text (ISNULL (req.sql_handle, conn.most_recent_sql_handle)) as SQLText
WHERE req.session_id <> @@SPID 
    AND sess.is_user_process = 1 
ORDER BY qp.session_id asc, row_count desc 
--this is to prevent massive grants
OPTION (max_grant_percent = 3, MAXDOP 1)

Samla in tre eller fyra ögonblicksbilder med en minuts mellanrum för att ge dig tillräckligt med data för analys. Mer specifikt kan du jämföra talen row_count för varje operator över tid och se vilka som visar en betydande ökning av antalet rader (miljoner eller mer).
I ett nytt frågefönster i SSMS samlar du in en uppskattad frågeplan för problemfrågan genom att köra följande kommandon:
```
SET SHOWPLAN_XML ON
GO
<problem query here>
GO
SET SHOWPLAN_XML OFF
```
Använd nod-ID:t med det högsta radantalet som identifierats av frågan i steg 3 och leta upp samma nod i den uppskattade frågeplanen. Det här steget hjälper dig att förstå vilken operator i planen som är den främsta orsaken till den långa körningstiden.

Stoppa XEvent genom att köra följande kommando:

ALTER EVENT SESSION [NodePerfStats] ON SERVER STATE = STOP

Du kan använda statistikprofileringsinfrastrukturen för lightweight-frågekörning v2 för att samla in livefrågeplaner med faktiska värden för radantal. Med den här profileringsinfrastrukturen kan du undersöka frågeoperatorer i en frågeplan vid körning och förstå var större delen av tiden spenderas i en fråga.

Följ dessa steg för att identifiera de långsamma stegen i frågan:

Om du vill aktivera den enkla infrastrukturen i dessa versioner av SQL Server använder du någon av följande metoder:

Aktivera spårningsflagga 7412 genom att köra följande kommando:
```
DBCC TRACEON (7412, -1)
```

Du kan också aktivera query_thread_profile XEvent genom att köra följande kommandon:

CREATE EVENT SESSION [PerfStats_LWP_Plan_v2] ON SERVER
ADD EVENT sqlserver.query_plan_profile(
 ACTION(sqlos.scheduler_id,sqlserver.database_id,sqlserver.is_system,
   sqlserver.plan_handle,sqlserver.query_hash_signed,sqlserver.query_plan_hash_signed,
   sqlserver.server_instance_name,sqlserver.session_id,sqlserver.session_nt_username,
   sqlserver.sql_text))
ADD TARGET package0.ring_buffer(SET max_memory=(25600))
WITH (MAX_MEMORY=4096 KB,
 EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
 MAX_DISPATCH_LATENCY=30 SECONDS,
 MAX_EVENT_SIZE=0 KB,
 MEMORY_PARTITION_MODE=NONE,
 TRACK_CAUSALITY=OFF,
 STARTUP_STATE=OFF);

ALTER EVENT SESSION [PerfStats_LWP_Plan_v2] ON SERVER STATE = START

Starta den berörda oändliga frågan från programmet.

Använd ett kommando som liknar följande för att identifiera den Session_id oändliga fråga som körs:

SELECT t.text, session_id 
FROM sys.dm_exec_requests req
CROSS APPLY sys.dm_exec_sql_text (req.sql_handle) as t

Kör följande kommando tre eller fyra gånger med en minuts mellanrum för att undersöka frågeplanen och den faktiska statistiken i planen. Se till att spara frågeplanen varje gång, så att du kan jämföra dem och fastställa vilken frågeoperator som förbrukar större delen av cpu-tiden. Mer specifikt kan du jämföra radantalet (faktiskt antal rader) för varje operator över tid och se vilken av operatorerna som visar en betydande ökning av antalet rader (miljoner eller mer). Ersätt <session_id> med heltalsvärdet som du hittade i föregående steg 3.
```
SELECT * FROM sys.dm_exec_query_statistics_xml (<session_id>)
```

Stoppa XEvent om du startade en eller inaktivera spårningsflaggan:

ALTER EVENT SESSION [PerfStats_LWP_Plan_v2] ON SERVER STATE = STOP
-- or
DBCC TRACEOFF (7412, -1)

Du kan använda statistikprofileringsinfrastrukturen för lightweight-frågekörning v3 för att samla in livefrågeplaner med faktiska värden för radantal. Med den här profileringsinfrastrukturen kan du undersöka frågeoperatorer i en frågeplan vid körning och förstå var större delen av tiden spenderas i en fråga. Enkel profilering är aktiverat som standard på SQL Server 2019.

Följ dessa steg för att identifiera de långsamma stegen i frågan:

Starta den berörda oändliga frågan från ditt program.

Använd ett kommando som liknar följande för att identifiera den Session_id oändliga fråga som körs:

SELECT t.text, session_id 
FROM sys.dm_exec_requests req
CROSS APPLY sys.dm_exec_sql_text (req.sql_handle) as t

Kör följande kommando tre eller fyra gånger för att undersöka frågeplanen och den faktiska statistiken i planen. Se till att spara frågeplanen varje gång, så att du kan jämföra dem och fastställa vilken frågeoperator som förbrukar större delen av cpu-tiden. Ersätt <session_id> med heltalsvärdet som du hittade i föregående steg 3.
```
SELECT * FROM sys.dm_exec_query_statistics_xml (<session_id>)
```
Mer specifikt väljer du XML-länken under kolumnen query_plan . När den grafiska frågeplanen öppnas i ett nytt fönster högerklickar du på den och väljer Spara körningsplan som.... Upprepa stegen för att samla in tre eller fyra ögonblicksbilder med en minuts mellanrum för att ge dig tillräckligt med data för analys. Mer specifikt kan du jämföra radantalet (det faktiska antalet rader) för varje operator över tid och se vilken av operatorerna som visar en betydande ökning av antalet rader (miljoner eller mer).
Kommentar

Om du inte får några utdata från sys.dm_exec_query_statistics_xmlkan du kontrollera om databasalternativet LAST_QUERY_PLAN_STATS har inaktiverats genom att köra följande kommando:
```
SELECT name, value, value_for_secondary, is_value_default 
FROM sys.database_scoped_configurations
WHERE name = 'LAST_QUERY_PLAN_STATS'
```
Du kan aktivera den senaste frågeplansstatistiken på databasnivå genom att köra ALTER DATABASE SCOPED CONFIGURATION SET LAST_QUERY_PLAN_STATS = ON.

Metod för att granska insamlade planer

Det här avsnittet visar hur du granskar insamlade data. Den använder flera XML-frågeplaner (med tillägget *.sqlplan) som samlats in i SQL Server 2016 SP1 och senare versioner.

Följ dessa steg för att jämföra körningsplaner:

Öppna en tidigare sparad frågekörningsplanfil (.sqlplan).
Högerklicka i ett tomt område i körningsplanen och välj Jämför Showplan.
Välj den andra frågeplansfilen som du vill jämföra.
Leta efter tjocka pilar som anger ett stort antal rader som flödar mellan operatorer. Välj sedan operatorn före eller efter pilen och jämför antalet faktiska rader mellan två planer.
Jämför den andra och tredje planen för att se om det största flödet av rader sker i samma operatorer.

Här är ett exempel:

Åtgärd

Se till att statistiken uppdateras för de tabeller som används i frågan.
Leta efter en indexrekommendations som saknas i frågeplanen och tillämpa eventuella.
Skriv om frågan med målet för att förenkla den:
- Använd mer selektiva WHERE predikat för att minska de data som bearbetas i förväg.
- Bryt isär den.
- Välj vissa delar i temporära tabeller och anslut dem senare.
- Ta bort TOP, EXISTSoch FAST (T-SQL) i de frågor som körs under mycket lång tid på grund av optimerarens radmål. Du kan också använda tipset DISABLE_OPTIMIZER_ROWGOAL . Mer information finns i Row Goals Gone Rogue.
- Undvik att använda vanliga tabelluttryck (CTE) i sådana fall när de kombinerar instruktioner till en enda stor fråga.
Prova att använda frågetips för att skapa en bättre plan:
- HASH JOIN eller MERGE JOIN tips
- FORCE ORDER antydan
- FORCESEEK antydan
- RECOMPILE
- ANVÄND PLAN N'<xml_plan>' om du har en snabb frågeplan som du kan framtvinga
Använd Query Store (QDS) för att framtvinga en bra känd plan om en sådan plan finns och om din SQL Server-version stöder Query Store.

Diagnostisera väntetider eller flaskhalsar

Det här avsnittet ingår här som referens om problemet inte är en tidskrävande CPU-körningsfråga. Du kan använda den för att felsöka frågor som är långa på grund av väntetider.

Om du vill optimera en fråga som väntar på flaskhalsar identifierar du hur lång väntetiden är och var flaskhalsen är (väntetypen). När väntetypen har bekräftats kan du minska väntetiden eller eliminera väntetiden helt.

Om du vill beräkna den ungefärliga väntetiden subtraherar du CPU-tiden (arbetstiden) från den förflutna tiden för en fråga. Cpu-tiden är vanligtvis den faktiska körningstiden och den återstående delen av frågans livslängd väntar.

Exempel på hur du beräknar ungefärlig väntetid:

Förfluten tid (ms)	CPU-tid (ms)	Väntetid (ms)
3200	3000	200
7080	1000	6080

Identifiera flaskhalsen eller vänta

Kör följande fråga för att identifiera historiska frågor som väntar länge (till exempel >20 % av den totala förflutna tiden är väntetiden). Den här frågan använder prestandastatistik för cachelagrade frågeplaner sedan SQL Server startades.

SELECT t.text,
         qs.total_elapsed_time / qs.execution_count
         AS avg_elapsed_time,
         qs.total_worker_time / qs.execution_count
         AS avg_cpu_time,
         (qs.total_elapsed_time - qs.total_worker_time) / qs.execution_count
         AS avg_wait_time,
         qs.total_logical_reads / qs.execution_count
         AS avg_logical_reads,
         qs.total_logical_writes / qs.execution_count
         AS avg_writes,
         qs.total_elapsed_time
         AS cumulative_elapsed_time
FROM sys.dm_exec_query_stats qs
         CROSS apply sys.Dm_exec_sql_text (sql_handle) t
WHERE (qs.total_elapsed_time - qs.total_worker_time) / qs.total_elapsed_time
         > 0.2
ORDER BY qs.total_elapsed_time / qs.execution_count DESC

Kör följande fråga för att identifiera att frågor körs med längre väntetider än 500 ms:

SELECT r.session_id, r.wait_type, r.wait_time AS wait_time_ms
FROM sys.dm_exec_requests r 
   JOIN sys.dm_exec_sessions s ON r.session_id = s.session_id 
WHERE wait_time > 500
AND is_user_process = 1

Om du kan samla in en frågeplan kontrollerar du WaitStats från körningsplanens egenskaper i SSMS:
1. Kör frågan med Inkludera faktisk körningsplan på.
2. Högerklicka på operatorn längst till vänster på fliken Körningsplan
3. Välj Egenskaper och sedan egenskapen WaitStats .
4. Kontrollera WaitTimeMs och WaitType.
Om du är bekant med scenarier med PSSDiag/SQLdiag eller SQL LogScout LightPerf/GeneralPerf kan du använda någon av dem för att samla in prestandastatistik och identifiera väntande frågor på din SQL Server-instans. Du kan importera de insamlade datafilerna och analysera prestandadata med SQL Nexus.

Referenser för att eliminera eller minska väntetider

Orsakerna och lösningarna för varje väntetyp varierar. Det finns ingen allmän metod för att lösa alla väntetyper. Här följer artiklar om hur du felsöker och löser vanliga problem med väntetyp:

Beskrivningar av många väntetyper och vad de anger finns i tabellen i Typer av väntetider.

Dela via