[HTTPCORE-254] Erratic results from metrics

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 4.1
• Fix Version/s: 4.1.1
• Assignee: Unassigned
• Reporter: Sebb
• Created: 14/Apr/11 10:55
• Updated: 23/Jul/11 09:59
• Resolved: 14/Apr/11 11:00

Description

The values obtained from getMetrics are erratic. For example, the following code:

DefaultHttpClient httpclient = new DefaultHttpClient();
try {
HttpRequestBase req = new HttpGet("http://wiki.apache.org/jakarta-jmeter/JMeterCommitters");
for(int i = 0; i<3;i++) {
HttpContext localContext = new BasicHttpContext();
HttpResponse rsp = httpclient.execute(req, localContext);
System.out.println(rsp.getStatusLine());
HttpConnection conn = (HttpConnection) localContext.getAttribute(ExecutionContext.HTTP_CONNECTION);
HttpConnectionMetrics metrics = conn.getMetrics();
long hdr = metrics.getReceivedBytesCount();
System.out.println("hdr "+hdr);

HttpEntity entity = rsp.getEntity();
// Thread.sleep(1500);
if (entity != null)

{ EntityUtils.consume(entity); }

long total = metrics.getReceivedBytesCount();
System.out.println("tot "+total);
metrics.reset();
}
} finally

{ // When HttpClient instance is no longer needed, // shut down the connection manager to ensure // immediate deallocation of all system resources httpclient.getConnectionManager().shutdown(); }

}

May produce:

HTTP/1.1 200 OK
hdr 284
tot 566
HTTP/1.1 200 OK
hdr 283
tot 313
HTTP/1.1 200 OK
hdr 283
tot 313

Enabling the sleep produces more consistent (but still inaccurate) results:

HTTP/1.1 200 OK
hdr 284
tot 10946
HTTP/1.1 200 OK
hdr 283
tot 10945
HTTP/1.1 200 OK
hdr 283
tot 10945

Rather unexpected behaviour, but as it happens, a very simple cause:

// AbstractSessionInputBuffer lines 184-189
// If the remaining capacity is big enough, read directly from the
// underlying input stream bypassing the buffer.
if (len > this.minChunkLimit)

{ return this.instream.read(b, off, len); }

else {
// otherwise read to the buffer first

The code also bypasses the metrics collection...

Fixing this results in the following (with or without the sleep):

HTTP/1.1 200 OK
hdr 284
tot 16643
HTTP/1.1 200 OK
hdr 283
tot 16642
HTTP/1.1 200 OK
hdr 283
tot 16642

[Note that the slight variation in size is due to a minor change in the headers.]