locked
SQL Server Operations Get Progressively Slower RRS feed

  • Question

  • I have a .NET 4 Windows Service that continually inserts incoming data batches into a SQL Server database.  With each batch, the service truncates a staging table, uses SqlBulkCopy to insert the data into the staging table, and finally uses a stored procedure to insert the data from the staging table into the permanent table (this last step is to ensure that there are no duplicate key entries, using a left join to the permanent table).  These operations are wrapped up within a transaction that the service commits for each batch.

    When the service starts, it completes the process quickly, in about 5 seconds or less.  As the service continues to run, the process gets slower and slower, eventually degrading to where it will consistently take up to 180 seconds to complete a batch.  What is interesting is that, if I stop and restart the service, the first batch again takes only 5 seconds or less, and then the gradual performance degradation begins again.

    I have tried adding sleeps of varying lengths, closing the connection between batches, and even closing the connection, sleeping (even up to a minute between batches), and then reopening the connection.  None of these has been able to get the process back to its original speed.

    What could be causing this degradation in performance, and how could I address this, short of creating a new, independent process (possibly shelling out to an EXE and waiting until it completes), within my service's working loop?

    Thanks.

    • Moved by Bob Beauchemin Thursday, May 23, 2013 2:09 AM Moved to the appropriate forum for SQL Server .NET clients
    Wednesday, May 22, 2013 3:49 PM

Answers

  • I never could figure out why the SQL Server operations continued to slow down, so I implemented a hack that seems to be working well.

    I created a stand-alone executable that processes a single batch, and then I modified the service so that it starts that executable as its own process.  Pretty ugly, but the batches now run consistently in 3 to 10 seconds each (depending on the amount and complexity of the data within each batch).

    • Marked as answer by Enriqueman Friday, May 24, 2013 5:54 PM
    Friday, May 24, 2013 5:54 PM

All replies

  • >>if I stop and restart the service, the first batch again takes only 5 seconds or less, and then the gradual performance degradation begins again.

    So looks like the problem is in your program.  I would start with basic .NET performance analysis of your program to see what's taking the time.

    So you might try generic .NET forum as this one is for CLR inside SQL Server.

    David


    David http://blogs.msdn.com/b/dbrowne/

    Wednesday, May 22, 2013 4:07 PM
  • I spent a significant amount of time looking at the code and generating lots of logging.  The code stayed performing the same with each iteration, but the calls to truncate the tables, bulk copy the data, and execute the stored procedures continued to get slower.  This is what convinced me that the slow-down is within SQL Server.
    Wednesday, May 22, 2013 9:05 PM
  • But restarting your Service fixes the problem?  That's what doesn't make sense.

    While the app is slow, run the query here: http://blogs.msdn.com/b/dbrowne/archive/2013/01/18/my-favorite-query-for-investigating-sql-server-performance.aspx

    And see what it says for SQL Server waits.  It will help tell if SQL is waiting on your app, or your app is waiting on SQL.

    David


    David http://blogs.msdn.com/b/dbrowne/

    Wednesday, May 22, 2013 9:48 PM
  • David,

    Not quite sure which piece of this result is the SQL Server waits, but here are a couple of representative results (taken while the process is running at about 25 seconds per batch):

    session_id 56
    host_name UADEV1
    status suspended
    wait_type ASYNC_NETWORK_IO
    wait_time 10
    last_wait_type ASYNC_NETWORK_IO
    total_elapsed_time 3107
    logical_reads 16250
    reads 0
    writes 0
    statement_text select ... 

    CPU_USED 943.8
    ASYNC_NETWORK_IO 14.6
    WRITELOG 4
    PAGEIOLATCH_SH 3.8
    SOS_SCHEDULER_YIELD 0.4

    session_id 56
    host_name UADEV1
    status running
    wait_type NULL
    wait_time 0
    last_wait_type SOS_SCHEDULER_YIELD
    total_elapsed_time 4422
    logical_reads 72027
    reads 0
    writes 3
    statement_text INSERT INTO ...

    CPU_USED 862.55
    ASYNC_NETWORK_IO 76.4
    WRITELOG 28
    PAGEIOLATCH_SH 4.6
    PREEMPTIVE_OLEDBOPS 0.8
    SOS_SCHEDULER_YIELD 0.6
    PREEMPTIVE_OS_DELETESECURITYCONTEXT 0.2

    What would I glean from these numbers?

    Thanks,

    Eric.

    Wednesday, May 22, 2013 10:07 PM
  • CPU_USED 943.8
    ASYNC_NETWORK_IO 14.6

    That means that SQL was using 943ms of CPU time per second and only had 14ms per second of waiting on your application.  In those snapshots your app is waiting on SQL Server.  If that's representative of the "bad" executions, look to see if the query plans have changed between the good and bad executions.

    David


    David http://blogs.msdn.com/b/dbrowne/

    Wednesday, May 22, 2013 10:20 PM
  • I never could figure out why the SQL Server operations continued to slow down, so I implemented a hack that seems to be working well.

    I created a stand-alone executable that processes a single batch, and then I modified the service so that it starts that executable as its own process.  Pretty ugly, but the batches now run consistently in 3 to 10 seconds each (depending on the amount and complexity of the data within each batch).

    • Marked as answer by Enriqueman Friday, May 24, 2013 5:54 PM
    Friday, May 24, 2013 5:54 PM