Bug 211388

Summary: ResourceLoadStatisticsDatabaseStore checks 'hasHadUserInteraction' without ensuring the domain has been added to the ITP database
Product: WebKit Reporter: Brent Fulgham <bfulgham>
Component: WebKit Misc.Assignee: Brent Fulgham <bfulgham>
Status: RESOLVED FIXED    
Severity: Normal CC: achristensen, beidson, bfulgham, cdumez, katherine_cheney, webkit-bug-importer, wilander
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
Attachments:
Description Flags
Patch
none
Patch
none
Patch none

Brent Fulgham
Reported 2020-05-04 10:08:26 PDT
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.
Attachments
Patch (3.93 KB, patch)
2020-05-04 10:33 PDT, Brent Fulgham 		no flags
DetailsFormatted DiffDiff
Patch (5.10 KB, patch)
2020-05-04 10:50 PDT, Brent Fulgham 		no flags
DetailsFormatted DiffDiff
Patch (2.40 KB, patch)
2020-05-04 12:14 PDT, Brent Fulgham 		no flags
DetailsFormatted DiffDiff
Show Obsolete (2) View All Add attachment proposed patch, testcase, etc.
Radar WebKit Bug Importer
Comment 1 2020-05-04 10:08:45 PDT
<rdar://problem/62849919>
Brent Fulgham
Comment 2 2020-05-04 10:33:36 PDT
Created attachment 398389 [details] Patch
Brent Fulgham
Comment 3 2020-05-04 10:50:05 PDT
Created attachment 398391 [details] Patch
Kate Cheney
Comment 4 2020-05-04 11:00:02 PDT
(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
Comment 5 2020-05-04 11:31:21 PDT
(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
Comment 6 2020-05-04 11:59:45 PDT
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
Comment 7 2020-05-04 12:01:07 PDT
(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
Comment 8 2020-05-04 12:03:17 PDT
(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
Comment 9 2020-05-04 12:07:13 PDT
Retitling to address the actual bug.
Kate Cheney
Comment 10 2020-05-04 12:12:54 PDT
(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
Comment 11 2020-05-04 12:14:29 PDT
Created attachment 398398 [details] Patch
John Wilander
Comment 12 2020-05-04 12:57:41 PDT
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
Comment 13 2020-05-04 15:00:31 PDT
Committed r261115: <https://trac.webkit.org/changeset/261115> All reviewed patches have been landed. Closing bug and clearing flags on attachment 398398 [details].
Note You need to log in before you can comment on or make changes to this bug.