asp.net - Occasionally Getting SqlException: Timeout expired

Question

I have application running on my server. The problem with this application is that daily I am getting nearly 10-20, System.Data.SqlClient.SqlException Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding only one of my SP. Here is my SP,

            ALTER PROCEDURE [dbo].[Insertorupdatedevicecatalog] 
                            (@OS                NVARCHAR(50) 
                            ,@UniqueID          VARCHAR(500)
                            ,@Longitude         FLOAT 
                            ,@Latitude          FLOAT
                            ,@Culture           VARCHAR(10)
                            ,@Other             NVARCHAR(200)
                            ,@IPAddress         VARCHAR(50)
                            ,@NativeDeviceID    VARCHAR(50))
            AS 
            BEGIN 

                DECLARE @OldUniqueID VARCHAR(500) = '-1';
                SELECT @OldUniqueID = [UniqueID] FROM DeviceCatalog WHERE (@NativeDeviceID != '' AND [NativeDeviceID] = @NativeDeviceID);

                BEGIN TRANSACTION [Tran1]
                    BEGIN TRY
                        IF EXISTS(SELECT 1 FROM DeviceCatalog WHERE [UniqueID] = @UniqueID) 
                        BEGIN 
                            UPDATE  DeviceCatalog 
                               SET  [OS] = @OS
                                   ,[Location] = geography::STGeomFromText('POINT(' + CONVERT(VARCHAR(100 ), @Longitude) + ' ' + CONVERT(VARCHAR(100), @Latitude) + ')', 4326)
                                   ,[Culture] = @Culture
                                   ,[Other] = @Other
                                   ,[Lastmodifieddate] = Getdate()
                                   ,[IPAddress] = @IPAddress
                            WHERE   [UniqueID] = @UniqueID;
                        END
                        ELSE 
                        BEGIN
                            INSERT INTO DeviceCatalog
                                        ([OS]
                                        ,[UniqueID]
                                        ,[Location] 
                                        ,[Culture] 
                                        ,[Other]
                                        ,[IPAddress]
                                        ,[NativeDeviceID])
                                VALUES  (@OS
                                        ,@UniqueID
                                        ,geography::STGeomFromText('POINT(' + CONVERT(VARCHAR(100) ,@Longitude) + ' ' + CONVERT(VARCHAR(100), @Latitude) + ')', 4326) 
                                        ,@Culture
                                        ,@Other
                                        ,@IPAddress
                                        ,@NativeDeviceID);
                                IF(@OldUniqueID != '-1' AND @OldUniqueID != @UniqueID)
                                BEGIN
                                    EXEC DeleteOldDevice @OldUniqueID, @UniqueID;
                                END
                        END
                        COMMIT TRANSACTION [Tran1];
                    END TRY
                    BEGIN CATCH
                        ROLLBACK TRANSACTION [Tran1];
                        DECLARE @ErrorNumber nchar(5), @ErrorMessage nvarchar(2048);
                        SELECT
                            @ErrorNumber = RIGHT('00000' + ERROR_NUMBER(), 5),
                            @ErrorMessage = @ErrorNumber + ' ' + ERROR_MESSAGE();
                        RAISERROR (@ErrorMessage, 16, 1);
                    END CATCH
            END

Is there is any issue with this SP? Why I am getting Timeout exception only in this SP? Here is the Stack Trace,

System.Data.SqlClient.SqlException (0x80131904): Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning()
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)
   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
   at App.Classes.DBLayer.Execute(SqlCommand command, Boolean executeNonQuery)
   at App.Helpers.SQLHelper.GetResult(List`1 parameters, Boolean storedProcedure, String commandText, ResultType type)
   at App.Helpers.SQLHelper.ExecuteNonQuery(List`1 parameters, Boolean storedProcedure, String commandText)
   at App.Services.DeviceCatalogService.InsertOrUpdateDeviceCatalog(DeviceCatalog deviceCataLog)
   at WebApplication1.Handlers.RegisterDevice.ProcessRequest(HttpContext context)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Answer 1

You need to investigate this on the server side to understand why is the execution timing out. Note that the server has no timeout, the timeout is caused by the default 30 seconds on SqlCommand.CommandTimeout.

A good resource is Waits and Queues, which is a methodology to diagnose performance bottlenecks with SQL Server. Based on the actual cause of the timeout, proper action can be taken. You must establish first and foremost whether you're dealing with slow execution (a bad plan) or blocking.

If I'd venture a guess, I would say that the unhealthy pattern of IF EXISTS... UPDATE is the root cause. This pattern is incorrect and will cause failures under concurrency. Two concurrent transaction executing the IF EXISTS simultaneously will both reach the same conclusion and both attempt to INSERT or UPDATE. Depending on the exiting constraints in the database you can end up with a deadlock (the lucky case) or with a lost write (the unlucky case). However, only proper investigation would reveal the actual root cause. Could be something totally different, like auto-growth events.

Your procedure is also incorrectly handling the CATCH block. You must always check the XACT_STATE() because the transaction may be already rolled back by the time your CATCH block runs. Is also not clear what you expect from naming the transaction, this is a common mistake I see often associated with confusing named transactions with savepoints. For a correct pattern see Exception Handling and Nested Transactions.

Edit

Here is a possible way to investigate this:

1. Change the relevant CommandTimeout to 0 (ie. infinite).
2. Enable the blocked process threshold, set it to 30 seconds (the former CommandTimeout)
3. Monitor in Profiler for Blocked Process Report Event
4. Start your workload
5. See if the Profiler produces any report events. If it does, they will pinpoint the cause.

These actions will cause a 'blocked process report' event every time you would had get a timeout, if the timeout was cause by blocking. You application will continue to wait until the blocking is removed, if the blocking is caused by a live-lock then it will wait forever.