doesn't work with lighthouse devtoolslog.json?

zzo commented 5 years ago

So https://github.com/GoogleChrome/lighthouse/issues/4005 implies this module will generate a HAR file from lighthouse output from the lighthouse cli like: $ lighthouse --save-assets http://google.com

which generates several files the interesting one being: www.google.com_2018-11-28_11-31-08-0.devtoolslog.json

Trying the create a HAR file from that gives errors like:

m-c02x8099jgh7:~ m0t01b6$ DEBUG=* node node_modules/chrome-har/tools/harCreator.js ~/www.google.com_2018-11-28_11-31-08-0.devtoolslog.json 
chrome-har Request will be sent with requestId F64EEE5F8CA7C3C531714B9410C214AB that can't be mapped to any page at the moment. +0ms
chrome-har Couldn't find original request for redirect response: F64EEE5F8CA7C3C531714B9410C214AB +2ms
chrome-har Request will be sent with requestId F64EEE5F8CA7C3C531714B9410C214AB that can't be mapped to any page at the moment. +0ms
chrome-har Couldn't find original request for redirect response: F64EEE5F8CA7C3C531714B9410C214AB +0ms
chrome-har Request will be sent with requestId F64EEE5F8CA7C3C531714B9410C214AB that can't be mapped to any page at the moment. +0ms

Unhandled rejection TypeError: Cannot read property 'content' of undefined

  at Object.harFromMessages (/Users/m0t01b6/node_modules/chrome-har/index.js:326:28)

  at fs.readFileAsync.then.then.messages (/Users/m0t01b6/node_modules/chrome-har/tools/harCreator.js:22:28)

  at tryCatcher (/Users/m0t01b6/node_modules/bluebird/js/release/util.js:16:23)

  at Promise._settlePromiseFromHandler (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:512:31)

  at Promise._settlePromise (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:569:18)

  at Promise._settlePromise0 (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:614:10)

  at Promise._settlePromises (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:694:18)

  at Promise._fulfill (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:638:18)

  at Promise._resolveCallback (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:432:57)

  at Promise._settlePromiseFromHandler (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:524:17)

  at Promise._settlePromise (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:569:18)

  at Promise._settlePromise0 (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:614:10)

  at Promise._settlePromises (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:694:18)

  at Promise._fulfill (/Users/m0t01b6/node_modules/bluebird/js/release/promise.js:638:18)

  at /Users/m0t01b6/node_modules/bluebird/js/release/nodeback.js:42:21

  at FSReqWrap.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:53:3)

Thoughts??? THANKS!!!

abhagupta commented 5 years ago

+1.

soulgalore commented 5 years ago

Sorry I don't know what Lighthouse produces. I've seen there have been multiple issues where people have had problem with Puppeteer where the trace logs aren't the same as If you use standalone Chrome, maybe it's something like that?

zzo commented 5 years ago

I provided a link to a gist containing what lighthouse produces - it looks a lot like the stuff in the test/ directory but not exactly apparently?
How specifically are you generating those test files via the chrome remote debugger protocol? From Network events like https://chromedevtools.github.io/devtools-protocol/tot/Network#event-responseReceived ? thanks!!

soulgalore commented 5 years ago

I guess it still could be that the events are out of order and we don't catch that and in Chrome using Browsertime they are not. I will happily merge a PR if anyone can fix it :)

Best Peter

zzo commented 5 years ago

so do you think it's 'just' an ordering problem? do you look at the output from lighthouse in the gist? thanks!!

soulgalore commented 5 years ago

I don't know but that's my guess :)

zzo commented 5 years ago

ok ya I moved the 'Page.frameStartedLoading' event to the top the lighthouse-generated JSON file and all worked :) In the lighthouse file there are Network.requestWillBeSent and Network.responseReceived events in the file with the matching frameId BEFORE the Page.frameStartedLoading event with the same frameId. Not sure if the fix is to just error out with an explanation when this happens (easy) or to attempt to buffer those events and 'replay' them once we see the Page.frameStartedLoading event (hard), or to pre-process/re-write the json file on the fly when this condition is detected. OR just punt :)

soulgalore commented 5 years ago

I did a fix a couple of days ago to catch requestWillBeSent that happens before navigation https://github.com/sitespeedio/chrome-har/pull/34/files but then I guess also the responses are received in your trace before the frame started loading? Those responses could be mapped to the "unmapped" requests then.

zzo commented 5 years ago

Yes correct in my trace I see requests and a response BEFORE the Page.frameStartedLoading event with the matching frameId.

So when I use a lighthouse trace and run it thru the tests (with my 'fix' to move stuff to the beginning of the 'messages' array I get this error:

Generates valid HARs


/Users/m0t01b6/chrome-har/test/tests.js:32
31:       const timings = entry.timings;

32:       t.true(

33:         entry._requestTime + Math.max(0, timings.blocked) / 1000 > previousEnd,
Two entries too close on connection 119
Value is not true:
false
entry._requestTime + Math.max(0, timings.blocked) / 1000 > previousEnd
=> false
previousEnd
=> 47731.200914
entry._requestTime + Math.max(0, timings.blocked) / 1000
=> 47731.119414
Math.max(0, timings.blocked) / 1000
=> 0.0017649999999999999
Math.max(0, timings.blocked)
=> 1.765
timings.blocked
=> 1.765
timings
=> {
_queued: 0.519,
blocked: 1.765,
connect: -1,
dns: -1,
receive: 0.62,
send: 0.693,
ssl: -1,
wait: 78.558,
}
Math
=> Object @Math {}

entry._requestTime => 47731.117649

dunno if you need the whole 'entry' object that gets dumped after this... So my 'fix' does not work? thanks!!

smick commented 5 years ago

Having the same issue running chrome-har with puppeteer.

    TypeError: Cannot read property 'content' of undefined
    at harFromMessages (/Users/me/Desktop/har-backup/node_modules/chrome-har/index.js:316:28)
    at /Users/me/Desktop/har-bckup/index.js:48:17
    at <anonymous>

    "chrome-har": "^0.7.0",
    "puppeteer": "^1.11.0"

node: v8.14.0 Chromium: r609904

Thanks for any suggestions for getting this working.

soulgalore commented 5 years ago

Yeah, as I said before I think the problem is the order. I haven't had time to look at it yet, working on other things first.

soulgalore commented 5 years ago

I did a fix in 13a21ea5ac3162c3b42b4262bbfd0e5152b9ab64 for this, one thing missing is handling of redirects, I'll look at that later today.

soulgalore commented 5 years ago

I've pushed 0.7.1 with fixes that collect requests/responses that happens before navigation. One known bug is that it doesn't handle redirects. Please let me know if the new version works for you both!

zzo commented 5 years ago

Nice! thanks will give it a whirl

On Thu, Dec 13, 2018 at 12:17 PM Peter Hedenskog notifications@github.com wrote:

I've pushed 0.7.1 with fixes that collect requests/responses that happens before navigation. One known bug is that it doesn't handle redirects. Please let me know if the new version works for you both!

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/sitespeedio/chrome-har/issues/35#issuecomment-447106403, or mute the thread https://github.com/notifications/unsubscribe-auth/AAr0GnYrTvq1LloJx2Q42VrX7O8cX3nmks5u4rXOgaJpZM4Y4dUk .

sitespeedio / chrome-har

doesn't work with lighthouse devtoolslog.json? #35