test 573 failing in original mingw

[jay]

I did this

./runtests.pl -p 573

fails during comparison of connect time:
connect time 0.000000e+000 is < epsilon 1.084202e-019

log

=== Start of file stderr573
 URL: http://127.0.0.1:8990/573
 00:12:14.380000 == Info: STATE: INIT => CONNECT handle 0xa4af18; line 1413 (connection #-5000)
 00:12:14.380000 == Info: Added connection 0. The cache now contains 1 members
 00:12:14.380000 == Info: timeout on name lookup is not supported
 00:12:14.380000 == Info:   Trying 127.0.0.1...
 00:12:14.380000 == Info: TCP_NODELAY set
 00:12:14.380000 == Info: STATE: CONNECT => WAITCONNECT handle 0xa4af18; line 1466 (connection #0)
 00:12:14.380000 == Info: Connected to 127.0.0.1 (127.0.0.1) port 8990 (#0)
 00:12:14.380000 == Info: STATE: WAITCONNECT => SENDPROTOCONNECT handle 0xa4af18; line 1583 (connection #0)
 00:12:14.380000 == Info: Marked for [keep alive]: HTTP default
 00:12:14.380000 == Info: STATE: SENDPROTOCONNECT => DO handle 0xa4af18; line 1601 (connection #0)
 00:12:14.380000 => Send header, 56 bytes (0x38)
 0000: GET /573 HTTP/1.1
 0013: Host: 127.0.0.1:8990
 0029: Accept: */*
 0036:
 00:12:14.380000 == Info: STATE: DO => DO_DONE handle 0xa4af18; line 1680 (connection #0)
 00:12:14.380000 == Info: STATE: DO_DONE => WAITPERFORM handle 0xa4af18; line 1807 (connection #0)
 00:12:14.380000 == Info: STATE: WAITPERFORM => PERFORM handle 0xa4af18; line 1817 (connection #0)
 00:12:14.380000 == Info: HTTP 1.1 or later with persistent connection, pipelining supported
 00:12:14.380000 <= Recv header, 17 bytes (0x11)
 0000: HTTP/1.1 200 OK
 00:12:14.380000 <= Recv header, 37 bytes (0x25)
 0000: Date: Thu, 09 Nov 2010 14:49:00 GMT
 00:12:14.380000 == Info: Server test-server/fake is not blacklisted
 00:12:14.380000 <= Recv header, 26 bytes (0x1a)
 0000: Server: test-server/fake
 00:12:14.380000 <= Recv header, 46 bytes (0x2e)
 0000: Last-Modified: Tue, 13 Jun 2000 12:10:00 GMT
 00:12:14.380000 <= Recv header, 28 bytes (0x1c)
 0000: ETag: "21025-dc7-39462498"
 00:12:14.380000 <= Recv header, 22 bytes (0x16)
 0000: Accept-Ranges: bytes
 00:12:14.380000 <= Recv header, 19 bytes (0x13)
 0000: Content-Length: 6
 00:12:14.380000 == Info: Marked for [closure]: Connection: close used
 00:12:14.380000 <= Recv header, 19 bytes (0x13)
 0000: Connection: close
 00:12:14.380000 <= Recv header, 25 bytes (0x19)
 0000: Content-Type: text/html
 00:12:14.380000 <= Recv header, 20 bytes (0x14)
 0000: Funny-head: yesyes
 00:12:14.380000 <= Recv header, 2 bytes (0x2)
 0000:
 00:12:14.380000 <= Recv data, 6 bytes (0x6)
 0000: -foo-.
 00:12:14.380000 == Info: STATE: PERFORM => DONE handle 0xa4af18; line 1991 (connection #0)
 00:12:14.380000 == Info: multi_done
 00:12:14.380000 == Info: Closing connection 0
 00:12:14.380000 == Info: The cache now contains 0 members
 connect time 0.000000e+000 is < epsilon 1.084202e-019
 00:12:14.380000 == Info: Expire cleared
=== End of file stderr573

curl/libcurl version

********* System characteristics ********
* curl 7.54.0 (i686-pc-mingw32)
* libcurl/7.54.0 OpenSSL/1.0.2l zlib/1.2.11 nghttp2/1.23.1
* Features: Debug TrackMemory Largefile SSPI Kerberos SPNEGO NTLM SSL libz TLS-SRP HTTP2 HTTPS-proxy
* Host: COMPUTER
* System: MINGW32_NT-6.1 [removed] 1.0.17(0.48/3/2) 2011-04-24 23:39 i686 Msys
* Servers: SSL
* Env:
*****************************************

operating system

Windows 7 x64 Enterprise

[bagder]

Oops. With only millisecond resolution on the timer and everything happening within that single millisecond, the connect time is (correctly) evaluated to be zero... which the test doesn't like. A connect is supposed to take at least a tiny amount of time! =)

One (lame) way to fix this could be to have Curl_pgrsTime automatically add a microsecond to a connect time that is evaluated to 0.

A better way would probably be to use a timer on windows with better resolution...

[jay]

A better way would probably be to use a timer on windows with better resolution...

Setting a timer resolution smaller than the default in Windows (usually 15ms, Server versions may differ) will set it for all programs and also increases battery drain. There is a way to get RDTSC in Windows (Query Performance Counter API) however that will vary with processor speed I believe so for example you take a measurement and then the processor speed changes and changes back before you take another measurement, I don't think it's accurate for telling time in a case like that (I'm thinking SpeedStep, maybe I'm wrong).

[MarcelRaad]

@jay According to the QueryPerformanceFrequency documentation, "the frequency of the performance counter is fixed at system boot."
I haven't encountered any problems with it since Windows Vista / Server 2008. But on Server 2003 with multiple CPUs and XP with some older hardware, it's more or less a random number generator if you don't bind your thread to a specific logical CPU.

[bagder]

If a sub-15-millisecond timer is a problem, then I think I favor my first suggestion: we change the internal time stamps to count microseconds and then we can just add a microsecond or something if it seems to store a zero elapsed time.

[jay]

@MarcelRaad thanks. I just finished reading Windows documentation Acquiring high-resolution time stamps which I recommend to anyone who wants to know more about this.

[bagder]

So #1549 is basically my take at the approach I mentioned.