SQL Server : Understanding Bulk Change Map (BCM) Page and Bulk Logged Recovery Model

SQL Server : Understanding Bulk Change Map (BCM) Page and Bulk Logged Recovery Model

In the last post , we have discussed about the Differential Change Map pages and how it is utilized in the differential backup process.In this post, let us try to understand the bulk change map page and how the bulk logged recovery model works.

Bulk Change Map(BCM): SQL Server uses Bulk Change Map (BCM) page to track extent modified by bulk logged operation since last backup log operation. BCM page is the 7th page in the data file.BCM has a bit for every extent it tracks. If the bit is 1, the corresponding extent is modified after the last log backup due to bulk logged operation, if the bit is 0, there is no change in the corresponding extent due to bulk logged operation after the last log backup.A BCM page can hold information of around 64000 extents. Precisely BCM pages repeat after every 511232 pages .One BCM page can track the changes of exactly 63904 extents.The second BCM page will be 511239th page.

You can see the BCM pages in all the databases, but they are only relevant when the database is in the bulk recovery model.In this recovery model, while taking log backup, SQL server scans the BCM page and include the extents that are marked as changed in the log backup along with transaction log.This helps SQL server to make bulk logged operation to be recoverable if the database is restored from database backup and a sequence of transaction log backups.In the bulk logged recovery model, bulk logged operation like BCP,Bulkinsert,Select Into are minimally logged in the transaction log and modified extents are tracked through the BCM pages.This helps SQL server to have optimized performance for bulk operations.

BCM pages are not relevant in simple recovery and full recovery model. In simple and full recovery model, the bulk logged operation are treated as fully logged operation. In short, in simple and bulk recovery model, BCM page will not keep track of the changes happened through bulk logged operations.

Let us try to understand with a sample.

CREATE DATABASE Mydb

GO

ALTER DATABASE Mydb SET RECOVERY BULK_LOGGED

BACKUP DATABASE Mydb TO DISK='D:\mydb.bak'

GO

DBCC TRACEON(3604)

DBCC PAGE('MYDB',1,7,3)

From the output ,it is clear that none of the extents are changed due to bulk logged operations. Let us try to perform a bulk logged operation.

SELECT * INTO mydb..SalesOrderDetail FROM AdventureWorks2008.sales.SalesOrderDetail

DBCC PAGE('MYDB',1,6,3)

Now in the output, you can see two entries marked as MIN_LOGGED.The first one is due to the change in the IAM page and second one is the actual data inserted as part of Select Into operation.Now when we take a log backup, SQL server backups the transaction log changes along with extent marked as changed in the BCM file. After the log backup, the bits in the BCM pages are flipped to mark there is no extent changed due to the bulk logged operation. Let us take the log backup.

BACKUP LOG Mydb TO DISK='D:\mydblog.trn'

GO

DBCC PAGE('MYDB',1,7,3)

From the output, we can see that SQL server flipped the bit in BCM page and none of the extents are marked as changed due to the bulk logged operation. Note that BCM pages are not cleared by taking a full backup or differential backup.The base of the transaction log backups is the previous transaction log backup. SQL server should know what changes are happened between two transnational log backup.If a differential or full backup cleared the BCM page,next transaction log backup can not track/recover the changes between the previous log backup and full/differential backup. In short a full backup or differential backup will not break the transaction log backup chain. 

SQL Server :Part 1 : Architecture of Transaction Log

SQL Server :Part 1 : Architecture of Transaction Log

In our earlier post, we have discussed in detail about the architecture of the data file and different types of pages. In this post, we will be discussing about the architecture of log file.

Logging is a mechanism used in RDBMS to support various ACID (Atomicity,Consistency,Isolation and Durability) properties of transactions. A transaction log is a physical file in which SQL server stores the details of all transactions and data modifications performed on the database.In the event of of disaster, that causes SQL server to shutdown unexpectedly (Power failure/hardware failure), the transaction log is used to bring the database in a consistent state while restarting the server.On restarting the server, database goes through the recovery process.During this recovery process , the transaction log is used to make sure that all committed transactions are written to respective data pages (rolled forward) and revert the uncommitted transaction that were written to data pages.

