[ Partie 1 | Partie 2 | Partie 3 ]
Dans le premier article de cette série, j'ai montré l'analyse que j'ai utilisée pour déterminer que la trace par défaut n'est pas pour nous. En examinant quelles informations nous avions réellement besoin de collecter à sa place (changements de taille de fichier) et comment cela devrait être exposé aux utilisateurs, j'ai pris en compte les points suivants concernant la trace par défaut :
- il ne capture que automatique événements;
- il ne capture pas le lot "coupable" qui a causé l'événement, sauf si vous avez la chance qu'il ait également été capturé pour une autre raison (par exemple, DDL) ; et,
- il capture les événements en utilisant l'heure locale (nos serveurs sont à l'Est et obéissent à l'heure d'été).
Pour sa défense, il capture beaucoup d'informations importantes sur ces événements automatiques. Après avoir désactivé la trace par défaut, nous pouvons toujours souhaiter examiner les événements qui se sont produits avant la modification et qui ont été capturés dans ces fichiers. Mais une fois la trace par défaut désactivée, la ligne n'existe plus dans sys.traces
, vous ne pouvez donc pas déterminer le chemin vers le .trc
fichiers à partir de là. C'est ici que l'inflexibilité de la trace par défaut offre un avantage :les fichiers sont codés en dur pour résider dans le même dossier que SERVERPROPERTY(N'ErrorLogFileName')
. Ainsi, même si la trace par défaut est désactivée, nous pouvons toujours extraire des données des fichiers à l'aide de la requête suivante (avec des ajustements pour afficher les données en UTC) :
;WITH dst AS ( SELECT s,e,d FROM (VALUES ('20190310','20191103',240),('20191103','20200308',300), ('20200308','20201101',240),('20201101','20210314',300), ('20210314','20211107',240)) AS dst(s,e,d) ), -- will add 2022, 2023, etc. later (if DST is still a thing then) p AS ( SELECT TracePath = REVERSE(SUBSTRING(p, CHARINDEX(N'\', p), 260)) + N'log.trc' FROM (SELECT REVERSE((CONVERT(nvarchar(max), SERVERPROPERTY(N'ErrorLogFileName'))))) AS s(p) ), trc AS ( SELECT src = 'trc', t.DatabaseName, t.[FileName], DurationSeconds = CONVERT(decimal(18,3),Duration/1000000.0), StartTimeUTC = DATEADD(MINUTE, COALESCE(st1.d,0), t.StartTime), EndTimeUTC = DATEADD(MINUTE, COALESCE(st2.d,0), t.EndTime), FileType = CASE t.EventClass WHEN 92 THEN 'Data' WHEN 93 THEN 'Log' END, Culprit = TextData, IsAutomatic = 'true', ChangeMB = CONVERT(bigint, IntegerData)*8/1024, Principal = t.LoginName, t.HostName, App = CASE WHEN ApplicationName LIKE N'%Management Studio%Query%' THEN N'SSMS - Query Window' WHEN ApplicationName LIKE N'%Management Studio%' THEN N'SSMS - GUI!' ELSE ApplicationName END FROM p CROSS APPLY sys.fn_trace_gettable(p.TracePath, DEFAULT) AS t LEFT OUTER JOIN dst AS st1 ON t.StartTime >= DATEADD(HOUR,2,st1.s) AND t.StartTime < DATEADD(HOUR,2,st1.e) LEFT OUTER JOIN dst AS st2 ON t.EndTime >= DATEADD(HOUR,2,st2.s) AND t.EndTime < DATEADD(HOUR,2,st2.e) WHERE t.EventClass IN (92,93) ) SELECT * FROM trc ORDER BY StartTimeUTC DESC;
Exemples de résultats d'un serveur, où il y a certainement eu des événements manuels et automatiques qui se sont produits (cliquez pour agrandir) :
Écrire un remplacement
La session d'événements étendus que j'ai formulée pour remplacer cela, qui capturerait également les modifications manuelles de la taille du fichier et le texte de la requête qui a provoqué des événements automatiques, est la suivante :
CREATE EVENT SESSION FileSizeChanges ON SERVER ADD EVENT sqlserver.database_file_size_change ( ACTION ( sqlserver.sql_text, sqlserver.client_app_name, sqlserver.client_hostname, sqlserver.username, sqlserver.server_principal_name ) ) ADD TARGET package0.event_file ( SET filename = N'W:\SomePath\FileSizeChanges.xel', MAX_FILE_SIZE = 100, -- MB MAX_ROLLOVER_FILES = 100 -- 100 MB x 100 = max 10 GB ) WITH ( MAX_MEMORY = 8192 KB, EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS, MAX_DISPATCH_LATENCY = 30 SECONDS, MAX_EVENT_SIZE = 0 KB, TRACK_CAUSALITY = OFF, STARTUP_STATE = ON ); ALTER EVENT SESSION FileSizeChanges ON SERVER STATE = START;
Bien qu'il ressemble à username
et server_principal_name
peut être redondant, j'ai en fait trouvé des cas où ce dernier était NULL
(et il semble que ce problème existe depuis un moment).
Vérification des résultats
J'ai activé cette session le 22 février, il manque donc les événements que la trace par défaut a capturés le 12, mais elle a capturé plus que le seul événement de croissance automatique du 23. J'ai exécuté la requête suivante pour obtenir un résultat de la même forme que ci-dessus :
;WITH FileInfo(XEPath) AS ( SELECT LEFT(BasePath,COALESCE(NULLIF(CHARINDEX(SessionName,BasePath)-1,-1),0)) + SessionName + N'*.xel' FROM ( SELECT xmlsrc.data.value(N'(@name)[1]', N'nvarchar(max)'), SessionName FROM ( SELECT CONVERT(xml,target_data), s.[name] FROM sys.dm_xe_session_targets AS t INNER JOIN sys.dm_xe_sessions AS s ON s.[address] = t.event_session_address WHERE s.[name] = N'FileSizeChanges' ) AS xefile (TargetData, SessionName) CROSS APPLY TargetData.nodes(N'//EventFileTarget/File') AS xmlsrc(data) ) AS InnerData(BasePath, SessionName) ), SessionData(EventData) AS ( SELECT CONVERT(xml, TargetData.event_data) FROM FileInfo CROSS APPLY sys.fn_xe_file_target_read_file(FileInfo.XEPath, NULL, NULL, NULL) AS TargetData ), src AS ( SELECT EndTimeUTC = x.d.value(N'(@timestamp)[1]', N'datetime2'), DatabaseID = x.d.value(N'(data [@name="database_id"]/value)[1]', N'int'), [FileName] = x.d.value(N'(data [@name="file_name"]/value)[1]', N'sysname'), Duration = x.d.value(N'(data [@name="duration"]/value)[1]', N'int'), FileType = x.d.value(N'(data [@name="file_type"]/text)[1]', N'varchar(4)'), Culprit = x.d.value(N'(action[@name="sql_text"]/value)[1]', N'nvarchar(max)'), IsAutomatic = x.d.value(N'(data [@name="is_automatic"]/value)[1]', N'varchar(5)'), ChangeKB = x.d.value(N'(data [@name="size_change_kb"]/value)[1]', N'bigint'), Principal = x.d.value(N'(action[@name="server_principal_name"]/value)[1]', N'sysname'), username = x.d.value(N'(action[@name="username"]/value)[1]', N'sysname'), AppName = x.d.value(N'(action[@name="client_app_name"]/value)[1]', N'sysname'), HostName = x.d.value(N'(action[@name="client_hostname"]/value)[1]', N'sysname') FROM SessionData CROSS APPLY EventData.nodes(N'/event') AS x(d) ) SELECT src = 'xe', DatabaseName = DB_NAME(DatabaseID), [FileName], DurationSeconds = CONVERT(decimal(18,3), Duration/1000000.0), StartTimeUTC = DATEADD(MICROSECOND, -Duration, EndTimeUTC), EndTimeUTC, FileType, Culprit, IsAutomatic, ChangeMB = CONVERT(decimal(18,3), ChangeKB / 1024.0), Principal = COALESCE([Principal], COALESCE(NULLIF(username,N''), N'?')), HostName, App = CASE WHEN AppName LIKE N'%Management Studio%Query%' THEN N'SSMS - Query Window' WHEN AppName LIKE N'%Management Studio%' THEN N'SSMS - GUI!' ELSE AppName END FROM src ORDER BY StartTimeUTC DESC;
Les résultats montrent le plaisir supplémentaire que j'ai eu, y compris (haleter !) Exécuter une tâche "Réduire la base de données" à partir de l'interface utilisateur (cliquez pour agrandir) :
Le déployer partout
Convaincu que je pouvais maintenant obtenir une image plus complète des événements de changement de taille de fichier sur n'importe quel serveur, il était temps de déployer. J'ai utilisé une fenêtre de requête CMS pour d'abord désactiver la trace par défaut partout et définir le show advanced options
retour comme je l'ai trouvé :
IF EXISTS ( SELECT 1 FROM sys.configurations WHERE name = N'default trace enabled' AND value_in_use = 1 ) BEGIN DECLARE @OriginalAdvancedOptions bit = ( SELECT CONVERT(bit, value_in_use) FROM sys.configurations WHERE name = N'show advanced options' ); IF @OriginalAdvancedOptions = 0 -- need to turn this on if it's not already BEGIN EXEC sys.sp_configure @configname = N'show advanced options', @configvalue = 1; RECONFIGURE WITH OVERRIDE; END EXEC sys.sp_configure @configname = N'default trace enabled', @configvalue = 0; IF @OriginalAdvancedOptions = 0 -- need to set it back (else leave it) BEGIN EXEC sys.sp_configure @configname = N'show advanced options', @configvalue = 0; END RECONFIGURE WITH OVERRIDE; END GO
Ensuite, pour créer la session Extended Event, je dois utiliser SQL dynamique, car certains serveurs peuvent avoir des chemins différents pour SERVERPROPERTY(N'ErrorLogFileName')
et cet argument ne peut pas être paramétré.
DECLARE @path nvarchar(max) = (SELECT REVERSE(SUBSTRING(p, CHARINDEX(N'\', p), 4000)) FROM (SELECT REVERSE((CONVERT(nvarchar(max), SERVERPROPERTY(N'ErrorLogFileName'))))) AS s(p)); IF EXISTS (SELECT 1 FROM sys.dm_xe_sessions WHERE name = N'FileSizeChanges') BEGIN EXEC sys.sp_executesql N'DROP EVENT SESSION FileSizeChanges ON SERVER;'; END DECLARE @sql nvarchar(max) = N' CREATE EVENT SESSION FileSizeChanges ON SERVER ADD EVENT sqlserver.database_file_size_change ( ACTION ( sqlserver.sql_text, sqlserver.client_app_name, sqlserver.client_hostname, sqlserver.username, sqlserver.server_principal_name ) ) ADD TARGET package0.event_file ( SET filename = ''' + @path + N'FileSizeChanges.xel'', MAX_FILE_SIZE = 100, -- MB MAX_ROLLOVER_FILES = 100 -- 100 MB x 100 = max 10 GB ) WITH ( MAX_MEMORY = 8192 KB, EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS, MAX_DISPATCH_LATENCY = 30 SECONDS, MAX_EVENT_SIZE = 0 KB, TRACK_CAUSALITY = OFF, STARTUP_STATE = ON ); ALTER EVENT SESSION FileSizeChanges ON SERVER STATE = START;'; EXEC sys.sp_executesql @sql;
La preuve est dans le pudding
J'ai créé une charge de travail fictive qui était intentionnellement lourde avec des choses qui consigneraient les événements dans la trace par défaut, puis l'ai exécutée plusieurs fois avec et sans la trace par défaut activée, pour montrer que l'effet observateur peut avoir un impact sur la charge de travail.
SELECT [starting] = sysdatetime(); GO EXEC sys.sp_executesql N'CREATE OR ALTER PROCEDURE dbo.dostuff AS BEGIN SET NOCOUNT ON; SELECT DISTINCT TOP (1000) object_id, column_id INTO #blat FROM sys.all_columns; ALTER TABLE #blat ADD CONSTRAINT PK_wahoo PRIMARY KEY (object_id, column_id); ALTER TABLE #blat ADD CONSTRAINT DF_what DEFAULT(1) FOR object_id; CREATE INDEX IX_what ON #blat(column_id); DROP TABLE #blat; END'; EXEC dbo.dostuff; CREATE USER smidgen WITHOUT LOGIN; ALTER ROLE db_owner ADD MEMBER smidgen; DBCC TRACEON(2861) WITH NO_INFOMSGS; DBCC TRACEOFF(2861) WITH NO_INFOMSGS; DROP USER smidgen; GO 5000 SELECT [finished] = sysdatetime(); GO
Durée d'exécution moyenne :
Tracé par défaut | Temps moyen de la charge de travail |
---|---|
Activé | 147.4s |
Désactivé | 131.6s |
Une réduction de 10 à 11 % du temps d'exécution n'est certainement pas énorme en soi, mais c'est une grande victoire si vous pensez à l'impact cumulé sur toute une flotte de plus de 200 serveurs.
Quelle est la prochaine ?
Ne le faites pas encore . Nous devons encore parler de certains effets secondaires de la désactivation de la trace par défaut et créer des vues afin que les utilisateurs puissent facilement consommer les données de session sans devenir des experts XQuery. Restez à l'écoute !
[ Partie 1 | Partie 2 | Partie 3 ]