Bug 142186

Summary: NetworkCache efficacy logging is using too much CPU
Product: WebKit Reporter: Chris Dumez <cdumez>
Component: WebKit2Assignee: Chris Dumez <cdumez>
Status: RESOLVED FIXED    
Severity: Normal CC: benjamin, cmarcelo, commit-queue, koivisto
Priority: P2 Keywords: InRadar
Version: 528+ (Nightly build)   
Hardware: Unspecified   
OS: Unspecified   
Attachments:
Description Flags
Patch
none
Patch
none
Patch
none
Patch
none
Patch
none
Patch
none
Patch none

Description Chris Dumez 2015-03-02 13:15:18 PST
NetworkCache efficacy logging is using too much CPU. Around ~11% of the NetworkProcess' CPU usage on a PLT on iPhone.
We should improve this and re-enable it.

Radar: <rdar://problem/19632080>
Comment 1 Chris Dumez 2015-03-02 15:28:15 PST
Created attachment 247704 [details]
Patch
Comment 2 Chris Dumez 2015-03-02 16:55:23 PST
Created attachment 247721 [details]
Patch
Comment 3 Chris Dumez 2015-03-02 17:27:17 PST
Created attachment 247724 [details]
Patch
Comment 4 Chris Dumez 2015-03-02 18:51:13 PST
Created attachment 247732 [details]
Patch
Comment 5 Antti Koivisto 2015-03-03 09:25:44 PST
Comment on attachment 247732 [details]
Patch

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

Looks fine except...

> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:57
> +    if (!result) {
>          LOG_ERROR("Network cache statistics: failed to execute statement \"%s\" error \"%s\"", sql.utf8().data(), database.lastErrorMsg());
> +        ASSERT_NOT_REACHED();

Why make these fatal?

> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:311
> +    HashSet<String> hashesToAdd;
> +    hashesToAdd.swap(m_hashesToAdd);
> +    HashMap<String, NetworkCache::StoreDecision> storeDecisionsToAdd;
> +    storeDecisionsToAdd.swap(m_storeDecisionsToAdd);
>  
>      shrinkIfNeeded();
> +
> +    dispatch_async(m_backgroundIOQueue.get(), [this, hashesToAdd, storeDecisionsToAdd] {

This isn't thread safe because String refcounting is not thread safe. You need to take care that you pass isolated copies to the queue.
Comment 6 Chris Dumez 2015-03-03 09:43:13 PST
Comment on attachment 247732 [details]
Patch

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

>> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:57
>> +        ASSERT_NOT_REACHED();
> 
> Why make these fatal?

To make it more obvious when you get your queries wrong. There should no no other reason for them to fail.
When refactoring, I got one of my queries wrong and it took me a while to figure it out because nothing was complaining.

>> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:311
>> +    dispatch_async(m_backgroundIOQueue.get(), [this, hashesToAdd, storeDecisionsToAdd] {
> 
> This isn't thread safe because String refcounting is not thread safe. You need to take care that you pass isolated copies to the queue.

Ok.
Comment 7 Chris Dumez 2015-03-03 13:34:22 PST
Created attachment 247787 [details]
Patch
Comment 8 Antti Koivisto 2015-03-03 16:04:17 PST
Comment on attachment 247787 [details]
Patch

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

> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:332
> +    auto storeDecisionsToAdd = isolatedCopy(m_storeDecisionsToAdd);
> +    m_storeDecisionsToAdd.clear();
>  
>      shrinkIfNeeded();
> +
> +    dispatch_async(m_backgroundIOQueue.get(), [this, hashesToAdd, storeDecisionsToAdd] {

This still don't look thread safe. The vector gets copied to lambda, the contained strings get reffed by the copy, the original gets dereffed in main thread while the copy is dereffed in the queue. 

We have StringCapture for single strings but here you are probably better of bundling all the stuff you want to pass to a heap allocated struct. 

C++14 will solve this problem by allowing move initialization of the lambda capture.
Comment 9 Chris Dumez 2015-03-03 16:21:40 PST
(In reply to comment #8)
> Comment on attachment 247787 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=247787&action=review
> 
> > Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:332
> > +    auto storeDecisionsToAdd = isolatedCopy(m_storeDecisionsToAdd);
> > +    m_storeDecisionsToAdd.clear();
> >  
> >      shrinkIfNeeded();
> > +
> > +    dispatch_async(m_backgroundIOQueue.get(), [this, hashesToAdd, storeDecisionsToAdd] {
> 
> This still don't look thread safe. The vector gets copied to lambda, the
> contained strings get reffed by the copy, the original gets dereffed in main
> thread while the copy is dereffed in the queue. 
> 
> We have StringCapture for single strings but here you are probably better of
> bundling all the stuff you want to pass to a heap allocated struct. 
> 
> C++14 will solve this problem by allowing move initialization of the lambda
> capture.

I initially tried to use a Vector<StringCapture> but this did not compile because StringCapture doesn't have an assignment operator.
Comment 10 Chris Dumez 2015-03-03 17:33:11 PST
(In reply to comment #8)
> Comment on attachment 247787 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=247787&action=review
> 
> > Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:332
> > +    auto storeDecisionsToAdd = isolatedCopy(m_storeDecisionsToAdd);
> > +    m_storeDecisionsToAdd.clear();
> >  
> >      shrinkIfNeeded();
> > +
> > +    dispatch_async(m_backgroundIOQueue.get(), [this, hashesToAdd, storeDecisionsToAdd] {
> 
> This still don't look thread safe. The vector gets copied to lambda, the
> contained strings get reffed by the copy, the original gets dereffed in main
> thread while the copy is dereffed in the queue. 
> 
> We have StringCapture for single strings but here you are probably better of
> bundling all the stuff you want to pass to a heap allocated struct. 
> 
> C++14 will solve this problem by allowing move initialization of the lambda
> capture.

Could you please clarify what you are proposing? I'm afraid I don't understand.
Comment 11 Antti Koivisto 2015-03-04 01:59:07 PST
> Could you please clarify what you are proposing? I'm afraid I don't
> understand.

Something like

struct Capture {
   Vector<String> strings;
   ...
};
Capture* capture = new Capture { isolatedCopy(m_strings), ... }
dsipatch_async(..., [capture] {
  
     delete capture;
}

(shared_ptr works too if you want to avoid explicit new/delete)
Comment 12 Antti Koivisto 2015-03-04 02:03:57 PST
> I initially tried to use a Vector<StringCapture> but this did not compile
> because StringCapture doesn't have an assignment operator.

Maybe you could just add it. It doesn't have one because there didn't seem to be need.
Comment 13 Chris Dumez 2015-03-04 12:31:27 PST
Created attachment 247881 [details]
Patch
Comment 14 WebKit Commit Bot 2015-03-04 12:34:01 PST
Attachment 247881 [details] did not pass style-queue:


ERROR: Source/WTF/wtf/text/WTFString.h:642:  Should be indented on a separate line, with the colon or comma first on that line.  [whitespace/indent] [4]
Total errors found: 1 in 7 files


If any of these errors are false positives, please file a bug against check-webkit-style.
Comment 15 Antti Koivisto 2015-03-05 05:31:19 PST
Comment on attachment 247881 [details]
Patch

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

> Source/WTF/wtf/HashMap.h:512
> +    iterator it = collection.begin();
> +    iterator end = collection.end();
> +    for (unsigned i = 0; it != end; ++it, ++i)
> +        vector[i] = { (*it).key, (*it).value };

This might look slightly nicer with range-for.

> Source/WTF/wtf/text/WTFString.h:641
> +    StringCapture() = default;

I'm not sure '= default;' is better than { }

> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:46
> +static const double minWriteIntervalSeconds = 10;

minimum

std::chrono::duration would be nicer and allow losing 'Seconds' qualifier.

> Source/WebKit2/NetworkProcess/cache/NetworkCacheStatisticsCocoa.mm:72
> +    if (statement.step() != WebCore::SQLResultDone) {
>          LOG_ERROR("Network cache statistics: failed to execute statement \"%s\" error \"%s\"", statement.query().utf8().data(), statement.database().lastErrorMsg());
> +        ASSERT_NOT_REACHED();
> +        return false;

Is SQL failure in logging code really important enough to interrupt someone debugging something completely different? (this and other new asserts).

If this can't happen then we should just have the assert without branch. If it can happen then it shouldn't assert.
Comment 16 Chris Dumez 2015-03-05 10:03:46 PST
Comment on attachment 247881 [details]
Patch

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

>> Source/WTF/wtf/HashMap.h:512
>> +        vector[i] = { (*it).key, (*it).value };
> 
> This might look slightly nicer with range-for.

But I need the index for vector assignment. Otherwise I guess I could use Vector::append() instead.
However, I followed the pattern used in all the copyToVector() utility functions.
Comment 17 Chris Dumez 2015-03-05 10:15:37 PST
Created attachment 247963 [details]
Patch
Comment 18 WebKit Commit Bot 2015-03-05 10:17:59 PST
Attachment 247963 [details] did not pass style-queue:


ERROR: Source/WTF/wtf/text/WTFString.h:642:  Should be indented on a separate line, with the colon or comma first on that line.  [whitespace/indent] [4]
Total errors found: 1 in 7 files


If any of these errors are false positives, please file a bug against check-webkit-style.
Comment 19 WebKit Commit Bot 2015-03-05 11:00:22 PST
Comment on attachment 247963 [details]
Patch

Clearing flags on attachment: 247963

Committed r181086: <http://trac.webkit.org/changeset/181086>
Comment 20 WebKit Commit Bot 2015-03-05 11:00:28 PST
All reviewed patches have been landed.  Closing bug.