デフォルトトレースを隠すものは何ですか?





最初の作品はしばしば思い出されます... 平凡なオフィス、モニーク943Nと足下のPentium Dヒーター。 ボリス(ボリスの「カミソリ」ではない)は定規を手に持ってどこからともなく出てきて、サーバーを「傷つけない」ように強く要求した。



プロファイラーと初めて会ったのは、その遠い時代でした。 カスタムトレースは、アプリケーションのデバッグや遅いクエリの検索に非常に役立つことが判明しました。 その後、私は自分で DMVXEventsを発見しました...そして、プロファイラーの使用頻度を減らしました。 この行為の理由は簡単です-トレースは非常にリソースを消費します。



ただし、この機能は時期尚早に分析されるべきではありません。 2005バージョン以降、 SQL Serverをインストールすると、デフォルトで軽量のシステムトレースが作成され、多くの有用な情報が保存されます。



これは、 SQL Serverがインストールされているフォルダーにあり、 trc拡張子を持つ5つのファイルで構成されています。 サーバーが起動するたびに、トレース用の新しいファイルが自動的に作成され、最も古いファイルが上書きされます。 新しいイベントの記録は常に最新のファイルに行われ、そのサイズは20 MBに制限されています。 サイズを超えると、新しいファイルが自動的に作成されます。 この動作は変更できません。



この機能のみを無効または有効にできます。



EXEC sys.sp_configure 'show advanced options', 1 GO RECONFIGURE WITH OVERRIDE GO EXEC sys.sp_configure 'default trace enabled', 0 GO RECONFIGURE WITH OVERRIDE GO
      
      





次のリクエストにより、デフォルトのトレースが有効になっていることを確認できます。



 SELECT name, value FROM sys.configurations WHERE configuration_id = 1568
      
      





デフォルトのトレースへのパス:



 SELECT [path], start_time, last_event_time, event_count FROM sys.traces WHERE is_default = 1
      
      





そして今、私たちは最も興味深いものを開始します...デフォルトのトレースに保存できるイベントを見てみましょう:



 SELECT e.trace_event_id, e.name, c.category_id, c.name FROM sys.trace_categories c JOIN sys.trace_events e ON c.category_id = e.category_id
      
      





 trace_event_id name category_id name -------------- -------------------------- ----------- ----------------------------------- 196 CLR 20 Assembly Load 92 Database 2 Data File Auto Grow 93 Database 2 Log File Auto Grow 94 Database 2 Data File Auto Shrink 95 Database 2 Log File Auto Shrink 79 Errors and Warnings 3 Missing Column Statistics 80 Errors and Warnings 3 Missing Join Predicate 67 Errors and Warnings 3 Execution Warnings 69 Errors and Warnings 3 Sort Warnings 55 Errors and Warnings 3 Hash Warning 21 Errors and Warnings 3 EventLog 22 Errors and Warnings 3 ErrorLog 213 Errors and Warnings 3 Database Suspect Data Page 214 Errors and Warnings 3 CPU threshold exceeded 46 Objects 5 Object:Created 47 Objects 5 Object:Deleted 164 Objects 5 Object:Altered ...
      
      





そして、デフォルトのトレースからの情報の実用的な利点の小さな例を見てみましょう。



1.自動成長イベント



トランザクションに一定のディスク容量が必要であることは秘密ではないと思います。 データファイルまたはログ内。 ...は指定しませんが、一般的なケースでは、十分なスペースがない場合、ファイルは自動的に増加します。 この時点で、ファイルはロックされ、 SQL Serverはディスクサブシステムがディスク領域を割り当てるために必要な操作を行うまで待機します



