Determining the source of full transaction logs in SQL Server

Many DBAs at some point have had to deal with a full transaction log. Check out these steps for finding the cause to quickly solve the problem.

This Content Component encountered an error

A full transaction log is a sporadic, yet common problem for SQL Server DBAs. It can cause a transaction to be terminated prematurely, or even take a system down by blocking all incoming transactions. The key for DBAs is to understand what's going on so they can track down the course of the problem.

Ways transaction logs can fill up

Here are some possible causes of full transaction logs:

  1. Full, differential, or log backups have not occurred on the database in full recovery mode, causing the log to gradually fill up.
  2. An active backup is in process (backups are treated like transactions), which fill up a portion of the log while concurrent transactions fill up the remainder.
  3. An active transaction might be long running, such as an SPID that never issues a commit. Paused or high-performance with database mirroring can cause delays. The former causes transactions to not send, while the latter will only occur if the high-performance is significantly behind in sending its transactions to the mirror server.
  4. With transactional replication, if replication is behind or failing, the transaction log will not clear because transactions are not allowed to be flushed unless they are both committed and sent to the distribution database.
  5. If a database snapshot is in process, all transactions can pile in behind it while the snapshot is created.

Simple ways to respond

You have the following options to start with when troubleshooting a full transaction log:

  1. You can perform a backup to truncate the log. A transaction log backup would be fastest, but that could still be too slow depending on how critical the system is and the size of the log. A full or differential backup is normally ill-advised due to the time required to complete these on moderate-large systems.
  2. You can add additional transaction log files to the database and then perform one of the backups above. The addition of another transaction log file will buy you additional time while you run the necessary backups. It can also be removed later.
  3. You can switch the database into simple recovery mode, which will truncate the log automatically. Just remember that you will lose your transaction history since the last full/differential/transaction log backup.
  4. An active transaction that is filling up the log can be killed with some SPID, in the hope that it will not execute again and fill up the log. It will provide some intermediate relief while the source of the issue is tracked down, but should not be considered a resolution.
  5. Database mirroring/replication can be turned off while the source of the slow-down is investigated.

Determining the root cause

When folks from Microsoft discuss ways to mitigate the issue of full transaction logs, they typically review it from the standpoint of responding to the problem. Microsoft normally doesn't help you learn to investigate and resolve code issues that potentially are at the root of the issue.

Let's assume we run two transactions on a database... m1 and n2:

Transaction 1

begin tran m1

updatetbl
set f1 = f1 + f1

update tbl
set f1 = f1 + f1

update tbl
set f1 = f1 + f1

-- rollback tran m1

Transaction 2

begin tran n2

update tblm
set txtval =  Convert(varchar(4000), txtval + txtval)

update tblm
set txtval =  Convert(varchar(4000), txtval + txtval)

update tblm
set txtval =  Convertvarchar(4000), txtval + txtval)

--rollback tran n2

First of all, I want to draw attention to the names of the above transactions (m1 and n2). You will find that if you name your transactions, it's easier to track them in the system and trace them back to the source of the issue. I also find it easier for readability purposes. Note that I didn't commit or rollback the transactions -- you would see the same functionality if the application was controlling the transactions.

Running the following SQL code will get the list of currently active transactions:

select * from  sys.dm_tran_active_transactions

Result

(Click to enlarge)

The two transactions we are currently running show up in the list with their corresponding names, which makes them very easy to identify. It's simple to tell from this screen when the transaction started, so you can see if it's old and if an application, job, etc. might be allowing it to hang without a commit or rollback. In the transaction_type column, 1 is "read/write", 2 is "read-only", 3 is "system" and 4 is "distributed". Typically, the transactions that fill up the log will be 1, but that depends on the source of the logs filling up. If the logs are filled up by user processes, they will be type 1.

sys.dm_tran_session_transactions --Associates the transaction ids from the active transactions listing to active SPIDs

sys.dm_tran_database_transactions -- Lists the associated database with the transactions if you only want to look at one database. It also lists the state/status. Database transaction state: 1 not initialized yet, 3 initialized with no log records, 4 generated logs, 5 transaction prepared, 10 transaction committed, 11 transaction rolled back, 12 transaction is in the process of being committed.

Considering that a full transaction log is due to active log entries that are consuming space, states 4 or 12 will be the only ones that consume log space.

The database_transaction_log_record_count column will indicate the log records being taken up and database_transaction_replicate_record_count will indicate the log records that are waiting to be replicated. Database_transaction_log_bytes_used will indicate how much space is currently used and
Database_transaction_log_bytes_reserved will indicate how much has been reserved for use for the given transaction (for the scenario here, the reserved size is more important than what is actually used at the time).

Transaction Diagnostic T-SQL Code - Transactions does not have to be active, just open.

