NHibernate & SQL Server: occhio alle performance
Prendo spunto da un thread del newsgroup italiano di SQL Server (news://microsoft.public.it.sql) a cui ho risposto oggi per sottolineare come, spesso, sia il caso di guardare quello che ci viene fatto in automatico da tool più o meno potenti.
Venivano presentate due query, apparentemente simili, con identica clausola where, che producevano due risultati (in termini di performance) molto distanti tra loro.
Queste le interrogazioni:
select * FROM eventlog
WHERE EventId = '12'
AND sid= '00e9e52d-0ef3-455b-b264-c04156ac4631'
and EventDetail = 'Ricevuta Risposta da Server Web '
exec sp_executesql N'SELECT * FROM EventLog
WHERE EventId = @p0
and Sid = @p1
and EventDetail = @p2',
N'@p0 nvarchar(2),
@p1 nvarchar(36),
@p2 nvarchar(42)',
@p0 = N'12',
@p1 = N'00e9e52d-0ef3-455b-b264-c04156ac4631',
@p2 = N'Ricevuta Risposta da Server Web '
I piani di esecuzione riportavano:
QUERY 1: Index Seek cost 75% (2 secondi di esecuzione)
QUERY 2: Index Scan cost 94% (32 secondi di esecuzione)
Questa la struttura della tabella interessata:
CREATE TABLE [dbo].[EventLog] (
[DateTime] [int] NOT NULL ,
[EventSource] [varchar] (50) COLLATE SQL_Latin1_General_CP1_CS_AS NULL ,
[Sid] [varchar] (50) COLLATE SQL_Latin1_General_CP1_CS_AS NULL ,
[EventId] [varchar] (50) COLLATE SQL_Latin1_General_CP1_CS_AS NULL ,
[EventDetail] [varchar] (7000) COLLATE SQL_Latin1_General_CP1_CS_AS NULL ,
[EventData] [binary] (200) NULL
) ON [PRIMARY]
GO
CREATE CLUSTERED INDEX [EventLog1] ON [dbo].[EventLog]([Sid], [DateTime])
ON [PRIMARY]
GO
Avete già visto il problema?
Notate la definizione della tabella ed invece la definizione dei parametri per la sp_executesql?
Ecco il motivo della differenza: il mapping dei parametri fatto in maniera automatica da NHibernate.
Basta modificare la seconda query con i metadati corretti, ovvero in:
exec sp_executesql N'SELECT * FROM EventLog
WHERE EventId = @p0
and Sid = @p1
and EventDetail = @p2',
N'@p0 varchar(50),
@p1 varchar(50),
@p2 varchar(7000)',
@p0 = N'12',
@p1 = N'00e9e52d-0ef3-455b-b264-c04156ac4631',
@p2 = N'Ricevuta Risposta da Server Web '
che andiamo ad aiutare l'optimizer per poter ricevere un ottimo CLUSTERED INDEX SEEK.
Attenzione che anche voi potreste dire: "purtroppo la query è stata generata da NHibernate, pertanto non me ne sono nemmeno accorto"
Un ultimo consiglio: se si fosse continuato a testare il software in casa, con alcune centinaia di record, il problema non si sarebbe mai incontrato. Sono bastate 10 milioni di righe per trovarlo...
Ancora un altro motivo per simulare la vita reale che dovranno avere i nostri db... ;-)