既定では、 SQL Serverは新しいディスク領域をゼロで初期化します 。 データファイルの場合、 Instant File Initializationを使用してこの動作を無効にできます。 ただし、ログファイルの場合、初期化は引き続き行われ、確実に低速です。 したがって、 Auto Growイベントを常に監視することをお勧めします。



 SELECT StartTime , Duration = Duration / 1000 , DatabaseName = DB_NAME(DatabaseID) , [FileName] , GrowType = CASE WHEN EventClass = 92 THEN 'DATA' ELSE 'LOG' END FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t WHERE t.EventClass IN ( 92, -- Data File Auto Grow 93 -- Log File Auto Grow ) AND i.is_default = 1
      
      





そして、それらの数が急激に増加する場合:



 StartTime Duration DatabaseName FileName GrowType -------------------- ----------- ---------------------- -------------------------- -------- 2016-01-16 02:52:48 36 tempdb templog LOG 2016-01-16 02:52:49 50 tempdb tempdev DATA 2016-01-16 02:52:50 216 tempdb tempdev DATA 2016-01-16 02:52:51 43 tempdb tempdev DATA 2016-01-16 02:52:52 760 tempdb tempdev DATA 2016-01-16 02:52:54 270 tempdb tempdev DATA 2016-01-16 02:52:55 273 tempdb tempdev DATA 2016-01-16 02:52:56 286 tempdb tempdev DATA 2016-01-16 02:52:58 206 tempdb tempdev DATA 2016-01-16 02:52:59 513 tempdb tempdev DATA 2016-01-16 02:53:01 363 tempdb tempdev DATA 2016-01-16 02:53:03 300 tempdb tempdev DATA 2016-01-16 02:53:05 303 tempdb tempdev DATA 2016-01-16 02:53:08 200 tempdb tempdev DATA 2016-01-16 02:53:10 60 tempdb tempdev DATA 2016-01-16 02:53:12 350 tempdb tempdev DATA 2016-01-16 02:53:15 370 tempdb tempdev DATA 2016-01-16 02:53:17 243 tempdb tempdev DATA 2016-01-16 02:53:21 446 tempdb tempdev DATA 2016-01-16 02:53:25 163 tempdb tempdev DATA 2016-01-16 02:53:30 286 tempdb tempdev DATA 2016-01-16 02:53:36 426 tempdb tempdev DATA 2016-01-16 02:53:42 376 tempdb tempdev DATA 2016-01-16 02:53:49 120 tempdb tempdev DATA 2016-01-16 02:53:58 200 tempdb tempdev DATA 2016-01-16 02:54:06 186 tempdb tempdev DATA 2016-01-16 02:54:17 43 tempdb tempdev DATA 2016-01-16 02:54:27 6 tempdb tempdev DATA 2016-01-16 02:54:42 3 tempdb tempdev DATA 2016-01-16 02:55:04 30 tempdb tempdev DATA 2016-01-16 14:19:47 63 AdventureWorks2012 AdventureWorks2012_Log LOG 2016-01-16 14:19:47 20 AdventureWorks2012 AdventureWorks2012_Log LOG 2016-01-16 16:51:32 100 tempdb tempdev DATA 2016-02-16 17:31:02 66 tempdb templog LOG ...
      
      





これにより、ディスク上のファイルの断片化だけでなく、クエリの実行時に大幅な遅延が発生する可能性があります。



 SELECT GrowType = CASE WHEN EventClass = 92 THEN 'DATA' ELSE 'LOG' END , GrowCount = COUNT(1) , Duration = SUM(Duration) / 1000 FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t WHERE t.EventClass IN (92, 93) AND i.is_default = 1 AND t.DatabaseID = DB_ID('tempdb') GROUP BY EventClass
      
      





 GrowType GrowCount Duration -------- ----------- -------------------- DATA 36 7296 LOG 2 102
      
      





問題ベースの設定を見てみましょう。



 USE tempdb GO SELECT d.type_desc , d.name , d.physical_name , current_size_mb = ROUND(d.size * 8. / 1000, 0) , initial_size_mb = ROUND(m.size * 8. / 1000, 0) , auto_grow = CASE WHEN d.is_percent_growth = 1 THEN CAST(d.growth AS VARCHAR(10)) + '%' ELSE CAST(ROUND(d.growth * 8. / 1000, 0) AS VARCHAR(10)) + 'MB' END FROM sys.database_files d JOIN sys.master_files m ON d.[file_id] = m.[file_id] WHERE m.database_id = DB_ID('tempdb')
      
      





