Bug 217544 - Add debug logging for app-bound domains to gather telemetry on script evaluation
Summary: Add debug logging for app-bound domains to gather telemetry on script evaluation
Status: NEW
Alias: None
Product: WebKit
Classification: Unclassified
Component: WebKit Misc. (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Kate Cheney
Keywords: InRadar
Depends on:
Reported: 2020-10-09 17:33 PDT by Kate Cheney
Modified: 2022-02-09 10:13 PST (History)
6 users (show)

See Also:

Patch (7.93 KB, patch)
2020-10-12 14:08 PDT, Kate Cheney
ews-feeder: commit-queue-
Details | Formatted Diff | Diff
Patch (7.89 KB, patch)
2020-10-12 14:14 PDT, Kate Cheney
no flags Details | Formatted Diff | Diff
Patch (8.40 KB, patch)
2020-10-12 15:30 PDT, Kate Cheney
simon.fraser: review-
Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Kate Cheney 2020-10-09 17:33:07 PDT
We should add some logging to gather telemetry on script injection for app-bound domains.
Comment 1 Kate Cheney 2020-10-09 17:33:39 PDT
Comment 2 Kate Cheney 2020-10-12 14:08:28 PDT
Created attachment 411152 [details]
Comment 3 Kate Cheney 2020-10-12 14:14:14 PDT
Created attachment 411155 [details]
Comment 4 Kate Cheney 2020-10-12 15:30:09 PDT
Created attachment 411171 [details]
Comment 5 Simon Fraser (smfr) 2020-10-13 09:32:35 PDT
Comment on attachment 411171 [details]

I don't think it's necessary to land this in OpenSource.
Comment 6 Sam Weinig 2020-10-13 10:03:08 PDT
Comment on attachment 411171 [details]

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

> Source/WebKit/UIProcess/UserContent/WebUserContentControllerProxy.cpp:223
> +    for (auto& process : m_processes) {
> +        if (appBoundDomainsLoggingEnabled)
> +            logInBatches(process, userScript.userScript().source());
> +#endif
>          process.send(Messages::WebUserContentController::AddUserScripts({ { userScript.identifier(), world->identifier(), userScript.userScript() } }, immediately), identifier());
> +    }

Sounds like this might not actually need to get landed, but none-the-less, if you were going to land something like this, I would recommend going with something like this:

static void logScriptIfAppropriate(const WeakHashSet<WebProcessProxy>& processes, StringView userScript)
    Boolean keyExistsAndHasValidFormat = false;
    if (!CFPreferencesGetAppBooleanValue(CFSTR("LogAppBoundDomains"), kCFPreferencesCurrentApplication, &keyExistsAndHasValidFormat))
    bool anyProcessHasAlwaysOnLoggingAllowed = false;
    for (auto& process : m_processes) {
        if (process.websiteDataStore().sessionID().isAlwaysOnLoggingAllowed())
            anyProcessHasAlwaysOnLoggingAllowed = true;
    if (!anyProcessHasAlwaysOnLoggingAllowed)

    static constexpr unsigned maxIndividualLogLength = 950;
   unsigned totalBatches = userScript.length() / maxIndividualLogLength;
    for (unsigned currentBatch = 0; currentBatch < totalBatches; ++currentBatch)
        auto toLog = userScript.substring(maxIndividualLogLength * currentBatch, maxIndividualLogLength);
        RELEASE_LOG(AppBoundDomains, "(%d/%d) %.*s", currentBatch + 1, totalBatches + 1, maxIndividualLogLength, toLog.utf8().data());


void WebUserContentControllerProxy::addUserScript(API::UserScript& userScript, InjectUserScriptImmediately immediately)
     logScriptIfAppropriate(m_processes, userScript.userScript().source());

(not tested, but something along this lines).

This uses avoids potentially logging the same script multiple times if the multiple processes have isAlwaysOnLoggingAllowed enabled for their associated data stores, uses StringView to avoid unnecessary copies of the UserScript's source, and partitions the code in a single function, to be minimally invasive to the existing code.
Comment 7 Kate Cheney 2020-10-13 10:46:54 PDT
Thanks for the comments! If I post another patch, I'll align it with your suggestions Sam, it has a lot of improvements.