1968023 - tabDescriptor navigateTo times out because of missing webProgress notifications

Status: NEW

(DevTools :: about:debugging, defect, P3)

Description

[Julian Descottes [:jdescottes]]

The reason behind the recent intermittent spike for bug 1966826 is that the TabDescriptor navigateTo command seems to easily fail.

The code is at https://searchfox.org/mozilla-central/rev/02d33f4bf984f65bd394bfd2d19d66569ae2cfe1/devtools/server/actors/descriptors/tab.js#251-305

We listen for WebProgress listener notifications and we expect to get a STATE_STOP notification is waitForLoad is true.

However, when logging with MOZ_LOG=BCWebProgress:5, we seem to get the notification on the web progress side, but our callback is not triggered and we wait forever on await deferred.promise. What's more surprising is that there is 0 difference between the BCWebProgress logs for a successful run vs a failing run.

 0:51.37 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStateChange({isTopLevel:1, isLoadingDocument:0}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, STATE_START|STATE_IS_REQUEST|STATE_IS_DOCUMENT|STATE_IS_NETWORK|STATE_IS_WINDOW, NS_OK) on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_RESOLVING_HOST, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_RESOLVED_HOST, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_CONNECTING_TO, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_CONNECTED_TO, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_TLS_HANDSHAKE_STARTING, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_WAITING_FOR, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_TLS_HANDSHAKE_ENDED, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.38 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, NS_NET_STATUS_WAITING_FOR, "example.org") on {top:1, id:e, url:https://example.com/document-builder.sjs?html=page1}

 0:51.48 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStateChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, STATE_START|STATE_IS_REQUEST|STATE_IS_DOCUMENT|STATE_IS_NETWORK|STATE_IS_WINDOW, NS_OK) on {top:1, id:13, url:about:blank}

 0:51.57 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnLocationChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, https://example.org/document-builder.sjs?html=page2, 0) on {top:1, id:13, url:https://example.org/document-builder.sjs?html=page2}

 0:51.57 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnSecurityChange(<null>, <null>, 2) on {top:1, id:13, url:https://example.org/document-builder.sjs?html=page2}

 0:51.62 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStatusChange(<null>, <null>, NS_OK, "Transferring data from example.org…") on {top:1, id:13, url:https://example.org/document-builder.sjs?html=page2}

 0:51.72 GECKO(81954) [Parent 81954: Main Thread]: I/BCWebProgress OnStateChange({isTopLevel:1, isLoadingDocument:1}, {URI:https://example.org/document-builder.sjs?html=page2, originalURI:https://example.org/document-builder.sjs?html=page2}, STATE_STOP|STATE_IS_NETWORK|STATE_IS_WINDOW, NS_OK) on {top:1, id:13, url:https://example.org/document-builder.sjs?html=page2}

Comment 1

[Julian Descottes [:jdescottes]]

While I don't really know why we sometimes miss WebProgress listener updates, since the DebugTargetInfo is not even waiting for the navigateTo to resolve, we can just pass waitForLoad=false, and that should fix the issue.

Comment 2

[Julian Descottes [:jdescottes]]

This is only used by DebugTargetInfo, so while this is a bit concerning, it shouldn't cause issues on other areas of devtools