NEW 150826
Web Inspector: Timeline Records Unexpected FunctionCall inside of FunctionCall 
https://bugs.webkit.org/show_bug.cgi?id=150826
Summary Web Inspector: Timeline Records Unexpected FunctionCall inside of FunctionCall
Joseph Pecoraro
Reported 2015-11-02 17:07:25 PST
* SUMMARY Timeline Records Unexpected FunctionCall inside of FunctionCall. * TEST <body> <script> var observer = new MutationObserver(function alpha() { setTimeout(function beta() { console.log("whoa"); }, 10); }); observer.observe(document.body, {attributes: true, childList: true, characterData: true}); document.write("<b>Test</b>"); </script> * STEPS TO REPRODUCE 1. Inspect test page 2. Show Timeline 3. Reload (needs at least one timestamp...) 4. Start recording timeline 5. Reload 6. Stop recording timeline => warning in console about missing FunctionCall inside of FunctionCall * NOTES The eventRecorded stacking looks like: - RenderingFrame - TimerFire - FunctionCall (with Profile) - FunctionCall (no Profile) - TimerInstall I do find it interesting that the Profile for the Function Call has 2 root node ("alpha" and "beta"). Given this issue, I have a feeling that this is a backend issue generating records nested incorrectly. * PROTOCOL "method": "Timeline.eventRecorded", "params": { "record": { "startTime": 0.010606311028823256, "data": {}, "type": "RenderingFrame", "children": [{ "startTime": 0.02177164499880746, "endTime": 0.02231149101862684, "type": "TimerFire" "children": [{ "startTime": 0.021776599052827805, "endTime": 0.02230980701278895, "type": "FunctionCall" "data": { "scriptName": "file:///Users/pecoraro/Desktop/function-call.html", "scriptLine": 5, "profile": { "rootNodes": [{ "id": 8129808, "callInfo": { "callCount": 1, "startTime": 0.02185550204012543, "endTime": 0.02203003002796322, "totalTime": 0.00017452798783779144 }, "functionName": "beta", ... }, { "id": 4486534, "callInfo": { "callCount": 1, "startTime": 0.0220418720273301, "endTime": 0.022289311047643423, "totalTime": 0.00024743902031332254 }, "functionName": "alpha", ... }] } }, "children": [{ "startTime": 0.022038987022824585, "endTime": 0.02229272504337132, "type": "FunctionCall" "frameId": "0.1", "data": { "scriptName": "file:///Users/pecoraro/Desktop/function-call.html", "scriptLine": 3 }, "children": [{ "startTime": 0.022177679056767374, "frameId": "0.1", "type": "TimerInstall" "stackTrace": [{ "functionName": "setTimeout", "url": "[native code]", "lineNumber": 0, "columnNumber": 0 }, { "functionName": "alpha", "url": "file:///Users/pecoraro/Desktop/function-call.html", "lineNumber": 5, "columnNumber": 15 }], "data": { "timerId": 2, "timeout": 10, "singleShot": true }, }], }], }], } ...
Attachments
Add attachment proposed patch, testcase, etc.
Radar WebKit Bug Importer
Comment 1 2015-11-02 17:07:58 PST
<rdar://problem/23366530>
Joseph Pecoraro
Comment 2 2015-11-02 17:14:37 PST
* SIMPLER TEST (Just Reload) <body> <script> var observer = new MutationObserver(function alpha() { setTimeout(function beta() { console.log("whoa"); }, 1000); }); observer.observe(document.body, {attributes: true, childList: true, characterData: true}); document.write("<b>Test</b>"); </script> I'm still not really sure what is going on.
Blaze Burg
Comment 3 2016-08-03 11:12:09 PDT
Joe, is this bug invalid now that we have sampling profiler?
Joseph Pecoraro
Comment 4 2016-08-08 12:41:04 PDT
(In reply to comment #3) > Joe, is this bug invalid now that we have sampling profiler? The assertion can still happen. When viewing profile data it is not a problem. It might be possible for this to affect correlation of ScriptProfiler Event's and Timeline Event's.
Note You need to log in before you can comment on or make changes to this bug.