6

The log file stays pretty small (~500MB) until about 11PM, and at that point it begins growing until no disk space is available. The log file reached it's maximum size at 12:39AM, so the growth took place over approximately an hour and a half time frame. The drive that houses the logs only has about 40GB of total space available, so the log file can only grow to that 40GB. That should be plenty though as the data is fairly static and only about 50GB total. Here are a few more additional notes:

  • DB recovery model is full
  • Transaction log backups are taken every 15 minutes
  • A defrag job is called at 11PM but looking at the history it only runs for a few minutes max

How can I pinpoint the exact cause of this? It has to be a large transaction that is open but how can I determine that?

1
  • 3
    Use Extended Events to catch the long running transaction(s) or Server Side Trace whichever you prefer. Also you can use Adam's sp_whoisactive to take snapshots for further analysis -- How to Log Activity Using sp_whoisactive in a Loop. I'd start with these tools to see if it sheds some light for more troubleshooting steps/paths.
    – DenisT
    Feb 28, 2014 at 19:57

1 Answer 1

7

Best thing to do is to collect what caused the log file to grow by setting up an alert.

enter image description here

enter image description here

You can use sp_whoisactive to run and log into the table (as DennisT suggested) or dmv's like sys.dm_tran_active_transactions and sys.dm_tran_database_transactions

--  Find Log space usage
-- http://stackoverflow.com/a/5085179/1387418
select
    SessionTrans.session_id as [SPID],
    enlist_count as [Active Requests],
    ActiveTrans.transaction_id as [ID],
    ActiveTrans.name as [Name],
    ActiveTrans.transaction_begin_time as [Start Time],
    case transaction_type
        when 1 then 'Read/Write'
        when 2 then 'Read-Only'
        when 3 then 'System'
        when 4 then 'Distributed'
        else 'Unknown - ' + convert(varchar(20), transaction_type)
    end as [Transaction Type],
    case transaction_state
        when 0 then 'Uninitialized'
        when 1 then 'Not Yet Started'
        when 2 then 'Active'
        when 3 then 'Ended (Read-Only)'
        when 4 then 'Committing'
        when 5 then 'Prepared'
        when 6 then 'Committed'
        when 7 then 'Rolling Back'
        when 8 then 'Rolled Back'
        else 'Unknown - ' + convert(varchar(20), transaction_state)
    end as 'State',
    case dtc_state
        when 0 then NULL
        when 1 then 'Active'
        when 2 then 'Prepared'
        when 3 then 'Committed'
        when 4 then 'Aborted'
        when 5 then 'Recovered'
        else 'Unknown - ' + convert(varchar(20), dtc_state)
    end as 'Distributed State',
    DB.Name as 'Database',
    database_transaction_begin_time as [DB Begin Time],
    case database_transaction_type
        when 1 then 'Read/Write'
        when 2 then 'Read-Only'
        when 3 then 'System'
        else 'Unknown - ' + convert(varchar(20), database_transaction_type)
    end as 'DB Type',
    case database_transaction_state
        when 1 then 'Uninitialized'
        when 3 then 'No Log Records'
        when 4 then 'Log Records'
        when 5 then 'Prepared'
        when 10 then 'Committed'
        when 11 then 'Rolled Back'
        when 12 then 'Committing'
        else 'Unknown - ' + convert(varchar(20), database_transaction_state)
    end as 'DB State',
    database_transaction_log_record_count as [Log Records],
    database_transaction_log_bytes_used / 1024 as [Log KB Used],
    database_transaction_log_bytes_reserved / 1024 as [Log KB Reserved],
    database_transaction_log_bytes_used_system / 1024 as [Log KB Used (System)],
    database_transaction_log_bytes_reserved_system / 1024 as [Log KB Reserved (System)],
    database_transaction_replicate_record_count as [Replication Records],
    command as [Command Type],
    total_elapsed_time as [Elapsed Time],
    cpu_time as [CPU Time],
    wait_type as [Wait Type],
    wait_time as [Wait Time],
    wait_resource as [Wait Resource],
    reads as [Reads],
    logical_reads as [Logical Reads],
    writes as [Writes],
    SessionTrans.open_transaction_count as [Open Transactions],
    open_resultset_count as [Open Result Sets],
    row_count as [Rows Returned],
    nest_level as [Nest Level],
    granted_query_memory as [Query Memory],
    SUBSTRING(SQLText.text,ExecReqs.statement_start_offset/2,(CASE WHEN ExecReqs.statement_end_offset = -1 then LEN(CONVERT(nvarchar(max), SQLText.text)) * 2 ELSE ExecReqs.statement_end_offset end - ExecReqs.statement_start_offset)/2) AS query_text
from
    sys.dm_tran_active_transactions ActiveTrans (nolock)
    inner join sys.dm_tran_database_transactions DBTrans (nolock)
        on DBTrans.transaction_id = ActiveTrans.transaction_id
    inner join sys.databases DB (nolock)
        on DB.database_id = DBTrans.database_id
    left join sys.dm_tran_session_transactions SessionTrans (nolock)
        on SessionTrans.transaction_id = ActiveTrans.transaction_id
    left join sys.dm_exec_requests ExecReqs (nolock)
        on ExecReqs.session_id = SessionTrans.session_id
        and ExecReqs.transaction_id = SessionTrans.transaction_id
    outer apply sys.dm_exec_sql_text(ExecReqs.sql_handle) AS SQLText
where SessionTrans.session_id is not null -- comment this out to see SQL Server internal processes

More reference :

1
  • 1
    Update: I setup an agent job to run every 5 minutes and call the sp_whoisactive procedure. Those results made it very easy to figure out exactly where the problem was. I could see a delete statement that was failing when trying to delete almost half a billion records. Of course the operator to receive notifications for the job failure was disabled. Thanks for all of the help Mar 4, 2014 at 19:53

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.