Sql-server – Why does a rollback of a CREATE INDEX statement take longer than expected

clustered-indexindex-tuningrollbacksql server

Recently, I needed to apply a clustered index to a table. I first performed the operation in a Staging environment. The operation completed in about 20 minutes, so we planned for PROD to take approximately the same time. After I executed the statement, we let it run for about 4 minutes before we noticed some unanticipated blocking that was causing application queries to time out. Due to the timeouts, we decided to stop the execution, so I cancelled it.

Now, I assumed that either one of two things would happen when I pressed the cancel button:

1) SQL Server would stop organizing the data on disk and leave anything it had already moved where it was, thereby causing the rollback to be almost instant.

2) SQL Server would take the data it had already organized on disk and move it back to where it was before, thereby causing the rollback to take approximately as long as the statement had been executing. In this case, the statement had been running for 4 minutes, so the rollback should make the total time 8 minutes.

Well, neither one of those things happened. The rollback actually took 20 minutes by itself, which was the amount of total time the index took to apply in Staging. This made the total time 24 minutes (execution for 4, rollback for 20).

Now, I am no internals expert, but what I infer from this is that after I clicked the cancel button, SQL Server had to scan the entire index on disk to find what data it had moved, and then move it back.

Does anyone have any more insight on this? Am I even in the ballpark here?

FYI, the only thing different between the Staging and Prod environments is that Staging has about 1/6 of the RAM. Also, the table was around 28 million rows and was a heap.

Thanks all!

Best Answer

I believe what you are looking for is in the warning section of this MSDN reference under the Managing Heaps section.

Creating or dropping clustered indexes requires rewriting the entire table. If the table has nonclustered indexes, all the nonclustered indexes must all be recreated whenever the clustered index is changed. Therefore, changing from a heap to a clustered index structure or back can take a lot of time and require disk space for reordering data in tempdb.

Your tempdb is going to play a critical role here and if you already have contention there with normal production requests maintenance tasks like indexing or de-indexing could take significantly more time to complete. And as Kin stated your rollback is probably single threaded vs multi-threaded with the create and alter statements.

Related Solutions

Sql-server – Odd SQL Server hang when querying exec DMVs

I ran into the problem and found the bug article on MSDN. It has been fixed with cumulative updates for SQL 2008 and 2012. http://support.microsoft.com/kb/2803799

Sql-server – How to pinpoint root cause of excessive log file growth

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

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 :

Best Answer

Related Solutions

Sql-server – Odd SQL Server hang when querying exec DMVs

Sql-server – How to pinpoint root cause of excessive log file growth

Related Question