ResourceLoadStatisticsDatabaseStore checks 'hasHadUserInteraction' without ensuring the domain has been added to the ITP database

[Brent Fulgham]

While debugging another problem, I noticed that this code in ResourceLoadStatisticsDatabaseStore::hasHadUserInteraction:

    if (m_hadUserInteractionStatement.bindText(1, domain.string()) != SQLITE_OK
        || m_hadUserInteractionStatement.step() != SQLITE_ROW) {
        RELEASE_LOG_ERROR_IF_ALLOWED(m_sessionID, "%p - ResourceLoadStatisticsDatabaseStore::m_hadUserInteractionStatement failed, error message: %{private}s", this, m_database.lastErrorMsg());

This generates error logging for the expected case that a particular domain did not have user interaction.

We should avoid generating logging for normal program flow.

[Radar WebKit Bug Importer]

<rdar://problem/62849919>

[Brent Fulgham]

Created attachment 398389 [details]
Patch

[Brent Fulgham]

Created attachment 398391 [details]
Patch

[Kate Cheney]

(In reply to Brent Fulgham from comment #0)
> While debugging another problem, I noticed that this code in
> ResourceLoadStatisticsDatabaseStore::hasHadUserInteraction:
> 
>     if (m_hadUserInteractionStatement.bindText(1, domain.string()) !=
> SQLITE_OK
>         || m_hadUserInteractionStatement.step() != SQLITE_ROW) {
>         RELEASE_LOG_ERROR_IF_ALLOWED(m_sessionID, "%p -
> ResourceLoadStatisticsDatabaseStore::m_hadUserInteractionStatement failed,
> error message: %{private}s", this, m_database.lastErrorMsg());
> 
> This generates error logging for the expected case that a particular domain
> did not have user interaction.

I think this error should only arise if the domain does not exist in the ObservedDomains table, otherwise the row will exist with a userInteraction value of 0. Are you seeing this in logs? It might indicate a deeper issue if we are checking user interaction for a domain we haven't inserted yet.

> 
> We should avoid generating logging for normal program flow.

[Brent Fulgham]

(In reply to katherine_cheney from comment #4)
> > This generates error logging for the expected case that a particular domain
> > did not have user interaction.
> 
> I think this error should only arise if the domain does not exist in the
> ObservedDomains table, otherwise the row will exist with a userInteraction
> value of 0. Are you seeing this in logs? It might indicate a deeper issue if
> we are checking user interaction for a domain we haven't inserted yet.

Yes, I encountered the following error while debugging an unrelated issue with Google docs:

0x10a7fa000 - ResourceLoadStatisticsDatabaseStore::0x10a7fa000 - ResourceLoadStatisticsDatabaseStore::m_hadUserInteractionStatement failed, error message: no more rows available

From your comments, it sounds like this should be impossible (so the error logging is correct).

[Brent Fulgham]

One possible source is this:

void ResourceLoadStatisticsDatabaseStore::logUserInteraction(const TopFrameDomain& domain, CompletionHandler<void()>&& completionHandler)
{
    ASSERT(!RunLoop::isMain());

    bool didHavePreviousUserInteraction = hasHadUserInteraction(domain, OperatingDatesWindow::Long);
    auto result = ensureResourceStatisticsForRegistrableDomain(domain);
    if (!result.second) {


We do a 'hasHadUserInteraction' check before the 'ensureResource...' call.

[Kate Cheney]

(In reply to Brent Fulgham from comment #6)
> One possible source is this:
> 
> void ResourceLoadStatisticsDatabaseStore::logUserInteraction(const
> TopFrameDomain& domain, CompletionHandler<void()>&& completionHandler)
> {
>     ASSERT(!RunLoop::isMain());
> 
>     bool didHavePreviousUserInteraction = hasHadUserInteraction(domain,
> OperatingDatesWindow::Long);
>     auto result = ensureResourceStatisticsForRegistrableDomain(domain);
>     if (!result.second) {
> 
> 
> We do a 'hasHadUserInteraction' check before the 'ensureResource...' call.

That seems like a bug, and could explain the error you're seeing.

[Brent Fulgham]

(In reply to Brent Fulgham from comment #6)
> One possible source is this:
> 
> void ResourceLoadStatisticsDatabaseStore::logUserInteraction(const
> TopFrameDomain& domain, CompletionHandler<void()>&& completionHandler)
> {
>     ASSERT(!RunLoop::isMain());
> 
>     bool didHavePreviousUserInteraction = hasHadUserInteraction(domain,
> OperatingDatesWindow::Long);
>     auto result = ensureResourceStatisticsForRegistrableDomain(domain);
>     if (!result.second) {
> 
> 
> We do a 'hasHadUserInteraction' check before the 'ensureResource...' call.

Could we just switch the two lines? That would make it behave like the in-memory store version.

[Brent Fulgham]

Retitling to address the actual bug.

[Kate Cheney]

(In reply to Brent Fulgham from comment #8)
> (In reply to Brent Fulgham from comment #6)
> > One possible source is this:
> > 
> > void ResourceLoadStatisticsDatabaseStore::logUserInteraction(const
> > TopFrameDomain& domain, CompletionHandler<void()>&& completionHandler)
> > {
> >     ASSERT(!RunLoop::isMain());
> > 
> >     bool didHavePreviousUserInteraction = hasHadUserInteraction(domain,
> > OperatingDatesWindow::Long);
> >     auto result = ensureResourceStatisticsForRegistrableDomain(domain);
> >     if (!result.second) {
> > 
> > 
> > We do a 'hasHadUserInteraction' check before the 'ensureResource...' call.
> 
> Could we just switch the two lines? That would make it behave like the
> in-memory store version.

Yes, I think a switch is a good idea

[Brent Fulgham]

Created attachment 398398 [details]
Patch

[John Wilander]

Comment on attachment 398398 [details]
Patch

Good catch! This change matches the order in the memory store:
    auto& statistics = ensureResourceStatisticsForRegistrableDomain(domain);
    bool didHavePreviousUserInteraction = statistics.hadUserInteraction;
    statistics.hadUserInteraction = true;

[EWS]

Committed r261115: <https://trac.webkit.org/changeset/261115>

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