Weird timing with Audit Logout Event

  • We are experiencing an issue involving a stored procedure run multiple times on 2005 on two different servers. Some Background: Both servers are running 2005, sane service packs, os etc. Both machines are identical, one is used for UAT one PROD. The UAT server is smaller (12 CPU, 64 GB RAM), PROD is (24 CPU, 96GB RAM). The issue we are seeing that a certain transaction consisting of approx 150 procedure calls operates approximate 8 seconds faster on the smaller server than the Production server. The transaction is run from an ASP.NET connection from a Web server separated by only a firewall and two ethernet cables. The Connection is using MS Enterprise library to handle connecting and disconnecting.

    The ASP.NET code, stored procedures, tables, indexes, stats are all the same. When the transaction is run, there is point where the same procedure is called 80 times in a row. Each time the procedure is executed, the connection connects, executes the procedure, then disconnects (I will list profiler stuff in a minute). What we are noticing is that on the production server, a single procedure call takes ~100 ms from login to logout. The same sequence on the smaller UAT server takes 10-15 ms. SO the difference of the 80-90 ms on each call, being called 80 times, is effectively the difference in the two queries, we have compared the traces from end to end and they are almost identical exempt for this sequence. I will show some profiler entries in next post.

  • Here is the profiler entries from UAT Server

    Audit Login-- network protocol: TCP/IP 4748103

    RPC:Completedexec dbo.usp_CaseProcessContact_And_ 0240034748103

    Audit Logout 015895146290134748103

    RPC:Completedexec sp_reset_connection 0000 4748103

    Procedure took 3 ms, overall from login to Logout took 13 ms. Connection is reset is App pool as expected. Looks good.

    Same Sequence on Prod Server

    Audit Login-- network protocol: TCP/IP 474878

    RPC:Completedexec dbo.usp_CaseProcessContact_And_ 47656474878

    Audit Logout010471717687126474878

    RPC:Completedexec sp_reset_connection 0000 474878

    Procedure took 6 ms, But logout took 126 ms, and connection is reset in App pool. The differences of ~100 ms on each of the logouts being repeated 80 times is accumulating the 8 seconds (I believe).

    Of course, the Applications/Web team says it is a database issue and I am telling them the application is taking to long to disconnect.

    Are there any settings in the App pools on the webservers that might contribute to this?

    Any input would be appreciated.

  • Ted - Did you ever resolve this Issue? What OS was running on the prod system? I have seen issues that appear to be the same as what you are describing (delays of 100-300 miliseconds for pooled connection resets for a system under load) on SQL2008 R2 / Windows 2008 R2 Datacenter (No SP1) and resolved the issue with the assistance of MSFT support by the application of this hotfix http://support.microsoft.com/kb/2155311

    I'm currently seeing similar behavior on a different set of servers running SQL2008 R2 / Windows 2008 R2 Datacenter with SP1. Since this fix is included in SP1, it's not an option to apply it. Could be a regression issue with the service pack, maybe.

    Was curious to hear your feedback if this was ever resolved on your end and if so how?

    Thanks,

    Matt

  • Hi All,

    We are facing the same issue. Our application developed in .Net 4.0 is working very fine with UAT server and the responses are also fast. But we are facing a delay of 7-8 times in Production server.

    Details of UAT and Production server system is as below.

    UAT:

    OS - W2K8 Enterprise 64 Bit SP2

    SQL Server - W2K8 R2 Enterprise x 64 Bit RTM

    PROD:

    OS - W2K8 R2 Enterprise SP1

    SQL Server - W2K8 R2 Enterprise x 64 Bit RTM

    Both Sql server are running as Virtual machine and the storage is shared.

    We have found that Audit_Logout is taking 16 ms (including query execution 8ms) in UAT and 3666 ms (including query execution 6ms).

    Please reply back with exact solution (if someone has faced earlier).

Viewing 4 posts - 1 through 3 (of 3 total)

You must be logged in to reply to this topic. Login to reply