Showing posts with label Transaction Log. Show all posts
Showing posts with label Transaction Log. Show all posts

Tuesday, 15 February 2011

When Is Data Written To Disc?

When you run a query in SQL, the first thing that happens, is SQL checks to see if the data pages that it needs to modify are currently in the Buffer Cache or not. It does this by reading an in-memory hash table, that records the dbid-fileno-pageno of each page that is in the cache at that time. You can see for yourself what pages are currently in your cache, by sys.dm_os_buffer_descriptors. If the pages are not in the cache, then it reads them in from disc.

Once all the required pages are in cache, SQL will begin an Implicit Transaction (if an Explicit Transaction is not already open for the statement). It will then perform the required operations on the page(s). If this was a DML operation, it will also mark them as being dirty. (This just means that they have changed in memory, without being written to disc). It also writes the transaction records to the log cache.

When the transaction (either implicit or explicit) commits, all transaction records, up to and including the commit, will be written to the log. There is a caveat here however; It is not just the log records from this specific transaction that are written. In order to make the transaction durable, SQL will also have to flush other log records that are intermingled with this transaction. It is also worthy of note, that SQL never writes individual log records, it always writes in blocks of between 512 bytes and 60 kb. This is called the "Log Block" and it's size is managed dynamically, internally.

This process is called write-ahead logging, or WAL, and ensures database consistency, but can cause a bottleneck, because SQL caps the amount of transactions that can be "in-flight". (This means that the Log Manager has issued a write, but an acknowledgement that the write has completed). The cap is different depending on your version of SQL, but in 2008, it is 3840KB, regardless of whether you are using a 32-bit or 64-bit version.

If this is causing a bottleneck, then you will notice lots of WRITELOG waits, when you query sys.dm_os_wait_stats. If this is the case, then you should try to optimize your transaction log. Details can be found in this post.

Once the log records have been committed to disc, then SQL is free to flush the "Dirty Pages" to disc. It does not do this straight away however. These dirty data pages are written to disc when the LazyWritter kicks in, or when a Checkpoint occurs.

A checkpoint occurs in a number of circumstances. Firstly, and most obviously, if you manually issue a checkpoint, when a backup starts, when the server is shut down (gracefully), or when an ALTER DATABASE statement is run. Also, if you are in Simple Recovery Model, a checkpoint will occur when your log is 70% full, or if you are in Full Recovery Model, a Checkpoint will run periodically, depending on your setting for recoveryinterval, which allows you to specify a target recovery time.

The LazyWriter process is a SQLOS thread, and it's role in life is to keep the Buffer Pool clean, with enough space to add new pages. It does this by periodically scanning the buffer cache and keeping track of how often a page is referenced. If it decides that it is no longer useful to keep a page in the cache, (using an algorithm that tracks how often a page is used and even what type of page it is) it checks to see if the page is "Dirty", if it is it writes it to the data file. It then marks the page as being "free" in a linked list. When a worker thread needs a page, it will choose one from this list.

Find my book, Pro SQL Server Administration on Amazon -

America

United Kingdom

Sunday, 6 February 2011

Optimizing You Log File

Optimizing your transaction log could easily fill a 50 page white paper, or a week's consultancy, but here are a few points to get you started:

How many physical log files?
This one is easy...One! Exactly one, always one, the answer is one! There is an urban myth that having multiple log files will improve performance, but this is just a myth. Log files are written sequentially, so if you have multiple files, it fills one, then fills the next one, etc. Pointless!

How many virtual log files?
This one is a bit more complicated. Your physical log file is managed internally with a series of virtual log files. See this post for more details. If you have too few, then the active portion of your log may be too large, leading to longer backup times. If you have too many VLFs however, this leads to "log fragmentation" and cause performance issues.

The general rule of thumb is to have VLFs sized at around 500MB. To achieve this, grow your log in 8000MB chunks. If you already have log fragmentation, the way to resolve it, is to shrink your log file (thus deleting the existing VLFs) and then grow it again, using the desired chunk size.

I/O Subsystem
This breaks down into two parts. Firstly, make sure that you put the log file on a separate physical disc to your data files. Otherwise you will get I/O contention.

The second part is a little more complex, and that is what RAID level should you use? Well, this depends on what features of SQL you are using. Before we begin, it may be beneficial to bring some context, by looking at the standard RAID levels, and how many IOs they generate.

RAID 1 - IOs = R + (W*2) / 2
RAID 5 - IOs = R + (W*4) / No Of Discs
RAID 10 - IOs = R + (W*2) / No Of Discs

