Apr 12, 2012

Page Split 3.5: Advantage of Extended Events in SQL Server 2012

[Updated 13th April 2012 12:27 am] Note: Jonathan Kehayias (Blog)  pointed out that some of his work is being referenced but not cited. Since it is a series, I was under the impression that all references could be published at the end; but Jonathan updated me that it should be there with each post. So it is mentioned at the end of this post. Regret for the anxiety caused.  Thanks Jonathan. I will be updating other posts int his series.
Unlike previous versions, SQL Server 2012 provides more details on page splits. You you all would have seen in the first part of the series, that page split can be an event, where a new page added to the table.
The page split we should be worried is an existing page splits to accommodate either a new or an existing row.
In SQL Server 2012 extended events, we can track the database, the sql statement which caused the page split and even the type of page split.

Lets use this example: Lets select the page split test, extended event session and (if it is stopped , start and) open the watch live data. (There could be a delay in showing the events int he screen, but they are captured live)
Now execute the following script

IF DB_ID('page_split') IS NULL
       create database page_split;
go
use page_split
go
IF Object_Id('dbo.Note') IS NOT NULL
drop table Note
GO

CREATE TABLE dbo.Note
(
NoteID int NOT NULL CONSTRAINT PK_Note PRIMARY KEY CLUSTERED (NoteID),
NoteText char(1300) NOT NULL
)
GO

Insert into dbo.Note Values (1,REPLICATE('a', 1300));
GO
Insert into dbo.Note Values (2,REPLICATE('b', 1300));
GO
Insert into dbo.Note Values (3,REPLICATE('c', 1300));
GO
-- The row with NoteID = 4 is missing here
GO
Insert into dbo.Note Values (5,REPLICATE('e', 1300));
GO
Insert into dbo.Note Values (6,REPLICATE('f', 1300));
GO
Insert into dbo.Note Values (7,REPLICATE('g', 1300));
GO
Insert into dbo.Note Values (4,REPLICATE('d', 1300));
GO

When the code is executed, we can see three page split related information getting into our watch window.
(Lets add the following columns from details section to the table view: database_name, SplitOperation, new_page_file_id, new_page_page_id, page_id, sql_text)

The watch window will look like this:
 



The first page split operation called SPLIT_EMPTY_BTREE has occurred when the very first row is inserted. (Well after the first insert, but before the next insert.) The sql_text column says the first row of insert has caused the page split.  This is the natual page split event, which occurs whenever the first page is added to the clustered index.This is page only the table became a table with blood and flesh not just a table in concept. However, at this time the table will be confined to one page.

Then we see two page split operations have occurred when the row with NoteID =4 is inserted. The event, SPLIT_FOR_ROOT_NODE which mans the root page has gone through a split.  It generally occurs when new pages are added and they exceed the capacity of the clustered index pages.
The event SPLIT_FOR_INSERT a page split has occurred due to insert of a new row. But it does not specify whether it is a new page added at the end of the table or middle of the table

To identify the page splits, which occurs in the middle of the page, we need to track another event.
First of all lets close the watch window and stop the session. Then we go to the properties and select the events tab.

In Channel, we need to select debug (This is the only channel not selected by default) and search for transaction_log event.


 Lets press the configure button.
We can select the same global fields and move to filter tab.