データベースの初期サイズは、データファイル用に8 MB、ログ用に1 MBです。



 type name physical_name current_size_mb initial_size_mb auto_grow ----- ---------- ------------------------------ ------------------ ------------------ --------- ROWS tempdev D:\SQL_2012\DATA\tempdb.mdf 258.000000 8.000000 10% LOG templog D:\SQL_2012\DATA\templog.ldf 3.000000 1.000000 1MB
      
      





...現在のサイズと比較すると、明らかに十分ではありません。 さらに、 SQL Serverの各再起動時にtempdbが再作成されることを覚えておく必要があります 。 一番下の行は、次に起動するときに、9 MBのファイル、リクエストの実行の遅延、およびデフォルトトレースのメッセージの新しいバッチを再び取得します。



この状況から抜け出す方法は何ですか? ファイルサイズを監視し、それらの空き容量を確保します。



 SELECT s.[file_id] , s.name , size = CAST(s.size * 8. / 1024 AS DECIMAL(18,2)) , space_used = CAST(t.space_used * 8. / 1024 AS DECIMAL(18,2)) , free_space = CAST((s.size - t.space_used) * 8. / 1024 AS DECIMAL(18,2)) , used_percent = CAST(t.space_used * 100. / s.size AS DECIMAL(18,2)) , s.max_size , s.growth , s.is_percent_growth FROM sys.database_files s CROSS APPLY ( SELECT space_used = FILEPROPERTY(s.name, 'SpaceUsed') ) t
      
      





2.自動縮小イベント



最近、 AUTO_CLOSEオプションはパフォーマンスを低下させると書きました。 したがって、 AUTO_SHRINKはさらに悪化します。30分ごとに、 SQL Serverはデータベースファイルの空き領域を切り捨てようとします。 このプロセスはかなりリソースを消費し、ディスク上のファイルの断片化につながる可能性があります。 ファイルを切り捨てると、インデックスの断片化が大きくなり、論理読み取りが増加し、クエリのパフォーマンスが低下します。



簡単な状況を想像してください...テーブルからデータが削除されました-ファイルの切り捨て。 新しいデータを挿入しました-十分なスペースがなく、 SQL Serverはファイルサイズを増やす必要がありました。 彼らはデータを削除し、再びすべてを新しい方法で...



 SELECT StartTime , EndTime , Duration = Duration / 1000 , DatabaseName = DB_NAME(DatabaseID) , [FileName] , GrowType = CASE WHEN EventClass = 94 THEN 'DATA' ELSE 'LOG' END , NTDomainName , ApplicationName , LoginName , TextData , IsSystem FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t WHERE t.EventClass IN ( 94, -- Data File Auto Shrink 95 -- Log File Auto Shrink ) AND i.is_default = 1
      
      





 StartTime Duration DatabaseName FileName GrowType ------------------- ----------- ------------------------- ------------------------ -------- 2016-02-10 11:57:54 116 AdventureWorks2012 AdventureWorks2012_Log LOG 2016-02-10 14:58:21 113 AdventureWorks2012 AdventureWorks2012_Log LOG 2016-02-10 19:30:02 113 AdventureWorks2012 AdventureWorks2012_Log LOG 2016-02-10 21:00:26 16 AdventureWorks2012 AdventureWorks2012_Log LOG
      
      





このオプションを無効にすることをお勧めします。



 SELECT 'ALTER DATABASE ' + QUOTENAME(name) + ' SET AUTO_SHRINK OFF WITH NO_WAIT;' FROM sys.databases WHERE is_auto_shrink_on = 1
      
      





3. DBCCイベント



