elapsed time problem

I've just written a very "trivial" monitoring tool and it's providing
bizarre results. The code doesn't error as such, I think it may be the
concept that's wrong.

The tool is in two parts. The first is an ASP web page on a remote server
and the second is a VB6 application running locally which calls the ASP
page.

When called, the ASP web page loads the current time into a variable with
double point precision [dStart = CDbl(TImer)], does some work [connecting
through to a database and iterating through the resultant recordset] and
then records the finish time, also as a double. It then returns an XML
string that contains these start and end values.

In a similar vein, the VB6 application notes the start time, calls this ASP
page and then notes the end time. It calls the ASP page by creating a
MSXML2.XMLHTTP object and doing a SYNCHRONOUS connection (asynch=False).
The responseText gets loaded into a MSXML2.DOMDOCUMENT and the ASP
processing times are extracted using XPath expressions.

The VB6 application then calculates the times. So, I effectively have four
times:
startVBRequest, startASPProcessing, endASPProcessing and endVBRequest.

To my mind:
+ the processing time on the remote server is (endASPProcessing -
startASPProcessing)
+ the total time is (endVBRequest - startVBRequest)
+ the network-hop time is ((endVBRequest - startVBRequest) -
(endASPProcessing - startASPProcessing))

Because these are using time-differences, the local clock values of the
machines should be irrelevant.

My problem is that whilst I get finite values for the ASP processing time,
the total time values are 0, making the network time negative.

I don't like to think I'm breaking the laws of physics here, so there must a
better way of measuring elapsed times? By the way - although the monitoring
tool is currently in VB6, I'm soon going to make it ASP too, so don't want
to use any controls (OCX).

Any advice here?

Thanks

Griff

Tony
Mon Oct 11 05:11:35 CDT 2004

Sounds reasonable to me. I can only think there must be a coding problem in
the recording of the start/end request times Griff. Any chance you could
post a bit of sample code?

Tony Proctor

"Griff" <Howling@The.Moon> wrote in message
news:OpKsvk3rEHA.3876@TK2MSFTNGP15.phx.gbl...
> I've just written a very "trivial" monitoring tool and it's providing
> bizarre results. The code doesn't error as such, I think it may be the
> concept that's wrong.
>
> The tool is in two parts. The first is an ASP web page on a remote server
> and the second is a VB6 application running locally which calls the ASP
> page.
>
> When called, the ASP web page loads the current time into a variable with
> double point precision [dStart = CDbl(TImer)], does some work [connecting
> through to a database and iterating through the resultant recordset] and
> then records the finish time, also as a double. It then returns an XML
> string that contains these start and end values.
>
> In a similar vein, the VB6 application notes the start time, calls this
ASP
> page and then notes the end time. It calls the ASP page by creating a
> MSXML2.XMLHTTP object and doing a SYNCHRONOUS connection (asynch=False).
> The responseText gets loaded into a MSXML2.DOMDOCUMENT and the ASP
> processing times are extracted using XPath expressions.
>
> The VB6 application then calculates the times. So, I effectively have
four
> times:
> startVBRequest, startASPProcessing, endASPProcessing and endVBRequest.
>
> To my mind:
> + the processing time on the remote server is (endASPProcessing -
> startASPProcessing)
> + the total time is (endVBRequest - startVBRequest)
> + the network-hop time is ((endVBRequest - startVBRequest) -
> (endASPProcessing - startASPProcessing))
>
> Because these are using time-differences, the local clock values of the
> machines should be irrelevant.
>
> My problem is that whilst I get finite values for the ASP processing time,
> the total time values are 0, making the network time negative.
>
> I don't like to think I'm breaking the laws of physics here, so there must
a
> better way of measuring elapsed times? By the way - although the
monitoring
> tool is currently in VB6, I'm soon going to make it ASP too, so don't want
> to use any controls (OCX).
>
> Any advice here?
>
> Thanks
>
> Griff
>
>

Griff
Mon Oct 11 05:32:37 CDT 2004

> Sounds reasonable to me. I can only think there must be a coding problem
in
> the recording of the start/end request times Griff. Any chance you could
> post a bit of sample code?

Literally just:
dBeginRequest = CDbl(Timer)

However, I have just noted that that monitoring server I'm running this on
is running at 100% CPU (the anti-virus kit is using all the resource). I
don't have the authority to re-boot this, so I've just tried my application
on serveral colleagues' PCs and it responds with completely sensible
results.

Now, I would have thought that if the monitoring server were running slowly,
then this should serve to increase the perceived network hop (since on
effectively has delays between the start and end time), not to give me the
elapsed time as zero. However, it's obviously in a sorry state, so I'm not
going to second guess what else is wrong with it.

So, hopefully just a false alarm....

Griff

Tony
Mon Oct 11 05:50:46 CDT 2004

Timer() is just returning the seconds from (the last-)midnight. The 100%
activity shouldn't have that much of an impact.

Re: code, I was more interested in the points at which you record the start
& end times, and what lies in between them. My first thought when I saw that
your question was also posted to a vbscript group was that you were seeing a
cached HTML response, and so the time would be close to 0. However, since
you're actually using XMLHTTP and getting an XML response then this
shouldn't be applicable.

Tony Proctor

