In this post we’ll look at how you can use Extended Events to track the activity of Ghost Cleanup inside of your SQL Server. To do this, we’ll first take a look at the ghost_cleanup Event and what it returns.

The ghost_cleanup Event is in the sqlserver Package and returns the file_id and page_id that the ghost cleanup process is working on. Since most SQL Servers have multiple databases, we probably will want to track the database_id through an Action as well. Since ghost cleanup is a background process, and we don’t know much about how it works, or how many Events are going to be generated, we could start off with the synchronous_event_counter Target, but in this case, I just want to capture Events and all of them, so we will just go with the asynchronous_file_target.

This is a really basic Event Session, it captures one Event, sqlserver.ghost_cleanup and collects the sqlserver.database_id Action when the Event fires. The Event data is captured by the package0.asynchronous_file_target, and the Event Session is configured to not allow Event Loss. After the starting the Event Session and allowing it to run, we can query the files for the captured events and see how ghost_cleanup is running on our instance.

From around 15 minutes of runtime on one of my development servers, over 17.5K Events have fired, much more than I initially anticipated, and after nearly 30 minutes of runtime, I had just over 37K Events.

Some interesting information can be found in the Events. In SQL Server 2008, the Ghost Cleanup process runs every 10 seconds, just as Paul has documented in his blog posts, which was a change from every 5 seconds in SQL Server 2005.

The process in 2008 cleans up 200 pages at a time, something Paul hasn’t specifically blogged about for SQL Server 2008. Before anyone debates this, Paul’s statement “It will check through or cleanup a limited number of pages each time it wakes up - I remember the limit is 10 pages - to ensure it doesn't swamp the system.” from his Inside the Storage Engine: Ghost cleanup in depth is based on SQL Server 2005, which also ran ghost cleanup every 5 seconds instead of 10 seconds. We can look at the Event information over subsequent 10 second intervals and see that 200 pages are cleaned up each time ghost_cleanup runs.

This has to be one of my favorite aspects of Extended Events. You get to really learn about SQL Server Internals by just playing with SQL Server. I have a couple more blog posts that show how you can learn about SQL Server Internals using Extended Events for this series, and if you are interested in a previous post on the subject check out TSQL Tuesday #11 – Physical IO’s Don’t Always Accumulate Wait Times.

Comments

It looks like even SQL 2005 was performing Ghost processing at 10 sec interval. You can see this using the SQL Profiler Transaction events which shows the Ghost Cleanup tran name. So it looks like both version have the same frequency.

What specific EventSubClass are you tracking in the Profiler TransactionLog Event for this? I spent about two hours tonight working back through my Ghost Cleanup Demo's and sample code to figure out what Log_op or Context you could be trying to key on and I give up. I can't see anyway that you can accurately track ghost cleanup operations through the TransactionLog Event in Profiler, or the sqlserver.transaction_log Event in Denali CTP1 Extended Events either. Each ghost_cleanup event fires off multiple Log operations and in tracing those out I see them occuring in non-ghost cleanup operations in the database as well.