デフォルトトレースのもう1つの有用性は、 DBCCコマンドをいつ誰が開始したかを追跡できることです 。 通常、 DBCC CHECKDBをscる価値はありませんが、実稼働中の誰かが狂っている場合は、次のようにします。



 DBCC SHRINKDATABASE DBCC FREEPROCCACHE DBCC DROPCLEANBUFFERS
      
      





簡単に追跡できます:



 SELECT t.TextData, t.ApplicationName, t.LoginName, t.StartTime FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t WHERE i.is_default = 1 AND t.EventClass = 116 -- Audit DBCC Event AND t.ApplicationName IS NOT NULL
      
      





そばの角に立つことの利点について誰かと予防的な会話をする:



 TextData ApplicationName LoginName StartTime ----------------------- ------------------ ----------- ----------------------- DBCC SHRINKDATABASE(1) SSMS - Query PC\IgorS 2016-02-10 20:03:46.307 DBCC FREEPROCCACHE SSMS - Query PC\IgorS 2016-02-10 20:03:43.430 DBCC DROPCLEANBUFFERS SSMS - Query PC\IgorS 2016-02-10 20:03:44.767
      
      





4.エラーおよび警告イベント



SQL Serverにクエリの実行に必要な十分な空きメモリがない状況では、 tempdbで一部のステートメントの結果の処理が発生します 。 オプティマイザーが予想される行数の誤った推定を行った場合にも、同じ動作が発生します。



tempdbで スピルを呼び出す要求を作成してみましょう。



 SELECT * FROM Sales.SalesOrderHeader WHERE DueDate > ShipDate ORDER BY OrderDate DESC
      
      









デフォルトのトレースからのメッセージのおかげで、これらのリクエストを追跡できます。



 SELECT TOP(10) EventName = e.name , t.TextData , t.ApplicationName , t.LoginName , t.StartTime , DatabaseName = DB_NAME(t.DatabaseID) FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t JOIN sys.trace_events e ON e.trace_event_id = t.EventClass WHERE i.is_default = 1 AND e.category_id = 3 ORDER BY t.StartTime DESC
      
      





 EventName ApplicationName LoginName StartTime DatabaseName ------------------ ----------------- ------------- ----------------------- --------------------- Sort Warnings SSMS - Query PC\SergeyS 2016-02-11 13:06:44.867 AdventureWorks2012
      
      





実行計画を見つけて、クエリの最適化を試みます。



 USE AdventureWorks2012 GO SELECT TOP(5) p.query_plan , e.[text] , qyery_cost = p.query_plan.value( '(/*:ShowPlanXML/*:BatchSequence/*:Batch/*:Statements/*:StmtSimple/@StatementSubTreeCost)[1]', 'FLOAT' ) , s.last_execution_time , last_exec_ms = s.last_worker_time / 1000 , s.execution_count FROM sys.dm_exec_query_stats s CROSS APPLY sys.dm_exec_query_plan(s.plan_handle) p CROSS APPLY sys.dm_exec_sql_text(s.plan_handle) e WHERE e.[text] NOT LIKE '%sys%' AND s.last_execution_time >= DATEADD(MS, -2500, '2016-02-10 19:41:45.983') AND e.[dbid] = DB_ID() ORDER BY s.last_execution_time
      
      





 query_plan text qyery_cost execution_time last_exec_ms ----------------- -------------------------------- ----------- ------------------- -------------- <ShowPlanXML ... SELECT * FROM Sales.SalesOrde... 1,10126 2016-02-11 13:06:44 1538
      
      





ところで、実際の実行計画はDMVを介して利用できません。 これらは、 クエリ実行後のプラン表示段階 、対応するトレースイベント 、またはSET STATISTICS XML ONコマンドによってのみ取得できます。 SQL Server 2012以降、新しいXEventがそのような目的専用追加されました-post_query_execution_showplan