"Griff" <Howling@The.Moon> wrote in message
news:uyjNk23rEHA.2580@TK2MSFTNGP15.phx.gbl...
> > Sounds reasonable to me. I can only think there must be a coding problem
> in
> > the recording of the start/end request times Griff. Any chance you could
> > post a bit of sample code?
>
> Literally just:
> dBeginRequest = CDbl(Timer)
>
> However, I have just noted that that monitoring server I'm running this on
> is running at 100% CPU (the anti-virus kit is using all the resource). I
> don't have the authority to re-boot this, so I've just tried my
application
> on serveral colleagues' PCs and it responds with completely sensible
> results.
>
> Now, I would have thought that if the monitoring server were running
slowly,
> then this should serve to increase the perceived network hop (since on
> effectively has delays between the start and end time), not to give me the
> elapsed time as zero. However, it's obviously in a sorry state, so I'm
not
> going to second guess what else is wrong with it.
>
> So, hopefully just a false alarm....
>
> Griff
>
>

Bob
Mon Oct 11 11:07:02 CDT 2004

Griff wrote:

>>Sounds reasonable to me. I can only think there must be a coding problem
>
> in
>
>>the recording of the start/end request times Griff. Any chance you could
>>post a bit of sample code?
>
>
> Literally just:
> dBeginRequest = CDbl(Timer)



You might look into the GetTickCount API.
I tend to use that instead of "Timer" if I want any more precision than
whole seconds. Not sure quite where I got the impression that "Timer"
is imprecise, but for historical (and perhaps apocryphal) reasons I just
don't trust it.



Bob

Griff
Mon Oct 11 11:14:32 CDT 2004

Bob

Thanks for that; I hadn't heard of that API (but I guess there's a lot of
API calls I haven't heard of).

However, whilst making the "request" time more precise might give me a
non-zero time back, it still has to be greater than the "processing" time on
the server being monitored otherwise I'll still end up with negative values.
I'll give it a go and if it works, I'll let the group know.

Thanks

Griff

Griff
Mon Oct 11 11:20:45 CDT 2004

> Re: code, I was more interested in the points at which you record the
start
> & end times, and what lies in between them.

I've now done what I said I'd do and create it all as as ASP script. Same
results, so I'm posting VBScript code here. It's in the format of two
functions.

The function "tableRow" is passed the descriptive name of the server it has
to connect to and it's IP address and it returns a row in a HTML table.
It's a bit more bloated with lines of code than it used to be, but that's
only so I could really check individual values.

This calls a function called "queryServer".

Private Function tableRow(ByVal serverName, byval ipAddress)
Dim dBeginRequest
Dim dBeginProcessing
Dim dEndProcessing
Dim dEndRequest
Dim lRecordsProcessed

Dim dProcessingTime
Dim dRequestTime
Dim dNetworkTime

' Start the request
dBeginRequest = CDbl(Timer)

' Query the server
queryServer ipAddress, dBeginProcessing, dEndProcessing, lRecordsProcessed

' End the request
dEndRequest = CDbl(Timer)

' Work out the times
dProcessingTime = dEndProcessing - dBeginProcessing
dRequestTime = dEndRequest - dBeginRequest
dNetworkTime = dRequestTime - dProcessingTime

tableRow = "<tr>" & _
"<td>" & serverName & "</td>" & _
"<td>" & dProcessingTime & "</td>" & _
"<td>" & lRecordsProcessed & "</td>" & _
"<td>" & IIf(dNetworkTime >=0, dNetworkTime, 0) & "</td>" & _
"<td>" & dRequestTime & "</td>" & _
"</tr>" & vbnewline
End Function
'------------------------
private function queryServer(byVal ipAddress, byref dBeginProcessing, byref
dEndProcessing, byref lRecordsProcessed)
Dim oHTTP
Dim oDoc

Set oHTTP = Server.CreateObject("MSXML2.XMLHTTP")
Set oDoc = Server.CreateObject("MSXML2.DOMDOCUMENT")

with oHTTP
.open "GET", "http://" & ipAddress & "/performance.asp", False
.send

With oDoc
.async = False
.loadXML Trim(oHTTP.responseText)
End With

end with
Set oHTTP = Nothing

With oDoc
dBeginProcessing = cDbl(.selectSingleNode("//responseTimes/start").text)
dEndProcessing = cDbl(.selectSingleNode("//responseTimes/end").text)
lRecordsProcessed =
cDbl(.selectSingleNode("//responseTimes/databaseCount").text)
End With
set oDoc = nothing
end function

Bob
Mon Oct 11 11:53:11 CDT 2004

Griff wrote:

> However, whilst making the "request" time more precise might give me a
> non-zero time back, it still has to be greater than the "processing" time on
> the server being monitored otherwise I'll still end up with negative values.
> I'll give it a go and if it works, I'll let the group know.



oh ... wait ... you're trying to compare time measurements
taken on DIFFERENT BOXES?

Either get synchronization services installed and working on both,
or GIVE UP NOW, while you still have some sanity left.




Bob

Griff
Tue Oct 12 05:50:41 CDT 2004

> oh ... wait ... you're trying to compare time measurements
> taken on DIFFERENT BOXES?

Well, not exactly....

One the remote server, I'm recording the start time and end time (both as
double precision floating points) but I'm only interested in the difference
between them which represents the processing time on the remote server.

One the local server, I'm also recording the start time and end time (both
as double precision floating points) and I'm only interested in the
difference between them which represents the network hop plus the remote
processing time.

I do take the processing time away from the (network hop plus remote
processing time) to identify the network hop only. Because I'm only dealing
with elapsed time, I don't think I need synchronisation between the servers.

The problem I seem to have is that the (network hop plus remote processing
time) recorded on the local server appears to be less than the processing
time recorded on the remote server.

> Either get synchronization services installed and working on both,
> or GIVE UP NOW, while you still have some sanity left.

Generous of you to assume my current sanity levels are what they are :-)