SQL Server Performance

Poor performing stored proc

Discussion in 'Performance Tuning for DBAs' started by josephobrien, Nov 21, 2002.

  1. josephobrien New Member

    New DBA trying to get a handle on performance. I was going over the
    stored procedure/sql batch performance by ApplicationName (collected via SQL Profiler) and found that one of the worse performers of one of our applications was a call to a stored proc. The confusing thing is that this sproc requires an argument @source and the poor performing calls to this stored proc appears in the trace information (TextData) as just the simply stored proc with no arguments.
    I can see calls to this sproc with arguments in the same trace - which
    are good performers.

    Data summarized via excel:

    SP Call Execs Avg CPUAvg ReadExec*CPU
    sp_XXX_in 428 67458123288758

    sp_XX_in 'BankX' 34 257 75

    I can't explain how this happens - as I would expect that SQL Server
    would throw an errror if you called the stored proc with no arguments.
    Then I thought
    perhaps it is a case where the stored proc is called with an
    un-initialize parameter like so

    declare @source char(20)
    exec sp_XXX_in @source


    declare @source char(20)
    set @sounce=null
    exec sp_XXX_in @source

    Can't reproduce the bad behavior from within Query Analyzer. The
    thing about the calls is that they look like table scans on a large
    table (in terms of writes). I then thought that perhaps this is some
    symptom of using ado - something like a Parameters.Refresh making a
    call to the server.

    Antone ever see anything like this???

    Joe E O

    Here is code like the stored proc:

    CREATE procedure sp_XXX_in
    @source char(20)

    SELECT top 200
    -- < Lots of columns snipped to brevity >
    big_order_table with (nolock)
    (identity_column > 900000 and
    status = 'pending' AND
    appr_or_eval_flag = 'E' and
    source = @source)
  2. bradmcgehee New Member

    I am assuming that when you tried this code in QA, you ran the proc manually without and with the parameter to see what happens, and that the behaviour you got was normal (i.e. the run without the proc failed). If this is the case, I have not seen it, as an error would be normal

    Also, I am assuming that the source code (used to supply the parameter) doesn't test for a missing parameter, which allows the non-parameter SP to be run in SQL Server.

    While I don't know the cause of this strange behavior, you can work around it by adding error checking code in the application, or even in the proc, to prevent this situation. I know this is only a work-around. Perhaps others have seen this and can offer some feedback.

    Brad M. McGehee
  3. josephobrien New Member

    Thanks Brad,
    I appreciate you taking the time to respond to my question.

    I almost believe that this is some side effect of Ado, or something that SQL Server is doing internally (I tried to check for recompiles – with no luck). I just find it strange that I can#%92t reproduce the bad behavior in QA.

    I will have development add some error checking to the stored proc. Perhaps that will provide some more information...

    Thanks again..

    Joe O#%92Brien
  4. josephobrien New Member

    Brad<br />I found out what it is or at least what I strongly believe the issue to be. <br />I have two similarly named stored procs in this application <br />“sp_X_XX_XXXXXXXXXXX_XXXXXX_XX” and <br />“sp_X_XX_XXXXXXXXXXX_XXXXXX_XX _FIRSTIN”. <br /><br />I had been tracing the just the RPC:Completed and SQL:BatchCompleted Events in an attempt to get the duration of the different calls. So what I believe happened was that the TextData for the RPC:Completed event truncated the name of the Stored procedure call. <br /><br />So that “sp_ X_XX_XXXXXXXXXXX_XXXXXX_XX _FIRSTIN” appears in the <br />Trace as “sp_X_XX_XXXXXXXXXXX_XXXXXX_XX”. <br /><br />“sp_X_XX_XXXXXXXXXXX_XXXXXX_XX_FIRST” is a bad stored proc that is doing a table scan, while “sp_X_XX_XXXXXXXXXXX_XXXXXX_XX” is very well behaved. <br /><br /><br />How I found this was that I added the SP<img src='/community/emoticons/emotion-7.gif' alt=':S' />tatement Completed Event and found the SQL statement (there was only one) that appeared in the trace right after the RPC<img src='/community/emoticons/emotion-7.gif' alt=':S' />tarted and before RPC:Completed for the bad RPC call – was from the <br />sp_ X_XX_XXXXXXXXXXX_XXXXXX_XX _FIRSTIN stored proc. <br /><br /> I ran this through Query Analyzer and found the same exact resource consumption of the RPC:Completed event. <br /><br />The one nagging question is why is the TextData getting truncated. I have ADO application that perform and ADO.COMMAND.PARAMETER.REFRESH that generate the following RPC call: <br /><br />declare @P1 int<br />declare @P3 int<br />declare @P4 int<br />declare @P5 int<br />set @P1=0<br />set @P3=8<br />set @P4=1<br />set @P5=1<br />exec sp_ddopen @P1 output, N'sp_sproc_columns', @P3 output, @P4 output, @P5 output, N'sp[_]X[_]XX[_]XXXXXXXXXX[_]XXXXXX[_]XX[_]FirstIn', NULL, NULL, NULL<br />select @P1, @P3, @P4, @P5<br /><br />Why isn't this truncated????<br /><br />Thanks again...<br /><br />Joe O#%92Brien <br />
  5. bradmcgehee New Member

    I don't know why the data is truncated, I would not expect this. It looks like you did an excellant job of identifying the problem. ADO does cause some strange issues some time, and that may be the cause. Another small possibility is that because the names of the procs are so similar, the query optimizer is getting confused when it trys to cache and reuse it.

    Also, when you call the sproc, do you call it by its object name only, or do you use the object owner's name also, such as dbo.sproc? I mention this because by adding the object owner's name to a object's name helps boost performance because SQL Server doesn't need to resolve the name of the sproc, and also helps to ensure proper reuse of the plan in the optimizer. This may not be the issue, but I thought it might be something else to try. Also, have you tried changing the name so that they are more different, and see what happens?

    Brad M. McGehee

Share This Page