個人的には、あらゆる種類の警告を追跡できることを嬉しく思います。



 SELECT DISTINCT d.SalesOrderID, d.UnitPrice, h.OrderDate FROM Sales.SalesOrderHeader h JOIN Sales.SalesOrderDetail d ON h.SalesOrderID = d.SalesOrderID WHERE h.DueDate > h.ShipDate
      
      









 EventName ApplicationName LoginName StartTime DatabaseName ---------------- ----------------- ------------- ----------------------- --------------------- Hash Warning SSMS - Query PC\SergeyS 2016-02-11 13:14:44.433 AdventureWorks2012
      
      





たとえば、接続が進むフィールドを誤って指定し忘れた場合:



 SELECT * FROM Sales.Currency c, Sales.CountryRegionCurrency r --WHERE c.CurrencyCode = r.CurrencyCode
      
      









 EventName ApplicationName LoginName StartTime DatabaseName ----------------------- ----------------- ------------- ------------------- --------------------- Missing Join Predicate SSMS - Query PC\SergeyS 2016-02-11 13:18:20 AdventureWorks2012
      
      





または、統計列がフィルタリングされていない場合:



 SELECT DatabaseLogID FROM dbo.DatabaseLog WHERE PostTime = '2012-03-14 13:14:18.847'
      
      









 EventName TextData DatabaseName --------------------------- ------------------------------------------ -------------------- Missing Column Statistics NO STATS:([dbo].[DatabaseLog].[PostTime]) AdventureWorks2012
      
      





5.オブジェクトイベント



デフォルトのトレースでは、オブジェクトの作成と削除を追跡できます。



 USE [master] GO IF DB_ID('test') IS NOT NULL DROP DATABASE [test] GO CREATE DATABASE [test] GO USE [test] GO CREATE TABLE dbo.tbl (ID INT) GO ALTER TABLE dbo.tbl ADD Col VARCHAR(20) GO CREATE UNIQUE CLUSTERED INDEX ix ON dbo.tbl (ID) GO USE [master] GO IF DB_ID('test') IS NOT NULL DROP DATABASE [test] GO
      
      





 SELECT EventType = e.name , t.DatabaseName , t.ApplicationName , t.LoginName , t.StartTime , t.ObjectName , ObjectType = CASE t.ObjectType WHEN 8259 THEN 'Check Constraint' WHEN 8260 THEN 'Default Constraint' WHEN 8262 THEN 'Foreign Key' WHEN 8272 THEN 'Stored Procedure' WHEN 8274 THEN 'Rule' WHEN 8275 THEN 'System Table' WHEN 8276 THEN 'Server Trigger' WHEN 8277 THEN 'Table' WHEN 8278 THEN 'View' WHEN 8280 THEN 'Extended Stored Procedure' WHEN 16724 THEN 'CLR Trigger' WHEN 16964 THEN 'Database' WHEN 17222 THEN 'FullText Catalog' WHEN 17232 THEN 'CLR Stored Procedure' WHEN 17235 THEN 'Schema' WHEN 17985 THEN 'CLR Aggregate Function' WHEN 17993 THEN 'Inline Table-valued SQL Function' WHEN 18000 THEN 'Partition Function' WHEN 18004 THEN 'Table-valued SQL Function' WHEN 19280 THEN 'Primary Key' WHEN 19539 THEN 'SQL Login' WHEN 19543 THEN 'Windows Login' WHEN 20038 THEN 'Scalar SQL Function' WHEN 20051 THEN 'Synonym' WHEN 20821 THEN 'Unique Constraint' WHEN 21075 THEN 'Server' WHEN 21076 THEN 'Transact-SQL Trigger' WHEN 21313 THEN 'Assembly' WHEN 21318 THEN 'CLR Scalar Function' WHEN 21321 THEN 'Inline scalar SQL Function' WHEN 21328 THEN 'Partition Scheme' WHEN 21333 THEN 'User' WHEN 21572 THEN 'Database Trigger' WHEN 21574 THEN 'CLR Table-valued Function' WHEN 21587 THEN 'Statistics' WHEN 21825 THEN 'User' WHEN 21827 THEN 'User' WHEN 21831 THEN 'User' WHEN 21843 THEN 'User' WHEN 21847 THEN 'User' WHEN 22601 THEN 'Index' WHEN 22611 THEN 'XMLSchema' WHEN 22868 THEN 'Type' END FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t JOIN sys.trace_events e ON t.EventClass = e.trace_event_id WHERE e.name IN ('Object:Created', 'Object:Deleted', 'Object:Altered') AND t.ObjectType != 21587 AND t.DatabaseID != 2 AND i.is_default = 1 AND t.EventSubClass = 1
      
      





 EventType DatabaseName ApplicationName StartTime ObjectName ObjectType ---------------- -------------- ---------------- ----------------------- ------------- ------------ Object:Created test SSMS - Query 2016-02-11 13:36:46.727 NULL Database Object:Created test SSMS - Query 2016-02-11 13:36:46.760 tbl Table Object:Altered test SSMS - Query 2016-02-11 13:36:46.803 tbl Table Object:Created test SSMS - Query 2016-02-11 13:36:46.837 ix Index Object:Deleted test SSMS - Query 2016-02-11 13:36:56.347 NULL Database
      
      