(Please note that there is a mistake in yesterday's blog. During the filter operation, The text says, select database_id and ">" sign. The picture does not match that.)


Lets select the following filter conditions:


And/Or Field Operation Value
  database_id >   4
And operation = LOP_DELETE_SPLIT


Please make sure to go to the next tab named event fields and select database_name.


Now lets save the session, start it, open the watch live data window and run the following script:
 
IF
 DB_ID('page_split') IS NULL
       create database page_split;
go
use page_split
go
IF Object_Id('dbo.Note') IS NOT NULL
drop table Note
GO

CREATE TABLE dbo.Note
(
NoteID int NOT NULL CONSTRAINT PK_Note PRIMARY KEY CLUSTERED (NoteID),
NoteText char(1300) NOT NULL
)
GO

Insert into dbo.Note Values (1,REPLICATE('a', 1300));
GO
Insert into dbo.Note Values (2,REPLICATE('b', 1300));
GO
Insert into dbo.Note Values (3,REPLICATE('c', 1300));
GO
-- The row with NoteID = 4 is missing here
GO
Insert into dbo.Note Values (5,REPLICATE('e', 1300));
GO
Insert into dbo.Note Values (6,REPLICATE('f', 1300));
GO
Insert into dbo.Note Values (7,REPLICATE('g', 1300));
GO
Insert into dbo.Note Values (4,REPLICATE('d', 1300));
GO
Insert into dbo.Note Values (8,REPLICATE('h', 1300));
GO
Insert into dbo.Note Values (9,REPLICATE('i', 1300));
GO
Insert into dbo.Note Values (10,REPLICATE('j', 1300));
GO
Insert into dbo.Note Values (11,REPLICATE('k', 1300));
GO

Now you can see the split operations and log event.

Lets Concentrate on the last three lines in the table view (i.e. from the highlighted row till the end):

The highlighted row shows that the delete operation in log (LOP_DELETE_SPLIT) has happened when row with NoteID =4 is inserted. The next row shows that during the time, SPLIT_FOR_INSERT too has occurred. These two events are fired because the row is inserted in the middle.

But when the insert statement sent the row with NoteID = 11, which needs a new page and it is a simple append operation, only SPLIT_FOR_INSERT has occurred, but LOP_DELETE_SPLIT didn't occur.

I leave the following code to the readers to try and see the events and operations.

alter table Note alter column NoteText varchar(8000)
GO
update dbo.Note set NoteText = REPLICATE('b', 8000) where NoteID =2

References:

http://sqlskills.com/blogs/jonathan/post/Tracking-Problematic-Pages-Splits-in-SQL-Server-2012-Extended-Events-e28093-No-Really-This-Time!.aspx
This post is about page splits which happens in the middle of a table and how it could be tracked. This post does not have the UI walk through, but carries a heap of information on extended events and how to identify the page splits using code. Jonathan Kehayias has done an excellent job on this.

http://sqlblog.com/blogs/jonathan_kehayias/archive/2011/01/03/using-extended-events-in-sql-server-denali-ctp1-to-map-out-the-transactionlog-sql-trace-event-eventsubclass-values.aspx
Again from Jonathan,  where he talks a lot about the extended events related to transaction log.

2 comments:

Jonathan Kehayias (MCITP, MVP) said...

The issue with posting no reference when ten logging a complex solution like tracking the LOP_DELETE_SPLIT log operations as shown in the post I pointed out to you, is that you are passing the information as being your original thoughts/solution. The fact that you did so after I pointed you to the solution rather than pointing your readers to the other source is the problem. It certainly isn't something I'd expect from a fellow MVP. Your comment at the top of this post is very misleading as to what the issue is especially since my previous comment was deleted. I'll write a blog post that covers the details completely.

Prithiviraj Kulasingham said...

Hi Jonathan,
Sorry again for creating this issue.
This series is not about "my inventions"; rather I compiled this four part article from my learning to bring awareness about page splits.
I agree that you have done a significant work on extended events related to transaction log, and how it works with page splits. As of I know it is you who has published this work too. When I posted the part 3 of my 4 part series, you updated me through a comment about your research.
With that update, I also read other posts of yours. I also found something new on page splits. So, I decided to update my readers. As your posts didn't carry about the UI part and it is hidden by default in UI, I decided to write the update. I Marked it as Part 3.5 (not 4)
I never had an intention of stealing your work. Please note that I kept your comment on part 3 untouched. I was planning to include all references with the 4th part. I sent you a note on that, and with that I removed the comment.
But You updated me on how it could be (mis)interpreted if the references are not mentioned within the post. You spent your late night, you explained it and I decided to update all posts.
Thanks again for spending the night on explaining Plagiarism. Regrets again if I have added any more confusion or frustration. Hope it is corrected now.
Please continue to visit and I love to learn from your constructive criticism.

Post a Comment