Menghapus jejak default

[ Bagian 1 | Bagian 2 | Bagian 3 ]

Dalam posting pertama dalam seri ini, saya menunjukkan analisis yang saya gunakan untuk menentukan bahwa jejak default bukan untuk kita. Sambil melihat informasi apa yang sebenarnya perlu kami kumpulkan sebagai gantinya (ukuran file berubah), dan bagaimana hal ini harus diungkapkan kepada pengguna, saya mempertimbangkan poin-poin berikut tentang pelacakan default:

hanya menangkap otomatis acara;
ini tidak menangkap kelompok "pelaku" yang menyebabkan peristiwa tersebut, kecuali jika Anda cukup beruntung karena itu juga ditangkap karena alasan lain (mis. DDL); dan,
ini merekam peristiwa menggunakan waktu lokal (server kami adalah Timur dan mematuhi DST).

Dalam pembelaannya, ia menangkap banyak informasi penting tentang peristiwa otomatis itu. Setelah kami menonaktifkan pelacakan default, kami mungkin masih ingin meninjau peristiwa yang terjadi sebelum perubahan dan direkam dalam file tersebut. Tetapi setelah pelacakan default dinonaktifkan, baris tidak lagi ada di sys.traces , jadi Anda tidak dapat menentukan jalur ke .trc file dari sana. Di sinilah ketidakfleksibelan jejak default sebenarnya memberikan manfaat:file di-hardcode untuk berada di folder yang sama dengan SERVERPROPERTY(N'ErrorLogFileName') . Jadi, meskipun pelacakan default dinonaktifkan, kami masih dapat menarik data dari file menggunakan kueri berikut (dengan penyesuaian untuk menampilkan data dalam 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;

Contoh hasil dari satu server, dimana pasti ada beberapa kejadian manual dan otomatis yang terjadi (klik untuk memperbesar):

Menulis pengganti

Sesi Extended Events yang saya rumuskan untuk menggantikan ini, yang juga akan menangkap perubahan ukuran file manual dan teks kueri yang menyebabkan event otomatis, adalah sebagai berikut:

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;

Sementara itu terlihat seperti username dan server_principal_name mungkin berlebihan, saya benar-benar menemukan kasus di mana yang terakhir adalah NULL (dan sepertinya masalah ini sudah lama terjadi).

Memeriksa hasil

Saya mengaktifkan sesi itu pada tanggal 22 Februari, sehingga tidak ada peristiwa yang diambil oleh jejak default pada tanggal 12, tetapi sesi tersebut menangkap lebih dari satu peristiwa pertumbuhan otomatis dari tanggal 23. Saya menjalankan kueri berikut untuk mendapatkan hasil dengan bentuk yang sama seperti di atas:

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

Hasilnya menunjukkan kesenangan tambahan yang saya miliki, termasuk (terkesiap!) menjalankan tugas "Shrink Database" dari UI (klik untuk memperbesar):

Menyebarkannya di mana saja

Yakin bahwa saya sekarang bisa mendapatkan gambaran yang lebih lengkap tentang peristiwa perubahan ukuran file di server mana pun, sekarang saatnya untuk menyebarkan. Saya menggunakan jendela kueri CMS untuk menonaktifkan pelacakan default terlebih dahulu di mana saja, dan menyetel show advanced options kembali seperti yang saya temukan:

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

Kemudian, untuk membuat sesi Extended Event, saya perlu menggunakan SQL dinamis, karena beberapa server mungkin memiliki jalur yang berbeda untuk SERVERPROPERTY(N'ErrorLogFileName') dan argumen itu tidak dapat diparameterisasi.

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;

Buktinya ada di puding

Saya membuat beban kerja tiruan yang sengaja dibuat berat dengan hal-hal yang akan mencatat peristiwa ke pelacakan default, lalu menjalankannya beberapa kali dengan dan tanpa mengaktifkan pelacakan default, untuk menunjukkan bahwa efek pengamat dapat berdampak pada beban kerja.

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

Waktu proses rata-rata:

Jejak default	Waktu beban kerja rata-rata
Diaktifkan	147.4s
Dinonaktifkan	131.6s

Pengurangan waktu proses 10-11% tentu saja tidak besar secara terpisah, tetapi ini adalah kemenangan besar jika Anda memikirkan dampak kumulatif di seluruh armada 200+ server.

Apa selanjutnya?

Jangan lakukan ini . Kami masih harus membicarakan beberapa efek samping dari menonaktifkan pelacakan default, dan membuat tampilan sehingga pengguna dapat dengan mudah menggunakan data sesi tanpa menjadi ahli XQuery. Tetap disini!