HARs captured with browsermob proxy get timing problems when loaded into http://www.softwareishard.com/har/viewer/

[nmcconom]

When I load the HARs I capture with browsermob now I get the following sorts of errors in the harviewer page:

HAR Validation
Sum of request timings doesn't correspond to the total value: http://www.amazon.co.uk/ (request.time: 1505 vs. sum: 1284), request#: 0, parent page: www.amazon.co.uk HAR Validation
Sum of request timings doesn't correspond to the total value: http://z-ecx.images-amazon.com/images/G/01/browser-scripts/uk-site-wide-1.2.6/site-wide-2650665772.css._V165058414_.css (request.time: 280 vs. sum: 272), request#: 1, parent page: www.amazon.co.uk HAR Validation
Sum of request timings doesn't correspond to the total value: http://z-ecx.images-amazon.com/images/G/01/nav2/gamma/websiteGridCSS/websiteGridCSS-websiteGridCSS-9085.css._V165356162_.css (request.time: 560 vs. sum: 555), request#: 2, parent page: www.amazon.co.uk HAR Validation
Sum of request timings doesn't correspond to the total value: http://g-ecx.images-amazon.com/images/G/02/x-locale/common/transparent-pixel._V167145160_.gif (request.time: 270 vs. sum: 269), request#: 3, parent page: www.amazon.co.uk HAR Validation
Sum of request timings doesn't correspond to the total value: http://g-ecx.images-amazon.com/images/G/02/gno/images/orangeBlue/navPackedSprites-UK-15._V202471918_.png (request.time: 590 vs. sum: 566), request#: 4, parent page: www.amazon.co.uk HAR Validation
Sum of request timings doesn't correspond to the total value: http://g-ecx.images-amazon.com/images/G/02/x-site/BlackFriday2011/uk_xsite_bf_lozenge._V164928606_.png (request.time: 468 vs. sum: 415), request#: 5, parent page: www.amazon.co.uk HAR Validation
Sum of request timings doesn't correspond to the total value: http://g-ecx.images-amazon.com/images/G/02/uk-jw/homepage/UK_WAT_BrandStore-Perfect_ROTO._V177647797_.png (request.time: 413 vs. sum: 367), request#: 6, parent page: www.amazon.co.uk

Note that they recently updated their version to be stricter on timings -see below link

http://code.google.com/p/harviewer/source/browse/trunk/webapp/ReleaseNotes.txt

• Validation extended (negative timings not allowed and summary of timings must be correct)

[pierredelacelle]

I'm also having trouble with some har generated with browsermob proxy.

Har are randomly inconsistent about entries timings.

Validation done with http://www.janodvarko.cz/har/viewer/

Sum of request timings doesn't correspond to the total value: http://example.com/ (request.time: 659 vs. sum: 660), request#: 0, parent page: 4f136ad9a11460e81e000001 Sum of request timings doesn't correspond to the total value: http://example.com/modules/mic/mic.css (request.time: 70 vs. sum: 71), request#: 7, parent page: 4f136ad9a11460e81e000001 Sum of request timings doesn't correspond to the total value: http://media1.legourmetdunet.com/img/c/12-category.jpg (request.time: 86 vs. sum: 132), request#: 15, parent page: 4f136ad9a11460e81e000001 Sum of request timings doesn't correspond to the total value: http://media1.legourmetdunet.com/img/c/13-category.jpg (request.time: 60 vs. sum: 92), request#: 16, parent page: 4f136ad9a11460e81e000001

In my case, browsermob proxy is used through API. Don't know if this matters.

Anyway, great job on the project!

[zanemayo]

You can try and sleep for a few seconds after webdriver.get() returns. That helped sort out some problems for me

[sidaf]

I may have found the issue for this. Here is a dump from a request that produced errors when using the viewer mentioned above:

time: 149 startedDateTime: 2012-10-27T00:06:01.386+0000 response: Object request: Object timings: Object blocked: 2 dns: 0 connect: 51 send: 0 wait: 97 receive: 1

The error is produces as 'time' (149) does not equal the sum of all the timings (151). The reason for this is that the 'blocked' value is not factored in.

The 'time' value is produced by the following line of code:

org/browsermob/proxy/http/BrowserMobHttpClient.java:634:

entry.setTime(RequestInfo.get().getTotalTime());

The getTotalTime() method reads as follows:

public long getTotalTime() { if (end == null || start == null) { return -1; } return end.getTime() - start.getTime(); }

So far so good, but if you read up a bit further in that file you will find this:

org/browsermob/proxy/http/RequestInfo.java:101

// blocked is special - we don't record this start time as we don't want it to // count towards receive time and total time blocked = end.getTime() - start.getTime();

As 'start' time is not recorded when 'blocked' happens, 'blocked' doesn't get factored in when getTotalTime is calculated, so if any blocking takes place this leads to time < timings combined.

One possible solution is to ignore blocking altogether, I think this can be done by commenting out the following line:

org/browsermob/proxy/http/BrowserMobHttpClient.java:118:

RequestInfo.get().blocked(start, new Date());

Another solution is to include blocking in the start time calculation but I don't know what consequences that might have, as it must have been treated as 'special' for some reason.