Bug 224194 - Add additional page load diagnostic logging
Summary: Add additional page load diagnostic logging
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: WebKit Misc. (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Brent Fulgham
URL:
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2021-04-05 11:46 PDT by Brent Fulgham
Modified: 2021-04-06 15:38 PDT (History)
8 users (show)

See Also:


Attachments
Patch (20.74 KB, patch)
2021-04-05 11:59 PDT, Brent Fulgham
no flags Details | Formatted Diff | Diff
Patch (23.59 KB, patch)
2021-04-05 15:45 PDT, Brent Fulgham
no flags Details | Formatted Diff | Diff
Patch (23.73 KB, patch)
2021-04-05 16:49 PDT, Brent Fulgham
no flags Details | Formatted Diff | Diff
Patch for landing (27.86 KB, patch)
2021-04-06 15:10 PDT, Brent Fulgham
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Brent Fulgham 2021-04-05 11:46:22 PDT
Add additional logging to help identify places where page loads fail to complete.
Comment 1 Radar WebKit Bug Importer 2021-04-05 11:46:42 PDT
<rdar://problem/76227175>
Comment 2 Brent Fulgham 2021-04-05 11:59:57 PDT
Created attachment 425182 [details]
Patch
Comment 3 katherine_cheney 2021-04-05 12:23:39 PDT
Comment on attachment 425182 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=425182&action=review

Yay, more logging!

> Source/WebCore/loader/ResourceLoader.cpp:130
> +            RELEASE_LOG_IF_ALLOWED("init: Cancelling because the document loader has no frame.");

I think this should be "releaseResources: ..." instead of "init: ... ".

> Source/WebKit/NetworkProcess/NetworkConnectionToWebProcess.cpp:562
> +    RELEASE_LOG_IF_ALLOWED(Loading, "removeLoadIdentifier %" PRIu64 " and aborting corresponding loader", identifier);

This message format diverges from the typical format of <functionName><colon><message>. Maybe it could be refactored to align more?

> Source/WebKit/WebProcess/WebPage/WebPage.cpp:6728
> +    RELEASE_LOG_IF_ALLOWED(Process, "WebPage: Registered handler %" PRIu64 " for the '%s' scheme", handlerIdentifier, scheme..utf8().data());

I think WebPage: is redundant because RELEASE_LOG_IF_ALLOWED should already include it. Should this be "registerURLSchemeHandler: ..." instead?

> Source/WebKit/WebProcess/WebPage/WebURLSchemeTaskProxy.cpp:109
> +            WEBURLSCHEMETASKPROXY_RELEASE_LOG_IF_ALLOWED(Loading, "Redirected scheme task would have been sent to a different URL.");

Ditto about format, do we want this to say "didPerformRedirection: Redirected scheme task would have been sent to a different URL"?

> Source/WebKit/WebProcess/WebPage/WebURLSchemeTaskProxy.cpp:115
> +        WEBURLSCHEMETASKPROXY_RELEASE_LOG_IF_ALLOWED(Loading, "Received redirect during previous redirect processing, queuing it.");

Ditto re: format.

> Source/WebKit/WebProcess/WebPage/WebURLSchemeTaskProxy.cpp:129
> +        WEBURLSCHEMETASKPROXY_RELEASE_LOG_IF_ALLOWED(Loading, "Received response during redirect processing, queuing it.");

Ditto.

> Source/WebKit/WebProcess/WebPage/WebURLSchemeTaskProxy.cpp:152
> +        WEBURLSCHEMETASKPROXY_RELEASE_LOG_IF_ALLOWED(Loading, "Received data during response processing, queuing it.");

Ditto.
Comment 4 Brent Fulgham 2021-04-05 14:30:42 PDT
Comment on attachment 425182 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=425182&action=review

>> Source/WebCore/loader/ResourceLoader.cpp:130
>> +            RELEASE_LOG_IF_ALLOWED("init: Cancelling because the document loader has no frame.");
> 
> I think this should be "releaseResources: ..." instead of "init: ... ".

I'm trying to capture the reason the 'init' method is failing to create a loader, and is triggering a cancel and complete(false) -- so I think this is the right label.

>> Source/WebKit/NetworkProcess/NetworkConnectionToWebProcess.cpp:562
>> +    RELEASE_LOG_IF_ALLOWED(Loading, "removeLoadIdentifier %" PRIu64 " and aborting corresponding loader", identifier);
> 
> This message format diverges from the typical format of <functionName><colon><message>. Maybe it could be refactored to align more?

Will do.

>> Source/WebKit/WebProcess/WebPage/WebPage.cpp:6728
>> +    RELEASE_LOG_IF_ALLOWED(Process, "WebPage: Registered handler %" PRIu64 " for the '%s' scheme", handlerIdentifier, scheme..utf8().data());
> 
> I think WebPage: is redundant because RELEASE_LOG_IF_ALLOWED should already include it. Should this be "registerURLSchemeHandler: ..." instead?

Oh, yes! You are right.

>> Source/WebKit/WebProcess/WebPage/WebURLSchemeTaskProxy.cpp:109
>> +            WEBURLSCHEMETASKPROXY_RELEASE_LOG_IF_ALLOWED(Loading, "Redirected scheme task would have been sent to a different URL.");
> 
> Ditto about format, do we want this to say "didPerformRedirection: Redirected scheme task would have been sent to a different URL"?

Yep (and same to below).
Comment 5 Brent Fulgham 2021-04-05 15:45:47 PDT
Created attachment 425217 [details]
Patch
Comment 6 katherine_cheney 2021-04-05 15:48:07 PDT
Comment on attachment 425182 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=425182&action=review

>>> Source/WebCore/loader/ResourceLoader.cpp:130
>>> +            RELEASE_LOG_IF_ALLOWED("init: Cancelling because the document loader has no frame.");
>> 
>> I think this should be "releaseResources: ..." instead of "init: ... ".
> 
> I'm trying to capture the reason the 'init' method is failing to create a loader, and is triggering a cancel and complete(false) -- so I think this is the right label.

Oops, I misread the diff. You're right!
Comment 7 Brent Fulgham 2021-04-05 16:49:06 PDT
Created attachment 425222 [details]
Patch
Comment 8 Brent Fulgham 2021-04-06 09:45:39 PDT
The test failure is not related to my patch.
Comment 9 Alex Christensen 2021-04-06 11:13:00 PDT
Comment on attachment 425222 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=425222&action=review

> Source/WebKit/NetworkProcess/NetworkConnectionToWebProcess.cpp:364
> +    RELEASE_LOG_IF_ALLOWED(Loading, "didClose: WebProcess (%d) closed its connection. Aborting related loaders.", connection.remoteProcessID());

Cool!  Do we want a log in the web process if the network process closes its connection?
Comment 10 Brent Fulgham 2021-04-06 11:30:37 PDT
(In reply to Alex Christensen from comment #9)
> Comment on attachment 425222 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=425222&action=review
> 
> > Source/WebKit/NetworkProcess/NetworkConnectionToWebProcess.cpp:364
> > +    RELEASE_LOG_IF_ALLOWED(Loading, "didClose: WebProcess (%d) closed its connection. Aborting related loaders.", connection.remoteProcessID());
> 
> Cool!  Do we want a log in the web process if the network process closes its
> connection?

Yes -- that's a great idea. I'll add that.
Comment 11 Brent Fulgham 2021-04-06 15:10:12 PDT
Created attachment 425329 [details]
Patch for landing
Comment 12 EWS 2021-04-06 15:38:02 PDT
Committed r275563: <https://commits.webkit.org/r275563>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 425329 [details].