Bug 107937 – Web Inspector: CPU pegged when inspecting LocalStorage that mutates.

• Status: RESOLVED
• Resolution: FIXED
• Component: Web Inspector (Deprecated)

[Pavel Feldman]

Downstream issue: http://code.google.com/p/chromium/issues/detail?id=172075

[Vivek Galatage]

The issue is with the current implementation of View update. The InspectorDOMStorageAgent fires domStorageUpdated() event for which the view triggers DOMStorage.getEntries. 

The domStorageUpdated event is fired for every set/remove/clear actions on the localStorage/sessionStorage. So in the test scenario mentioned above, the view update is also triggered for 1000 times. But the operation is expensive one as there are around 1000 entries in the localStorage. So for every call, the marshalling/unmarshalling is carried out, returned as an array back to inspector and then inspector creates a data grid of items. By the time the view is updated for one call, another is queued up to repeat the whole thing. This is very heavy operation as the objects also go through the GC recycle. Hence the inspector stalls or pegs the CPU.

I have modified the domStorageUpdated() event with some more additional parameters as:

/*
 * @param {string} storageId
 * @param {string} storageAction: Could be one of "ItemSet", "ItemRemoved", "ItemsCleared"
 * @param {string} key
 * @param {string} oldValue
 * @param {string} newValue
 */

domStorageUpdated(storageId, storageAction, key, oldValue, newValue)

So now its much more easier to update the view with just the change that occurred within the storage thereby reducing the getEntries calls altogether. When "ItemsCleared" is received, the entire grid is removed.

Here are the WIP patches
1. WebKit patch
http://pastebin.com/uaxUnxty

2. Chromium port patch
http://pastebin.com/PpwRZGwN

Please let me know if we can proceed with the above approach to fix the said issue.

[Vivek Galatage]