Logically transaction log is a set of log records.Each records is identified by a log sequence number (LSN). The new log records is always written at the logical end of log file with a LSN which is greater than the previous one.Each LSN will be associated with a transaction id , which can be used to group the log records of a transaction. As log file store the log records in the sequential order as it happens, It is not necessary that, log records of a transaction are always available in sequence in the log file.Each log records will have the LSN of previous log as a backward pointer and that will help in rollback of transaction.

Transaction log will store separate log entries for each operation.For example, while inserting a record into a table, transaction log will store separate log entry for inserting into clustered index and other non clustered index. In the same way, if a single update statement is updating 10 records, transaction log will capture 10 separate log entries.For data modification, transaction log store either the logical operation performed or the before and after image of the record.

To understand it better, let us look into the transaction log using the sys.fn_dblog. It is an undocumented function which will help us to read the active portion of the log. we are using the below query to create two tables and insert some records into that.We will delete the records from these table to keep the table clean. This insert and delete operation is to make sure that the pages are allocated to the table and we will not get unnecessary entries in the transaction log while examining it.We have issued a manual checkpoint to force the SQL server to write the log information to data file and clear the log. Note that, one table is heap table and other one is clustered index table.

USE Mydb

GO

CREATE TABLE LoginfoHeap

(
   id INT)


GO

CREATE TABLE LoginfoCI

(
   id INT PRIMARY KEY)


INSERT INTO LoginfoHeap VALUES(1),(2)

INSERT INTO LoginfoCI VALUES(2),(4)

GO

DELETE FROM LoginfoHeap 

DELETE FROM LoginfoCI

GO

CHECKPOINT

GO

SELECT 
[Current LSN], 
Operation  ,Context    ,
[Transaction ID],
[Previous LSN],AllocUnitName,[
Previous Page LSN],
[Page ID],[XACT ID],SUSER_SNAME(CONVERT(VARBINARY,[Transaction SID])) AS 'Login',
[Begin Time],[End Time]
FROM sys.fn_dblog (NULL, NULL)







From the output it is very clear that , we have only two active log entries.First one is written ,when the checkpoint started. The second one is written,  when the checkpoint completed the process.

Now we will insert,update and delete records to these tables through two session 

---SESSION I
   BEGIN TRAN
   INSERT INTO LoginfoCI VALUES(2)

--SESSION 2
   BEGIN TRAN
   INSERT INTO LoginfoHeap VALUES(1),(2)

---SESSION I
   INSERT INTO LoginfoCI VALUES(4)

--SESSION 2
   UPDATE LoginfoHeap   SET id =8 WHERE id=1

---SESSION I
   UPDATE LoginfoCI  SET id =6 WHERE id=2

--SESSION 2
   DELETE FROM LoginfoHeap    WHERE id=2

---SESSION I
   DELETE FROM LoginfoCI   WHERE id=4
   SELECT * FROM sys.dm_tran_current_transaction
   COMMIT

--SESSION 2
   SELECT * FROM sys.dm_tran_current_transaction
   COMMIT

The DMV sys.dm_tran_current_transcation returns a single row that displays the state information of the current transaction in the current session.We are interested only in the transaction_id, which will help us to filter the output of sys.fn_dblog. Let us see the output of sys.fn_dblog.

SELECT 
[Current LSN], 
Operation  ,
Context    ,
[Transaction ID],
[Previous LSN],
AllocUnitName,
[Previous Page LSN],
[Page ID],[XACT ID],
SUSER_SNAME(CONVERT(VARBINARY,[Transaction SID])) AS 'Login',
[Begin Time],
[End Time]
FROM sys.fn_dblog (NULL, NULL) 
WHERE [Transaction ID] IN 
(
   SELECT [Transaction ID] FROM sys.fn_dblog (NULL, NULL) 
   WHERE [XACT ID] IN (856960,856981)
)

The values 856960 and 856981 are the transaction_id returned from sys.dm_tran_current_transaction.We have filter the output to get only the relevant rows in which we are interested.

In our script, we have opened two transaction and all our transaction log entries are grouped to 
one of these transaction_id marked in red and green.Let us analyse what we did and how it is captured in the transaction log.

In the session 1, we have started the transaction and inserted a single record.The first records in the output map to the BEGIN TRAN command. This is the starting point of the transaction and created a new transaction_id.The previous LSNcolumn value is 0 as this is the first log entry in this transaction.In the same log records,it stores the XACT_ID,login and transaction start time.The second record represent the insert into the clustered table.The transaction_id is used to group the entries associated with a transaction. The previouse LSN column, is a pointer to the previous log entry in the same transaction which help SQL server to move backwards in case of rollback.Page id column refer the the page number where this LSN made the change.Previous Page LSN column refer the last log sequence number(LSN) which modify this page.When LSN modify a page, it will also update the corresponding LSN number in the page header (m_lsn field in the header. For more detail refer this post)

