I have a problem where occasionally (less that 1%) a packet is not
processed for as long as 25 seconds.
1) I get the exact same behavior with ADO 2.8 and ADO.NET.
2) A detailed view of the chain of events looks like this:
? T+0 seconds ? connection from the pool is allocated
? T+0 seconds ? vb call to Command.Execute (or c# call to
DataAdapter.Fill)
? T+0 seconds ? single packet (118 bytes) is sent to database machine
(from a web server)
? T+0.1 seconds ? ack received from database machine indicating packet
was successfully received in full
? T+25 seconds ? SQL Profiler trace "Start Time" for database call
? T+25 seconds ? SQL Profiler trace "End Time" for database call
? T+25 seconds ? data returns to application
? T+25 seconds ? connection is returned to the pool
So the "lost time" occurs on the database machine between the time the
packet is received, and the time Profiler claims SQL Server started
working on the query.
I've tried to run perfmon on the obvious counters on the database but
I've failed to find anything out of the ordinary. There are so many
counters! Any ideas on what specifically I should be looking at now?
~ James
Occasional delay in processing incoming packetsJames wrote:
> I have a problem where occasionally (less that 1%) a packet is not
> processed for as long as 25 seconds.
> 1) I get the exact same behavior with ADO 2.8 and ADO.NET.
> 2) A detailed view of the chain of events looks like this:
> . T+0 seconds - connection from the pool is allocated
> . T+0 seconds - vb call to Command.Execute (or c# call to
> DataAdapter.Fill)
> . T+0 seconds - single packet (118 bytes) is sent to database machine
> (from a web server)
> . T+0.1 seconds - ack received from database machine indicating packet
> was successfully received in full
> . T+25 seconds - SQL Profiler trace "Start Time" for database call
> . T+25 seconds - SQL Profiler trace "End Time" for database call
> . T+25 seconds - data returns to application
> . T+25 seconds - connection is returned to the pool
>
> So the "lost time" occurs on the database machine between the time the
> packet is received, and the time Profiler claims SQL Server started
> working on the query.
> I've tried to run perfmon on the obvious counters on the database but
> I've failed to find anything out of the ordinary. There are so many
> counters! Any ideas on what specifically I should be looking at now?
> ~ James
> Occasional delay in processing incoming packets
If you can, try setting up an alias to teh SQL Server machine using a
different network protocol (e.g. named pipes instead of TCP/IP). That
way you can see if the problem is related to the network library. If the
start time in Profiler is T+25, it sounds like SQL Server is not getting
the packet until T+25.
You can set up aliases from the SQL Server Client Tools - Client Network
Utility.
David G.|||I created a Named Pipes alias and used that instead of TCP/IP. I've
never done that before, so I checked to make sure the connections were
using Named Pipes before continuing.
During this test I still have the same problem.
"David G." <david_nospam@.nospam.com> wrote in message news:<eOaWzPOhEHA.1276@.TK2MSFTNGP09.phx.gbl>...
> James wrote:
> > I have a problem where occasionally (less that 1%) a packet is not
> > processed for as long as 25 seconds.
> >
> > 1) I get the exact same behavior with ADO 2.8 and ADO.NET.
> >
> > 2) A detailed view of the chain of events looks like this:
> >
> > . T+0 seconds - connection from the pool is allocated
> > . T+0 seconds - vb call to Command.Execute (or c# call to
> > DataAdapter.Fill)
> > . T+0 seconds - single packet (118 bytes) is sent to database machine
> > (from a web server)
> > . T+0.1 seconds - ack received from database machine indicating packet
> > was successfully received in full
> > . T+25 seconds - SQL Profiler trace "Start Time" for database call
> > . T+25 seconds - SQL Profiler trace "End Time" for database call
> > . T+25 seconds - data returns to application
> > . T+25 seconds - connection is returned to the pool
> >
> >
> > So the "lost time" occurs on the database machine between the time the
> > packet is received, and the time Profiler claims SQL Server started
> > working on the query.
> >
> > I've tried to run perfmon on the obvious counters on the database but
> > I've failed to find anything out of the ordinary. There are so many
> > counters! Any ideas on what specifically I should be looking at now?
> >
> > ~ James
> >
> > Occasional delay in processing incoming packets
> If you can, try setting up an alias to teh SQL Server machine using a
> different network protocol (e.g. named pipes instead of TCP/IP). That
> way you can see if the problem is related to the network library. If the
> start time in Profiler is T+25, it sounds like SQL Server is not getting
> the packet until T+25.
> You can set up aliases from the SQL Server Client Tools - Client Network
> Utility.|||James wrote:
> I created a Named Pipes alias and used that instead of TCP/IP. I've
> never done that before, so I checked to make sure the connections were
> using Named Pipes before continuing.
> During this test I still have the same problem.
> "David G." <david_nospam@.nospam.com> wrote in message
> news:<eOaWzPOhEHA.1276@.TK2MSFTNGP09.phx.gbl>...
>> James wrote:
>> I have a problem where occasionally (less that 1%) a packet is not
>> processed for as long as 25 seconds.
>> 1) I get the exact same behavior with ADO 2.8 and ADO.NET.
>> 2) A detailed view of the chain of events looks like this:
>> . T+0 seconds - connection from the pool is allocated
>> . T+0 seconds - vb call to Command.Execute (or c# call to
>> DataAdapter.Fill)
>> . T+0 seconds - single packet (118 bytes) is sent to database
>> machine (from a web server)
>> . T+0.1 seconds - ack received from database machine indicating
>> packet was successfully received in full
>> . T+25 seconds - SQL Profiler trace "Start Time" for database call
>> . T+25 seconds - SQL Profiler trace "End Time" for database call
>> . T+25 seconds - data returns to application
>> . T+25 seconds - connection is returned to the pool
>>
>> So the "lost time" occurs on the database machine between the time
>> the packet is received, and the time Profiler claims SQL Server
>> started working on the query.
>> I've tried to run perfmon on the obvious counters on the database
>> but I've failed to find anything out of the ordinary. There are so
>> many counters! Any ideas on what specifically I should be looking
>> at now?
>> ~ James
>> Occasional delay in processing incoming packets
>> If you can, try setting up an alias to teh SQL Server machine using a
>> different network protocol (e.g. named pipes instead of TCP/IP). That
>> way you can see if the problem is related to the network library. If
>> the start time in Profiler is T+25, it sounds like SQL Server is not
>> getting the packet until T+25.
>> You can set up aliases from the SQL Server Client Tools - Client
>> Network Utility.
Is this occurring from only one client or from all clients? What SP are
you running on SQL Server?
--
David G.|||There are 11 web servers and they all exhibit the same behavior.
At first I thought the times of the occurrences on the different web
servers did not correlate ? but now I think they do. Previously I was
only tracking delays of 5 seconds or greater. I think if I track all
delays I may get more matches.
I also tried tracing everything that was executing on the server ? I
did that for 6 minutes and I had one delay of 6 seconds on one web
server to compare. Then I looked for things that started at the same
time that my delayed sp was supposed to start? and I found only two
items ? which is very strange because this is a busy database. So I
grouped the results of the trace by StartTime per second yielding 360
numbers . The normal parts of the graph bounce around between 200 and
600 (not including full text calls) ? and for the second that I
submitted the delayed sp, the number plummets to 2. Full text calls
plummet to 0, and EndTimes for this second are 0 also. This was
followed by a peak of 860 (non-ft StartTimes) 7 seconds later. I do
not know if this happens every time ? I have more testing to do.
I wish I had somewhere I could post the data for DL but I do not right
now.
Anyone know what the capacity of SQL server is for incoming sql
requests? It averaged 895/second (including fulltext index calls to
sp_fulltext_getdata) with a peak of 1549 during this 6 minutes.
>> What SP are you running on SQL Server?
Service Pack?
SQL Server Machine:
Windows Server 2003 Enterprise (NT 5.2 (3790))
Quad Xeon 3.06GHz, 4GB RAM
SQL Server Enterprise 8.00.818 (SP3)
Stored Procedure?
The stored procedure I targeted just does a single row select on a
small table using the PK. I haven't gone to this level of detail on
any other sp, but I assume the problem can affect any call to the db.
~ James
"David G." <david_nospam@.nospam.com> wrote in message news:<eDkzArfhEHA.3912@.TK2MSFTNGP11.phx.gbl>...
> James wrote:
> > I created a Named Pipes alias and used that instead of TCP/IP. I've
> > never done that before, so I checked to make sure the connections were
> > using Named Pipes before continuing.
> >
> > During this test I still have the same problem.
> >
> > "David G." <david_nospam@.nospam.com> wrote in message
> > news:<eOaWzPOhEHA.1276@.TK2MSFTNGP09.phx.gbl>...
> >> James wrote:
> >> I have a problem where occasionally (less that 1%) a packet is not
> >> processed for as long as 25 seconds.
> >>
> >> 1) I get the exact same behavior with ADO 2.8 and ADO.NET.
> >>
> >> 2) A detailed view of the chain of events looks like this:
> >>
> >> . T+0 seconds - connection from the pool is allocated
> >> . T+0 seconds - vb call to Command.Execute (or c# call to
> >> DataAdapter.Fill)
> >> . T+0 seconds - single packet (118 bytes) is sent to database
> >> machine (from a web server)
> >> . T+0.1 seconds - ack received from database machine indicating
> >> packet was successfully received in full
> >> . T+25 seconds - SQL Profiler trace "Start Time" for database call
> >> . T+25 seconds - SQL Profiler trace "End Time" for database call
> >> . T+25 seconds - data returns to application
> >> . T+25 seconds - connection is returned to the pool
> >>
> >>
> >> So the "lost time" occurs on the database machine between the time
> >> the packet is received, and the time Profiler claims SQL Server
> >> started working on the query.
> >>
> >> I've tried to run perfmon on the obvious counters on the database
> >> but I've failed to find anything out of the ordinary. There are so
> >> many counters! Any ideas on what specifically I should be looking
> >> at now?
> >>
> >> ~ James
> >>
> >> Occasional delay in processing incoming packets
> >>
> >> If you can, try setting up an alias to teh SQL Server machine using a
> >> different network protocol (e.g. named pipes instead of TCP/IP). That
> >> way you can see if the problem is related to the network library. If
> >> the start time in Profiler is T+25, it sounds like SQL Server is not
> >> getting the packet until T+25.
> >>
> >> You can set up aliases from the SQL Server Client Tools - Client
> >> Network Utility.
> Is this occurring from only one client or from all clients? What SP are
> you running on SQL Server?
