You are viewing a plain text version of this content. The canonical link for it is here.
Posted to httpclient-users@hc.apache.org by "alin(王霖)" <xa...@gmail.com> on 2008/12/22 10:46:26 UTC
Why client connection's port changed always when server support Keep-alive?
HI:
I use httpclient3 and httpclient4 for a multi-thread load test, and
always set http request header with "Connection:Keep-Alive".
When i input command "netstat -na | grep myserverhost:myserverport" in
console(My system is windows xp + cygwin) , output like following:
C:\Documents and Settings\lin.wangl>netstat -na | grep 192.168.208.110:80
TCP 10.1.26.82:4159 192.168.208.110:80 ESTABLISHED
TCP 10.1.26.82:4160 192.168.208.110:80 ESTABLISHED
But the ports of client connections(here is 10.1.26.82) is changing while
load test is running.
through log4j, httpclient4 told me:
17:33:33,049 DEBUG DefaultRequestDirector:463 - Connection can be kept alive
for 15000 ms
17:33:33,065 DEBUG ThreadSafeClientConnManager:221 - Released connection is
reusable.
17:33:33,065 DEBUG ConnPoolByRoute:374 - Releasing connection
[HttpRoute[{}->http://192.168.208.110]][null]
17:33:33,065 DEBUG ConnPoolByRoute:394 - Pooling connection [HttpRoute[{}->
http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
Who can tell me why this is?
--
best Regards
alin
Re: Why client connection's port changed always when server support
Keep-alive?
Posted by Oleg Kalnichevski <ol...@apache.org>.
alin(王霖) wrote:
> Dear Oleg:
>
> Thank you very much for the help.
> Here is the total trace level log of two httpclient requests and responses,
> split with "--------- finish first send ------------" .
>
> httpclient4 log:
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter http.useragent =
> Jakarta Commons-HttpClient/3.0.1
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
> http.protocol.version = HTTP/1.1
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
> http.connection-manager.class = class
> org.apache.commons.httpclient.SimpleHttpConnectionManager
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
> http.protocol.cookie-policy = rfc2109
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
> http.protocol.element-charset = US-ASCII
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
> http.protocol.content-charset = ISO-8859-1
> 10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
> http.method.retry-handler =
> org.apache.commons.httpclient.DefaultHttpMethodRetryHandler@1a73d3c
> 10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
> http.dateparser.patterns = [EEE, dd MMM yyyy HH:mm:ss zzz, EEEE, dd-MMM-yy
> HH:mm:ss zzz, EEE MMM d HH:mm:ss yyyy, EEE, dd-MMM-yyyy HH:mm:ss z, EEE,
> dd-MMM-yyyy HH-mm-ss z, EEE, dd MMM yy HH:mm:ss z, EEE dd-MMM-yyyy HH:mm:ss
> z, EEE dd MMM yyyy HH:mm:ss z, EEE dd-MMM-yyyy HH-mm-ss z, EEE dd-MMM-yy
> HH:mm:ss z, EEE dd MMM yy HH:mm:ss z, EEE,dd-MMM-yy HH:mm:ss z,
> EEE,dd-MMM-yyyy HH:mm:ss z, EEE, dd-MM-yyyy HH:mm:ss z]
> 10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
> http.connection-manager.max-total = 1000
> 10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
> http.connection-manager.max-per-host = {HostConfiguration[]=2}
> 10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
> http.connection.timeout = 5000
> 10:27:29,510 DEBUG DefaultHttpParams:150 - Set parameter http.socket.timeout
> = 5000
> 10:27:29,510 DEBUG DefaultHttpParams:150 - Set parameter
> http.connection.stalecheck = true
> 10:27:29,510 DEBUG HttpClient:71 - Java version: 1.5.0
> 10:27:29,510 DEBUG HttpClient:72 - Java vendor: Sun Microsystems Inc.
> 10:27:29,510 DEBUG HttpClient:73 - Java class path:
> D:\workspace\top-java-client\trunk\target\test-classes;D:\workspace\top-java-client\trunk\target\classes;D:\setup\program\m2\commons-codec\commons-codec\1.2\commons-codec-1.2.jar;D:\setup\program\m2\commons-httpclient\commons-httpclient\3.0.1\commons-httpclient-3.0.1.jar;D:\setup\program\m2\commons-lang\commons-lang\2.3\commons-lang-2.3.jar;D:\setup\program\m2\commons-logging\commons-logging\1.1.1\commons-logging-1.1.1.jar;D:\setup\program\m2\org\apache\httpcomponents\httpclient\4.0-beta2\httpclient-4.0-beta2.jar;D:\setup\program\m2\org\apache\httpcomponents\httpcore\4.0-beta3\httpcore-4.0-beta3.jar;D:\setup\program\m2\junit\junit\4.4\junit-4.4.jar;D:\setup\program\m2\log4j\log4j\1.2.12\log4j-1.2.12.jar
> 10:27:29,510 DEBUG HttpClient:74 - Operating system name: Windows XP
> 10:27:29,510 DEBUG HttpClient:75 - Operating system architecture: x86
> 10:27:29,510 DEBUG HttpClient:76 - Operating system version: 5.1
> 10:27:29,572 DEBUG HttpClient:81 - SUN 1.5: SUN (DSA key/parameter
> generation; DSA signing; SHA-1, MD5 digests; SecureRandom; X.509
> certificates; JKS keystore; PKIX CertPathValidator; PKIX CertPathBuilder;
> LDAP, Collection CertStores)
> 10:27:29,572 DEBUG HttpClient:81 - SunRsaSign 1.5: Sun RSA signature
> provider
> 10:27:29,572 DEBUG HttpClient:81 - SunJSSE 1.5: Sun JSSE provider(PKCS12,
> SunX509 key/trust factories, SSLv3, TLSv1)
> 10:27:29,588 DEBUG HttpClient:81 - SunJCE 1.5: SunJCE Provider (implements
> RSA, DES, Triple DES, AES, Blowfish, ARCFOUR, RC2, PBE, Diffie-Hellman,
> HMAC)
> 10:27:29,588 DEBUG HttpClient:81 - SunJGSS 1.0: Sun (Kerberos v5)
> 10:27:29,588 DEBUG HttpClient:81 - SunSASL 1.5: Sun SASL provider(implements
> client mechanisms for: DIGEST-MD5, GSSAPI, EXTERNAL, PLAIN, CRAM-MD5; server
> mechanisms for: DIGEST-MD5, GSSAPI, CRAM-MD5)
> 10:27:29,588 DEBUG DefaultHttpParams:150 - Set parameter
> http.connection.timeout = 1000
> 10:27:29,588 DEBUG DefaultHttpParams:150 - Set parameter http.socket.timeout
> = 1000
> 10:27:29,744 DEBUG ClientParamsStack:219 - 'http.conn-manager.timeout': 5000
> 10:27:29,744 DEBUG ThreadSafeClientConnManager:171 -
> ThreadSafeClientConnManager.getConnection: HttpRoute[{}->
> http://192.168.208.110], timeout = 5000
> 10:27:29,744 DEBUG ConnPoolByRoute:289 - Total connections kept alive: 0
> 10:27:29,744 DEBUG ConnPoolByRoute:290 - Total issued connections: 0
> 10:27:29,744 DEBUG ConnPoolByRoute:291 - Total allocated connection: 0 out
> of 1000
> 10:27:29,744 DEBUG ConnPoolByRoute:462 - No free connections [HttpRoute[{}->
> http://192.168.208.110]][null]
> 10:27:29,744 DEBUG ConnPoolByRoute:308 - Available capacity: 2 out of 2
> [HttpRoute[{}->http://192.168.208.110]][null]
> 10:27:29,744 DEBUG ConnPoolByRoute:489 - Creating new connection
> [HttpRoute[{}->http://192.168.208.110]]
> 10:27:29,822 DEBUG ClientParamsStack:219 - 'http.protocol.version': HTTP/1.1
> 10:27:29,822 DEBUG RequestAddCookies:125 - CookieSpec selected: best-match
> 10:27:29,838 DEBUG DefaultRequestDirector:408 - Attempt 1 to execute request
> 10:27:29,838 DEBUG wire:78 - >> "POST /router/rest HTTP/1.1[EOL]"
> 10:27:29,853 DEBUG wire:78 - >> "Content-Length: 188[EOL]"
> 10:27:29,853 DEBUG wire:78 - >> "Content-Type:
> application/x-www-form-urlencoded[EOL]"
> 10:27:29,853 DEBUG wire:78 - >> "Host: 192.168.208.110[EOL]"
> 10:27:29,853 DEBUG wire:78 - >> "Connection: Keep-Alive[EOL]"
> 10:27:29,853 DEBUG wire:78 - >> "[EOL]"
> 10:27:29,853 DEBUG headers:251 - >> POST /router/rest HTTP/1.1
> 10:27:29,853 DEBUG headers:254 - >> Content-Length: 188
> 10:27:29,853 DEBUG headers:254 - >> Content-Type:
> application/x-www-form-urlencoded
> 10:27:29,853 DEBUG headers:254 - >> Host: 192.168.208.110
> 10:27:29,853 DEBUG headers:254 - >> Connection: Keep-Alive
> 10:27:29,853 DEBUG wire:78 - >>
> "fields=name%2Cbuyer_credit%2Cphone%2Creal_name×tamp=2008-12-25+10%3A27%3A29&api_key=suibian&nick=tbtest5&method=taobao.user.get&sign=82D375615F2EC704D9DAD60992359B3A&format=json&v=1.0"
> 10:27:29,869 DEBUG wire:78 - << "HTTP/1.1 200 OK[EOL]"
> 10:27:29,869 DEBUG wire:78 - << "Date: Thu, 25 Dec 2008 02:26:40 GMT[EOL]"
> 10:27:29,869 DEBUG wire:78 - << "Server: Apache-Coyote/1.1[EOL]"
> 10:27:29,869 DEBUG wire:78 - << "X-Powered-By: Servlet 2.4;
> JBoss-4.2.2.GA(build: SVNTag=JBoss_4_2_2_GA
> date=200710221139)/Tomcat-5.5[EOL]"
> 10:27:29,869 DEBUG wire:78 - << "Content-Type:
> text/javascript;charset=UTF-8[EOL]"
> 10:27:29,869 DEBUG wire:78 - << "Content-Length: 85[EOL]"
> 10:27:29,885 DEBUG wire:78 - << "Vary: Accept-Encoding[EOL]"
> 10:27:29,885 DEBUG wire:78 - << "Keep-Alive: timeout=15, max=100[EOL]"
> 10:27:29,885 DEBUG wire:78 - << "Connection: Keep-Alive[EOL]"
> 10:27:29,885 DEBUG headers:237 - << HTTP/1.1 200 OK
> 10:27:29,885 DEBUG headers:240 - << Date: Thu, 25 Dec 2008 02:26:40 GMT
> 10:27:29,885 DEBUG headers:240 - << Server: Apache-Coyote/1.1
> 10:27:29,885 DEBUG headers:240 - << X-Powered-By: Servlet 2.4;
> JBoss-4.2.2.GA (build: SVNTag=JBoss_4_2_2_GA date=200710221139)/Tomcat-5.5
> 10:27:29,885 DEBUG headers:240 - << Content-Type:
> text/javascript;charset=UTF-8
> 10:27:29,885 DEBUG headers:240 - << Content-Length: 85
> 10:27:29,885 DEBUG headers:240 - << Vary: Accept-Encoding
> 10:27:29,885 DEBUG headers:240 - << Keep-Alive: timeout=15, max=100
> 10:27:29,885 DEBUG headers:240 - << Connection: Keep-Alive
> 10:27:29,900 DEBUG DefaultRequestDirector:463 - Connection can be kept alive
> for 15000 ms
> 10:27:29,900 DEBUG wire:78 - <<
> "{"rsp":{"users":[{"buyer_credit":{"good_num":1,"level":0,"score":1,"total_num":1}}]}}"
> 10:27:29,900 DEBUG ThreadSafeClientConnManager:221 - Released connection is
> reusable.
> 10:27:29,900 DEBUG ConnPoolByRoute:374 - Releasing connection
> [HttpRoute[{}->http://192.168.208.110]][null]
> 10:27:29,900 DEBUG ConnPoolByRoute:394 - Pooling connection [HttpRoute[{}->
> http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
> 10:27:29,900 DEBUG IdleConnectionHandler:78 - Adding connection at:
> 1230172049900
> 10:27:29,900 DEBUG ConnPoolByRoute:631 - Notifying no-one, there are no
> waiting threads
> --------- finish first send ------------
> 10:27:29,916 DEBUG ClientParamsStack:219 - 'http.conn-manager.timeout': 5000
> 10:27:29,916 DEBUG ThreadSafeClientConnManager:171 -
> ThreadSafeClientConnManager.getConnection: HttpRoute[{}->
> http://192.168.208.110], timeout = 5000
> 10:27:29,916 DEBUG ConnPoolByRoute:289 - Total connections kept alive: 1
> 10:27:29,916 DEBUG ConnPoolByRoute:290 - Total issued connections: 0
> 10:27:29,916 DEBUG ConnPoolByRoute:291 - Total allocated connection: 1 out
> of 1000
> 10:27:29,916 DEBUG ConnPoolByRoute:436 - Getting free connection
> [HttpRoute[{}->http://192.168.208.110]][null]
> 10:27:29,916 DEBUG DefaultRequestDirector:334 - Stale connection check
> 10:27:29,932 DEBUG ClientParamsStack:219 - 'http.protocol.version': HTTP/1.1
> 10:27:29,932 DEBUG RequestAddCookies:125 - CookieSpec selected: best-match
> 10:27:29,932 DEBUG DefaultRequestDirector:408 - Attempt 1 to execute request
> 10:27:29,932 DEBUG wire:78 - >> "POST /router/rest HTTP/1.1[EOL]"
> 10:27:29,932 DEBUG wire:78 - >> "Content-Length: 188[EOL]"
> 10:27:29,932 DEBUG wire:78 - >> "Content-Type:
> application/x-www-form-urlencoded[EOL]"
> 10:27:29,932 DEBUG wire:78 - >> "Host: 192.168.208.110[EOL]"
> 10:27:29,932 DEBUG wire:78 - >> "Connection: Keep-Alive[EOL]"
> 10:27:29,932 DEBUG wire:78 - >> "[EOL]"
> 10:27:29,932 DEBUG headers:251 - >> POST /router/rest HTTP/1.1
> 10:27:29,932 DEBUG headers:254 - >> Content-Length: 188
> 10:27:29,932 DEBUG headers:254 - >> Content-Type:
> application/x-www-form-urlencoded
> 10:27:29,932 DEBUG headers:254 - >> Host: 192.168.208.110
> 10:27:29,932 DEBUG headers:254 - >> Connection: Keep-Alive
> 10:27:29,932 DEBUG wire:78 - >>
> "fields=name%2Cbuyer_credit%2Cphone%2Creal_name×tamp=2008-12-25+10%3A27%3A29&api_key=suibian&nick=tbtest5&method=taobao.user.get&sign=82D375615F2EC704D9DAD60992359B3A&format=json&v=1.0"
> 10:27:29,963 DEBUG wire:78 - << "HTTP/1.1 200 OK[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Date: Thu, 25 Dec 2008 02:26:40 GMT[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Server: Apache-Coyote/1.1[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "X-Powered-By: Servlet 2.4;
> JBoss-4.2.2.GA(build: SVNTag=JBoss_4_2_2_GA
> date=200710221139)/Tomcat-5.5[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Content-Type:
> text/javascript;charset=UTF-8[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Content-Length: 85[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Vary: Accept-Encoding[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Keep-Alive: timeout=15, max=99[EOL]"
> 10:27:29,963 DEBUG wire:78 - << "Connection: Keep-Alive[EOL]"
> 10:27:29,963 DEBUG headers:237 - << HTTP/1.1 200 OK
> 10:27:29,963 DEBUG headers:240 - << Date: Thu, 25 Dec 2008 02:26:40 GMT
> 10:27:29,963 DEBUG headers:240 - << Server: Apache-Coyote/1.1
> 10:27:29,963 DEBUG headers:240 - << X-Powered-By: Servlet 2.4;
> JBoss-4.2.2.GA (build: SVNTag=JBoss_4_2_2_GA date=200710221139)/Tomcat-5.5
> 10:27:29,963 DEBUG headers:240 - << Content-Type:
> text/javascript;charset=UTF-8
> 10:27:29,963 DEBUG headers:240 - << Content-Length: 85
> 10:27:29,963 DEBUG headers:240 - << Vary: Accept-Encoding
> 10:27:29,963 DEBUG headers:240 - << Keep-Alive: timeout=15, max=99
> 10:27:29,963 DEBUG headers:240 - << Connection: Keep-Alive
> 10:27:29,963 DEBUG DefaultRequestDirector:463 - Connection can be kept alive
> for 15000 ms
> 10:27:29,963 DEBUG wire:78 - <<
> "{"rsp":{"users":[{"buyer_credit":{"good_num":1,"level":0,"score":1,"total_num":1}}]}}"
> 10:27:29,963 DEBUG ThreadSafeClientConnManager:221 - Released connection is
> reusable.
> 10:27:29,963 DEBUG ConnPoolByRoute:374 - Releasing connection
> [HttpRoute[{}->http://192.168.208.110]][null]
> 10:27:29,963 DEBUG ConnPoolByRoute:394 - Pooling connection [HttpRoute[{}->
> http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
> 10:27:29,963 DEBUG IdleConnectionHandler:78 - Adding connection at:
> 1230172049963
> 10:27:29,963 DEBUG ConnPoolByRoute:631 - Notifying no-one, there are no
> waiting threads
>
> total duration:328
> httpclient4.x0-->firstDuration:281
> httpclient4.x0-->successDuration:47,successTimes:1
>
>
As far as I can tell from the log, persistent connections get correctly
re-used
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Why client connection's port changed always when server support Keep-alive?
Posted by "alin(王霖)" <xa...@gmail.com>.
Dear Oleg:
Thank you very much for the help.
Here is the total trace level log of two httpclient requests and responses,
split with "--------- finish first send ------------" .
httpclient4 log:
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter http.useragent =
Jakarta Commons-HttpClient/3.0.1
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
http.protocol.version = HTTP/1.1
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
http.connection-manager.class = class
org.apache.commons.httpclient.SimpleHttpConnectionManager
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
http.protocol.cookie-policy = rfc2109
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
http.protocol.element-charset = US-ASCII
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
http.protocol.content-charset = ISO-8859-1
10:27:29,478 DEBUG DefaultHttpParams:150 - Set parameter
http.method.retry-handler =
org.apache.commons.httpclient.DefaultHttpMethodRetryHandler@1a73d3c
10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
http.dateparser.patterns = [EEE, dd MMM yyyy HH:mm:ss zzz, EEEE, dd-MMM-yy
HH:mm:ss zzz, EEE MMM d HH:mm:ss yyyy, EEE, dd-MMM-yyyy HH:mm:ss z, EEE,
dd-MMM-yyyy HH-mm-ss z, EEE, dd MMM yy HH:mm:ss z, EEE dd-MMM-yyyy HH:mm:ss
z, EEE dd MMM yyyy HH:mm:ss z, EEE dd-MMM-yyyy HH-mm-ss z, EEE dd-MMM-yy
HH:mm:ss z, EEE dd MMM yy HH:mm:ss z, EEE,dd-MMM-yy HH:mm:ss z,
EEE,dd-MMM-yyyy HH:mm:ss z, EEE, dd-MM-yyyy HH:mm:ss z]
10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
http.connection-manager.max-total = 1000
10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
http.connection-manager.max-per-host = {HostConfiguration[]=2}
10:27:29,494 DEBUG DefaultHttpParams:150 - Set parameter
http.connection.timeout = 5000
10:27:29,510 DEBUG DefaultHttpParams:150 - Set parameter http.socket.timeout
= 5000
10:27:29,510 DEBUG DefaultHttpParams:150 - Set parameter
http.connection.stalecheck = true
10:27:29,510 DEBUG HttpClient:71 - Java version: 1.5.0
10:27:29,510 DEBUG HttpClient:72 - Java vendor: Sun Microsystems Inc.
10:27:29,510 DEBUG HttpClient:73 - Java class path:
D:\workspace\top-java-client\trunk\target\test-classes;D:\workspace\top-java-client\trunk\target\classes;D:\setup\program\m2\commons-codec\commons-codec\1.2\commons-codec-1.2.jar;D:\setup\program\m2\commons-httpclient\commons-httpclient\3.0.1\commons-httpclient-3.0.1.jar;D:\setup\program\m2\commons-lang\commons-lang\2.3\commons-lang-2.3.jar;D:\setup\program\m2\commons-logging\commons-logging\1.1.1\commons-logging-1.1.1.jar;D:\setup\program\m2\org\apache\httpcomponents\httpclient\4.0-beta2\httpclient-4.0-beta2.jar;D:\setup\program\m2\org\apache\httpcomponents\httpcore\4.0-beta3\httpcore-4.0-beta3.jar;D:\setup\program\m2\junit\junit\4.4\junit-4.4.jar;D:\setup\program\m2\log4j\log4j\1.2.12\log4j-1.2.12.jar
10:27:29,510 DEBUG HttpClient:74 - Operating system name: Windows XP
10:27:29,510 DEBUG HttpClient:75 - Operating system architecture: x86
10:27:29,510 DEBUG HttpClient:76 - Operating system version: 5.1
10:27:29,572 DEBUG HttpClient:81 - SUN 1.5: SUN (DSA key/parameter
generation; DSA signing; SHA-1, MD5 digests; SecureRandom; X.509
certificates; JKS keystore; PKIX CertPathValidator; PKIX CertPathBuilder;
LDAP, Collection CertStores)
10:27:29,572 DEBUG HttpClient:81 - SunRsaSign 1.5: Sun RSA signature
provider
10:27:29,572 DEBUG HttpClient:81 - SunJSSE 1.5: Sun JSSE provider(PKCS12,
SunX509 key/trust factories, SSLv3, TLSv1)
10:27:29,588 DEBUG HttpClient:81 - SunJCE 1.5: SunJCE Provider (implements
RSA, DES, Triple DES, AES, Blowfish, ARCFOUR, RC2, PBE, Diffie-Hellman,
HMAC)
10:27:29,588 DEBUG HttpClient:81 - SunJGSS 1.0: Sun (Kerberos v5)
10:27:29,588 DEBUG HttpClient:81 - SunSASL 1.5: Sun SASL provider(implements
client mechanisms for: DIGEST-MD5, GSSAPI, EXTERNAL, PLAIN, CRAM-MD5; server
mechanisms for: DIGEST-MD5, GSSAPI, CRAM-MD5)
10:27:29,588 DEBUG DefaultHttpParams:150 - Set parameter
http.connection.timeout = 1000
10:27:29,588 DEBUG DefaultHttpParams:150 - Set parameter http.socket.timeout
= 1000
10:27:29,744 DEBUG ClientParamsStack:219 - 'http.conn-manager.timeout': 5000
10:27:29,744 DEBUG ThreadSafeClientConnManager:171 -
ThreadSafeClientConnManager.getConnection: HttpRoute[{}->
http://192.168.208.110], timeout = 5000
10:27:29,744 DEBUG ConnPoolByRoute:289 - Total connections kept alive: 0
10:27:29,744 DEBUG ConnPoolByRoute:290 - Total issued connections: 0
10:27:29,744 DEBUG ConnPoolByRoute:291 - Total allocated connection: 0 out
of 1000
10:27:29,744 DEBUG ConnPoolByRoute:462 - No free connections [HttpRoute[{}->
http://192.168.208.110]][null]
10:27:29,744 DEBUG ConnPoolByRoute:308 - Available capacity: 2 out of 2
[HttpRoute[{}->http://192.168.208.110]][null]
10:27:29,744 DEBUG ConnPoolByRoute:489 - Creating new connection
[HttpRoute[{}->http://192.168.208.110]]
10:27:29,822 DEBUG ClientParamsStack:219 - 'http.protocol.version': HTTP/1.1
10:27:29,822 DEBUG RequestAddCookies:125 - CookieSpec selected: best-match
10:27:29,838 DEBUG DefaultRequestDirector:408 - Attempt 1 to execute request
10:27:29,838 DEBUG wire:78 - >> "POST /router/rest HTTP/1.1[EOL]"
10:27:29,853 DEBUG wire:78 - >> "Content-Length: 188[EOL]"
10:27:29,853 DEBUG wire:78 - >> "Content-Type:
application/x-www-form-urlencoded[EOL]"
10:27:29,853 DEBUG wire:78 - >> "Host: 192.168.208.110[EOL]"
10:27:29,853 DEBUG wire:78 - >> "Connection: Keep-Alive[EOL]"
10:27:29,853 DEBUG wire:78 - >> "[EOL]"
10:27:29,853 DEBUG headers:251 - >> POST /router/rest HTTP/1.1
10:27:29,853 DEBUG headers:254 - >> Content-Length: 188
10:27:29,853 DEBUG headers:254 - >> Content-Type:
application/x-www-form-urlencoded
10:27:29,853 DEBUG headers:254 - >> Host: 192.168.208.110
10:27:29,853 DEBUG headers:254 - >> Connection: Keep-Alive
10:27:29,853 DEBUG wire:78 - >>
"fields=name%2Cbuyer_credit%2Cphone%2Creal_name×tamp=2008-12-25+10%3A27%3A29&api_key=suibian&nick=tbtest5&method=taobao.user.get&sign=82D375615F2EC704D9DAD60992359B3A&format=json&v=1.0"
10:27:29,869 DEBUG wire:78 - << "HTTP/1.1 200 OK[EOL]"
10:27:29,869 DEBUG wire:78 - << "Date: Thu, 25 Dec 2008 02:26:40 GMT[EOL]"
10:27:29,869 DEBUG wire:78 - << "Server: Apache-Coyote/1.1[EOL]"
10:27:29,869 DEBUG wire:78 - << "X-Powered-By: Servlet 2.4;
JBoss-4.2.2.GA(build: SVNTag=JBoss_4_2_2_GA
date=200710221139)/Tomcat-5.5[EOL]"
10:27:29,869 DEBUG wire:78 - << "Content-Type:
text/javascript;charset=UTF-8[EOL]"
10:27:29,869 DEBUG wire:78 - << "Content-Length: 85[EOL]"
10:27:29,885 DEBUG wire:78 - << "Vary: Accept-Encoding[EOL]"
10:27:29,885 DEBUG wire:78 - << "Keep-Alive: timeout=15, max=100[EOL]"
10:27:29,885 DEBUG wire:78 - << "Connection: Keep-Alive[EOL]"
10:27:29,885 DEBUG headers:237 - << HTTP/1.1 200 OK
10:27:29,885 DEBUG headers:240 - << Date: Thu, 25 Dec 2008 02:26:40 GMT
10:27:29,885 DEBUG headers:240 - << Server: Apache-Coyote/1.1
10:27:29,885 DEBUG headers:240 - << X-Powered-By: Servlet 2.4;
JBoss-4.2.2.GA (build: SVNTag=JBoss_4_2_2_GA date=200710221139)/Tomcat-5.5
10:27:29,885 DEBUG headers:240 - << Content-Type:
text/javascript;charset=UTF-8
10:27:29,885 DEBUG headers:240 - << Content-Length: 85
10:27:29,885 DEBUG headers:240 - << Vary: Accept-Encoding
10:27:29,885 DEBUG headers:240 - << Keep-Alive: timeout=15, max=100
10:27:29,885 DEBUG headers:240 - << Connection: Keep-Alive
10:27:29,900 DEBUG DefaultRequestDirector:463 - Connection can be kept alive
for 15000 ms
10:27:29,900 DEBUG wire:78 - <<
"{"rsp":{"users":[{"buyer_credit":{"good_num":1,"level":0,"score":1,"total_num":1}}]}}"
10:27:29,900 DEBUG ThreadSafeClientConnManager:221 - Released connection is
reusable.
10:27:29,900 DEBUG ConnPoolByRoute:374 - Releasing connection
[HttpRoute[{}->http://192.168.208.110]][null]
10:27:29,900 DEBUG ConnPoolByRoute:394 - Pooling connection [HttpRoute[{}->
http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
10:27:29,900 DEBUG IdleConnectionHandler:78 - Adding connection at:
1230172049900
10:27:29,900 DEBUG ConnPoolByRoute:631 - Notifying no-one, there are no
waiting threads
--------- finish first send ------------
10:27:29,916 DEBUG ClientParamsStack:219 - 'http.conn-manager.timeout': 5000
10:27:29,916 DEBUG ThreadSafeClientConnManager:171 -
ThreadSafeClientConnManager.getConnection: HttpRoute[{}->
http://192.168.208.110], timeout = 5000
10:27:29,916 DEBUG ConnPoolByRoute:289 - Total connections kept alive: 1
10:27:29,916 DEBUG ConnPoolByRoute:290 - Total issued connections: 0
10:27:29,916 DEBUG ConnPoolByRoute:291 - Total allocated connection: 1 out
of 1000
10:27:29,916 DEBUG ConnPoolByRoute:436 - Getting free connection
[HttpRoute[{}->http://192.168.208.110]][null]
10:27:29,916 DEBUG DefaultRequestDirector:334 - Stale connection check
10:27:29,932 DEBUG ClientParamsStack:219 - 'http.protocol.version': HTTP/1.1
10:27:29,932 DEBUG RequestAddCookies:125 - CookieSpec selected: best-match
10:27:29,932 DEBUG DefaultRequestDirector:408 - Attempt 1 to execute request
10:27:29,932 DEBUG wire:78 - >> "POST /router/rest HTTP/1.1[EOL]"
10:27:29,932 DEBUG wire:78 - >> "Content-Length: 188[EOL]"
10:27:29,932 DEBUG wire:78 - >> "Content-Type:
application/x-www-form-urlencoded[EOL]"
10:27:29,932 DEBUG wire:78 - >> "Host: 192.168.208.110[EOL]"
10:27:29,932 DEBUG wire:78 - >> "Connection: Keep-Alive[EOL]"
10:27:29,932 DEBUG wire:78 - >> "[EOL]"
10:27:29,932 DEBUG headers:251 - >> POST /router/rest HTTP/1.1
10:27:29,932 DEBUG headers:254 - >> Content-Length: 188
10:27:29,932 DEBUG headers:254 - >> Content-Type:
application/x-www-form-urlencoded
10:27:29,932 DEBUG headers:254 - >> Host: 192.168.208.110
10:27:29,932 DEBUG headers:254 - >> Connection: Keep-Alive
10:27:29,932 DEBUG wire:78 - >>
"fields=name%2Cbuyer_credit%2Cphone%2Creal_name×tamp=2008-12-25+10%3A27%3A29&api_key=suibian&nick=tbtest5&method=taobao.user.get&sign=82D375615F2EC704D9DAD60992359B3A&format=json&v=1.0"
10:27:29,963 DEBUG wire:78 - << "HTTP/1.1 200 OK[EOL]"
10:27:29,963 DEBUG wire:78 - << "Date: Thu, 25 Dec 2008 02:26:40 GMT[EOL]"
10:27:29,963 DEBUG wire:78 - << "Server: Apache-Coyote/1.1[EOL]"
10:27:29,963 DEBUG wire:78 - << "X-Powered-By: Servlet 2.4;
JBoss-4.2.2.GA(build: SVNTag=JBoss_4_2_2_GA
date=200710221139)/Tomcat-5.5[EOL]"
10:27:29,963 DEBUG wire:78 - << "Content-Type:
text/javascript;charset=UTF-8[EOL]"
10:27:29,963 DEBUG wire:78 - << "Content-Length: 85[EOL]"
10:27:29,963 DEBUG wire:78 - << "Vary: Accept-Encoding[EOL]"
10:27:29,963 DEBUG wire:78 - << "Keep-Alive: timeout=15, max=99[EOL]"
10:27:29,963 DEBUG wire:78 - << "Connection: Keep-Alive[EOL]"
10:27:29,963 DEBUG headers:237 - << HTTP/1.1 200 OK
10:27:29,963 DEBUG headers:240 - << Date: Thu, 25 Dec 2008 02:26:40 GMT
10:27:29,963 DEBUG headers:240 - << Server: Apache-Coyote/1.1
10:27:29,963 DEBUG headers:240 - << X-Powered-By: Servlet 2.4;
JBoss-4.2.2.GA (build: SVNTag=JBoss_4_2_2_GA date=200710221139)/Tomcat-5.5
10:27:29,963 DEBUG headers:240 - << Content-Type:
text/javascript;charset=UTF-8
10:27:29,963 DEBUG headers:240 - << Content-Length: 85
10:27:29,963 DEBUG headers:240 - << Vary: Accept-Encoding
10:27:29,963 DEBUG headers:240 - << Keep-Alive: timeout=15, max=99
10:27:29,963 DEBUG headers:240 - << Connection: Keep-Alive
10:27:29,963 DEBUG DefaultRequestDirector:463 - Connection can be kept alive
for 15000 ms
10:27:29,963 DEBUG wire:78 - <<
"{"rsp":{"users":[{"buyer_credit":{"good_num":1,"level":0,"score":1,"total_num":1}}]}}"
10:27:29,963 DEBUG ThreadSafeClientConnManager:221 - Released connection is
reusable.
10:27:29,963 DEBUG ConnPoolByRoute:374 - Releasing connection
[HttpRoute[{}->http://192.168.208.110]][null]
10:27:29,963 DEBUG ConnPoolByRoute:394 - Pooling connection [HttpRoute[{}->
http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
10:27:29,963 DEBUG IdleConnectionHandler:78 - Adding connection at:
1230172049963
10:27:29,963 DEBUG ConnPoolByRoute:631 - Notifying no-one, there are no
waiting threads
total duration:328
httpclient4.x0-->firstDuration:281
httpclient4.x0-->successDuration:47,successTimes:1
On Wed, Dec 24, 2008 at 8:57 PM, Oleg Kalnichevski <ol...@apache.org> wrote:
> On Wed, 2008-12-24 at 09:32 +0800, alin(王霖) wrote:
> > Dear Oleg:
> > Thanks for your reply. And here is my simple code (usging
> > httpclient4.0-beta2):
> >
> > private void initHttpClient() {
> > SchemeRegistry schemeRegistry = new SchemeRegistry();
> > schemeRegistry.register(
> > new Scheme("http", PlainSocketFactory.getSocketFactory(),
> > 80));
> > httpParams = new BasicHttpParams();
> > HttpProtocolParams.setVersion(httpParams, HttpVersion.HTTP_1_1);
> > this.setMaxTotalConnections(DEFAULT_MAX_TOTAL_CONNECTIONS);
> > this.setReadTimeout(DEFAULT_READ_TIMEOUT);
> > ClientConnectionManager cm = new ThreadSafeClientConnManager(
> > httpParams, schemeRegistry);
> > httpClient = new DefaultHttpClient(cm, httpParams);
> > }
> >
>
> The code looks all right to me, but it is of little use. I need to see a
> _complete_ wire / context log of the HTTP session to be able to tell why
> connections are not kept alive.
>
> Oleg
>
>
> >
> > On Tue, Dec 23, 2008 at 10:51 PM, Oleg Kalnichevski <olegk@apache.org
> >wrote:
> >
> > > On Mon, 2008-12-22 at 17:46 +0800, alin(王霖) wrote:
> > > > HI:
> > > > I use httpclient3 and httpclient4 for a multi-thread load test, and
> > > > always set http request header with "Connection:Keep-Alive".
> > > > When i input command "netstat -na | grep myserverhost:myserverport"
> in
> > > > console(My system is windows xp + cygwin) , output like following:
> > > >
> > > > C:\Documents and Settings\lin.wangl>netstat -na | grep
> > > 192.168.208.110:80
> > > > TCP 10.1.26.82:4159 192.168.208.110:80 ESTABLISHED
> > > > TCP 10.1.26.82:4160 192.168.208.110:80 ESTABLISHED
> > > >
> > > > But the ports of client connections(here is 10.1.26.82) is changing
> > > while
> > > > load test is running.
> > > > through log4j, httpclient4 told me:
> > > >
> > > > 17:33:33,049 DEBUG DefaultRequestDirector:463 - Connection can be
> kept
> > > alive
> > > > for 15000 ms
> > > > 17:33:33,065 DEBUG ThreadSafeClientConnManager:221 - Released
> connection
> > > is
> > > > reusable.
> > > > 17:33:33,065 DEBUG ConnPoolByRoute:374 - Releasing connection
> > > > [HttpRoute[{}->http://192.168.208.110]][null]
> > > > 17:33:33,065 DEBUG ConnPoolByRoute:394 - Pooling connection
> > > [HttpRoute[{}->
> > > > http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
> > > >
> > > > Who can tell me why this is?
> > > >
> > > >
> > >
> > >
> > > It is just not possible to tell from 16 milliseconds of logs.
> > >
> > > Oleg
> > >
> > >
> > > ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> > > For additional commands, e-mail: httpclient-users-help@hc.apache.org
> > >
> > >
> >
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
>
>
--
Yours alin
msn alin_ass@hotmail.com
phone 88155188-17496
mobile 13858061999
Re: Why client connection's port changed always when server
support Keep-alive?
Posted by Oleg Kalnichevski <ol...@apache.org>.
On Wed, 2008-12-24 at 09:32 +0800, alin(王霖) wrote:
> Dear Oleg:
> Thanks for your reply. And here is my simple code (usging
> httpclient4.0-beta2):
>
> private void initHttpClient() {
> SchemeRegistry schemeRegistry = new SchemeRegistry();
> schemeRegistry.register(
> new Scheme("http", PlainSocketFactory.getSocketFactory(),
> 80));
> httpParams = new BasicHttpParams();
> HttpProtocolParams.setVersion(httpParams, HttpVersion.HTTP_1_1);
> this.setMaxTotalConnections(DEFAULT_MAX_TOTAL_CONNECTIONS);
> this.setReadTimeout(DEFAULT_READ_TIMEOUT);
> ClientConnectionManager cm = new ThreadSafeClientConnManager(
> httpParams, schemeRegistry);
> httpClient = new DefaultHttpClient(cm, httpParams);
> }
>
The code looks all right to me, but it is of little use. I need to see a
_complete_ wire / context log of the HTTP session to be able to tell why
connections are not kept alive.
Oleg
>
> On Tue, Dec 23, 2008 at 10:51 PM, Oleg Kalnichevski <ol...@apache.org>wrote:
>
> > On Mon, 2008-12-22 at 17:46 +0800, alin(王霖) wrote:
> > > HI:
> > > I use httpclient3 and httpclient4 for a multi-thread load test, and
> > > always set http request header with "Connection:Keep-Alive".
> > > When i input command "netstat -na | grep myserverhost:myserverport" in
> > > console(My system is windows xp + cygwin) , output like following:
> > >
> > > C:\Documents and Settings\lin.wangl>netstat -na | grep
> > 192.168.208.110:80
> > > TCP 10.1.26.82:4159 192.168.208.110:80 ESTABLISHED
> > > TCP 10.1.26.82:4160 192.168.208.110:80 ESTABLISHED
> > >
> > > But the ports of client connections(here is 10.1.26.82) is changing
> > while
> > > load test is running.
> > > through log4j, httpclient4 told me:
> > >
> > > 17:33:33,049 DEBUG DefaultRequestDirector:463 - Connection can be kept
> > alive
> > > for 15000 ms
> > > 17:33:33,065 DEBUG ThreadSafeClientConnManager:221 - Released connection
> > is
> > > reusable.
> > > 17:33:33,065 DEBUG ConnPoolByRoute:374 - Releasing connection
> > > [HttpRoute[{}->http://192.168.208.110]][null]
> > > 17:33:33,065 DEBUG ConnPoolByRoute:394 - Pooling connection
> > [HttpRoute[{}->
> > > http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
> > >
> > > Who can tell me why this is?
> > >
> > >
> >
> >
> > It is just not possible to tell from 16 milliseconds of logs.
> >
> > Oleg
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> > For additional commands, e-mail: httpclient-users-help@hc.apache.org
> >
> >
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Why client connection's port changed always when server support Keep-alive?
Posted by "alin(王霖)" <xa...@gmail.com>.
Dear Oleg:
Thanks for your reply. And here is my simple code (usging
httpclient4.0-beta2):
private void initHttpClient() {
SchemeRegistry schemeRegistry = new SchemeRegistry();
schemeRegistry.register(
new Scheme("http", PlainSocketFactory.getSocketFactory(),
80));
httpParams = new BasicHttpParams();
HttpProtocolParams.setVersion(httpParams, HttpVersion.HTTP_1_1);
this.setMaxTotalConnections(DEFAULT_MAX_TOTAL_CONNECTIONS);
this.setReadTimeout(DEFAULT_READ_TIMEOUT);
ClientConnectionManager cm = new ThreadSafeClientConnManager(
httpParams, schemeRegistry);
httpClient = new DefaultHttpClient(cm, httpParams);
}
On Tue, Dec 23, 2008 at 10:51 PM, Oleg Kalnichevski <ol...@apache.org>wrote:
> On Mon, 2008-12-22 at 17:46 +0800, alin(王霖) wrote:
> > HI:
> > I use httpclient3 and httpclient4 for a multi-thread load test, and
> > always set http request header with "Connection:Keep-Alive".
> > When i input command "netstat -na | grep myserverhost:myserverport" in
> > console(My system is windows xp + cygwin) , output like following:
> >
> > C:\Documents and Settings\lin.wangl>netstat -na | grep
> 192.168.208.110:80
> > TCP 10.1.26.82:4159 192.168.208.110:80 ESTABLISHED
> > TCP 10.1.26.82:4160 192.168.208.110:80 ESTABLISHED
> >
> > But the ports of client connections(here is 10.1.26.82) is changing
> while
> > load test is running.
> > through log4j, httpclient4 told me:
> >
> > 17:33:33,049 DEBUG DefaultRequestDirector:463 - Connection can be kept
> alive
> > for 15000 ms
> > 17:33:33,065 DEBUG ThreadSafeClientConnManager:221 - Released connection
> is
> > reusable.
> > 17:33:33,065 DEBUG ConnPoolByRoute:374 - Releasing connection
> > [HttpRoute[{}->http://192.168.208.110]][null]
> > 17:33:33,065 DEBUG ConnPoolByRoute:394 - Pooling connection
> [HttpRoute[{}->
> > http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
> >
> > Who can tell me why this is?
> >
> >
>
>
> It is just not possible to tell from 16 milliseconds of logs.
>
> Oleg
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
>
>
--
Yours sincerely
alin
Re: Why client connection's port changed always when server
support Keep-alive?
Posted by Oleg Kalnichevski <ol...@apache.org>.
On Mon, 2008-12-22 at 17:46 +0800, alin(王霖) wrote:
> HI:
> I use httpclient3 and httpclient4 for a multi-thread load test, and
> always set http request header with "Connection:Keep-Alive".
> When i input command "netstat -na | grep myserverhost:myserverport" in
> console(My system is windows xp + cygwin) , output like following:
>
> C:\Documents and Settings\lin.wangl>netstat -na | grep 192.168.208.110:80
> TCP 10.1.26.82:4159 192.168.208.110:80 ESTABLISHED
> TCP 10.1.26.82:4160 192.168.208.110:80 ESTABLISHED
>
> But the ports of client connections(here is 10.1.26.82) is changing while
> load test is running.
> through log4j, httpclient4 told me:
>
> 17:33:33,049 DEBUG DefaultRequestDirector:463 - Connection can be kept alive
> for 15000 ms
> 17:33:33,065 DEBUG ThreadSafeClientConnManager:221 - Released connection is
> reusable.
> 17:33:33,065 DEBUG ConnPoolByRoute:374 - Releasing connection
> [HttpRoute[{}->http://192.168.208.110]][null]
> 17:33:33,065 DEBUG ConnPoolByRoute:394 - Pooling connection [HttpRoute[{}->
> http://192.168.208.110]][null]; keep alive for 15000 MILLISECONDS
>
> Who can tell me why this is?
>
>
It is just not possible to tell from 16 milliseconds of logs.
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org