Archived Forum Post
Index of archived forum posts
Question:
We replaced our library by chilkat and it is 4x slower. We guess it is the resolving phase. Can we disable it ?
Since we saw the post : http://www.chilkatforum.com/questions/5880/dns-caching We did more test with the CkHttp client but the dns caching doesn't seem to works:
DWORD tick = GetTickCount();
CkHttpResponse* rsp = http.SynchronousRequest(host.c_str(), port, useSsl, *request);
TRACE("test1 %d \n", GetTickCount() - tick);
tick = GetTickCount();
rsp = http.SynchronousRequest(host.c_str(), port, useSsl, *request);
TRACE("test2 %d \n", GetTickCount() - tick);
tick = GetTickCount();
rsp = http.SynchronousRequest(host.c_str(), port, useSsl, *request);
TRACE("test3 %d \n", GetTickCount() - tick);
tick = GetTickCount();
rsp = http.SynchronousRequest(host.c_str(), port, useSsl, *request);
TRACE("test4 %d \n", GetTickCount() - tick);
tick = GetTickCount();
rsp = http.SynchronousRequest(host.c_str(), port, useSsl, *request);
TRACE("test5 %d \n", GetTickCount() - tick);
tick = GetTickCount();
rsp = http.SynchronousRequest(host.c_str(), port, useSsl, *request);
TRACE("test6 %d \n", GetTickCount() - tick);
Result :
test1 453
test2 407
test3 453
test4 375
test5 359
test6 422
We did some test with XMLRPC chilkat client vs XmlRpcClient :
prepareRequest(methodName, params);
DWORD tick = GetTickCount();
const char* rsp = http.xmlRpc(url.c_str(), request.c_str());
TRACE("New %d \n", GetTickCount() - tick);
tick = GetTickCount();
XmlRpcClient c(server.c_str(), port, uri.c_str());
success = c.execute(methodName, params, result);
TRACE("old %d \n", GetTickCount() - tick);
Result :
New 297
old 93
New 329
old 62
New 328
old 63
New 328
old 109
New 297
old 78
New 328
old 63
New 296
old 79
New 312
old 78
New 375
old 125
New 453
old 188
New 297
old 62
New 375
old 141
New 390
old 94
New 297
old 109
New 422
old 141
New 375
old 63
New 297
old 62
New 297
old 93
These tests were done within a VPN.
My only guess is that maybe it has to do with DNS lookups (i.e. resolving a domain name to IP address). One way to find out what is consuming time is to turn on verbose logging (by setting the VerboseLogging property = true), and then examine the LastErrorText after the method call. The LastErrorText will always contain information about the call, even if successful, and when verbose, the time spent within each context, if greater than 1ms, will be shown.
Also, in any Chilkat method where a domain name is passed, you can instead pass the IP address. That would certainly avoid having Chilkat resolve the domain name.
Also, the Chilkat.Global.EnableDnsCaching property can be set to true. This makes it so that a domain name resolutions are cached. I'll check on the information at http://www.chilkatforum.com/questions/5880/dns-caching to see how this relates to Global.EnableDnsCaching
I looked into it...
The Chilkat.Global.EnableDnsCaching needs to be set to true to enable caching in the first place. The Http.DnsCacheClear would only have an effect if EnableDnsCaching was turned on. Otherwise, the cache is already empty because it was never enabled.
Thanks for your answers.
We were already using IP address. I enabled DNS caching and verbose without any noticeable improvement:
HTTP test (Time in ms):
test1 438
ChilkatLog:
SynchronousRequest(438ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
domain: 10.103.104.167
port: 80
ssl: 0
originallySetFromUrl: http://10.103.104.111:80/PSlicence/api/v1/authentication
httpRequest:
httpVersion: 1.1
verb: POST
path: /PSlicence/api/v1/authentication
contentType: application/x-www-form-urlencoded
charset: windows-1252
sendCharset: 0
mimeHeader:
requestParams:
requestItem:
name: action
value: login
--requestItem
requestIt
test2 375
ChilkatLog:
SynchronousRequest(375ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
domain: 10.103.104.167
port: 80
ssl: 0
originallySetFromUrl: http://10.103.104.111:80/PSlicence/api/v1/authentication
httpRequest:
httpVersion: 1.1
verb: POST
path: /PSlicence/api/v1/authentication
contentType: application/x-www-form-urlencoded
charset: windows-1252
sendCharset: 0
mimeHeader:
requestParams:
requestItem:
name: action
value: login
--requestItem
requestIt
XMLRPC comparison (New means chilkat http, old means another client) (Time in ms):
New 328
ChilkatLog:
XmlRpcPost(328ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
url: http://10.103.104.167:8084/RPC2
finalizeRequestHeader:
Auto-adding Host header.
--finalizeRequestHeader
fullRequest(312ms):
httpRequest:
httpVersion: 1.1
verb: POST
path: /RPC2
contentType: text/xml
charset: utf-8
sendCharset: 0
mimeHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
--httpRequest
HttpOptions:
AddHostHeader: 1
AllowCookieResponseCaching: 0
AllowGzip: 1
CookieDir:
FollowRedirects: 1
Login:
LoginDomain:
old 78
New 313
ChilkatLog:
XmlRpcPost(313ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
url: http://10.103.104.167:8084/RPC2
finalizeRequestHeader:
Auto-adding Host header.
--finalizeRequestHeader
fullRequest(313ms):
httpRequest:
httpVersion: 1.1
verb: POST
path: /RPC2
contentType: text/xml
charset: utf-8
sendCharset: 0
mimeHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
--httpRequest
HttpOptions:
AddHostHeader: 1
AllowCookieResponseCaching: 0
AllowGzip: 1
CookieDir:
FollowRedirects: 1
Login:
LoginDomain:
old 62
New 391
ChilkatLog:
XmlRpcPost(375ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
url: http://10.103.104.167:8084/RPC2
finalizeRequestHeader:
Auto-adding Host header.
--finalizeRequestHeader
fullRequest(375ms):
httpRequest:
httpVersion: 1.1
verb: POST
path: /RPC2
contentType: text/xml
charset: utf-8
sendCharset: 0
mimeHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
--httpRequest
HttpOptions:
AddHostHeader: 1
AllowCookieResponseCaching: 0
AllowGzip: 1
CookieDir:
FollowRedirects: 1
Login:
LoginDomain:
old 109
New 313
ChilkatLog:
XmlRpcPost(313ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
url: http://10.103.104.167:8084/RPC2
finalizeRequestHeader:
Auto-adding Host header.
--finalizeRequestHeader
fullRequest(313ms):
httpRequest:
httpVersion: 1.1
verb: POST
path: /RPC2
contentType: text/xml
charset: utf-8
sendCharset: 0
mimeHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
--httpRequest
HttpOptions:
AddHostHeader: 1
AllowCookieResponseCaching: 0
AllowGzip: 1
CookieDir:
FollowRedirects: 1
Login:
LoginDomain:
old 78
New 297
ChilkatLog:
XmlRpcPost(297ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
url: http://10.103.104.167:8084/RPC2
finalizeRequestHeader:
Auto-adding Host header.
--finalizeRequestHeader
fullRequest(297ms):
httpRequest:
httpVersion: 1.1
verb: POST
path: /RPC2
contentType: text/xml
charset: utf-8
sendCharset: 0
mimeHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
--httpRequest
HttpOptions:
AddHostHeader: 1
AllowCookieResponseCaching: 0
AllowGzip: 1
CookieDir:
FollowRedirects: 1
Login:
LoginDomain:
old 62
Thanks, but you truncated each LastErrorText. What we really need to see is the full contents of a verbose LastErrorText for one call to SynchronousRequest that takes longer than expected.
My bad, VS trace doesn't log all. At first, we thought that the our server cache could shorter the 2nd transaction, but we have the exact same result (Old client about 4x faster), if we use our old client first. (We run the exact same request)
Xmlrpc comparison:
[2016-11-25 11:08:53] [DEBUG] Chilkat http client took 313 ms
[2016-11-25 11:08:53] [DEBUG] ChilkatLog:
XmlRpcPost(313ms):
DllDate: Nov 12 2016
ChilkatVersion: 9.5.0.64
UnlockPrefix: IMAGEMHttp
Architecture: Little Endian; 32-bit
Language: Visual C++ 10.0 (32-bit)
VerboseLogging: 1
url: http://10.103.104.167:8084/RPC2
finalizeRequestHeader:
Auto-adding Host header.
--finalizeRequestHeader
fullRequest(313ms):
httpRequest:
httpVersion: 1.1
verb: POST
path: /RPC2
contentType: text/xml
charset: utf-8
sendCharset: 0
mimeHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
--httpRequest
HttpOptions:
AddHostHeader: 1
AllowCookieResponseCaching: 0
AllowGzip: 1
CookieDir:
FollowRedirects: 1
Login:
LoginDomain:
AuthMethod:
MaxResponseSize: 0
MaxUrlLen: 2000
PasswordLen: 0
ReadTimeoutMs: 300000
RequiredContentType:
ResumePoint: 0
SaveCookies: 1
SendBufferSize: 65535
SendCookies: 1
UnavailableRetryCount: 0
UnavailableRetryWaitMs: 2000
--HttpOptions
a_synchronousRequest(313ms):
generateRequestHeader:
httpRequestGenStartLine:
authOnly: 0
hasMimeBody: 1
genStartLine:
startLine: POST /RPC2 HTTP/1.1
--genStartLine
--httpRequestGenStartLine
startLine: POST /RPC2 HTTP/1.1
genHeaderSb:
getMimeHeaderHttp:
headerField: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
headerField: Connection: keep-alive
headerField: User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
headerField: Accept-Language: en-us,en;q=0.5
headerField: Accept-Encoding: gzip
--getMimeHeaderHttp
--genHeaderSb
addCookies:
Not auto-adding cookies.
sendCookies: 1
cookieDir:
--addCookies
m_host: 10.103.104.167:8084
finalRequestHdr: Content-Type: text/xml
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
Host: 10.103.104.167:8084
Content-Length: 191
--generateRequestHeader
fullHttpRequest(313ms):
domain: 10.103.104.167
port: 8084
ssl: 0
openHttpConnection(32ms):
Opening connection directly to HTTP server.
httpHostname: 10.103.104.167
httpPort: 8084
ssl: 0
bUsingHttpProxy: 0
httpProxyAuthMethod:
socket2Connect(32ms):
connect2(32ms):
hostname: 10.103.104.167
port: 8084
ssl: 0
connectSocket(32ms):
domainOrIpAddress: 10.103.104.167
port: 8084
connectTimeoutMs: 300000
connect_ipv6_or_ipv4(32ms):
This is an IPV4 numeric address.
Domain to IP address resolution not needed.
connecting to IPV4 address...
ipAddress: 10.103.104.167
createSocket:
Setting SO_SNDBUF size
sendBufSize: 262144
Setting SO_RCVBUF size
recvBufSize: 4194304
--createSocket
connect(32ms):
Waiting for the connect to complete...
myIP: 10.152.53.88
myPort: 4944
socket connect successful.
--connect
--connect_ipv6_or_ipv4
--connectSocket
--connect2
--socket2Connect
socketOptions:
SO_SNDBUF: 262144
SO_RCVBUF: 4194304
TCP_NODELAY: 0
SO_KEEPALIVE: 1
--socketOptions
HTTP connection succeeded.
--openHttpConnection
connectTime: Elapsed time: 32 millisec
startLine: POST /RPC2 HTTP/1.1
fullRequestHeader:
requestHeader: Content-Type: text/xml
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip
Host: 10.103.104.167:8084
Content-Length: 191
--fullRequestHeader
computeRequestDataSize:
Request body is in a memory buffer..
--computeRequestDataSize
sendRequestHeader:
sendHeaderElapsedMs: 0
--sendRequestHeader
sendRequestBody:
idleTimeoutMs: 300000
sendBodyElapsedMs: 0
--sendRequestBody
readResponseHeader(281ms):
responseHeader: HTTP/1.1 200 OK
Server: Apache XML-RPC 1.0
Connection: close
Content-Type: text/xml
Content-Length: 128
--readResponseHeader
statusCode: 200
statusText: OK
readResponseBody:
bDiscard: 0
contentLength: 128
numBytesToReceive: 128
--readResponseBody
responseBodySize: 128
checkCloseConnection:
Response includes connection:close header (or proxy-connection:close header)
cleanCloseHttpConnection:
terminateConnection:
TCP connection cleanly closed by peer.
Cleanly terminated TCP connection.
--terminateConnection
--cleanCloseHttpConnection
--checkCloseConnection
--fullHttpRequest
originalUrl: http://10.103.104.167:8084/RPC2
success: 1
--a_synchronousRequest
success: 1
--fullRequest
Success.
--XmlRpcPost
Success.
--ChilkatLog
[2016-11-25 11:08:53] [DEBUG] Old client took 78 ms
The LastErrorText tells us:
Try this new build, which should have TCP_NODELAY turned on:
http://chilkatdownload.com/prerelease/chilkat-9.5.0-x86-vc10-sp1.zip
http://chilkatdownload.com/prerelease/chilkat-9.5.0-x86_64-vc10-sp1.zip
That's it, now we got similar response time!
[2016-11-28 09:51:08] [DEBUG] Chilkat http client took 78 ms
[2016-11-28 09:51:08] [DEBUG] Old client took 63 ms
[2016-11-28 09:51:08] [DEBUG] Chilkat http client took 93 ms
[2016-11-28 09:51:08] [DEBUG] Old client took 78 ms
[2016-11-28 09:51:09] [DEBUG] Chilkat http client took 78 ms
[2016-11-28 09:51:09] [DEBUG] Old client took 78 ms
[2016-11-28 09:51:09] [DEBUG] Chilkat http client took 62 ms
[2016-11-28 09:51:09] [DEBUG] Old client took 78 ms
[2016-11-28 09:51:09] [DEBUG] Chilkat http client took 62 ms
[2016-11-28 09:51:09] [DEBUG] Old client took 94 ms
[2016-11-28 09:51:09] [DEBUG] Chilkat http client took 110 ms
[2016-11-28 09:51:10] [DEBUG] Old client took 79 ms