I was asked on Friday, “how do you tell if a database logging mode is reporting bulk or full, but it is still in simple?” – as mentioned before, a database is not in really full / bulk logged unless a full backup has been taken. Until that time the database is still running in a simple mode, sometimes referred to as pseudo-simple. It is not easy to spot, because the properties of the database will report full / bulk as appropriate and give no indication that it is not actually logging in the way it says.
The existence of a backup of the database is not a reliable enough mechanism for this, since the database can be backed up and then moved out of full / bulk logged mode into simple and back again. This breaks the backup and transaction log chain, but the database is still reporting full – to make it worse there is a backup record showing on the history, giving it an air of legitimacy.
The backup records can be accessed from the sys.sysdatabases and msdb.dbo.backupset, MSDN even has an example script showing how to see when a database was last backed up and by whom.
SELECT T1.Name as DatabaseName, COALESCE(Convert(varchar(12), MAX(T2.backup_finish_date), 101),'Not Yet Taken') as LastBackUpTaken, COALESCE(Convert(varchar(12), MAX(T2.user_name), 101),'NA') as UserName FROM sys.sysdatabases T1 LEFT OUTER JOIN msdb.dbo.backupset T2 ON T2.database_name = T1.name GROUP BY T1.Name ORDER BY T1.Name
To play around with the scripts you probably want a test database:
CREATE DATABASE [LogModeTest] ON PRIMARY ( NAME = N'LogModeTest', FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\DATA\LogModeTest.mdf' , SIZE = 3072KB , MAXSIZE = UNLIMITED, FILEGROWTH = 1024KB ) LOG ON ( NAME = N'LogModeTest_log', FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\DATA\LogModeTest_log.ldf' , SIZE = 1024KB , MAXSIZE = 2048GB , FILEGROWTH = 10%) COLLATE Latin1_General_CI_AI
With a minor alteration to the MSDN script you can get the backup history for this database:
SELECT T1.Name as DatabaseName, COALESCE(Convert(varchar(12), MAX(T2.backup_finish_date), 101),'Not Yet Taken') as LastBackUpTaken FROM sys.sysdatabases T1 LEFT OUTER JOIN msdb.dbo.backupset T2 ON T2.database_name = T1.name WHERE T1.Name = 'LogModeTest' GROUP BY T1.Name
The results show the database is not yet backed up:
DatabaseName LastBackUpTaken ----------------------------- --------------- LogModeTest Not Yet Taken
That is easy to fix, so let’s take a backup of the database and recheck the last backup value.
BACKUP DATABASE [LogModeTest] TO DISK = N'C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\Backup\LogModeTest.bak' WITH NOFORMAT, NOINIT, NAME = N'LogModeTest-Full Database Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10 DatabaseName LastBackUpTaken ------------------------------ --------------- LogModeTest 12/13/2009
As expected the date of the backup is now set. If we alter the logging mode of the database to simple we will break the transaction log chain. To demonstrate the backup information being an unreliable source, let’s change to simple, create a table and then return to the fully logged mode.
ALTER DATABASE [LogModeTest] SET RECOVERY SIMPLE WITH NO_WAIT CREATE TABLE foo(id int identity) ALTER DATABASE [LogModeTest] SET RECOVERY FULL WITH NO_WAIT
If we now attempt to backup the transaction log, SQL is going to throw an error.
BACKUP LOG [LogModeTest] TO DISK = N'C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\Backup\LogModeTest.bak' WITH NOFORMAT, NOINIT, NAME = N'LogModeTest-Transaction Log Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10 Msg 4214, Level 16, State 1, Line 1 BACKUP LOG cannot be performed because there is no current database backup. Msg 3013, Level 16, State 1, Line 1 BACKUP LOG is terminating abnormally.
And if we check the database backup history using the MSDN script:
DatabaseName LastBackUpTaken ------------------------------ --------------- LogModeTest 12/13/2009
So the backup history continues to show a date of the last full backup even though the transaction log chain is now broken. SQL certainly knows the database has not had a full backup since swapping into fully logged mode, so any transaction log backup is invalid, thus the error.
There is an easier way to find out that you are in pseudo-simple mode, without trying to perform a transaction log backup:
SELECT name, COALESCE(Convert(varchar(30),last_log_backup_lsn), 'No Full Backup Taken') as BackupLSN FROM sys.databases INNER JOIN sys.database_recovery_status on sys.databases.database_id = sys.database_recovery_status.database_id
Run this against your server and it lists the databases that have had a backup taken (by the existence of a backup LSN) and which have not had a full backup that could be used in recovery. If we then backup the database and recheck the values, the test database now records an LSN, showing it is out of psuedo-simple and into the full / bulk logged modes.
So that indicates whether we are in pseudo simple or not, but does not link back to the properties of the database to check what is the actual database logging mode – you are primarily only interested in databases that are not in simple mode in the first place, but are running in psuedo-simple due to the lack of a relevant full database backup. We can alter the query to handle this specific situation and the result is:
SELECT name, recovery_model_desc, COALESCE(Convert(varchar(30),last_log_backup_lsn), 'No Full Backup Taken') as BackupLSN FROM sys.databases INNER JOIN sys.database_recovery_status on sys.databases.database_id = sys.database_recovery_status.database_id WHERE sys.databases.recovery_model <> 3 AND last_log_backup_lsn is null
If you run that query against your database server and get any results then you have databases that are not running the recovery mode they are indicating / you that you think they are – which would generally not be a good thing.
Somewhat of a ‘doh’ moment when dealing with a SQL server in bulk logged mode, the transaction log was behaving very weirdly and growing very large for smaller index operations. When performing an additional operation, the actual percentage of log space used went down, and it was a repeatable test. At no point would you expect an operation to actually result in the log space showing as less space used. So something was up with the scenario, and I was asked to check it.
In bulk logged mode index creations are classed as a minimally logged operation, whether online or offline, and a drop index is a bit of a mixture, the index page deallocation is fully logged, but the heap rebuild is listed as a minimally logged operation. There was no obvious reason why the database was behaving as it was.
The steps to recreate this situation on your own computrer / server are rather simple, create a database for testing purposes and preallocated the log space as 200Meg. The database was set to bulk logged mode. I then created a basic table:
create table [tblOnlineIndexTest] ( id int, padding char(500) )
The table does not have a primary key so a uniquifier will be created, which we are not worried about. To create a number of rows, I simply ran the following SQL to generate some data, just over 60 meg of it.
insert into tblOnlineIndexTest (id, padding) values (1, REPLICATE('a',100)) go 100000
To check the log space, I used the DBCC command:
26.28% is used. The next step was the creation of a clustered index on the table:
create clustered index [PK_tblOnlineIndexTest] on [tblOnlineIndexTest] (id) WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, ONLINE = ON, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [primary]
The log was checked again and the space used was 21.34%. I twigged the underlying issue at this point, but continued to test a bit more to be sure.
Next I dropped the index and the log space jumped up to 53.27% of the total log space, and the log had grown in size, even though it was not at 100% of the space. The log has to reserve undo space in advance of the transaction to make sure it can always record an undo, so that a rollback does not get stopped by the transaction log being full / having no space left.
Last step was to recreate the same index and this time the log space dropped to 2.23% but the actual log file has grown by 66 Meg at this point. So the log got larger, but the actual amount of data in it was smaller.
The problem was a simple one, the database was not actually in bulk logged mode, just like a database set as ‘full’ logging, until the first full database backup is taken, the database is still in the simple logging mode. A transaction log has to be replayed against a starting position of a full backup, so the lack of a full backup on the database automatically prevents the bulk logging mode from actually being active.
When I was presented the initial problem to look at, I did not asked whether the initial database backup had been taken – I assumed it had been which was clearly a bad assumption. Whilst the SQL Server identified itself in bulk logged mode, the actual reality was that it was in simple mode so the transaction log will be automatically clearing down committed transactions from the log and reusing the space. Just because the database says it is in bulk logged or full modes, does not mean it actually is yet.