The T-SQL code below should be run from within the database you are concerned about. It will give you the following:

  1. Transactions that are taking up space in the database.
  2. The T-SQL code that initially fired the transaction.
  3. The size used by both the transaction and the system in the transaction in both MB and bytes
  4. The current state or status of the transaction.
  5. The number of log records used along with their lsn numbers.

This code can be run any time the transaction(s) are open, even if requests are not actively executing.

CREATE TABLE #Tmp_Transaction(
   ID int identity(1,1),
   [TransactionName] [nvarchar](32) NOT NULL,
   [transaction_id] [bigint] NOT NULL,
   [transaction_begin_time] [datetime] NOT NULL,
   [transaction_type] [int] NOT NULL,
   [transaction_state] [int] NOT NULL,
   [session_id] [int] NOT NULL,
   [TranLog_MB_Used] [bigint] NULL,
   [TranLog_MB_Reserved] [bigint] NULL,
   [TranLogSys_MB_Used] [int] NULL,
   [TranLogSys_MB_Reserved] [int] NULL,
   [database_transaction_type] [int] NOT NULL,
   [database_transaction_state] [int] NOT NULL,
   [database_transaction_status] [int] NOT NULL,
   [database_transaction_status2] [int] NOT NULL,
   [database_transaction_log_record_count] [bigint] NOT NULL,
   [database_transaction_replicate_record_count] [int] NOT NULL,
   [database_transaction_log_bytes_used] [bigint] NOT NULL,
   [database_transaction_log_bytes_reserved] [bigint] NOT NULL,
   [database_transaction_log_bytes_used_system] [int] NOT NULL,
   [database_transaction_log_bytes_reserved_system] [int] NOT NULL,
   [database_transaction_begin_lsn] [numeric](25, 0) NULL,
   [database_transaction_last_lsn] [numeric](25, 0) NULL,
   [database_transaction_most_recent_savepoint_lsn] [numeric](25, 0) NULL,
   [database_transaction_commit_lsn] [numeric](25, 0) NULL,
   [database_transaction_last_rollback_lsn] [numeric](25, 0) NULL,
   [database_transaction_next_undo_lsn] [numeric](25, 0) NULL,
   EventInfo nvarchar(Max
)

CREATE TABLE #inputb (EventType nvarchar( Max),  Parameters

i nt, EventInfo nvarchar Max)) -- hold buffer

 

declare @iRwCnt int
declare @i int
declare @iSPID int
declare @vSPID varchar(4)
set @i = 1


insert into #Tmp_Transaction(TransactionName, transaction_id,
transaction_begin_time, transaction_type, transaction_state, session_id,
TranLog_MB_Used, TranLog_MB_Reserved, TranLogSys_MB_Used, TranLogSys_MB_Reserved,
database_transaction_type, database_transaction_state, database_transaction_status,
database_transaction_status2, database_transaction_log_record_count,
database_transaction_replicate_record_count, database_transaction_log_bytes_used,
database_transaction_log_bytes_reserved,
database_transaction_log_bytes_used_system,
database_transaction_log_bytes_reserved_system, database_transaction_begin_lsn,
database_transaction_last_lsn, database_transaction_most_recent_savepoint_lsn,
database_transaction_commit_lsn, database_transaction_last_rollback_lsn,
database_transaction_next_undo_lsn)
select at.name [TransactionName], at.transaction_id, at.transaction_begin_time,
at.transaction_type, at.transaction_state, st.session_id,
(dt.database_transaction_log_bytes_used/1048576) [TranLog_MB_Used],
(dt.database_transaction_log_bytes_reserved/1048576) [TranLog_MB_Reserved], (dt.database_transaction_log_bytes_used_system/1048576) [TranLogSys_MB_Used],
(dt.database_transaction_log_bytes_reserved_system/1048576)
[TranLogSys_MB_Reserved],
dt.[database_transaction_type], dt.[database_transaction_state],
dt.[database_transaction_status], dt.[database_transaction_status2],
dt.[database_transaction_log_record_count],
dt.[database_transaction_replicate_record_count],
dt.[database_transaction_log_bytes_used],
dt.[database_transaction_log_bytes_reserved],
dt.[database_transaction_log_bytes_used_system],
dt.[database_transaction_log_bytes_reserved_system],
dt.[database_transaction_begin_lsn],
dt.[database_transaction_last_lsn],
dt.[database_transaction_most_recent_savepoint_lsn],
dt.[database_transaction_commit_lsn], dt.[database_transaction_last_rollback_lsn],
dt.[database_transaction_next_undo_lsn]
from sys.dm_tran_active_transactions at
inner join sys.dm_tran_session_transactions st on at.transaction_id =
st.transaction_id
inner join sys.dm_tran_database_transactions dt on at.transaction_id =
dt.transaction_id
where dt.database_id = DB_ID() and dt.database_transaction_state in (4,12) and
st.is_user_transaction = 1
set @iRwCnt =  @@ROWCOUNT

