Transaction not getting cleared in SIMPLE recovery model ?

  • Hi,

    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?

    Thanks in advance.

  • I see where you start an explicit transaction (BEGIN TRANSACTION), but I don't see where you commit or rollback the transaction(s) (COMMIT or ROLLBACK).

    If you start an explicit transaction you have to commit or roll back that transaction explicitly.

    I am curious if you actually have 600 separate transactions open using the GO 600. Which means you may need to issue 600 COMMITs.

  • You began the transaction 600 times (GO 600), hence you need 600 commits to actually commit that transaction. Or one rollback to undo it.

    May I suggest...

    BEGIN TRANSACTION

    GO

    INSERT INTO t1 DEFAULT VALUES

    GO 600

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Hi Gail,

    You are right on! Thanks very much for the help. I verified the fn_dblog().

    Select [spid],[Current LSN],[Operation],[Context],[Previous LSN],

    [Transaction Name], [Begin Time] as [Transaction Begin Time],[End Time] as [Transaction End Time],

    [AllocUnitId],[AllocUnitName]

    [Page ID],[Slot ID],[Previous Page LSN],

    [Description]

    from fn_dblog(null,null)

    where Operation in ('LOP_BEGIN_XACT','LOP_INSERT_ROWS');

    Thanks Again.

  • Hi Lynn,

    You are right. It opened 600 separate txns. Once I made the change suggested by Gail, I was able to clear the log.

    Select [spid],[Current LSN],[Operation],[Context],[Previous LSN],

    [Transaction Name], [Begin Time] as [Transaction Begin Time],[End Time] as [Transaction End Time],

    [AllocUnitId],[AllocUnitName]

    [Page ID],[Slot ID],[Previous Page LSN],

    [Description]

    from fn_dblog(null,null)

    where Operation in ('LOP_BEGIN_XACT','LOP_INSERT_ROWS');

    But one thing, I am little confused was , as far as I know, the checkpoint should hold the list of all un-committed transactions. But, I do see as only 1 transaction.

    checkpoint; -- doesn't clear anything

    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:000000b3:0001LOP_XACT_CKPT 1

    00000016:000000b3:0002LOP_END_CKPT NULL

    */

    Is that something wrong been shown for nested transactions ?? Any thoughts Gail ?

  • There's no such thing as a nested transaction. It's a syntactical lie, they don't actually exist.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Thanks for the clarification.

Viewing 7 posts - 1 through 6 (of 6 total)

You must be logged in to reply to this topic. Login to reply