How to repro a scenario for log-clearing the log in SIMPLE recovery model

How to repro a scenario for log-clearing the log in SIMPLE recovery model

I tried to repro a scenario for log-clearing the log in SIMPLE recovery model. I know if there is an ACTIVE TXN, and if we issue a CHECKPOINT in SIMPLE recovery model, nothing happens i.e. 0 VLFs gets cleared in my below scenario. But i commited my explicit transaction, still log_reuse_wait_Desc is showing ACTIVE TRANSACTION and log is not getting cleared. I repro'd the same scenario by inserting records using a WHILE-Loop and it works as expected but when I use GO <n-times> to insert records, the txn is still open. Can anyone figure-out why log is not getting cleared or do i missing something over here ???

My SQL Server details

=============
Microsoft SQL Server 2008 (SP3) - 10.0.5500.0 (X64)  

 

Below is my repro steps. Pl don't go with the output values as I have done multiple times but no use. Log doesn't get cleared. Just follow my steps/cmds and you should be able to reproduce the same.

 

 

USE [master]
GO
CREATE DATABASE [db1]
 ON  PRIMARY
( NAME = N'db1',
 FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\DATA\db1.mdf' ,
 SIZE = 10MB ,
 MAXSIZE = UNLIMITED,
 FILEGROWTH = 1MB )
 LOG ON
( NAME = N'db1_log',
FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\DATA\db1_log.LDF',
SIZE = 3MB , ---4 VLFs since size < 64mb
FILEGROWTH = 1MB)
GO

ALTER DATABASE db1 SET RECOVERY SIMPLE;
GO
DBCC LOGINFO(db1)
GO

/*
FileId    FileSize    StartOffset    FSeqNo    Status    Parity    CreateLSN
2        720896        8192        22        2        64        0
2        720896        729088        0        0        0        0
2        720896        1449984        0        0        0        0
2        974848        2170880        0        0        0        0
*/


USE db1
GO
CREATE TABLE t1
(C1 INT IDENTITY,
C2 CHAR (8000) DEFAULT 'a'  --- char datatype takes all the size even 1 char is inserted. use DATALENGTH() Function
);
GO


-- i opened a new session/window/spid in the ssms and started the below explicit transaction
BEGIN TRAN
    INSERT INTO t1 DEFAULT VALUES
    GO 600


-- I came back to original window where i created the database

dbcc loginfo(db1);


select recovery_model_desc,log_reuse_wait_desc
from sys.databases
where name = 'db1' ;

/*
recovery_model_desc        log_reuse_wait_desc
SIMPLE                    ACTIVE_TRANSACTION 
*/

dbcc opentran(db1);

/*
Transaction information for database 'db1'.

Oldest active transaction:
    SPID (server process ID): 57
    UID (user ID) : -1
    Name          : user_transaction
    LSN           : (22:63:2)
    Start time    : Aug 19 2013  9:54:32:103PM
    SID           : 0x0105000000000005150000007a6fe3176386abd260a96a96e8030000
DBCC execution completed. If DBCC printed error messages, contact your system administrator.

*/

-- I confirmed from log there is 1 Active txn
 Select [Current LSN],[Operation],         
        [Num Transactions]
        from fn_dblog(null,null)     
        where Operation in ('LOP_XACT_CKPT','LOP_XACT_CKPT','LOP_END_CKPT')
       
/*
Current     LSN            Operation        Num Transactions   
00000016:0000002e:0001    LOP_XACT_CKPT    1                   
00000016:0000002e:0002    LOP_END_CKPT    NULL               
*/

-- i went to new window and committed the explcit transaction
 COMMIT;
 
 
-- Came back to old window
CHECKPOINT; --to clear the log


dbcc loginfo(db1);
-- All are active (Status=2). none of the VLFs have been made inactive

select recovery_model_desc,log_reuse_wait_desc
from sys.databases
where name = 'db1';
/*
SIMPLE    ACTIVE_TRANSACTION
*/
dbcc opentran(db1);
/*
Transaction information for database 'db1'.

Oldest active transaction:
    SPID (server process ID): 57
    UID (user ID) : -1
    Name          : user_transaction
    LSN           : (22:63:2)
    Start time    : Aug 19 2013  9:54:32:103PM
*/


checkpoint;
go
Select [Current LSN],[Operation],         
        [Num Transactions]
        from fn_dblog(null,null)     
        where Operation in ('LOP_XACT_CKPT','LOP_XACT_CKPT','LOP_END_CKPT')
go
/*
Current LSN    Operation    Num Transactions
00000022:000001af:0001    LOP_XACT_CKPT    1
00000022:000001af:0002    LOP_END_CKPT    NULL
00000022:000001b1:0001    LOP_XACT_CKPT    1
00000022:000001b1:0002    LOP_END_CKPT    NULL
*/

-- Though i committed the Explicit open txn, why is it still Active and not allowing VLF's to clear.
Can anyone pl let me know what is that I am missing here?

Your problem is you opened 600 transactions and you only closed 1, you still have 599 open.

The command:

GOBEGIN TRAN
     INSERT INTO t1 DEFAULT VALUES
     GO 600Did not run the INSERT 600 times. It runs the BATCH 600 times, which includes the BEGIN TRAN.

Run this:

-- now I am committing the explicit txn
 WHILE @@TRANCOUNT> 0
  COMMIT;

The issue is that your test is still invalid as you have open transactions:


BEGIN TRAN

INSERT INTO t1 DEFAULT VALUES

GO 600

In your code, above, you've opened up 600 transactions (you've executed this batch 600 times so 600 transactions have been created). You've then issues a single commit, which decrements the transaction count to 599 (commits take off 1 transaction count). Since the count is still not 0, open transactions exist. You can use SELECT @@TRANCOUNT to verify.

The problem is the test is invalid. If you want to make the test valid, run the begin tran and then run the insert with the go operator so that you have a SINGLE transaction and not 600.

Copyright © 2007-2012 www.chuibin.com Chuibin Copyright