Database
 sql >> Datenbank >  >> RDS >> Database

Entfernen des Standard-Trace – Teil 2

[ Teil 1 | Teil 2 | Teil 3 ]

Im ersten Beitrag dieser Serie habe ich die Analyse gezeigt, die ich verwendet habe, um festzustellen, dass der Standard-Trace nichts für uns ist. Während ich mir ansah, welche Informationen wir tatsächlich an ihrer Stelle sammeln mussten (Änderungen der Dateigröße) und wie diese den Benutzern angezeigt werden sollten, habe ich die folgenden Punkte zum Standard-Trace berücksichtigt:

  • es erfasst nur automatisch Veranstaltungen;
  • Es erfasst nicht den „schuldigen“ Stapel, der das Ereignis verursacht hat, es sei denn, Sie haben das Glück, dass es auch aus einem anderen Grund erfasst wurde (z. B. DDL); und,
  • Es erfasst Ereignisse unter Verwendung der Ortszeit (unsere Server sind Eastern und gehorchen der Sommerzeit).

Zu seiner Verteidigung erfasst es viele wichtige Informationen über diese automatischen Ereignisse. Nachdem wir die Standardablaufverfolgung deaktiviert haben, möchten wir möglicherweise noch Ereignisse überprüfen, die vor der Änderung aufgetreten sind und in diesen Dateien erfasst wurden. Aber sobald der Standard-Trace deaktiviert ist, existiert die Zeile nicht mehr in sys.traces , sodass Sie den Pfad zu .trc nicht ermitteln können Dateien von dort. Hier bietet die Inflexibilität des Standard-Trace tatsächlich einen Vorteil:Die Dateien sind so fest codiert, dass sie sich im selben Ordner wie SERVERPROPERTY(N'ErrorLogFileName') befinden . Selbst wenn der Standard-Trace deaktiviert ist, können wir also immer noch Daten aus den Dateien abrufen, indem wir die folgende Abfrage verwenden (mit Anpassungen, um die Daten in UTC anzuzeigen):

;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;

Beispielergebnisse von einem Server, auf dem definitiv einige manuelle und automatische Ereignisse aufgetreten sind (zum Vergrößern klicken):

Einen Ersatz schreiben

Die Extended Events-Sitzung, die ich formuliert habe, um dies zu ersetzen, die auch manuelle Dateigrößenänderungen und den Abfragetext erfassen würde, der automatische Ereignisse verursachte, lautet wie folgt:

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;

Während es wie username aussieht und server_principal_name redundant sein kann, habe ich tatsächlich Fälle gefunden, in denen letzteres NULL war (und es scheint, dass dieses Problem schon eine Weile besteht).

Überprüfen der Ergebnisse

Ich habe diese Sitzung am 22. Februar aktiviert, daher fehlen die Ereignisse, die der Standard-Trace am 12. erfasst hat, aber es hat mehr als das einzelne Autogrowth-Ereignis vom 23. erfasst. Ich habe die folgende Abfrage ausgeführt, um ein Ergebnis mit der gleichen Form wie oben zu erhalten:

;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;

Die Ergebnisse zeigen den zusätzlichen Spaß, den ich hatte, einschließlich (keuch!) Ausführen einer „Datenbank verkleinern“-Aufgabe von der Benutzeroberfläche (zum Vergrößern anklicken):

Überall einsetzen

In der Zuversicht, dass ich mir jetzt ein vollständigeres Bild von Änderungen der Dateigröße auf jedem Server machen konnte, war es Zeit für die Bereitstellung. Ich habe ein CMS-Abfragefenster verwendet, um zuerst den Standard-Trace überall zu deaktivieren und die show advanced options einzustellen zurück, wie ich es gefunden habe:

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

Um dann die erweiterte Ereignissitzung zu erstellen, muss ich dynamisches SQL verwenden, da einige Server möglicherweise unterschiedliche Pfade für SERVERPROPERTY(N'ErrorLogFileName') haben und dieses Argument kann nicht parametrisiert werden.

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;

Der Beweis liegt im Pudding

Ich habe eine Scheinarbeitslast erstellt, die absichtlich viele Dinge enthält, die Ereignisse im Standard-Trace protokollieren, und sie dann mehrmals mit und ohne aktiviertem Standard-Trace ausgeführt, um zu zeigen, dass der Beobachtereffekt Auswirkungen auf die Arbeitslast haben kann.

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

Durchschnittliche Laufzeit:

Standard-Trace Durchschnittliche Workload-Zeit
Aktiviert 147,4s
Deaktiviert 131,6s

Eine Laufzeitverkürzung um 10–11 % ist für sich genommen sicherlich nicht riesig, aber es ist ein großer Gewinn, wenn Sie an die kumulativen Auswirkungen auf eine gesamte Flotte von über 200 Servern denken.

Was kommt als nächstes?

Mach das noch nicht . Wir müssen noch über einige Nebenwirkungen der Deaktivierung des Standard-Trace sprechen und Ansichten erstellen, damit Benutzer die Sitzungsdaten einfach nutzen können, ohne zu XQuery-Experten zu werden. Bleiben Sie dran!

[ Teil 1 | Teil 2 | Teil 3 ]