If you are just using SQL Server at a basic level, then RAID 1 is a good choice. This is because almost all activity on the log will be write activity. The only read activity will be backups and restores. In this scenario, RAID 1 is better than RAID 5 because for every one write, there will be two physical writes to the volume with RAID 1, as opposed to 4 writes with RAID 5. It is also better than RAID 10 in this scenario, because RAID 1 will perform the operations as sequential IO, where as RAID 10 will perform them as random IO.

However, this recommendation changes if you are using some of the more advanced feature of SQL, especially the HA features. If you are using Database Mirroring, Replication or Log Shipping, then you are liable to have a much higher read to write ratio, and hence need better read performance, whilst maintaining write performance. In this scenario, RAID 5 is still a no-go, because you will double the number of physical writes for every write operation, from 2 to 4, as discussed above, so your best choice would be RAID 10. RAID 10 will maintain the 2 writes per write operation ratio, but also give you improved (and more scalable) read performance. This is because the the overall IOs will be divided by the number of discs in both RAID 1 & RAID 10, but in RAID 1, you always have exactly 2 discs, where as with RAID 10, you will have a minimum of 4, and as many as you require.

Log Manager Bottlenecks
One reason that your log can become a bottleneck, is because in SQL Server 2008, the Log Manager will only allow you to have 3840K of data that has been sent to be written, but where no acknowledgement of the write has been received back. Before SQL 2008, this limit was even lower.

Monitoring Log Performance
Within SQL, keep an on the sys.dm_os_wait_stats dmv. If you see lots of WRITELOG waits, then the log is probably coming under pressure.

In Perfmon, you should be monitoring the obvious disc counters for you log drive, such as Avg Disk Queue Length, Disk Writes/Sec, etc, but you should also keep track of the Log specific SQL counters. In particular, pay attention to Log Flushes/Sec and Log Flush Wait Time.

Together, these counters should give you an all-round idea of how your log is performing. From a performance aspect, the Log tends to be the forgotten relative, but be careful, as forgotten relatives have a nasty habit of turning up unexpectedly, and making a nuisance of themselves!

Find my book, Pro SQL Server Administration on Amazon -

America

United Kingdom

Tuesday, 11 January 2011

How many Virtual Log Files do I have?

As you may know, a physical log file is made up of multiple Virtual Log Files (or VLFs). This allows SQL to manage space and transactions effectively. In fact, when you truncate a log, you are not actually physically deleting any data, instead, you are simply marking a VLF as inactive, so that it can be reused, and if you shrink a log, the smallest size you can shrink it to, is the size of the active VLFs. By active VLF, we mean VLFs that contain open transactions.

This has the effect that when the end of the transaction log is reached, SQL moves back to the start of the log (The first inactive VLF) and begins to recycle. There is a misconception that if the loop of VLFs catches up with itself, you will receive a 9002 (Log full) error. This is incorrect. SQL will actually grow the log, thus creating additional VLFs, and "skip" the active VLFs. When the loop next goes round, the "skipped" VLFs we be reused as normal (Providing it has now been marked as inactive). The only exception to this rule is quite an obvious one...If the maximum size you have set for the log file has been reached, or the drive is full. Obviously, if either of those conditions are met, you will receive a 9002 error as you would expect.

So, back to the point of this post...How many VLFs do you have? Well, this depends on the initial size of the log when you created it, how many times it has grown and by what size, also if you have shrunk the log file.

The math for the number of VLFs is as follows:

When the log is first created, if the log is less than 64MB, there will be 4 VLFs, if the log is larger than 64MB and smaller than 1GB then there will be 8 VLFs, and if the log is larger than 1GB, then there will be 16 VLFs.

Then, every time the log grows, the same rules will be applied. If you grow the log by less than 64MB, SQL will create an additional 4 VLFs, if you grow the log by between 64MB and 1GB, then SQL will add 8 new VLFs, and growing the log by more than 1GB, will result in 16 VLFs being added.

As a performance consideration, it is generally recommended that you have less than 50 VLFs and it is recommended that you grow your log file 8000MB chunks, in order to keep your VLFs at around 500MB in size. You should specifically not grow you log by exactly 8GB (or exactly 8192MBs), as this exposes a bug, that calculates the size incorrectly if it grows in multiples of 4GB, that makes it grow less than 1MB at a time, and kills your database!

So, the big question...Is it possible to actually see how many VLFs you currently have, and how many are active, etc? Well, of course it is! You can do exactly that by using DBCC LOGINFO.

Firstly, I created the database with the following script...


...If we then examine DBCC LOGINFO



