150826 2015-11-02 17:07:25 -0800 Web Inspector: Timeline Records Unexpected FunctionCall inside of FunctionCall 2026-01-12 09:01:52 -0800 1 1 1 Unclassified WebKit Web Inspector WebKit Nightly Build All All NEW InRadar P2 Normal --- 1 joepeck webkit-unassigned graouts inspector-bugzilla-changes webkit-bug-importer oldest_to_newest 1138773 0 joepeck 2015-11-02 17:07:25 -0800 * 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 }, }], }], }], } ... 1138774 1 webkit-bug-importer 2015-11-02 17:07:58 -0800 <rdar://problem/23366530> 1138778 2 joepeck 2015-11-02 17:14:37 -0800 * 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. 1217020 3 bburg 2016-08-03 11:12:09 -0700 Joe, is this bug invalid now that we have sampling profiler? 1218553 4 joepeck 2016-08-08 12:41:04 -0700 (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.