New Firefox HAR is missing page.

[soulgalore]

New Firefox HAR is missing page.

[juliandescottes]

@soulgalore Thanks I'll take a look. Quick question though: as far as I know the current (devtools-based) har builder for firefox is not able to generate multiple pages. Do you use a workaround for that or am I mistaken?

[soulgalore]

Hi @juliandescottes you are right. It works like this: For each page we tests, we get the HAR and then we merge them into one: https://github.com/sitespeedio/browsertime/blob/main/lib/support/har/index.js#L236

So in this case where it fails, we click on login to the login page and then Wikipedia redirects the user to https://en.wikipedia.org/wiki/Main_Page but doesn't seem to generate a new HAR.

[juliandescottes]

I intermittently get the same symptoms. One thing I noticed is that when the page entry is missing, all the requests for that page are missing as well, and in the logs I can see

https://en.wikipedia.org/w/index.php?title=Special:UserLogin&returnto=Main+Page has been tested before within the same run, it will get an extra query parameter named browsertime_run. Make sure to use alias to keep track of the URLs

In successful runs, I don't see this log. I will investigate more tomorrow, but does this ring any bell? Is there anything in the har helper which might confuse browsertime about which URL it is currently testing?

[juliandescottes]

Testing locally, it seems the navigation ends too early and stops the recording before any request had time to complete. It would be interesting to check with the old HAR approach to see if the same thing happens.

Edit: I also intermittently get

https://en.wikipedia.org/w/index.php?title=Special:UserLogin&returnto=Main+Page has been tested before within the same run, it will get an extra query parameter named browsertime_run. Make sure to use alias to keep track of the URLs

when using --skip-har for info, might not be HAR related? Maybe a Firefox change?

[soulgalore]

when using --skip-har for info, might not be HAR related? Maybe a Firefox change?

I checked the code and there's a bug there, we only handle a case when we use alias for a URL if we have a HAR. Let me fix that.

I'll fix so we can run the old HAR extension with a switch so it's easier to compare, I'll do that later today.

[soulgalore]

Ooops I didn't mean to close it.

@juliandescottes I was wrong on a couple of things: The old HAR exporter didn't produce any error but the HAR is actually faulty, it generates a broken HAR compared to the specification.

I modified script and added an extra wait, it seems like when we click on login, the page complete check happens before the actual navigation, that's why as you said the events doesn't happen. With that fix the HAR pages are generated correctly but it seems like the click on the login button still misses requests? I compared with the HAR I got from Chrome (generated using https://github.com/sitespeedio/chrome-har) and that one has +130 request and the one with bidi har has 30. Not 100% sure though that the Chrome HAR is 100% correct). One thing that would be cool would be if we could turn on logging in the bidi har lib, so that all requests/responses are logged just for debug?

You can change your script to:

// Stop and collect the measurement before the next page we want to measure
await commands.wait.byTime(10_000);
await commands.measure.stop();

That makes a ten second wait before we say the test is over (I'll fix that later in the Browsertime code). When I look in the new HAR it is missing the POST to the login page? There's a redirect change happening where cookies are set on different domains and I think maybe we miss some events there.

In the main branch I added back the old HAR exporter and then we can take the time to fix the new without any hurry. To run with the bidiversion you enable it with --firefox.bidihar

[juliandescottes]

@soulgalore Having a toggle for the bidi har sounds great while we work out the remaining issues, thanks :)

I agree we should add logging to the helper. On top of that, I don't know if there's an easy way to get firefox logs when running browsertime, but we could get BiDi logs with remote.log.level set to Trace. We would directly see all events emitted by BiDi then. But for now I'll add some logging. Probably event name, request id and request url could be enough to avoid making it too verbose. I'll also review cases where I discard requests or events because they have incomplete data and will add extra logging there.

Regarding missing requests between Chrome and Firefox, I know we are missing two types of requests right now: some image requests hitting a specific image cache, and requests blocked by CSP. It sounds odd if that accounts for 100 requests for that scenario though? Do you have an example HAR generated by chrome for this scenario I could look at?

[soulgalore]

@juliandescottes attached HAR from bidi and Chrome, checkout page 2. I think the bidi one should include the POST (when you click on the login button right)?

hars.zip

[juliandescottes]

@soulgalore I just published 0.0.7 which has a small fix for redirected requests and can be used to add logs via debugLogs: true in the options you provide to the adapter:

    this.har = new adapters.SeleniumBiDiHarRecorder({
      browsingContextIds: [windowId],
      debugLogs: true,
      driver: runner.getDriver()
    });

[juliandescottes]

With the new logs, I can see that the POST request you mentioned is excluded because we don't get any response for it:

[har-recorder] Process network entry for url: https://login.wikimedia.org/wiki/Special:CentralLogin/start?token=c8124b27e9d756dc3bce01e1735d3e67&cpPosIndex=1
[har-recorder] Warning: Ignoring entry without response for url: https://login.wikimedia.org/wiki/Special:CentralLogin/start?token=c8124b27e9d756dc3bce01e1735d3e67&cpPosIndex=1 (id: 200-1)

This could be due to an issue we fixed in https://bugzilla.mozilla.org/show_bug.cgi?id=1808688 which prevented to collect responses for some redirects. It should be fixed in 112 (which should hit release next week). Can we test with Beta or Nightly easily to see if the POST request shows up?

[soulgalore]

Ah cool , let me try with beta.

[juliandescottes]

Ok, I tried with --firefox-binary pointing to a recent Nightly, and with this I think we have almost all requests accounted for, but 3 requests don't get properly assigned to a page:

• POST https://en.wikipedia.org/w/index.php?title=Special:UserLogin&returnto=Main+Page
• GET https://en.wikipedia.org/wiki/Special:CentralLogin/start?token...
• GET https://en.wikipedia.org/wiki/Special:CentralLogin/complete?token...

So basically all the redirects which lead to load the Main Page. That's not too surprising. I don't have a good BiDi event implemented yet to monitor the beginning of a navigation so I create the page entries of the har object mostly by finding the first request which seems to be responsible for the load ...

In case of redirects however I should be able to find the real request which started the redirect chain.

[soulgalore]

Hehe, I also tried the same:

[juliandescottes]

Ahah, yes that's exactly what I had.

Ok I fixed the redirect issue in 0.0.8, and the 3 requests are now correctly listed in the second page (still testing with Nightly). The number of requests also seems reasonably close to the Chrome HAR shared in this discussion.

Let me know if you spot another inconsistency!

[soulgalore]

Did a try now and this looks much better, thanks for the fix @juliandescottes !

[juliandescottes]

Did a try now and this looks much better, thanks for the fix @juliandescottes !

Great, thanks for testing!
For info Firefox 112 should be released today, which means that the issue with missing requests should be fixed even when using the release channel.
I'll let you decide whether to keep this issue opened or not, as usual I'm happy to investigate if you see another issue.

[soulgalore]

Cool, I released a new version earlier today with 112 :)