Bug 189684 – Clear persistent storage between tests for resourceLoadStatistics

• Status: RESOLVED
• Resolution: FIXED
• Component: New Bugs

[Woodrow Wang]

Currently, in WKWebsiteDataStoreStatisticsResetToConsistentState, only the resource load statistics' maps in the UI process and web content processes are cleared, but the persistent storage is not. This patch deletes the plist on disk between tests when resetting to a consistent state.

[Radar WebKit Bug Importer]

<rdar://problem/44539993>

[Woodrow Wang]

This is a speculative fix for the flakiness seen here: https://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=http%2Ftests%2FwebAPIStatistics%2Fnavigator-functions-accessed-data-collection.html%20http%2Ftests%2FwebAPIStatistics%2Fcanvas-read-and-write-data-collection.html%20http%2Ftests%2FwebAPIStatistics%2Ffont-load-data-collection.html%20http%2Ftests%2FwebAPIStatistics%2Fscreen-functions-accessed-data-collection.html 

Some of the data from previous tests (canvas data collection) leaks into subsequent tests (font loading data collection). This patch deletes the plist between tests, hopefully to rule out that as a source of flakiness.

[Radar WebKit Bug Importer]

<rdar://problem/44540099>

[Woodrow Wang]

Created attachment 349977 [details]
Patch

[John Wilander]

Comment on attachment 349977 [details]
Patch

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

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:778
> +            m_memoryStore->clear([callbackAggregator = callbackAggregator.copyRef()] { });

You need to clear the memory store before you grandfather, otherwise you'll clear the grandfathered entries.

Further, you should grandfather in the completion handler of m_memoryStore->clear() to not run the risk of a race. This will remove the need for the callback aggregator.

[Woodrow Wang]