In the session 2, we have opened another transaction and inserted two records through single insert statement to the heap table. You can map these operations to row number 3,4, and 5 in the transaction log output. Third row represent the Begin tran command. Even if we inserted two records in single insert statement , SQL server recorded two separate entry in the transaction log. 

As a next step, in session 1 we have added 1 record to the clustered index table.We can map this operation to the 6th record in the transaction log output.

In the next statement , we have modified a record in heap table through Session 2. You can map this to the 7th record in the transaction log output.If you look into the previous LSN column , it will be current LSN column value of the last record associated with this transaction.

In the same way, as a next statement we have modified a record in the clustered table through session 1. We can map the 8th and 9th records in the transaction log output to the update operation on the clustered table. You might have noticed that, when we modified a record in the heap table, transaction log recorded operation in a single row. Where as the same operation in a clustered table has two record in the transaction log. One for delete and other one for insert. When you modify the clustered index key, SQL server internally delete the existing record and insert a new record. This is because, the record need to be stored in the new location based on the modified value(based on the order of clustered index column). The easiest way for SQL server to achieve this is , delete the existing record and insert it as new records with modified clustered column value.

In the next two statement, we are deleting one record from heap table and clustered table.This can be mapped to the 10th and 11th records in the output.Finally we have issued the commit statement in both sessions.12th and 13th record in the transaction log output can be mapped to the commit operation.The Previous LSN column refer the Current LSN column of corresponding  begin tran statement. It will also capture the transaction end time in the End time column.

Understanding the VLF(Virtual Log File)

A database can have one or more log file. In general there will be only one log file as there is no performance improvement by having multiple log file. SQL server uses the transaction log in sequential manner.As the data file divided into pages,log files are divided into virtual log file(VLF).The size of the VLFs  in a log file may not be in equal size. SQL server decide the size and number of VLF in a log file based on the size of the log file growth as given below.

Growth upto 64 MB          = 4  VLF

From 64 MB to 1 GB       = 8   VLF

Larger than 1 GB             = 16 VLF

Let us create a database with 64 MB initial log size and later increase it to 1 GB. As per above calculation the log file should have 12 VLFs.  4 VLF based on initial size and 8 VLF due to changing the log size to 1 GB.

USE MASTER;
GO
CREATE DATABASE Mydb
ON 
(      NAME = MyDb_dat,  FILENAME = 'D:\MyDb\Mydb.mdf',
       SIZE = 10MB, MAXSIZE = 3072MB,   FILEGROWTH = 5MB )

LOG ON ( NAME = MyDb_log,FILENAME = 'D:\MyDb\MyDB.ldf',
    SIZE = 64MB, MAXSIZE = 2048MB, FILEGROWTH = 5MB ) ;
GO

ALTER DATABASE Mydb 
MODIFY FILE ( NAME = MyDb_Log,FILENAME = 'D:\MyDb\MyDB.ldf',    SIZE = 1024MB)

Now Let us see how many VLF got created. To find out the number of VLF in database log file, we can make use of DBCC Loginfo.

DBCC loginfo('mydb')

The output is given below.















There are 12  records in the output each represent a VLF.Let us try to understand the result

FileId: This is the file id of the log file and will be same for all 12 records as we have only one log file.If we have multiple log file , we can multiple numbers here

FileSize: This is the size of the VLF. If you look into the first four, have same size except the fourth one. This because first 8KB of the log file is used for file header. If you add filesize value of first four records along with 8192(8KB) , you will get 64MB which is the initial size of the log file.

16711680+16711680+16711680+16965632 =67100672+8192 =67108864bytes =64MB

In the same if you add the last 8 records it will account the 960 MB (1024-64) , the growth happened due to the alter statement.

StartOffSet: This values is also in bytes, and is the sort column of the output. The first VLF alwasy start from 8192, which is the number of bytes in a page.As mentioned above, the first 8KB is used for file header and will not store any log.