while @i <= @iRwCnt
begin
   select @iSPID = t.session_id from #Tmp_Transaction t where t.ID = @i
   set @vSPID = Convert(varchar,@iSPID)

   truncate table #inputb
   INSERT #inputb EXEC ( 'DBCC INPUTBUFFER (' + @vSPID + ') WITH NO_INFOMSGS')

   update t
   set t.EventInfo = select top 1 EventInfo from #inputb)
    from #Tmp_Transaction t
   where t.ID = @i

   set @i = @i+1

end

select TransactionName, transaction_id, transaction_begin_time, transaction_type,
transaction_state, session_id, TranLog_MB_Used, TranLog_MB_Reserved,
TranLogSys_MB_Used, TranLogSys_MB_Reserved, EventInfo, database_transaction_type,
database_transaction_state, database_transaction_status,
database_transaction_status2, database_transaction_log_record_count,
database_transaction_replicate_record_count, database_transaction_log_bytes_used,
database_transaction_log_bytes_reserved,
database_transaction_log_bytes_used_system,
database_transaction_log_bytes_reserved_system, database_transaction_begin_lsn,
database_transaction_last_lsn, database_transaction_most_recent_savepoint_lsn,
database_transaction_commit_lsn, database_transaction_last_rollback_lsn,
database_transaction_next_undo_lsn
from #Tmp_Transaction

drop table #Tmp_Transaction
drop table #inputb

Transaction T-SQL Diagnostic - Transactions have to be actively executing for this to work.

This next code is designed to be used with the T-SQL above to provide a complete picture. Basically it will give you information on actively executing transactions, providing you with:

  1. Various information on what the initial T-SQL call was.
  2. What sub-text within the initial T-SQL call is currently executing.
  3. What the current state/begin time is, as well as any completion percentage.


SELECT st.Session_id, req.Blocking_Session_ID [Blocker], req.Wait_Type,
req.Wait_Time [WaitTimeMS], req.Wait_Resource, req.open_transaction_count,
req.percent_complete, dt.transaction_id, dt.database_transaction_begin_time, case
when
dt.database_transaction_type = 1 then  'RW' when dt.database_transaction_type =
2 then 'R' whendt.database_transaction_type = 3 then 'Sys' else 'Unknown' end
[TranType],
case when dt.database_transaction_state = 1 then  'Not Initialized' when
dt.database_transaction_state = 3 then  'Initialized, but no logs' when
dt.database_transaction_state = 4 then  'Generated logs' when
dt.database_transaction_state = 5 then  'Prepared' when
dt.database_transaction_state = 10 then  'Committed' when
dt.database_transaction_state = 11 then  'Rolled Back' when
dt.database_transaction_state = 12 then  'In process of committing' else 'Unknown'
end [TranState],
req. Status, req.Command, stxt.objectid [ExecObjID],
(SUBSTRING(stxt. text,req.statement_start_offset/2,( CASE WHEN
req.statement_end_offset = -1 then  LEN(CONVERT(nvarchar(max), stxt. text)) * 2 ELSE
req.statement_end_offset end -req.statement_start_offset)/2)) [SubText], stxt. text,
req.statement_start_offset
FROM  sys.dm_tran_database_transactions dt nolock)
inner join sys.dm_tran_session_transactions st nolock) on dt.transaction_id =
st.transaction_id
inner join  sys.dm_exec_requests req (nolock) on st.transaction_id =
req.transaction_id
CROSS APPLY  sys.dm_exec_sql_text(req. sql_handle) [stxt]
where dt.database_id = db_id() and st.is_user_transaction = 1

This should give you the knowledge and tools to quickly resolve transaction log issues. Now that we have discussed how to determine the source of your transaction log filling up, I hope that you will be able to assist others in utilizing the transaction log more efficiently.

ABOUT THE AUTHOR

Matthew Schroeder is a senior software engineer who works on SQL Server database systems ranging in size from 2 GB to 3+ TB, with between 2k and 40+k trans/sec. He specializes in OLTP/OLAP DBMS systems as well as highly scalable processing systems written in .NET. Matthew is a Microsoft certified MCITP, Database Developer, has a master's degree in computer science and more than 12 years of experience in SQL Server/Oracle. He can be reached at cyberstrike@aggressivecoding.com.

This was first published in May 2009

Dig deeper on Microsoft SQL Server Performance Monitoring and Tuning

Pro+

Features

Enjoy the benefits of Pro+ membership, learn more and join.

0 comments

Oldest 

Forgot Password?

No problem! Submit your e-mail address below. We'll send you an email containing your password.

Your password has been sent to:

-ADS BY GOOGLE

SearchBusinessAnalytics

SearchDataCenter

SearchDataManagement

SearchAWS

SearchOracle

SearchContentManagement

SearchWindowsServer

Close