THE SQL Server Blog Spot on the Web

Welcome to SQLblog.com - The SQL Server blog spot on the web Sign in | |
in Search

Michael Zilberstein

Page splits, extended events, index page allocation and all the fish

2 years ago I wrote about monitoring page splits with Extended Events. Only 2 bloggers explored Extended Events feature at that time, so my post was more of a learning than for any practical matter. Yet one question remained open: according to straightforward calculations, after 3 splits of the first page, next split should have occurred on another page - but trace with extended events clearly showed 4 splits of initial page.

Recently Pavel Nefyodov has drawn my attention to another curious fact: initially we had 1 page; after all those splits we had 10. But trace showed 10 splits, not 9. So where did additional split come from? And finally I've realized that there is another simple way to trace those splits - via transaction log. If we manually checkpoint the system before and perform insert in transaction afer - our transaction log will containg exactly the relevant data; and it'll remain this way all the time transaction stays open. We'll query transaction log using undocumented but widely known fn_dblog function.

OK, Let's see some code (mostly taken from my old post which in turn used page split demo from Kalen Delaney's blog). Initial configuration (including trace definition):

USE tempdb;
GO

CREATE TABLE split_page  
(id INT IDENTITY(0,2) PRIMARY KEY,
id2 bigint DEFAULT 0,
data1 VARCHAR(33) NULL,  
data2 VARCHAR(8000) NULL);
GO

INSERT INTO split_page DEFAULT VALUES;
GO 385

CREATE EVENT SESSION MonitorPageSplits ON SERVER
ADD EVENT sqlserver.page_split
(
  
ACTION (sqlserver.database_id, sqlserver.sql_text)  
   
WHERE sqlserver.database_id = 2
)
ADD TARGET package0.asynchronous_file_target
(
  
SET  
      
filename = N'c:\temp\MonitorPageSplits.etx',  
      
metadatafile = N'c:\temp\MonitorPageSplits.mta'
);
GO

CHECKPOINT
GO

Short glance at our table's allocation inside data file:

DBCC IND(tempdb, split_page, -1);
GO

PagePID IndexID iam_chain_type PageType IndexLevel
175 1 In-row data 10 NULL
148 1 In-row data 1 0

So we have 1 IAM page and 1 data page. Now the split itself and - remember, we should query transaction log before committing transaction if we don't want accidental checkpoint to ruine all our efforts.

ALTER EVENT SESSION MonitorPageSplits ON SERVER STATE = start;
GO

SET IDENTITY_INSERT split_page  ON;
GO
BEGIN TRAN

INSERT INTO
split_page (id, id2, data1, data2)
     
SELECT 111, 0, REPLICATE('a', 33), REPLICATE('b', 8000);
GO

SET IDENTITY_INSERT split_page  OFF;
GO

SELECT [Current LSN], Operation, Context, [Page ID], [Description]
FROM fn_dblog(NULL, NULL)

COMMIT
GO

ALTER
EVENT SESSION MonitorPageSplits ON SERVER STATE = STOP;
GO
DROP EVENT SESSION MonitorPageSplits ON SERVER;
GO

SELECT  
  
split.value('(/event/data[@name=''file_id'']/value)[1]','int') AS [file_id],
  
split.value('(/event/data[@name=''page_id'']/value)[1]','int') AS [page_id],
  
split.value('(/event[@name=''page_split'']/@timestamp)[1]','datetime') AS [event_time],
  
split.value('(/event/action[@name=''sql_text'']/value)[1]','varchar(max)') AS [sql_text]
FROM
  
(  
      
SELECT CAST(event_data AS XML) AS split
      
FROM sys.fn_xe_file_target_read_file('c:\temp\MonitorPageSplits*.etx', 'c:\temp\MonitorPageSplits*.mta', NULL, NULL)
   )
AS t
ORDER BY [event_time]

First let's take a look at our table now:

PagePID IndexID iam_chain_type PageType IndexLevel
175 1 In-row data 10 NULL
148 1 In-row data 1 0
184 1 In-row data 2 1
185 1 In-row data 1 0
187 1 In-row data 1 0
188 1 In-row data 1 0
189 1 In-row data 1 0
190 1 In-row data 1 0
191 1 In-row data 1 0
392 1 In-row data 1 0
393 1 In-row data 1 0
394 1 In-row data 1 0

Transaction log contains more rows than we are interested in, so I cleaned irrelevant ones out from the table below and correlated transaction log with extended events trace. I also transformed hexadecimal page numbers from transaction log to decimal ones - like we see in extended events trace.