FSeqNo: The file sequence number indicates the order of usage of the VLFs. The row with the highest FSeqNo value is the VLF where current log records are being written.FSeqNo values are not consistent. It will keep changing each time when VLF are getting reused. We will discuss more about this later in this post. A value of 0 in this column means that this VLF has never been used at all. That is the reason we have 0 for all records except one where it is currently logging.

Status: Status has two possible values : 0 and 2. A value of 2 means the VLF is not reusable and a value 0 means it can be reused.It will be more clear as we go further.

Parity: Parity has three possible values 0 ,64 and 128. If the VLF is not used yet, it will have a value 0 and will be set to 64 on first use.Every time a VLF is reused, the parity value is switched between 64 and 128.

CreateLSN: The value indicates when the VLF is created or to group the VLF based on the creation. A values 0 indicates, those VLFs are created as part of database creation. In our case first four records has a value 0 which indicate these VLFs are created as part of database creation with 64MB log size. The remaining 8 records has the same value. These VLF are created as part of our alter database statement to increase the size of the log file from 64 MB to 1024MB

The above output description is referred from Kalen Delaney Blog Post

Now our transaction log will looks like below

Now we have learned about the LSN and VLF. we will discuss more about transaction log in the next post.

 

The following DMV query can be used to pull detail information about indexes.

/*********************************************************************************

Script: Index Fragmentation Status (includes Partitioned Tables/Indexes)

**********************************************************************************/

select schema_name(o.schema_id) as [schema_name] ,

object_name(o.object_id) as [table_name] ,

i.name as [index_name] ,

i.type_desc as [index_type] ,

dmv.page_count ,

dmv.fragment_count ,

round(dmv.avg_fragment_size_in_pages,2, 2) [avg_fragment_size_in_pages] ,

round(dmv.avg_fragmentation_in_percent,2, 2) [avg_fragmentation_in_percent] ,

case when dmv.avg_fragmentation_in_percent <=5 then 'RELAX'

when dmv.avg_fragmentation_in_percent<= 30 then 'REORGANIZE'

when dmv.avg_fragmentation_in_percent> 30 then 'REBUILD'

end as [action] ,

stats_date(dmv.object_id, i.index_id) as stats_update_date ,

case when isnull(ps.function_id, 1) = 1 then 'NO'

else 'YES'

end as partitioned ,

coalesce(fg.name, fgp.name) as [file_group_name] ,

p.partition_number as [partition_number] ,

p.rows as [partition_rows] ,

prv_left.value as [partition_lower_boundary_value] ,

prv_right.value as [partition_upper_boundary_value] ,

case when pf.boundary_value_on_right =1 then 'RIGHT'

when pf.boundary_value_on_right= 0 then 'LEFT'

else 'NONE'

end as [partition_range] ,

pf.name as [partition_function] ,

ds.name as [partition_scheme]

from sys.partitions as p with ( readpast )

inner join sys.indexes as i with ( readpast ) on i.object_id = p.object_id

and i.index_id = p.index_id

inner join sys.objects as o with ( readpast ) on o.object_id = i.object_id

inner join sys.dm_db_index_physical_stats(db_id(), null, null, null,

N'LIMITED')dmv on dmv.OBJECT_ID = i.object_id

and dmv.index_id = i.index_id

and dmv.partition_number = p.partition_number

left join sys.data_spaces as ds with ( readpast ) on ds.data_space_id = i.data_space_id

left join sys.partition_schemes asps with ( readpast ) on ps.data_space_id = ds.data_space_id

left join sys.partition_functions aspf with ( readpast ) on pf.function_id = ps.function_id

left join sys.destination_data_spaces asdds with ( readpast ) on dds.partition_scheme_id =ps.data_space_id

and dds.destination_id = p.partition_number

left join sys.filegroups as fg with ( readpast ) on fg.data_space_id = i.data_space_id

left join sys.filegroups as fgp with ( readpast ) on fgp.data_space_id = dds.data_space_id

left join sys.partition_range_values asprv_left with ( readpast ) on ps.function_id = prv_left.function_id

and prv_left.boundary_id = p.partition_number

- 1

left join sys.partition_range_values asprv_right with ( readpast ) on ps.function_id = prv_right.function_id

and prv_right.boundary_id = p.partition_number

where objectproperty(p.object_id, 'ISMSShipped') = 0

order by [avg_fragmentation_in_percent] DESC,

[table_name] ,

[index_name]