(In reply to comment #1)


> Here are the WIP patches
> 1. WebKit patch
> http://pastebin.com/uaxUnxty
> 
> 2. Chromium port patch
> http://pastebin.com/PpwRZGwN
> 

The above patches just outline the work done in the backend. Currently I am just logging the domStorageEvent and its associated data in the console on domStorageUpdated(). This will eventually be replaced with proper handling of the action.

[Vsevolod Vlasov]

(In reply to comment #2)
> (In reply to comment #1)
> 
> 
> > Here are the WIP patches
> > 1. WebKit patch
> > http://pastebin.com/uaxUnxty
> > 
> > 2. Chromium port patch
> > http://pastebin.com/PpwRZGwN
> > 
> 
> The above patches just outline the work done in the backend. Currently I am just logging the domStorageEvent and its associated data in the console on domStorageUpdated(). This will eventually be replaced with proper handling of the action.

I didn't look deeply into your patches but sounds like it might be easier to simply add a timeout for localStorage view update (do not update it more than once per second, probably only when this view is shown and focused)

[Vivek Galatage]

(In reply to comment #3)

> I didn't look deeply into your patches but sounds like it might be easier to simply add a timeout for localStorage view update (do not update it more than once per second, probably only when this view is shown and focused)

Thank you for your feedback. I agree that setting the timeout is much easier than that one presented in the patch. 

The reason for the above patch is the information about the DOM storage change has almost reached the frontend. (Currently the InspectorDOMStorageAgent::didDispatchDOMStorageEvent() method does receive all the changed key, newValue and oldValue). The only missing thing is exposing this back to the front-end. This way only the delta change will be notified and we need not fetch the whole local/session storage entries again and again. Thereby reducing the round trips. And this will be done, as you have pointed out below, only when the view is in focus. Your thoughts?

[Vivek Galatage]

ping?

[Vsevolod Vlasov]

(In reply to comment #5)
> ping?

(In reply to comment #4)
> (In reply to comment #3)
> 
> > I didn't look deeply into your patches but sounds like it might be easier to simply add a timeout for localStorage view update (do not update it more than once per second, probably only when this view is shown and focused)
> 
> Thank you for your feedback. I agree that setting the timeout is much easier than that one presented in the patch. 
> 
> The reason for the above patch is the information about the DOM storage change has almost reached the frontend. (Currently the InspectorDOMStorageAgent::didDispatchDOMStorageEvent() method does receive all the changed key, newValue and oldValue). The only missing thing is exposing this back to the front-end. This way only the delta change will be notified and we need not fetch the whole local/session storage entries again and again. Thereby reducing the round trips. And this will be done, as you have pointed out below, only when the view is in focus. Your thoughts?

I don't understand why do you need storageAction parameter. It seems to me that the action performed is already defined by key/newValue pair. 
Key is null => Clear
Key is not null, Value is null => Remove
Key and Value are not Nulls => Set

[Vivek Galatage]

(In reply to comment #6)
> I don't understand why do you need storageAction parameter. It seems to me that the action performed is already defined by key/newValue pair. 
> Key is null => Clear
> Key is not null, Value is null => Remove
> Key and Value are not Nulls => Set

Yeah perfect. This sounds good to me! And I apologize for doing a bit of over-engineering :)

[Vivek Galatage]

(In reply to comment #6)
> I don't understand why do you need storageAction parameter. It seems to me that the action performed is already defined by key/newValue pair. 
> Key is null => Clear
> Key is not null, Value is null => Remove
> Key and Value are not Nulls => Set

I performed a quick test as:

1. localStorage.setItem("hello","world");
creates a new entry in the local storage.

2. localStorage.setItem("hello","");
3. localStorage.removeItem("hello");

Now for 2 and 3, we get the return values as
key: "hello"
newValue: ""
oldValue: "world"

So in this case we wont be able to distinguish which operation was performed.

[Vsevolod Vlasov]

(In reply to comment #8)
> (In reply to comment #6)
> > I don't understand why do you need storageAction parameter. It seems to me that the action performed is already defined by key/newValue pair. 
> > Key is null => Clear
> > Key is not null, Value is null => Remove
> > Key and Value are not Nulls => Set
> 
> I performed a quick test as:
> 
> 1. localStorage.setItem("hello","world");
> creates a new entry in the local storage.
> 
> 2. localStorage.setItem("hello","");
> 3. localStorage.removeItem("hello");
> 
> Now for 2 and 3, we get the return values as
> key: "hello"
> newValue: ""
> oldValue: "world"
> 
> So in this case we wont be able to distinguish which operation was performed.

We do not distinguish empty and null strings in the inspector protocol. You can still distinguish this cases on the back-end though. I'm fine with adding separate inspector protocol method for each case.

[Vivek Galatage]

Created attachment 186560 [details]
Patch

[Vivek Galatage]

(In reply to comment #10)
> Created an attachment (id=186560) [details]
> Patch

The functionality test is available at LayoutTests/inspector/storage-panel-dom-storage-update.html 

I think we need to add the protocol test. But this is not a public protocol api/event yet. So shall we add that test to LayoutTests/inspector-protocol ?

[Pavel Feldman]

Comment on attachment 186560 [details]
Patch

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

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:71
> +        var rootNode = this._dataGrid.rootNode();

You should not be doing this all when the view is not visible.

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:80
> +                if (childNode.data.key === key && childNode.data.value === oldValue) {

Why do you need to compare the old values? If key is getting removed, it does not matter what value it had.

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:88
> +            rootNode.appendChild(childNode);

This is still going to be slow if localstorage is being populated within a loop. I wonder if it makes sense to send keys only and request values lazily. Could be a part of a separate change though.

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:94
> +                if (childNode.data.key === key && childNode.data.value === oldValue) {

ditto

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:104
>      update: function()

This mo longer needs to be public.

> Source/WebCore/inspector/front-end/ResourcesPanel.js:120
> +    WebInspector.domStorageModel.addEventListener(WebInspector.DOMStorageModel.Events.DOMStorageChanged, this._domStorageChanged, this);

While you are here, it might make sense to move the listener registration from the panel into the views.

[Vivek Galatage]

Comment on attachment 186560 [details]
Patch

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

Thank you for your review.

>> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:71
>> +        var rootNode = this._dataGrid.rootNode();
> 
> You should not be doing this all when the view is not visible.

This check is done prior to calling onChange in ResourcesPanel::_domStorageChanged(). Hence I did avoid calling it again here.

>> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:80
>> +                if (childNode.data.key === key && childNode.data.value === oldValue) {
> 
> Why do you need to compare the old values? If key is getting removed, it does not matter what value it had.

Agree. Will remove it.

>> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:88
>> +            rootNode.appendChild(childNode);
> 
> This is still going to be slow if localstorage is being populated within a loop. I wonder if it makes sense to send keys only and request values lazily. Could be a part of a separate change though.

hmm I am not quite sure why would it be slow in a loop. Can you please let me know what is that I am missing? As the event, "DOMStorageChanged", is fired every time there's a change in the DOM storage, the value associated with the key is also sent alongwith.

>> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:104
>>      update: function()
> 
> This mo longer needs to be public.

Agree. Will change it.

>> Source/WebCore/inspector/front-end/ResourcesPanel.js:120
>> +    WebInspector.domStorageModel.addEventListener(WebInspector.DOMStorageModel.Events.DOMStorageChanged, this._domStorageChanged, this);
> 
> While you are here, it might make sense to move the listener registration from the panel into the views.

In that case the view needs to know about the model. I think the current registration mechanism shields the view from having the knowledge of the model. Also the panel has control over the views(i.e. which view is currently visible and which of them are not).

[Vivek Galatage]

Created attachment 186585 [details]
Patch

[Vivek Galatage]

Created attachment 186588 [details]
Patch

[Vivek Galatage]

Comment on attachment 186588 [details]
Patch

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

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:77
> +            this.deleteButton.visible = false;

The delete button's visibility should be handled as well.

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:187
>      },

The above lines were causing the view update being called twice by explicitly calling update() and the other being triggered by the DOM Storage Agent. This is unnecessary hence removing it.

> Source/WebCore/inspector/front-end/DOMStorageItemsView.js:-149
> -        this.update();

ditto

[Build Bot]

Comment on attachment 186588 [details]
Patch

Attachment 186588 [details] did not pass win-ews (win):
Output: http://queues.webkit.org/results/16368679

[Vivek Galatage]

(In reply to comment #17)
> (From update of attachment 186588 [details])
> Attachment 186588 [details] did not pass win-ews (win):
> Output: http://queues.webkit.org/results/16368679

This change is not related to the build failure observed on win ews.

[Vivek Galatage]

ping r?

[Yury Semikhatsky]

Comment on attachment 186588 [details]
Patch

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

> Source/WebCore/inspector/Inspector.json:1500
> +                    { "name": "oldValue", "type": "string" },

oldValue and newValue should be optional as they makes sense not for all actions. Even key param should be optional as there is no key for itemsCleared. Vsevolod's suggestion to split the event into 4 would eliminate the problem.

> Source/WebCore/inspector/InspectorDOMStorageAgent.cpp:238
> +    if (key.isEmpty() && key.isNull())

isNull implies isEmpty

> Source/WebCore/inspector/InspectorDOMStorageAgent.cpp:240
> +    else if (newValue.isEmpty() && newValue.isNull())

ditto

> Source/WebCore/inspector/InspectorDOMStorageAgent.cpp:242
> +    else if (oldValue.isEmpty() && oldValue.isNull())

ditto

[Vivek Galatage]

Created attachment 187045 [details]
Patch

[WebKit Review Bot]

Comment on attachment 187045 [details]
Patch

Rejecting attachment 187045 [details] from commit-queue.

Failed to run "['/mnt/git/webkit-commit-queue/Tools/Scripts/webkit-patch', '--status-host=queues.webkit.org', '--bot-id=gce-cq-04', 'land-attachment', '--force-clean', '--non-interactive', '--parent-command=commit-queue', 187045, '--port=chromium-xvfb']" exit_code: 2 cwd: /mnt/git/webkit-commit-queue

Last 500 characters of output:
commit-queue/Source/WebKit/chromium/third_party/v8-i18n --revision 164 --non-interactive --force --accept theirs-conflict --ignore-externals' in '/mnt/git/webkit-commit-queue/Source/WebKit/chromium'
54>At revision 164.

________ running '/usr/bin/python tools/clang/scripts/update.py --mac-only' in '/mnt/git/webkit-commit-queue/Source/WebKit/chromium'

________ running '/usr/bin/python gyp_webkit' in '/mnt/git/webkit-commit-queue/Source/WebKit/chromium'
Updating webkit projects from gyp files...

Full output: http://queues.webkit.org/results/16435214

[Vivek Galatage]

Created attachment 187129 [details]
Patch

[WebKit Review Bot]

Comment on attachment 187129 [details]
Patch

Clearing flags on attachment: 187129

Committed r142161: <http://trac.webkit.org/changeset/142161>

[WebKit Review Bot]

All reviewed patches have been landed.  Closing bug.