(In reply to John Wilander from comment #5)
> Comment on attachment 349977 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=349977&action=review
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:778
> > +            m_memoryStore->clear([callbackAggregator = callbackAggregator.copyRef()] { });
> 
> You need to clear the memory store before you grandfather, otherwise you'll
> clear the grandfathered entries.
I'll fix that. 
> 
> Further, you should grandfather in the completion handler of
> m_memoryStore->clear() to not run the risk of a race. This will remove the
> need for the callback aggregator.
Great point, I'll update this shortly!

[Woodrow Wang]

Created attachment 349986 [details]
Patch

[Chris Dumez]

Comment on attachment 349986 [details]
Patch

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

r=me with fixes.

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:775
> +            m_memoryStore->clear([this, shouldGrandfather, callCompletionHandlerOnMainThread = WTFMove(callCompletionHandlerOnMainThread)] () mutable {

this, protectedThis = makeRef(*this)

I think you need to protect this here since there is nothing that guarantees that |this| stays alive AFAICT.

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> +                    m_memoryStore->grandfatherExistingWebsiteData(WTFMove(callCompletionHandlerOnMainThread));

You likely need to null-check m_memoryStore here. It would have been cleared in between.

[John Wilander]

(In reply to Chris Dumez from comment #8)
> Comment on attachment 349986 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=349986&action=review
> 
> r=me with fixes.
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:775
> > +            m_memoryStore->clear([this, shouldGrandfather, callCompletionHandlerOnMainThread = WTFMove(callCompletionHandlerOnMainThread)] () mutable {
> 
> this, protectedThis = makeRef(*this)
> 
> I think you need to protect this here since there is nothing that guarantees
> that |this| stays alive AFAICT.
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> > +                    m_memoryStore->grandfatherExistingWebsiteData(WTFMove(callCompletionHandlerOnMainThread));
> 
> You likely need to null-check m_memoryStore here. It would have been cleared
> in between.

Could you also ASSERT m_memoryStore, please? I'd like to know if we're failing to grandfather website data.

[Woodrow Wang]

(In reply to Chris Dumez from comment #8)
> Comment on attachment 349986 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=349986&action=review
> 
> r=me with fixes.
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:775
> > +            m_memoryStore->clear([this, shouldGrandfather, callCompletionHandlerOnMainThread = WTFMove(callCompletionHandlerOnMainThread)] () mutable {
> 
> this, protectedThis = makeRef(*this)
> 
> I think you need to protect this here since there is nothing that guarantees
> that |this| stays alive AFAICT.
I'll add this. 
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> > +                    m_memoryStore->grandfatherExistingWebsiteData(WTFMove(callCompletionHandlerOnMainThread));
> 
> You likely need to null-check m_memoryStore here. It would have been cleared
> in between.
Good call, I'll also ASSERT m_memoryStore so we will know if grandfathering has happened as expected.

[Woodrow Wang]

Created attachment 350032 [details]
Patch

[Chris Dumez]

Comment on attachment 350032 [details]
Patch

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

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> +                    ASSERT(m_memoryStore);

I do not believe this assertion is correct. There is no such guarantee. If applicationWillTerminate() gets called, we'll destroy m_memoryStore.

[John Wilander]

(In reply to Chris Dumez from comment #12)
> Comment on attachment 350032 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=350032&action=review
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> > +                    ASSERT(m_memoryStore);
> 
> I do not believe this assertion is correct. There is no such guarantee. If
> applicationWillTerminate() gets called, we'll destroy m_memoryStore.

Are you saying we'll hit this assertion in the TestRunner on debug bots? How would you rather check that we don't have regular cases where the memory store is null when we're supposed to grandfather?

[Chris Dumez]

(In reply to John Wilander from comment #13)
> (In reply to Chris Dumez from comment #12)
> > Comment on attachment 350032 [details]
> > Patch
> > 
> > View in context:
> > https://bugs.webkit.org/attachment.cgi?id=350032&action=review
> > 
> > > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> > > +                    ASSERT(m_memoryStore);
> > 
> > I do not believe this assertion is correct. There is no such guarantee. If
> > applicationWillTerminate() gets called, we'll destroy m_memoryStore.
> 
> Are you saying we'll hit this assertion in the TestRunner on debug bots? How
> would you rather check that we don't have regular cases where the memory
> store is null when we're supposed to grandfather?

Probably not on the bots but people will be able to hit it on their device is some code calls scheduleClearInMemoryAndPersistent(ShouldGrandfather::Yes) and then exit the application quickly.

[John Wilander]

(In reply to Chris Dumez from comment #14)
> (In reply to John Wilander from comment #13)
> > (In reply to Chris Dumez from comment #12)
> > > Comment on attachment 350032 [details]
> > > Patch
> > > 
> > > View in context:
> > > https://bugs.webkit.org/attachment.cgi?id=350032&action=review
> > > 
> > > > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> > > > +                    ASSERT(m_memoryStore);
> > > 
> > > I do not believe this assertion is correct. There is no such guarantee. If
> > > applicationWillTerminate() gets called, we'll destroy m_memoryStore.
> > 
> > Are you saying we'll hit this assertion in the TestRunner on debug bots? How
> > would you rather check that we don't have regular cases where the memory
> > store is null when we're supposed to grandfather?
> 
> Probably not on the bots but people will be able to hit it on their device
> is some code calls
> scheduleClearInMemoryAndPersistent(ShouldGrandfather::Yes) and then exit the
> application quickly.

Are people using debug builds that way? I've never come across that we take application quit into consideration when we add a correctness debug ASSERT.

[Chris Dumez]

Comment on attachment 350032 [details]
Patch

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

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:-793
> -        if (shouldGrandfather == ShouldGrandfather::Yes && m_memoryStore)

Also note that the previous code was doing a null check as expected.

>>>> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
>>>> +                    ASSERT(m_memoryStore);
>>> 
>>> I do not believe this assertion is correct. There is no such guarantee. If applicationWillTerminate() gets called, we'll destroy m_memoryStore.
>> 
>> Are you saying we'll hit this assertion in the TestRunner on debug bots? How would you rather check that we don't have regular cases where the memory store is null when we're supposed to grandfather?
> 
> Probably not on the bots but people will be able to hit it on their device is some code calls scheduleClearInMemoryAndPersistent(ShouldGrandfather::Yes) and then exit the application quickly.

Also note that this assertion would anyway not cover the case where m_memoryStore is null before we call clear...

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:781
> +                    callCompletionHandlerOnMainThread();

i.e. this code path.

[Chris Dumez]

(In reply to John Wilander from comment #15)
> (In reply to Chris Dumez from comment #14)
> > (In reply to John Wilander from comment #13)
> > > (In reply to Chris Dumez from comment #12)
> > > > Comment on attachment 350032 [details]
> > > > Patch
> > > > 
> > > > View in context:
> > > > https://bugs.webkit.org/attachment.cgi?id=350032&action=review
> > > > 
> > > > > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:777
> > > > > +                    ASSERT(m_memoryStore);
> > > > 
> > > > I do not believe this assertion is correct. There is no such guarantee. If
> > > > applicationWillTerminate() gets called, we'll destroy m_memoryStore.
> > > 
> > > Are you saying we'll hit this assertion in the TestRunner on debug bots? How
> > > would you rather check that we don't have regular cases where the memory
> > > store is null when we're supposed to grandfather?
> > 
> > Probably not on the bots but people will be able to hit it on their device
> > is some code calls
> > scheduleClearInMemoryAndPersistent(ShouldGrandfather::Yes) and then exit the
> > application quickly.
> 
> Are people using debug builds that way? I've never come across that we take
> application quit into consideration when we add a correctness debug ASSERT.

We have to worry about application termination here because:
void WebResourceLoadStatisticsStore::applicationWillTerminate()
{
    flushAndDestroyPersistentStore();
}

We do a best effort at flushing things to disk before exiting the app, and then we destroy the objects.

It is not OK to add an assertion that can hit in valid use cases, even if those cases are rare.

[Woodrow Wang]

Created attachment 350059 [details]
Patch

[Chris Dumez]

Comment on attachment 350059 [details]
Patch

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

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:780
> +                        RELEASE_LOG(ResourceLoadStatistics, "WebResourceLoadStatisticsStore::scheduleClearInMemoryAndPersistent m_memoryStore is null when trying to grandfather data.");

Why log here but not..

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:786
>              callCompletionHandlerOnMainThread();

.. here?

[Woodrow Wang]

(In reply to Chris Dumez from comment #19)
> Comment on attachment 350059 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=350059&action=review
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:780
> > +                        RELEASE_LOG(ResourceLoadStatistics, "WebResourceLoadStatisticsStore::scheduleClearInMemoryAndPersistent m_memoryStore is null when trying to grandfather data.");
> 
> Why log here but not..
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:786
> >              callCompletionHandlerOnMainThread();
> 
> .. here?

To my understanding, the existing log is useful as we expect when grandfathering is requested that the memory store is non-null. The latter site is where we have no memory store to clear at all in the function, which seems like possible behavior. If this is unexpected, what should the log statement be?

[Chris Dumez]

Comment on attachment 350059 [details]
Patch

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

>>> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:780
>>> +                        RELEASE_LOG(ResourceLoadStatistics, "WebResourceLoadStatisticsStore::scheduleClearInMemoryAndPersistent m_memoryStore is null when trying to grandfather data.");
>> 
>> Why log here but not..
> 
> To my understanding, the existing log is useful as we expect when grandfathering is requested that the memory store is non-null. The latter site is where we have no memory store to clear at all in the function, which seems like possible behavior. If this is unexpected, what should the log statement be?

You could do the exact same login gin the else case below if (shouldGrandfather == ShouldGrandfather::Yes). There is no difference really. It is just a matter a timing: was the memory store destroyed before or after the call to clear() ?

[Woodrow Wang]

(In reply to Chris Dumez from comment #21)
> Comment on attachment 350059 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=350059&action=review
> 
> >>> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:780
> >>> +                        RELEASE_LOG(ResourceLoadStatistics, "WebResourceLoadStatisticsStore::scheduleClearInMemoryAndPersistent m_memoryStore is null when trying to grandfather data.");
> >> 
> >> Why log here but not..
> > 
> > To my understanding, the existing log is useful as we expect when grandfathering is requested that the memory store is non-null. The latter site is where we have no memory store to clear at all in the function, which seems like possible behavior. If this is unexpected, what should the log statement be?
> 
> You could do the exact same login gin the else case below if
> (shouldGrandfather == ShouldGrandfather::Yes). There is no difference
> really. It is just a matter a timing: was the memory store destroyed before
> or after the call to clear() ?
I see, I can add the extra logging statement with slightly different wording to differentiate the two cases.

[Woodrow Wang]

Created attachment 350082 [details]
Patch

[Chris Dumez]

Comment on attachment 350082 [details]
Patch

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

Please see if you can refactor this code a bit so that it is not as big and not as error prone. You may also consider using CompletionHandlerCallingScope to make sure the completion handler is always called.

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:780
> +                        RELEASE_LOG(ResourceLoadStatistics, "WebResourceLoadStatisticsStore::scheduleClearInMemoryAndPersistent After being cleared, m_memoryStore is null when trying to grandfather data.");

The completion is not called in this case, which is wrong.

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:785
> +        } else

The else case is multi-line so you need curly brackets.

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:788
> +            else

This is wrong, you now fail to call the completion handler in the if case. This else should be dropped so that callCompletionHandlerOnMainThread() is always called.

[Woodrow Wang]

(In reply to Chris Dumez from comment #24)
> Comment on attachment 350082 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=350082&action=review
> 
> Please see if you can refactor this code a bit so that it is not as big and
> not as error prone. You may also consider using
> CompletionHandlerCallingScope to make sure the completion handler is always
> called.
I'll refactor the code to use CompletionHandlerCallingScope to ensure the completion handler is always called. 
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:780
> > +                        RELEASE_LOG(ResourceLoadStatistics, "WebResourceLoadStatisticsStore::scheduleClearInMemoryAndPersistent After being cleared, m_memoryStore is null when trying to grandfather data.");
> 
> The completion is not called in this case, which is wrong.
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:785
> > +        } else
> 
> The else case is multi-line so you need curly brackets.
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:788
> > +            else
> 
> This is wrong, you now fail to call the completion handler in the if case.
> This else should be dropped so that callCompletionHandlerOnMainThread() is
> always called.

[Woodrow Wang]

Created attachment 350130 [details]
Patch

[Chris Dumez]

Comment on attachment 350130 [details]
Patch

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

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:769
>          CompletionHandler<void()> callCompletionHandlerOnMainThread = [completionHandler = WTFMove(completionHandler)]() mutable {

We do not need this local variable anymore, we could just inline the lambda when constructing the CompletionHandlerCallingScope. LGTM otherwise.

[Woodrow Wang]

Created attachment 350147 [details]
Patch

[Chris Dumez]

Comment on attachment 350147 [details]
Patch

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

> Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:772
> +        CompletionHandlerCallingScope completionHandlerCaller(WTFMove(callCompletionHandlerOnMainThread));

You still did not inline the lambda in here.

[Woodrow Wang]

(In reply to Chris Dumez from comment #29)
> Comment on attachment 350147 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=350147&action=review
> 
> > Source/WebKit/UIProcess/WebResourceLoadStatisticsStore.cpp:772
> > +        CompletionHandlerCallingScope completionHandlerCaller(WTFMove(callCompletionHandlerOnMainThread));
> 
> You still did not inline the lambda in here.
Oops, I'll do so right now.

[Woodrow Wang]

Created attachment 350151 [details]
Patch

[Chris Dumez]

Comment on attachment 350151 [details]
Patch

LGTM

[WebKit Commit Bot]

Comment on attachment 350151 [details]
Patch

Rejecting attachment 350151 [details] from commit-queue.

Failed to run "['/Volumes/Data/EWS/WebKit/Tools/Scripts/webkit-patch', '--status-host=webkit-queues.webkit.org', '--bot-id=webkit-cq-02', 'validate-changelog', '--check-oops', '--non-interactive', 350151, '--port=mac']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit

ChangeLog entry in Source/WebKit/ChangeLog contains OOPS!.

Full output: https://webkit-queues.webkit.org/results/9274508

[WebKit Commit Bot]

Comment on attachment 350151 [details]
Patch

Clearing flags on attachment: 350151

Committed r236229: <https://trac.webkit.org/changeset/236229>

[Dawei Fenton (:realdawei)]

(In reply to WebKit Commit Bot from comment #34)
> Comment on attachment 350151 [details]
> Patch
> 
> Clearing flags on attachment: 350151
> 
> Committed r236229: <https://trac.webkit.org/changeset/236229>

Seeing API Timeouts after on Mac WK1 after this revision

sample output:
https://build.webkit.org/builders/Apple%20High%20Sierra%20Release%20WK1%20(Tests)/builds/8069/steps/run-api-tests/logs/stdio
Test suite failed

Timeout

    TestWebKitAPI.ResourceLoadStatistics.GrandfatherCallback

[Dawei Fenton (:realdawei)]

(In reply to Dawei Fenton (:realdawei) from comment #35)
> (In reply to WebKit Commit Bot from comment #34)
> > Comment on attachment 350151 [details]
> > Patch
> > 
> > Clearing flags on attachment: 350151
> > 
> > Committed r236229: <https://trac.webkit.org/changeset/236229>
> 
> Seeing API Timeouts on Mac WK1 after this revision
> 
> sample output:
> https://build.webkit.org/builders/
> Apple%20High%20Sierra%20Release%20WK1%20(Tests)/builds/8069/steps/run-api-
> tests/logs/stdio
> Test suite failed
> 
> Timeout
> 
>     TestWebKitAPI.ResourceLoadStatistics.GrandfatherCallback


Also timing out on iOS
https://build.webkit.org/builders/Apple%20iOS%2011%20Simulator%20Release%20WK2%20(Tests)/builds/7505/steps/run-api-tests/logs/stdio

[Dawei Fenton (:realdawei)]

Reverted r236229 for reason:

caused API timouts on mac and ios

Committed r236233: <https://trac.webkit.org/changeset/236233>

[Woodrow Wang]

(In reply to Dawei Fenton (:realdawei) from comment #37)
> Reverted r236229 for reason:
> 
> caused API timouts on mac and ios
> 
> Committed r236233: <https://trac.webkit.org/changeset/236233>

Submitting another patch with a fix for the timeout on the ResourceLoadStatistics::GrandfatherCallback test.

[Woodrow Wang]

Created attachment 350279 [details]
Patch

[Chris Dumez]

Comment on attachment 350279 [details]
Patch

r=me

[WebKit Commit Bot]

Comment on attachment 350279 [details]
Patch

Clearing flags on attachment: 350279

Committed r236320: <https://trac.webkit.org/changeset/236320>

[John Wilander]

Moving to resolved based on the landed patch.