image

So we can see that indeed there have been 3 splits of the first page. From transaction log we see that first action was actually allocating of page 184 which is - look at the allocation table above - index page. According to transaction log this page is allocated - not splitted from any other page. Still extended events trace shows as if it has been splitted from the first data page of our table. Don't know whether this behavior can be considered as bug - probably not. Anyway - both unanswered question from my old post are resolved: first page indeed has been splitted 3 times and we had only 9 data page splits while 10th split belongs to index page allocation.

Have a nice week!

Published Monday, April 25, 2011 11:49 PM by Michael Zilberstein

Comment Notification

If you would like to receive an email when updates are made to this post, please register here

Subscribe to this post's comments using RSS

Comments

 

Greg Linwood said:

It's such a shame that monitoring page splits is still such a hard task. This should be easy for DBAs to do, without having to write nasty scripts against a buggy API.

April 26, 2011 4:40 AM
 

Michael Zilberstein said:

Greg,

In Denali it is much better - you can distinguish between different types of split and also you can identify object - for details look at this great article by Jonathan Kehayias:

http://sqlblog.com/blogs/jonathan_kehayias/archive/2010/12/27/tracking-page-splits-in-sql-server-denali-ctp1.aspx

April 26, 2011 4:57 AM
 

Greg Linwood said:

it will be great if Denali finally improves this, but I hope Microsoft provides something more usable than xevent scripts. Obviously this type of information should be available in the index DMVs & shouldn't require DBAs to run xevent scripts manually on servers.

April 26, 2011 9:45 AM
 

Michael Zilberstein said:

That's an item for Connect, isn't it? :-)

April 26, 2011 10:15 AM
 

Greg Linwood said:

I think it's been logged a few times in the past, but hopefully Microsoft doesn't need to be told that DBAs need a convenient way of seeing where fragmentation is occurring in SQL DB objects..

April 26, 2011 10:39 AM
 

Michael Zilberstein said:

I think, Jonathan Kehayias and Adam Machanic filed and item asking to add a way to resolve page_id and file_id to a particular object and also distinguish between different split types (50:50 split vs new page allocation) in page_split extended event. It has been implemented in Denali. But I didn't find any request to add this data to standard DMVs. Specifically, I think, it should appear in sys.dm_db_index_operational_stats. So I filed mine one :-)

https://connect.microsoft.com/SQLServer/feedback/details/664900/please-add-page-splits-data-per-index-index-level-and-page-split-type

April 26, 2011 11:02 AM
 

AaronBertrand said:

April 26, 2011 1:38 PM
 

Michael Zilberstein said:

Aaron,

ouch, I missed your item. It makes mine almost redundant - besides a little more details about particular data I would like to see.

April 26, 2011 6:17 PM
 

Greg Linwood said:

Does anyone know whether Aaron's connect suggestion is actually being actioned? Michael, I hope Jonathan & Adam's item also has merit, but resolving page_ids, file_ids etc are what devs want to do. DBAs shouldn't have to work like devs (write scripts) to do the fundamentals of their jobs. Monitoring fragmentation events in databases is obviously a DBA fundamental & the only option at the moment is to scan dabatabases using index physical stats DMV or DBCC, neither of which is acceptable for large, high perf databases (as the impact is too large). DBAs should be able to simply query index operational stats occassionally or have access to an easy to use monitoring tool (eg Profiler) to identify where splitting is occuring. Having to write xevents scripts simply puts this fundamental task outside the reach of most DBAs. Some simply don't know how to write those scripts but even those DBAs who are able to write the scripts shouldn't have to.

April 26, 2011 7:51 PM
 

Greg Linwood said:

I meant to say that I think Jonathan & Adam's idea has merit & I hope it being actioned..

April 26, 2011 8:15 PM
 

AaronBertrand said:

Well, the good news is that after 2+ years it still hasn't been closed as "Won't Fix" like so many other suggestions, and one of very few items overall that have an official stamp of "we'll look at it" from Tobias himself.

April 27, 2011 11:16 AM
 

Aaron Bertrand said:

This week, after seeing a lot of the DMV enhancements made in SQL Server 2008 R2 SP1 , I thought I would

May 2, 2011 8:18 AM

Leave a Comment

(required) 
(required) 
Submit
Powered by Community Server (Commercial Edition), by Telligent Systems
  Privacy Statement