SQL Profiler Shows Update (EventClass) with No Errors, But Data in Table is Not Changed

Question

I am trying to debug a web app that uses a database and I need a little help. The problem is that part of the code throws a timeout error. I started using SQL Server Profiler to check the communication between the app and the database. (I am not really a database expert and this is a new tool for me).

The app is supposed to call an UPDATE on a specific record. Shortly after, it calls a SELECT on the same record (because it refreshes the screen). I can see both the UPDATE and the SELECT event classes in the Profiler trace. (There are a few other event classes between them). The SELECT is showing with a duration of 30499 and an Error of 2 - Abort. I am guessing this is the source of my timeout error.

This is where it gets interesting. By selecting the EventClass in the Profiler trace, I can see the SQL SELECT statement that is being called. I copied and pasted this into a new query in Management Studio and tried it out. The SELECT statement worked fine and returned the record before my finger left the f5 key. However, the data in the record was the old data. It seems that the previous UPDATE call did not change the record.

Looking at the Profiler trace again, the UPDATE event class shows an Error of 0 - OK. When I select the UPDATE event class and copy the SQL code into Management Studio it runs fine and does update the record. Is anyone able to help me work out what is going on please.

If the UPDATE statement is shown in Profiler with no error, then does this mean that it should have updated the database?
What could be causing the SELECT statement to abort (considering that it runs fine when I try it in SQL Server Management Studio)?
Could problems with the UPDATE be causing the record to lock up which stop the SELECT from running?

Any advice to help me debug and fix this would be appreciated.

Ben · Answer 1 · 2014-04-29T14:00:29.217

Managed to fix this problem. Turns out that the data access handler in the application code should have called commit after the UPDATE call, but this was missing.

Based on my limited understanding, the access handler (based on Interop.COMSVCSLib) is using a buffer(?) built in to SQL Server. For some reason, I expected this buffer to be external to the database.

Thus SQL Server Profiler was capturing the UPDATE call even though the update was not being committed. When the SELECT was called, presumably SQL Server was still waiting for the update to be committed and so caused the timeout. When the UPDATE failed to be committed then SQL Server caused the data to be thrown away and the old data was preserved.

(If someone wants to write a more detailed answer that can help me understand this process better then I will mark it as the answer, since I don't really like answering my own questions).

score 3 · Accepted Answer · answered Aug 03 '14 at 01:12

If the UPDATE statement is shown in Profiler with no error, then does this mean that it should have updated the database?

Yes, but whether the change is visible to other database connections depends on whether the change is committed or not, and on the current transaction isolation level in use by the other connection. To be clear, the SQL:BatchCompleted Profiler Event is triggered when a T-SQL batch completes, it does not mean that any containing transaction has also committed.

What could be causing the SELECT statement to abort (considering that it runs fine when I try it in SQL Server Management Studio)?

In your case, the update was performed inside a transaction which was not committed. The SELECT statement was issued on a separate database connection under an isolation level that does not permit reading uncommitted data. From the description given, the SELECT was blocked by the exclusive lock held by the uncommitted change.

The fact that you were able to issue the SELECT and have it return the pre-update version of the row means your Management Studio session was using a row-versioning isolation level, almost certainly READ COMMITTED SNAPSHOT ISOLATION.

The SELECT issued from the application must be running under a different isolation level, one that does not use row-versioning, and blocks when it encounters an exclusive lock, perhaps SERIALIZABLE. You should check the application code to determine this.

If you know of a way to show uncommitted update calls in Profiler (rather than an error-free update followed by an abort on a select) then can you add this as an answer please? This would help a lot when I am debugging this code.

There are lots of options here. You might find also tracing the SQLTransaction Event Class sufficient for your needs. Alternatively, there are many system views and commands to help you see uncommitted transactions. You may find a query like the following useful to show details for open user transactions:

SELECT
    DES.session_id,
    DES.[host_name],
    DES.[program_name],
    DES.login_name,
    DES.last_request_start_time,
    DES.reads,
    DES.writes,
    transaction_isolation_level =
        CASE DES.transaction_isolation_level
            WHEN 0 THEN 'Unspecified'
            WHEN 1 THEN 'Read Uncomitted'
            WHEN 2 THEN 'Read Committed'
            WHEN 3 THEN 'Repeatable Read'
            WHEN 4 THEN 'Serializable'
            WHEN 5 THEN 'Snapshot'
        END,
    DES.open_transaction_count,
    DTDT.database_transaction_begin_time,
    transaction_state =
        CASE DTDT.database_transaction_state
            WHEN 1 THEN 'Not initialized'
            WHEN 3 THEN 'Initialized'
            WHEN 4 THEN 'Open and has generated log records'
            WHEN 5 THEN 'Prepared'
            WHEN 10 THEN 'Committed'
            WHEN 11 THEN 'Aborted'
            WHEN 12 THEN 'Being committed'
        END
FROM sys.dm_exec_sessions AS DES
JOIN sys.dm_tran_session_transactions AS DTST
    ON DTST.session_id = DES.session_id
JOIN sys.dm_tran_database_transactions AS DTDT
    ON DTDT.database_id = DES.database_id
WHERE 
    DES.is_user_process = 1
    AND DTST.is_user_transaction = 1
    AND DTDT.database_transaction_type = 1
    AND DES.open_transaction_count > 0;

The system views used in that code are all documented in Books Online:

sys.dm_exec_sessions
sys.dm_tran_session_transactions
sys.dm_tran_database_transactions

You may also find DBCC OPENTRAN useful as a way to quickly see the longest open transaction.

SQL Profiler Shows Update (EventClass) with No Errors, But Data in Table is Not Changed

2 Answers2