none
Sql command timeout on SP which runs fine in query analyser

    Question

  • Hi all,

    I have this situation I which I can't recreate but it reoccurres like twice a day
    We have:
    1. ASP.NET application, .NET 3.5, VB.NET
    2. Sql stored procedure on sql Server 9.0.4035. Normal execution time 2 sec. Since I don't care about dirty reads it has a 'SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED' after the BEGIN

    The app calls the stored procedure. Everything works just fine. However, every now and then the stored procedure 'hangs' or at least takes more than 600 seconds. The 'hang' starts without any pattern and usualy occurs twice a day. When it kicks in it usually lasts for about 45 minutes. Other pages using differnt queries / sp's have no problem. All other SP's and queries which are in the problem page but are run before the problem procedure run without a glitch.


    When running the profiler it's clear that the SP does not fire an RPC:Completed event while the problem occurs. When i copy/paste the textData to the profiler and execute it there is no problem at all. The SP executes in just 2 secs.

    When I reset the application pools of the ASP.net application nothing changes. When I adjust the web.config the problem persists.

    At the activity monitor in SQL server I only see 1 active action -> the execution of the the problem SP


    I think the usual suspects here would be:
    1. connectionpool problems
    2. to many connections
    3. connectivity problems
    4. uncomplete transactions / locked tables

    I'm quite sure I ruled out 1, 2 and 3. Other pages work fine, query executed before the problem SP on the same page work fine. Connections are opend like this:

    Using sqlConnection As New SqlConnection(connectionString)
      Using sqlCommand As New SqlCommand(SP_AUTOCOMPLETE_NAME, sqlConnection)
        Try
          sqlConnection.Open()
          'sqlConneciton.ExecuteWhatever
        Catch
        End Try
      End Using
    End Using
    

     

    or otherwise using the SqlDataSource in the ASP.NET markup:

      <asp:SqlDataSource ID="sdsOpdrachten" runat="server" DataSourceMode="DataSet" 
            ConnectionString="<%$ ConnectionStrings:LiveConnectionString %>" 
            SelectCommand="sp_GetOpdrachtenOverzicht" 
            SelectCommandType="StoredProcedure" CancelSelectOnNullParameter= "False">
            <SelectParameters>
                <asp:ControlParameter Name="verzonden" ControlID="chkOpdrachtVerzonden" PropertyName="checked" Type="Boolean" DefaultValue="True" />
                <asp:ControlParameter Name="nietVerzonden" ControlID="chkOpdrachtNietVerzonden" PropertyName="checked" Type="Boolean" DefaultValue="True" />
                <asp:ControlParameter Name="monstersDeelsOntvangen" ControlID="chkMonstersDeelsOntvangen" PropertyName="checked" Type="Boolean" DefaultValue="True" />
                <asp:ControlParameter Name="monstersOntvangen" ControlID="chkMonstersOntvangen" PropertyName="checked" Type="Boolean" DefaultValue="True" />
                <asp:ControlParameter Name="rapportageGereed" ControlID="chkRapportageGereed" PropertyName="checked" Type="Boolean" DefaultValue="True" />
                <asp:ControlParameter Name="Vanaf" ControlID="cdVanaf" PropertyName="SelectedDate" Type="DateTime" />
                <asp:ControlParameter Name="relatieId" ControlID="ddlKiesKlant" PropertyName="SelectedValue" Type="Int64" />
                <asp:ControlParameter Name="geannuleerd" ControlID="chkGeannuleerd" PropertyName="checked" Type="Boolean" DefaultValue="True" />
            </SelectParameters>
        </asp:SqlDataSource>
    

    That (probably) leaves me with suspect 4. However, as far as I can tell we don't use any Transactions. When i execute DBCC OPENTRAN it returns 'No active open transactions'. Also, I added 'SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED' to this procedure so it probably even should lock on transactions.

    Any help, clue, hint or whatever on this problem is welcome. I'm realy stuck here.....


    The stored procedure:

    ALTER PROCEDURE [dbo].[sp_GetOpdrachtenOverzicht]
     @verzonden as bit,
     @nietVerzonden as bit,
     @vanaf as DateTime,
     @monstersOntvangen as bit,
     @monstersDeelsOntvangen as bit,
     @geannuleerd as bit,
     @rapportageGereed as bit,
     @relatieId as integer
    AS
    BEGIN
     SET NOCOUNT ON;
     SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
    
    select 
      case when xlsR.opdrachtId is null then 0 else 1 end as heeftXlsRapport
     , case when pdfE.opdrachtId is null then 0 else 1 end as heeftPdfEindrapport
     , case when pdfT.opdrachtId is null then 0 else 1 end as heeftPdfTussenrapport
     ,s.*
    from
     (SELECT 
      * --removed all columns so it would fit a bit better in my forum post  
     FROM 
      MA_Opdracht opdracht 
      inner join MA_Relatie_Contactpersoon contact 
       on opdracht.ContactpersoonID = contact.ID
      inner join MA_Relatie relatie
       on opdracht.RelatieID  = relatie.ID 
      inner join MA_Relatie_Contactpersoon aanvrager
       on opdracht.syscreator = aanvrager.WindowsUser
      LEFT JOIN MA_Opdracht_Status opdracht_status 
       ON opdracht_status.StatusCode = opdracht.[Status]
      where 
    
      ( 
       @verzonden = 1 and opdracht_status.StatusCode = 'V'
        OR 
       @nietVerzonden = 1 and opdracht_status.StatusCode = 'NV'
        OR
       @monstersOntvangen = 1 and opdracht_status.StatusCode = 'IB'
        or
       @monstersDeelsOntvangen = 1 and opdracht_status.StatusCode = 'NC'
        or
       @rapportageGereed = 1 and opdracht_status.StatusCode = 'R'
        or
       @geannuleerd = 1 and opdracht_status.StatusCode = 'A'
      )
      AND
      ( @vanaf is null or opdracht.syscreated >= @vanaf)
      and
      ( @relatieId = -1 or opdracht.RelatieID = @relatieId)
     ) s 
     left join dbo.GetRapportages('AA-XLRAPPORTAGE') xlsR on s.Status = 'R'  and xlsR.opdrachtId = cast(s.OpdrachtID as varchar)
     left join dbo.GetRapportages('AA-EINDRAPPORTAGE') pdfE on s.Status = 'R' and pdfE.opdrachtId = cast(s.OpdrachtID as varchar)
     left join dbo.GetRapportages('AA-TUSSENRAPPORTAGE') pdfT on s.Status in ('IB', 'NC', 'R') and pdfT.opdrachtId = cast(s.OpdrachtID as varchar)
    END
    
    
    


    The function used for the joins (which I now realise isn't that pretty but should not give any problems)

    ALTER FUNCTION [dbo].[GetRapportages]
    ( 
     @type_proces as varchar(20)
    
    )
    RETURNS TABLE 
    AS
    RETURN 
    (
     select  
      opdrachtId as opdrachtid  from 
      (select 
       (select * from dbo.Split(Bestandsnaam, '_',2)) as opdrachtId
       from [100].dbo._ORBIS_Listdir 
       where 
        type_proces= @type_proces 
        AND Vink = 2
      ) zoekMaxVolgnummer
      where len(opdrachtid) < 9
         and isnumeric(opdrachtid) = 1
     group by opdrachtId
    )
    
    
    

    And the split function, which i 'downloaded' somewhere, which also shouldn't give any problems:

    ALTER  FUNCTION [dbo].[Split] (@s varchar(512), @sep char(1), @column integer )
    RETURNS table
    AS
    RETURN (
        WITH Pieces(pn, start, stop) AS (
          SELECT 1, 1, CHARINDEX(@sep, @s)
          UNION ALL
          SELECT pn + 1, stop + 1, CHARINDEX(@sep, @s, stop + 1)
          FROM Pieces
          WHERE stop > 0 
        )
        SELECT SUBSTRING(@s, start, CASE WHEN stop > 0 THEN stop-start ELSE 512 END) AS s
        FROM Pieces where pn = @column
      )
    
    
    
    Wednesday, March 10, 2010 1:06 PM

Answers

  • When the problem occurs, immediately go into Management Studio.  Execute an sp_who2 command and examine everything that is running on the SQL Server.

    Locate the hung process.  Especially look for the BlkBy column to identify cases where the process is blocking waiting for other processes.  The Command column gives a general classification as to what the process is currently doing, so it might also be interesting.  (Note that there are some kinds of blocking that READ UNCOMMITTED will not override.)

    Take note of the hung session ID (SPID) from sp_who2.  You can use the following to try to narrow down which statement within the stored procedure is hanging:

    select t.text, substring(t.text, (r.statement_start_offset/2)+1, 
    	((case r.statement_end_offset when -1 then datalength(t.text) else r.statement_end_offset end - r.statement_start_offset)/2) + 1) from sys.dm_exec_requests r 
    cross apply sys.dm_exec_sql_text(r.sql_handle) t
    where r.session_id=SPID here
    
    Have you rebooted this SQL Server recently?  I've seen SQL hang problems go away permanently or semi-permanently after performing a reboot of the SQL Server machine.

    Another problem that sometimes occurs in that a very sub-optimal query plan ends up in the plan cache.  The knee-jerk fix is to add a WITH RECOMPILE to the definition of the stored procedure.  However, if the stored procedure is executed frequently, this can negatively affect performance since the stored procedure will be recompiled every time it is called.  A more robust solution is the OPTIMIZE FOR query hint (http://technet.microsoft.com/en-us/library/ms181714(SQL.90).aspx).  The "trick" is to pass in optimization values that perform well for all cases encountered by your application.  The knee-jerk way of using this is to use the values for which the stored procedure commonly encounters a performance problem.  That's not the optimal way to use OPTIMIZE FOR, but it's better than using WITH RECOMPILE.
    • Marked as answer by NicoV Friday, March 12, 2010 2:52 PM
    Thursday, March 11, 2010 12:27 AM

All replies

  • When the problem occurs, immediately go into Management Studio.  Execute an sp_who2 command and examine everything that is running on the SQL Server.

    Locate the hung process.  Especially look for the BlkBy column to identify cases where the process is blocking waiting for other processes.  The Command column gives a general classification as to what the process is currently doing, so it might also be interesting.  (Note that there are some kinds of blocking that READ UNCOMMITTED will not override.)

    Take note of the hung session ID (SPID) from sp_who2.  You can use the following to try to narrow down which statement within the stored procedure is hanging:

    select t.text, substring(t.text, (r.statement_start_offset/2)+1, 
    	((case r.statement_end_offset when -1 then datalength(t.text) else r.statement_end_offset end - r.statement_start_offset)/2) + 1) from sys.dm_exec_requests r 
    cross apply sys.dm_exec_sql_text(r.sql_handle) t
    where r.session_id=SPID here
    
    Have you rebooted this SQL Server recently?  I've seen SQL hang problems go away permanently or semi-permanently after performing a reboot of the SQL Server machine.

    Another problem that sometimes occurs in that a very sub-optimal query plan ends up in the plan cache.  The knee-jerk fix is to add a WITH RECOMPILE to the definition of the stored procedure.  However, if the stored procedure is executed frequently, this can negatively affect performance since the stored procedure will be recompiled every time it is called.  A more robust solution is the OPTIMIZE FOR query hint (http://technet.microsoft.com/en-us/library/ms181714(SQL.90).aspx).  The "trick" is to pass in optimization values that perform well for all cases encountered by your application.  The knee-jerk way of using this is to use the values for which the stored procedure commonly encounters a performance problem.  That's not the optimal way to use OPTIMIZE FOR, but it's better than using WITH RECOMPILE.
    • Marked as answer by NicoV Friday, March 12, 2010 2:52 PM
    Thursday, March 11, 2010 12:27 AM
  • Hi BinaryCoder,

    Those are some very usefull hints / tips!

    While playing around with those I found that the
    left join dbo.GetRapportages('AA-XLRAPPORTAGE') xlsR on s.Status = 'R'  and xlsR.opdrachtId = cast(s.OpdrachtID as varchar)

    is a realy resource intensive join on a realy crappy all varchar column table with ton's of rows which are used by a lot of processes. i realy had no insight in what processes where using this table, so I just made a descent strongly typed replica of the table. After doing this the problem disappeard (and the query execution time was reduced from 2 sec's to 0.2 sec's :))

    About the READ UNCOMMITTED. Could you please give some hints on what kind of processes / locks still will block it? This might be usefull info for... anyone.

    Thanks again,

    Nico

    Friday, March 12, 2010 2:59 PM