RecoveryUnitId
FileId
FileSize
StartOffset
FSeqNo
Status
Parity
CreateLSN
0
2
134152192
8192
34
2
64
0
0
2
134152192
134160384
0
0
0
0
0
2
134152192
268312576
0
0
0
0
0
2
134152192
402464768
0
0
0
0
0
2
134152192
536616960
0
0
0
0
0
2
134152192
670769152
0
0
0
0
0
2
134152192
804921344
0
0
0
0
0
2
134668288
939073536
0
0
0
0


...As you can see, 8 VLFs have been created, as you would expect. In this output, FileID is the ID of the physical log file, FileSize is the size of the VLF, StartOffset marks the beginning of the VLF in relation to the beginning of the physical Log, FSeqNo is the sequence number of the VLF, Status is set to 0 for inactive and 2 for active, (so if you were troubleshooting a log that would not truncate, one point of call would be to look in this columns for lots of 2s!), Parity is a parity bit column, and CreateLSN is the first LSN of the VLF. You may know that a description of RecoveryUnitID is conspicuous by it's absence. This is because is has only appeared in Denali, and tonight is the first time I have seen it, so more details to follow, but I suspect it ties in with the new HADR features!?! Watch This Space for updates!

Anyway, I digress...If we now increase the log size by an additional 8GB, (This will not expose the bug for me, as I am running Denali, and the bug is fixed in this release. If I were running on SQL 05 or 08, I would have increased by 8000MB), it will add 16 new VLF, giving us a total of 24. This means that we see the following results...



RecoveryUnitId
FileId
FileSize
StartOffset
FSeqNo
Status
Parity
CreateLSN
0
2
134152192
8192
34
2
64
0.00
0
2
134152192
134160384
0
0
0
0.00
0
2
134152192
268312576
0
0
0
0.00
0
2
134152192
402464768
0
0
0
0.00
0
2
134152192
536616960
0
0
0
0.00
0
2
134152192
670769152
0
0
0
0.00
0
2
134152192
804921344
0
0
0
0.00
0
2
134668288
939073536
0
0
0
0.00
0
2
536870912
1073741824
0
0
0
34000000006600000.00
0
2
536870912
1610612736
0
0
0
34000000006600000.00
0
2
536870912
2147483648
0
0
0
34000000006600000.00
0
2
536870912
2684354560
0
0
0
34000000006600000.00
0
2
536870912
3221225472
0
0
0
34000000006600000.00
0
2
536870912
3758096384
0
0
0
34000000006600000.00
0
2
536870912
4294967296
0
0
0
34000000006600000.00
0
2
536870912
4831838208
0
0
0
34000000006600000.00
0
2
536870912
5368709120
0
0
0
34000000006600000.00
0
2
536870912
5905580032
0
0
0
34000000006600000.00
0
2
536870912
6442450944
0
0
0
34000000006600000.00
0
2
536870912
6979321856
0
0
0
34000000006600000.00
0
2
536870912
7516192768
0
0
0
34000000006600000.00
0
2
536870912
8053063680
0
0
0
34000000006600000.00
0
2
536870912
8589934592
0
0
0
34000000006600000.00
0
2
536870912
9126805504
0
0
0
34000000006600000.00


...Finally, if we try to shrink the log file back down to 950MB, because we are just deleting inactive VLFs, we will end up with our original 4 VLFs, with the same original sizes, totaling 1GB, not 950MB...

RecoveryUnitId
FileId
FileSize
StartOffset
FSeqNo
Status
Parity
CreateLSN
0
2
134152192
8192
34
2
64
0.00
0
2
134152192
134160384
0
0
0
0.00
0
2
134152192
268312576
0
0
0
0.00
0
2
134152192
402464768
0
0
0
0.00
0
2
134152192
536616960
0
0
0
0.00
0
2
134152192
670769152
0
0
0
0.00
0
2
134152192
804921344
0
0
0
0.00
0
2
134668288
939073536
0
0
0
0.00


...Hope you found this useful, and I will post an update, with the meaning of RecoveryUnitID column, as soon as I have it, unless of course you already know, in which case, please post a comment!

CREATE DATABASE LogInfoTest
ON  PRIMARY
( NAME = N'instantinittest', FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL11.DENALI\MSSQL\DATA\loginfotest.mdf')

 LOG ON
( NAME = N'instantinittest_log', FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL11.DENALI\MSSQL\DATA\loginfotest_log.ldf' ,   SIZE = 1GB)

Find my book, Pro SQL Server Administration on Amazon -

America

United Kingdom