6.サーバーイベント



また、デフォルトのトレールを通じて、誰がいついつベースをバックアップおよび復元したかを監視できます。



 SELECT CASE WHEN t.EventSubClass = 1 THEN 'BACKUP' ELSE 'RESTORE' END, t.TextData, t.ApplicationName, t.LoginName, t.StartTime FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t WHERE i.is_default = 1 AND t.EventClass = 115 -- Audit Backup/Restore Event
      
      





 TextData ApplicationName LoginName StartTime -------------------- ------------------------------- ----------- ------------------------- BACKUP DATABASE SSMS - Query PC\SergeyS 2016-01-21 13:05:26.390 RESTORE DATABASE dbForge Studio for SQL Server PC\SergeyS 2016-01-22 12:46:45.717 BACKUP DATABASE SQLCMD sa 2016-01-24 10:16:40.317
      
      





または、 SQL Serverのメモリ使用量を監視します



 SELECT t.StartTime , [Type] = CASE WHEN EventSubClass = 1 THEN 'UP' ELSE 'DOWN' END , t.IntegerData FROM sys.traces i CROSS APPLY sys.fn_trace_gettable([path], DEFAULT) t WHERE t.EventClass = 81 -- Server Memory Change AND i.is_default = 1
      
      





 StartTime Type IntegerData ------------------------ ----- ----------- 2016-02-10 02:52:42.887 UP 191 2016-02-10 02:53:00.640 UP 371 2016-02-10 02:53:34.917 UP 734 2016-02-10 02:53:52.140 UP 916 2016-02-10 10:05:00.027 DOWN 736 2016-02-10 10:17:17.417 UP 921 2016-02-10 11:52:14.930 DOWN 735 2016-02-10 12:00:32.577 DOWN 553 2016-02-10 13:06:11.540 UP 751 2016-02-10 15:11:10.487 UP 936 2016-02-10 15:15:26.107 DOWN 714
      
      





あとがき



デフォルトのトレースは、サーバーのステータスを監視するための強力なツールです。 もちろん、これには多くの欠点があります。たとえば、前述の20 MBの制限や、この機能はSQL Server 2008以降廃止されたというMicrosoftの声明です。 ただし、それでも、 SQL Serverの問題の初期診断中にデフォルトのトレースが非常に役立つ場合があります 。 上記の例がこれを明確に実証できることを願っています。



すべてがMicrosoft SQL Server 2012(SP3)(KB3072779)-11.0.6020.0(X64)でテストされました。



この記事を英語圏の聴衆と共有したい場合:

SQL ServerのDEFAULT TRACEの隠された宝石



All Articles