Il mio collega Steve Wright (blog | @SQL_Steve) mi ha spinto di recente con una domanda su uno strano risultato che stava vedendo. Per testare alcune funzionalità nel nostro strumento più recente, SQL Sentry Plan Explorer PRO, aveva prodotto una tabella ampia e grande e stava eseguendo una serie di query su di essa. In un caso stava restituendo molti dati, ma STATISTICS IO
stava mostrando che si stavano verificando pochissime letture. Ho eseguito il ping di alcune persone su #sqlhelp e, poiché sembrava che nessuno avesse visto questo problema, ho pensato di parlarne sul blog.
TL;Versione DR
In breve, tieni presente che ci sono alcuni scenari in cui non puoi fare affidamento su STATISTICS IO
per dire la verità. In alcuni casi (questo che coinvolge TOP
e parallelismo), riporterà ampiamente le letture logiche. Questo può portarti a credere di avere una query molto favorevole all'I/O quando non lo fai. Ci sono altri casi più ovvi, come quando hai un sacco di I/O nascosti dall'uso di funzioni scalari definite dall'utente. Pensiamo che Plan Explorer renda questi casi più ovvi; questo, tuttavia, è un po' più complicato.
La query del problema
La tabella ha 37 milioni di righe, fino a 250 byte per riga, circa 1 milione di pagine e una frammentazione molto bassa (0,42% a livello 0, 15% a livello 1 e 0 oltre). Non ci sono colonne calcolate, nessuna UDF in gioco e nessun indice tranne una chiave primaria raggruppata sul INT
iniziale colonna. Una semplice query che restituisce 500.000 righe, tutte colonne, utilizzando TOP
e SELECT *
:
SET STATISTICS IO ON; SELECT TOP 500000 * FROM dbo.OrderHistory WHERE OrderDate < (SELECT '19961029');
(E sì, mi rendo conto che sto violando le mie stesse regole e sto usando SELECT *
e TOP
senza ORDER BY
, ma per semplicità sto facendo del mio meglio per ridurre al minimo la mia influenza sull'ottimizzatore.)
Risultati:
(500000 righe interessate)Tabella 'Cronologia ordini'. Conteggio scansioni 1, letture logiche 23, letture fisiche 0, letture read-ahead 0, letture logiche lob 0, letture fisiche lob 0, letture read-ahead lob 0.
Stiamo restituendo 500.000 righe e ci vogliono circa 10 secondi. So immediatamente che qualcosa non va con il numero di letture logiche. Anche se non sapevo già dei dati sottostanti, posso dire dai risultati della griglia in Management Studio che questo sta estraendo più di 23 pagine di dati, indipendentemente dal fatto che provengano dalla memoria o dalla cache, e questo dovrebbe riflettersi da qualche parte in STATISTICS IO
. Guardando il piano...
... vediamo che c'è un parallelismo e che abbiamo scansionato l'intera tabella. Quindi, come è possibile che ci siano solo 23 letture logiche?
Un'altra query "identica"
Una delle mie prime domande a Steve è stata:"Cosa succede se elimini il parallelismo?" Quindi l'ho provato. Ho preso la versione subquery originale e ho aggiunto MAXDOP 1
:
SET STATISTICS IO ON; SELECT TOP 500000 * FROM dbo.OrderHistory WHERE OrderDate < (SELECT '19961029') OPTION (MAXDOP 1);
Risultati e piano:
(500000 righe interessate)Tabella 'Cronologia ordini'. Conteggio scansioni 1, letture logiche 149589, letture fisiche 0, letture read-ahead 0, letture logiche lob 0, letture fisiche lob 0, letture read-ahead lob 0.
Abbiamo un piano leggermente meno complesso, e senza il parallelismo (per ovvi motivi), STATISTICS IO
ci mostra numeri molto più credibili per i conteggi logici delle letture.
Qual è la verità?
Non è difficile vedere che una di queste domande non dice tutta la verità. Mentre STATISTICS IO
potrebbe non raccontarci tutta la storia, forse la traccia lo farà. Se recuperiamo le metriche di runtime generando un piano di esecuzione effettivo in Plan Explorer, vediamo che la query magica a bassa lettura sta, in effetti, estraendo i dati dalla memoria o dal disco e non da una nuvola di polvere magica di folletto. In effetti ha *più* letture rispetto all'altra versione:
Quindi è chiaro che le letture stanno avvenendo, semplicemente non vengono visualizzate correttamente in STATISTICS IO
uscita.
Qual è il problema?
Bene, sarò abbastanza onesto:non lo so, a parte il fatto che il parallelismo sta sicuramente giocando un ruolo, e sembra essere una specie di condizione razziale. STATISTICS IO
(e, poiché è qui che otteniamo i dati, la nostra scheda I/O tabella) mostra un numero di letture molto fuorviante. È chiaro che la query restituisce tutti i dati che stiamo cercando ed è chiaro dai risultati della traccia che utilizza le letture e non l'osmosi per farlo. Ne ho chiesto a Paul White (blog | @SQL_Kiwi) e lui ha suggerito che solo alcuni dei conteggi di I/O pre-thread vengono inclusi nel totale (e concorda sul fatto che si tratta di un bug).
Se vuoi provarlo a casa, tutto ciò di cui hai bisogno è AdventureWorks (dovrebbe essere riprodotto rispetto alle versioni 2008, 2008 R2 e 2012) e la seguente query:
SET STATISTICS IO ON; DBCC SETCPUWEIGHT(1000) WITH NO_INFOMSGS; GO SELECT TOP (15000) * FROM Sales.SalesOrderHeader WHERE OrderDate < (SELECT '20080101'); SELECT TOP (15000) * FROM Sales.SalesOrderHeader WHERE OrderDate < (SELECT '20080101') OPTION (MAXDOP 1); DBCC SETCPUWEIGHT(1) WITH NO_INFOMSGS;
(Nota che SETCPUWEIGHT
è usato solo per convincere il parallelismo. Per ulteriori informazioni, vedere il post del blog di Paul White su Plan Costing.)
Risultati:
Tabella 'SalesOrderHeader'. Conteggio scansioni 1, letture logiche 4, letture fisiche 0, letture read-ahead 0, letture logiche lob 0, letture fisiche lob 0, letture read-ahead lob 0.Tabella 'SalesOrderHeader'. Conteggio scansioni 1, letture logiche 333, letture fisiche 0, letture read-ahead 0, letture logiche lob 0, letture fisiche lob 0, letture read-ahead lob 0.
Paul ha indicato una riproduzione ancora più semplice:
SET STATISTICS IO ON; GO SELECT TOP (15000) * FROM Production.TransactionHistory WHERE TransactionDate < (SELECT '20080101') OPTION (QUERYTRACEON 8649, MAXDOP 4); SELECT TOP (15000) * FROM Production.TransactionHistory AS th WHERE TransactionDate < (SELECT '20080101');
Risultati:
Tabella 'Cronologia transazioni'. Conteggio scansioni 1, letture logiche 5, letture fisiche 0, letture read-ahead 0, letture logiche lob 0, letture fisiche lob 0, letture read-ahead lob 0.Tabella 'TransactionHistory'. Conteggio scansioni 1, letture logiche 110, letture fisiche 0, letture read-ahead 0, letture logiche lob 0, letture fisiche lob 0, letture read-ahead lob 0.
Quindi sembra che possiamo riprodurlo facilmente a piacimento con un TOP
operatore e un DOP sufficientemente basso. Ho segnalato un bug:
- STATISTICS IO riporta le letture logiche per i piani paralleli
E Paul ha segnalato altri due bug in qualche modo correlati che coinvolgono il parallelismo, il primo a seguito della nostra conversazione:
- Errore di stima della cardinalità con predicato spinto su una ricerca [post del blog correlato]
- Prestazioni scarse con parallelismo e Top [post del blog correlato]
(Per i nostalgici, ecco altri sei bug di parallelismo che ho segnalato qualche anno fa.)
Qual è la lezione?
Fai attenzione a fidarti di una singola fonte. Se guardi esclusivamente a STATISTICS IO
dopo aver modificato una query come questa, potresti essere tentato di concentrarti sul miracoloso calo delle letture anziché sull'aumento della durata. A quel punto potresti darti una pacca sulla spalla, lasciare il lavoro presto e goderti il fine settimana, pensando di aver appena avuto un enorme impatto sulle prestazioni della tua richiesta. Quando ovviamente nulla potrebbe essere più lontano dalla verità.