Determining the source of full transaction logs in SQL Server
Matthew Schroeder, Contributer
Rating: -4.44- (out of 5)
|
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:
- Full, differential, or log backups have not occurred on the database in full recovery mode, causing the log to gradually fill up.
- 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.
- 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.
- 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.
- If a database snapshot is in process, all transactions can pile in behind it while the snapshot is created.
Simple ways to ...
To continue reading for free, register below or login
To read more you must become a member of SearchSQLServer.com
respond
You have the following options to start with when troubleshooting a full transaction log:
- 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.
- 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.
- 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.
- 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.
- 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)
[IMAGE]
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:
- Transactions that are taking up space in the database.
- The T-SQL code that initially fired the transaction.
- The size used by both the transaction and the system in the transaction in both MB and bytes
- The current state or status of the transaction.
- 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 int, 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:
- Various information on what the initial T-SQL call was.
- What sub-text within the initial T-SQL call is currently executing.
- 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:
[IMAGE]
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. Schroeder currently works for the gaming vendor IGT providing services to gaming companies. He also works as an independent consultant, specializing in SQL Server, Oracle and .NET for industries such as gaming, automotive, e-commerce, entertainment, banking and nonprofit. Schroeder specializes in OLTP/OLAP DBMS systems as well as highly scalable processing systems written in .NET. He 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.
|
|
|
|
|
|
