Closed
Bug 976562
Opened 10 years ago
Closed 10 years ago
FireFox JavaScript goes parallel
Categories
(Core :: JavaScript Engine, defect)
Tracking
()
RESOLVED
DUPLICATE
of bug 697151
People
(Reporter: Jan_Dockx, Unassigned)
Details
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_1) AppleWebKit/537.73.11 (KHTML, like Gecko) Version/7.0.1 Safari/537.73.11
Steps to reproduce:
FireFox 27.0.1 on Mac OS X 10.9.1
Issue first reported on earlier version of FF on Windows 7.
We have positive evidence that, in a complex case, the JavaScript engine stop execution of a function in the middle of the function's body, does other things, and later returns to the rest of the function. This should not be possible in JavaScript, which should be single-threaded (baring yield or WebWorkers, which are not used).
Sadly, I cannot reproduce the issue in a simple example. I tried with jsfiddle.
We understand that it is impossible to resolve the issue without a reproducible example, but I think it is important to note my story. Maybe some later report can trigger an insight together with this report.
The application is created with dojo 1.9.2 etc.
In this application, a number of remote AJAX calls are launched. When each of these calls resolves, the data is put in model objects, that fire callbacks telling listeners that they have changed. Some of these callbacks result ultimately in the calling of the following function:
var FF_HACK_COUNTER = 0;
_renderHazardOrPrevention: function(pddSentencesPropertyName, node) {
var callCounter = ++FF_HACK_COUNTER;
console.log("---");
console.log("CALL: " + callCounter + " / " + FF_HACK_COUNTER);
var self = this;
var pdd = self.get("target");
if (!pdd) {
domConstruct.empty(node);
domConstruct.create("li", {innerHTML: "?Sentences?"}, node);
return;
}
var sentences = pdd.get(pddSentencesPropertyName).sort(js.sortComparable);
if (sentences.length <= 0) {
domConstruct.empty(node);
domConstruct.create("li", {innerHTML: self._noEntry()}, node);
return;
}
console.log("BEFORE RENDER: " + callCounter + " / " + FF_HACK_COUNTER);
var lang = self.get("lang");
if (callCounter === FF_HACK_COUNTER) {
console.log("RENDER START: " + callCounter + " / " + FF_HACK_COUNTER);
domConstruct.empty(node);
sentences.forEach(function(sentence) {
var li = domConstruct.create("li", {className: "sentence"}, node);
domConstruct.create("span", {className: "label", innerHTML: sentence ? sentence.getCodeRepresentation(lang) : "?"}, li);
domConstruct.create("span", {className: "entry", innerHTML: sentence ? sentence.getLabel(lang) : "?"}, li);
});
console.log("RENDER END: " + callCounter + " / " + FF_HACK_COUNTER);
}
else {
console.log("SKIP: " + callCounter + " / " + FF_HACK_COUNTER);
}
}
This function is used to manipulate the contents of 2 distinct ul-elements on change of the model objects. The code presented above is already doctored to try to minimize the effect we see with FireFox.
`FF_HACK_COUNTER` is initially 0. On each call of the function, we `++` this counter, and copy its value in a function scope variable `callCounter`. This variable is not assigned to after this, so it remains the same until the end of the function call. There is no other assignment to `FF_HACK_COUNTER` either, so, during the execution of this function body, these 2 variabels should be equal.
The function starts out by writing the `callCounter` and `FF_HACK_COUNTER` to the console. We do this repeatedly to demonstrate what happens, and will call this "log" in the text below.
Next, we gather some data, and, depending on the state of the data, we render differently. Each time, we empty the ul-node, and then add one or more li-elements to the ul-node.
The effect we see is clear with the third case. If we are passed the 2 other cases, we log. Next, we test whether `callCounter === FF_HACK_COUNTER`.
THIS SHOULD ALWAYS BE TRUE. IT ISN'T.
If the test succeeds, we proceed with the third rendering, wheren we log again, clear the ul-node, add li-elements, and log again. If the test fails, we log ("SKIP").
The only logging we should see is:
"---"
"CALL: n / n"
for the first to render cases, and
"---"
"CALL: n / n"
"BEFORE RENDER: n / n"
"RENDER START: n / n"
"RENDER END: n / n"
in that exact order.
Actual results:
Below however is the log of a session that is typical.
A screencast of this run is available at http://youtu.be/TCOH0z_uz4M.
This concerns the 2 ul-elements under the titles "Risicozinnen" and "Veiligheidszinnen".
14:52:57.727 "14:52:57,727 INFO - pictoperfect-config/serverBaseUrl - server base url defined: https://www.pictoperfect.com/dev/server/app/ (dev)" log4javascript_uncompressed.js:1926
14:53:05.130 "DEPRECATED: dojox/mobile/sniff Use dojo/sniff instead -- will be removed in version: 2.0" kernel.js:203
14:53:05.140 "EXPERIMENTAL: dojox.mvc -- APIs subject to change without notice." kernel.js:227
14:53:05.149 "EXPERIMENTAL: dojox.widget.Standby -- APIs subject to change without notice." kernel.js:227
14:53:05.980 "EXPERIMENTAL: dojox.fx.flip -- APIs subject to change without notice." kernel.js:227
14:53:06.584 "---" Section_02.js:137
14:53:06.584 "CALL: 1 / 1" Section_02.js:138
14:53:06.585 "---" Section_02.js:137
14:53:06.585 "CALL: 2 / 2" Section_02.js:138
14:53:14.416 "---" Section_02.js:137
14:53:14.416 "CALL: 3 / 3" Section_02.js:138
14:53:14.420 "BEFORE RENDER: 3 / 3" Section_02.js:152
14:53:14.420 "RENDER START: 3 / 3" Section_02.js:155
14:53:14.422 "RENDER END: 3 / 3" Section_02.js:162
14:53:14.422 "---" Section_02.js:137
14:53:14.422 "CALL: 4 / 4" Section_02.js:138
14:53:14.424 "BEFORE RENDER: 4 / 4" Section_02.js:152
14:53:14.424 "RENDER START: 4 / 4" Section_02.js:155
14:53:14.425 "RENDER END: 4 / 4" Section_02.js:162
14:53:14.464 "---" Section_02.js:137
14:53:14.464 "CALL: 5 / 5" Section_02.js:138
14:53:14.468 "BEFORE RENDER: 5 / 5" Section_02.js:152
14:53:14.468 "RENDER START: 5 / 5" Section_02.js:155
14:53:14.470 "RENDER END: 5 / 5" Section_02.js:162
14:53:14.479 "---" Section_02.js:137
14:53:14.479 "CALL: 6 / 6" Section_02.js:138
14:53:14.482 "BEFORE RENDER: 6 / 6" Section_02.js:152
14:53:14.482 "RENDER START: 6 / 6" Section_02.js:155
14:53:14.484 "RENDER END: 6 / 6" Section_02.js:162
14:53:18.101 "---" Section_02.js:137
14:53:18.101 "CALL: 7 / 7" Section_02.js:138
14:53:18.104 "BEFORE RENDER: 7 / 7" Section_02.js:152
14:53:18.104 "RENDER START: 7 / 7" Section_02.js:155
14:53:18.106 "RENDER END: 7 / 7" Section_02.js:162
14:53:18.302 "---" Section_02.js:137
14:53:18.303 "CALL: 8 / 8" Section_02.js:138
14:53:18.306 "BEFORE RENDER: 8 / 8" Section_02.js:152
14:53:18.307 "RENDER START: 8 / 8" Section_02.js:155
14:53:18.309 "RENDER END: 8 / 8" Section_02.js:162
14:53:18.442 "---" Section_02.js:137
14:53:18.442 "CALL: 9 / 9" Section_02.js:138
14:53:18.445 "BEFORE RENDER: 9 / 9" Section_02.js:152
14:53:18.445 "RENDER START: 9 / 9" Section_02.js:155
14:53:18.587 "---" Section_02.js:137
14:53:18.587 "CALL: 10 / 10" Section_02.js:138
14:53:18.590 "BEFORE RENDER: 10 / 10" Section_02.js:152
14:53:18.591 "RENDER START: 10 / 10" Section_02.js:155
14:53:18.664 "---" Section_02.js:137
14:53:18.664 "CALL: 11 / 11" Section_02.js:138
14:53:18.670 "BEFORE RENDER: 11 / 11" Section_02.js:152
14:53:18.670 "RENDER START: 11 / 11" Section_02.js:155
14:53:18.744 "---" Section_02.js:137
14:53:18.744 "CALL: 12 / 12" Section_02.js:138
14:53:18.853 "---" Section_02.js:137
14:53:18.853 "CALL: 13 / 13" Section_02.js:138
14:53:18.991 "---" Section_02.js:137
14:53:18.991 "CALL: 14 / 14" Section_02.js:138
14:53:19.088 "---" Section_02.js:137
14:53:19.088 "CALL: 15 / 15" Section_02.js:138
14:53:19.227 "---" Section_02.js:137
14:53:19.227 "CALL: 16 / 16" Section_02.js:138
14:53:19.315 "---" Section_02.js:137
14:53:19.315 "CALL: 17 / 17" Section_02.js:138
14:53:19.638 "BEFORE RENDER: 17 / 17" Section_02.js:152
14:53:19.638 "RENDER START: 17 / 17" Section_02.js:155
14:53:19.642 "RENDER END: 17 / 17" Section_02.js:162
14:53:19.710 "---" Section_02.js:137
14:53:19.710 "CALL: 18 / 18" Section_02.js:138
14:53:19.712 "BEFORE RENDER: 18 / 18" Section_02.js:152
14:53:19.712 "RENDER START: 18 / 18" Section_02.js:155
14:53:19.714 "RENDER END: 18 / 18" Section_02.js:162
14:53:19.750 "---" Section_02.js:137
14:53:19.750 "CALL: 19 / 19" Section_02.js:138
14:53:19.752 "BEFORE RENDER: 19 / 19" Section_02.js:152
14:53:19.752 "RENDER START: 19 / 19" Section_02.js:155
14:53:19.753 "RENDER END: 19 / 19" Section_02.js:162
14:53:19.784 "---" Section_02.js:137
14:53:19.784 "CALL: 20 / 20" Section_02.js:138
14:53:19.786 "BEFORE RENDER: 20 / 20" Section_02.js:152
14:53:19.786 "RENDER START: 20 / 20" Section_02.js:155
14:53:19.787 "RENDER END: 20 / 20" Section_02.js:162
14:53:19.812 "---" Section_02.js:137
14:53:19.812 "CALL: 21 / 21" Section_02.js:138
14:53:19.814 "BEFORE RENDER: 21 / 21" Section_02.js:152
14:53:19.814 "RENDER START: 21 / 21" Section_02.js:155
14:53:19.815 "RENDER END: 21 / 21" Section_02.js:162
14:53:19.844 "---" Section_02.js:137
14:53:19.844 "CALL: 22 / 22" Section_02.js:138
14:53:19.846 "BEFORE RENDER: 22 / 22" Section_02.js:152
14:53:19.846 "RENDER START: 22 / 22" Section_02.js:155
14:53:19.847 "RENDER END: 22 / 22" Section_02.js:162
14:53:19.881 "---" Section_02.js:137
14:53:19.881 "CALL: 23 / 23" Section_02.js:138
14:53:19.883 "BEFORE RENDER: 23 / 23" Section_02.js:152
14:53:19.884 "RENDER START: 23 / 23" Section_02.js:155
14:53:19.967 "---" Section_02.js:137
14:53:19.968 "CALL: 24 / 24" Section_02.js:138
14:53:19.973 "BEFORE RENDER: 24 / 24" Section_02.js:152
14:53:19.973 "RENDER START: 24 / 24" Section_02.js:155
14:53:19.976 "RENDER END: 24 / 24" Section_02.js:162
14:53:20.314 "---" Section_02.js:137
14:53:20.314 "CALL: 25 / 25" Section_02.js:138
14:53:20.323 "BEFORE RENDER: 25 / 25" Section_02.js:152
14:53:20.323 "RENDER START: 25 / 25" Section_02.js:155
14:53:20.327 "RENDER END: 25 / 25" Section_02.js:162
14:53:20.452 "---" Section_02.js:137
14:53:20.452 "CALL: 26 / 26" Section_02.js:138
14:53:20.457 "BEFORE RENDER: 26 / 26" Section_02.js:152
14:53:20.458 "RENDER START: 26 / 26" Section_02.js:155
14:53:20.460 "RENDER END: 26 / 26" Section_02.js:162
14:53:20.500 "---" Section_02.js:137
14:53:20.500 "CALL: 27 / 27" Section_02.js:138
14:53:20.692 "---" Section_02.js:137
14:53:20.693 "CALL: 28 / 28" Section_02.js:138
14:53:20.703 "BEFORE RENDER: 28 / 28" Section_02.js:152
14:53:20.703 "RENDER START: 28 / 28" Section_02.js:155
14:53:20.708 "RENDER END: 28 / 28" Section_02.js:162
14:53:21.409 "BEFORE RENDER: 27 / 28" Section_02.js:152
14:53:21.410 "SKIP: 27 / 28" Section_02.js:165
14:53:22.024 "RENDER END: 23 / 28" Section_02.js:162
14:53:22.059 "---" Section_02.js:137
14:53:22.059 "CALL: 29 / 29" Section_02.js:138
14:53:22.061 "BEFORE RENDER: 29 / 29" Section_02.js:152
14:53:22.062 "RENDER START: 29 / 29" Section_02.js:155
14:53:22.063 "RENDER END: 29 / 29" Section_02.js:162
14:53:22.086 "---" Section_02.js:137
14:53:22.086 "CALL: 30 / 30" Section_02.js:138
14:53:22.088 "BEFORE RENDER: 30 / 30" Section_02.js:152
14:53:22.089 "RENDER START: 30 / 30" Section_02.js:155
14:53:22.091 "RENDER END: 30 / 30" Section_02.js:162
14:53:22.117 "---" Section_02.js:137
14:53:22.118 "CALL: 31 / 31" Section_02.js:138
14:53:22.121 "BEFORE RENDER: 31 / 31" Section_02.js:152
14:53:22.121 "RENDER START: 31 / 31" Section_02.js:155
14:53:22.123 "RENDER END: 31 / 31" Section_02.js:162
14:53:22.160 "---" Section_02.js:137
14:53:22.160 "CALL: 32 / 32" Section_02.js:138
14:53:22.163 "BEFORE RENDER: 32 / 32" Section_02.js:152
14:53:22.163 "RENDER START: 32 / 32" Section_02.js:155
14:53:22.165 "RENDER END: 32 / 32" Section_02.js:162
14:53:22.295 "BEFORE RENDER: 16 / 32" Section_02.js:152
14:53:22.296 "SKIP: 16 / 32" Section_02.js:165
14:53:22.403 "BEFORE RENDER: 15 / 32" Section_02.js:152
14:53:22.403 "SKIP: 15 / 32" Section_02.js:165
14:53:22.497 "BEFORE RENDER: 14 / 32" Section_02.js:152
14:53:22.497 "SKIP: 14 / 32" Section_02.js:165
14:53:22.607 "BEFORE RENDER: 13 / 32" Section_02.js:152
14:53:22.607 "SKIP: 13 / 32" Section_02.js:165
14:53:22.718 "BEFORE RENDER: 12 / 32" Section_02.js:152
14:53:22.718 "SKIP: 12 / 32" Section_02.js:165
14:53:22.813 "RENDER END: 11 / 32" Section_02.js:162
14:53:22.920 "RENDER END: 10 / 32" Section_02.js:162
14:53:23.009 "RENDER END: 9 / 32" Section_02.js:162
As you can see, there are 2 (1-2) calls that fall into one of the first render cases.
Then, all proceeds as expected: (3-8).
Then, however, things get strange:
We see the logging for the 9th call start out, and proceed until RENDER START, but not until RENDER END.
The same happens on the 10th and 11th call.
The 12th-16h call until proceed until "CALL". None of them are "render case 1 or 2", as we shall see.
17-22 then goes as expected. 23 has a problem, 24-26 are ok, 27 is strange, 28 is ok.
The truly weird part comes now. After 28, we see and SKIP for 27, the END of 23.
29-32 is normal.
And finally we see SKIP for 16-12, and END for 11-9.
The actual numbers differ by run. What is constant is the winding down of "interrupted" executions in reverse order at the end.
We are sure from a large number of experiments that we see the execution of the function "yield" "near the end" of the function when there are "many" calls in quick succession. When we go through the code with the debugger, nothing happens out of the ordinary. There is no async code in the execution of the function body whatsoever, or at least, there shouldn't be.
Sadly, since JavaScript is, in principle, single-threaded, we cannot now for sure when the yield occurs, and there is no sure synchronization method we can use to work around this. As you can see, the if-test works to not destroy rendering with late executions, but the run presented also shows that this is no guarantee (9-11 yield inside the if branch).
We have tried many different "code reorganizations" to find out where the problem is located, and if we could work around it. We thought once it was in the forEach, but it isn't (we get the same behavior with a for loop). We thought once it was in the sort, but it isn't (we get the same behavior without it).
Expected results:
We understand that this is difficult to believe without proof. We didn't believe it at first either. We spent several hours trying to reproduce the effect in jsfiddle without success, and cannot submit the entire code base of this product, since the app is not public.
We though it important enough however to make a note here, for future reference.
|
||
Comment 1•10 years ago
|
||
Thank you for the report. Things start to go wrong when the counter reaches 9, right? It's possible that's when we reach our threshold for baseline JIT compilation. Would you mind trying the following to disable the JIT compilers: (1) Go to about:config in the address bar (2) Accept the warning (3) In the search box, type javascript.options.baselinejit.content (4) You should get one match, double click on it to toggle its value to "false" (5) Restart the browser. Can you still reproduce this with the pref disabled?
Thanks for taking this serious, Jan. 1) I can't guarantee that the function always yields at or after the 9th call. In any case, that was not behaviour that "jumped out" in the hours I've been wrokking this. 2) Did as you asked. No go. This is now slower, and I had to up some timeouts. But the "yield" behaviour is still there. The output of this run is below. Now the first call that goes haywire is 15. It seems that only 15 - 21 is out of whack. But what is peculiar is that now the yielding is in all those cases more early in the function body. That's a first. Until now, the yielding always happened late in the function. 18:30:32.559 "18:30:32,559 INFO - pictoperfect-config/serverBaseUrl - server base url defined: https://www.pictoperfect.com/dev/server/app/ (dev)" log4javascript_uncompressed.js:1926 18:30:41.694 "DEPRECATED: dojox/mobile/sniff Use dojo/sniff instead -- will be removed in version: 2.0" kernel.js:203 18:30:41.702 "EXPERIMENTAL: dojox.mvc -- APIs subject to change without notice." kernel.js:227 18:30:41.707 "EXPERIMENTAL: dojox.widget.Standby -- APIs subject to change without notice." kernel.js:227 18:30:42.642 "EXPERIMENTAL: dojox.fx.flip -- APIs subject to change without notice." kernel.js:227 18:30:43.006 "CALL: 1 / 1" Section_02.js:159 18:30:43.006 "CALL: 2 / 2" Section_02.js:159 18:30:57.125 "CALL: 3 / 3" Section_02.js:159 18:30:57.147 "BEFORE RENDER: 3 / 3" Section_02.js:173 18:30:57.147 "RENDER START: 3 / 3" Section_02.js:176 18:30:57.148 "RENDER END: 3 / 3" Section_02.js:187 18:30:57.148 "CALL: 4 / 4" Section_02.js:159 18:30:57.159 "BEFORE RENDER: 4 / 4" Section_02.js:173 18:30:57.159 "RENDER START: 4 / 4" Section_02.js:176 18:30:57.160 "RENDER END: 4 / 4" Section_02.js:187 18:30:57.325 "CALL: 5 / 5" Section_02.js:159 18:30:57.347 "BEFORE RENDER: 5 / 5" Section_02.js:173 18:30:57.347 "RENDER START: 5 / 5" Section_02.js:176 18:30:57.348 "RENDER END: 5 / 5" Section_02.js:187 18:30:57.373 "CALL: 6 / 6" Section_02.js:159 18:30:57.384 "BEFORE RENDER: 6 / 6" Section_02.js:173 18:30:57.384 "RENDER START: 6 / 6" Section_02.js:176 18:30:57.385 "RENDER END: 6 / 6" Section_02.js:187 18:31:07.983 "CALL: 7 / 7" Section_02.js:159 18:31:08.005 "BEFORE RENDER: 7 / 7" Section_02.js:173 18:31:08.005 "RENDER START: 7 / 7" Section_02.js:176 18:31:08.006 "RENDER END: 7 / 7" Section_02.js:187 18:31:08.849 "CALL: 8 / 8" Section_02.js:159 18:31:08.870 "BEFORE RENDER: 8 / 8" Section_02.js:173 18:31:08.870 "RENDER START: 8 / 8" Section_02.js:176 18:31:08.871 "RENDER END: 8 / 8" Section_02.js:187 18:31:09.761 "CALL: 9 / 9" Section_02.js:159 18:31:09.788 "BEFORE RENDER: 9 / 9" Section_02.js:173 18:31:09.789 "RENDER START: 9 / 9" Section_02.js:176 18:31:09.790 "RENDER END: 9 / 9" Section_02.js:187 18:31:10.632 "CALL: 10 / 10" Section_02.js:159 18:31:10.653 "BEFORE RENDER: 10 / 10" Section_02.js:173 18:31:10.653 "RENDER START: 10 / 10" Section_02.js:176 18:31:10.654 "RENDER END: 10 / 10" Section_02.js:187 18:31:11.118 "CALL: 11 / 11" Section_02.js:159 18:31:11.140 "BEFORE RENDER: 11 / 11" Section_02.js:173 18:31:11.140 "RENDER START: 11 / 11" Section_02.js:176 18:31:11.141 "RENDER END: 11 / 11" Section_02.js:187 18:31:11.689 "CALL: 12 / 12" Section_02.js:159 18:31:11.711 "BEFORE RENDER: 12 / 12" Section_02.js:173 18:31:11.711 "RENDER START: 12 / 12" Section_02.js:176 18:31:11.712 "RENDER END: 12 / 12" Section_02.js:187 18:31:12.220 "CALL: 13 / 13" Section_02.js:159 18:31:12.241 "BEFORE RENDER: 13 / 13" Section_02.js:173 18:31:12.242 "RENDER START: 13 / 13" Section_02.js:176 18:31:12.243 "RENDER END: 13 / 13" Section_02.js:187 18:31:12.719 "CALL: 14 / 14" Section_02.js:159 18:31:12.741 "BEFORE RENDER: 14 / 14" Section_02.js:173 18:31:12.741 "RENDER START: 14 / 14" Section_02.js:176 18:31:12.742 "RENDER END: 14 / 14" Section_02.js:187 18:31:13.221 "CALL: 15 / 15" Section_02.js:159 18:31:13.243 "BEFORE RENDER: 15 / 15" Section_02.js:173 18:31:13.243 "RENDER START: 15 / 15" Section_02.js:176 18:31:13.551 "CALL: 16 / 16" Section_02.js:159 18:31:13.875 "CALL: 17 / 17" Section_02.js:159 18:31:14.198 "CALL: 18 / 18" Section_02.js:159 18:31:14.525 "CALL: 19 / 19" Section_02.js:159 18:31:14.850 "CALL: 20 / 20" Section_02.js:159 18:31:15.466 "CALL: 21 / 21" Section_02.js:159 18:31:15.711 "BEFORE RENDER: 21 / 21" Section_02.js:173 18:31:15.711 "RENDER START: 21 / 21" Section_02.js:176 18:31:15.713 "RENDER END: 21 / 21" Section_02.js:187 18:31:16.334 "CALL: 22 / 22" Section_02.js:159 18:31:16.344 "BEFORE RENDER: 22 / 22" Section_02.js:173 18:31:16.345 "RENDER START: 22 / 22" Section_02.js:176 18:31:16.345 "RENDER END: 22 / 22" Section_02.js:187 18:31:16.449 "CALL: 23 / 23" Section_02.js:159 18:31:16.460 "BEFORE RENDER: 23 / 23" Section_02.js:173 18:31:16.460 "RENDER START: 23 / 23" Section_02.js:176 18:31:16.460 "RENDER END: 23 / 23" Section_02.js:187 18:31:16.563 "CALL: 24 / 24" Section_02.js:159 18:31:16.574 "BEFORE RENDER: 24 / 24" Section_02.js:173 18:31:16.574 "RENDER START: 24 / 24" Section_02.js:176 18:31:16.575 "RENDER END: 24 / 24" Section_02.js:187 18:31:16.677 "CALL: 25 / 25" Section_02.js:159 18:31:16.688 "BEFORE RENDER: 25 / 25" Section_02.js:173 18:31:16.688 "RENDER START: 25 / 25" Section_02.js:176 18:31:16.688 "RENDER END: 25 / 25" Section_02.js:187 18:31:16.791 "CALL: 26 / 26" Section_02.js:159 18:31:16.801 "BEFORE RENDER: 26 / 26" Section_02.js:173 18:31:16.802 "RENDER START: 26 / 26" Section_02.js:176 18:31:16.802 "RENDER END: 26 / 26" Section_02.js:187 18:31:16.905 "CALL: 27 / 27" Section_02.js:159 18:31:16.916 "BEFORE RENDER: 27 / 27" Section_02.js:173 18:31:16.916 "RENDER START: 27 / 27" Section_02.js:176 18:31:16.916 "RENDER END: 27 / 27" Section_02.js:187 18:31:17.021 "CALL: 28 / 28" Section_02.js:159 18:31:17.032 "BEFORE RENDER: 28 / 28" Section_02.js:173 18:31:17.032 "RENDER START: 28 / 28" Section_02.js:176 18:31:17.193 "RENDER END: 28 / 28" Section_02.js:187 18:31:17.298 "CALL: 29 / 29" Section_02.js:159 18:31:17.309 "BEFORE RENDER: 29 / 29" Section_02.js:173 18:31:17.309 "RENDER START: 29 / 29" Section_02.js:176 18:31:17.310 "RENDER END: 29 / 29" Section_02.js:187 18:31:17.414 "CALL: 30 / 30" Section_02.js:159 18:31:17.425 "BEFORE RENDER: 30 / 30" Section_02.js:173 18:31:17.425 "RENDER START: 30 / 30" Section_02.js:176 18:31:17.427 "RENDER END: 30 / 30" Section_02.js:187 18:31:17.532 "CALL: 31 / 31" Section_02.js:159 18:31:17.544 "BEFORE RENDER: 31 / 31" Section_02.js:173 18:31:17.544 "RENDER START: 31 / 31" Section_02.js:176 18:31:17.545 "RENDER END: 31 / 31" Section_02.js:187 18:31:17.650 "CALL: 32 / 32" Section_02.js:159 18:31:17.663 "BEFORE RENDER: 32 / 32" Section_02.js:173 18:31:17.663 "RENDER START: 32 / 32" Section_02.js:176 18:31:17.665 "RENDER END: 32 / 32" Section_02.js:187 18:31:17.803 "BEFORE RENDER: 20 / 32" Section_02.js:173 18:31:17.803 "OUT OF ORDER - SKIPPED: 20 / 32" Section_02.js:191 18:31:18.361 "BEFORE RENDER: 19 / 32" Section_02.js:173 18:31:18.361 "OUT OF ORDER - SKIPPED: 19 / 32" Section_02.js:191 18:31:18.916 "BEFORE RENDER: 18 / 32" Section_02.js:173 18:31:18.916 "OUT OF ORDER - SKIPPED: 18 / 32" Section_02.js:191 18:31:19.468 "BEFORE RENDER: 17 / 32" Section_02.js:173 18:31:19.468 "OUT OF ORDER - SKIPPED: 17 / 32" Section_02.js:191 18:31:20.024 "BEFORE RENDER: 16 / 32" Section_02.js:173 18:31:20.024 "OUT OF ORDER - SKIPPED: 16 / 32" Section_02.js:191 18:31:20.580 "RENDER END: 15 / 32" Section_02.js:187
What I forgot to mentioned in the first report, and what might be important too: While working this code, we got at some point (I have it tagged in our svn) code where at the end of the function we call `alert`. Now, `alert` is supposed to be modal and blocking, right? Well, what we got was 5 or 6 alert-dialogs STACKED ON TOP OF EACH OTHER. That was when we decided this definitely could not be us doing weird things.
|
|
||
Comment 4•10 years ago
|
||
OK, thanks for testing that. (In reply to Jan Dockx from comment #2) > But what is peculiar is that now the yielding is in > all those cases more early in the function body. That's a first. Until now, > the yielding always happened late in the function. It could be timing-related; code runs slower in the interpreter than in the JITs. bz, any thoughts?
Flags: needinfo?(bzbarsky)
I reverted to our svn tag that has the demonstration with the alerts. The screencast is at http://youtu.be/J8980Cn2XaU. What you see here is slightly different code. This was at a moment that we were trying to understand what was going on. If you watch the screen cast, you see an alert appear showing 2 numbers, and quickly after that, those numbers change. This is weird for an alert, and we found out that what actually happens is that SEVERAL ALERTS ARE STACKED, which should be impossible. As you can see, at the end, we unwind the stack by clicking the button. There is surely a timing aspect and race condition here, because we do not get the exact same behavior every time we run it. It depends certainly on the speed of the internet, i.e., the speed with which the server data comes in. In this screencast, we only see 3 alerts stacked, but we often got 6 or 7 when we where playing with this code. The code for this run: define(["dojo/_base/declare", "../_ContainsMixin", "dojo/text!./section_02.html", "ppwcode-util-oddsAndEnds/bindingChains", "dojo/dom-construct", "ppwcode-util-oddsAndEnds/js", "./createLoadingNode", "pictoperfect-viewmodel/productDocuments/Standard", "module", "dojo/i18n!./nls/labels", "ppwcode-util-oddsAndEnds/ui/MultiLangLabel", "../symbol/SymbolList", "ppwcode-util-oddsAndEnds/ui/Optional", "ppwcode-util-oddsAndEnds/ui/MultiLangFormatOutput"], function(declare, _ContainsMixin, template, bindingChains, domConstruct, js, createLoadingNode, Standard, module) { var Section2 = declare([_ContainsMixin], { // ... _renderHazardOrPrevention: function(pddSentencesPropertyName, node) { function stopLoading() { domConstruct.empty(node); if (node.done) { // we were loading node.done(); } } var callCounter; function xxxReport(message) { reportCounter++; console.log("call " + callCounter + " - report " + reportCounter + " - " + pddSentencesPropertyName + ": " + message); } callCounterMaster++; callCounter = callCounterMaster; xxxReport("START"); var self = this; var pdd = self.get("target"); if (!pdd) { xxxReport("no pdd"); stopLoading(); domConstruct.create("li", {innerHTML: "?Sentences?"}, node); xxxReport("DONE no pdd"); return; } xxxReport("pdd ok"); var sentences = pdd.get(pddSentencesPropertyName); if (allS.indexOf(sentences) >= 0) { xxxReport("REUSE OF SENTENCES"); } else { xxxReport(" sentences are fresh"); allS.push(sentences); } if (sentences.length <= 0) { xxxReport("zero sentences"); stopLoading(); domConstruct.create("li", {innerHTML: self._noEntry()}, node); xxxReport("DONE zero sentences"); return; } xxxReport("sentences > 0"); var missingCount = sentences.filter(function(sentence) {return !sentence;}).length; if (missingCount > 0) { xxxReport("missing sentences " + missingCount); if (!node.setAnnotation) { // we were not loading yet createLoadingNode(node, missingCount); // coercion to string } else { node.setAnnotation(missingCount); // coercion to string } xxxReport("DONE missing sentences " + missingCount); return; } xxxReport("no missing sentences"); alert(callCounter + " " + reportCounter); // stopLoading(); // var lang = self.get("lang"); //// alert(callCounter + " " + reportCounter); // sentences.sort(js.sortComparable); // domConstruct.create("li", {innerHTML: "THE SENTENCES"}, node); // sentences.forEach(function(sentence) { // THERE IS SOME SORT OF MUTEX HERE; A THREAD IS BUSY WITH node, AND WE YIELD // var li = domConstruct.create("li", {className: "sentence"}, node); // domConstruct.create("span", {className: "label", innerHTML: sentence ? sentence.getCodeRepresentation(lang) : "?"}, li); // domConstruct.create("span", {className: "entry", innerHTML: sentence ? sentence.getLabel(lang) : "?"}, li); // }); xxxReport("DONE no missing sentences"); } }); var reportCounter = 0; var callCounterMaster = 0; var allS = []; // ... return Section2; } ); Note the `alert` near the end, above the commented out block. The console output of this run: 19:14:12.497 "19:14:12,496 INFO - pictoperfect-config/serverBaseUrl - server base url defined: https://www.pictoperfect.com/dev/server/app/ (dev)" log4javascript_uncompressed.js:1926 19:14:17.803 "DEPRECATED: dojox/mobile/sniff Use dojo/sniff instead -- will be removed in version: 2.0" kernel.js:203 19:14:17.971 "EXPERIMENTAL: dojox.mvc -- APIs subject to change without notice." kernel.js:227 19:14:17.980 "EXPERIMENTAL: dojox.widget.Standby -- APIs subject to change without notice." kernel.js:227 19:14:18.516 "EXPERIMENTAL: dojox.fx.flip -- APIs subject to change without notice." kernel.js:227 19:14:19.058 "call 1 - report 1 - hazardSentences: START" Section_02.js:147 19:14:19.058 "call 1 - report 2 - hazardSentences: no pdd" Section_02.js:147 19:14:19.058 "call 1 - report 3 - hazardSentences: DONE no pdd" Section_02.js:147 19:14:19.059 "call 2 - report 4 - preventionSentences: START" Section_02.js:147 19:14:19.059 "call 2 - report 5 - preventionSentences: no pdd" Section_02.js:147 19:14:19.059 "call 2 - report 6 - preventionSentences: DONE no pdd" Section_02.js:147 19:14:25.677 "call 3 - report 7 - hazardSentences: START" Section_02.js:147 19:14:25.678 "call 3 - report 8 - hazardSentences: pdd ok" Section_02.js:147 19:14:25.680 "call 3 - report 9 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:25.680 "call 3 - report 10 - hazardSentences: sentences > 0" Section_02.js:147 19:14:25.680 "call 3 - report 11 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:25.687 "call 3 - report 12 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:25.687 "call 4 - report 13 - preventionSentences: START" Section_02.js:147 19:14:25.688 "call 4 - report 14 - preventionSentences: pdd ok" Section_02.js:147 19:14:25.691 "call 4 - report 15 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:25.691 "call 4 - report 16 - preventionSentences: sentences > 0" Section_02.js:147 19:14:25.691 "call 4 - report 17 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:25.692 "call 4 - report 18 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:25.726 "call 5 - report 19 - hazardSentences: START" Section_02.js:147 19:14:25.727 "call 5 - report 20 - hazardSentences: pdd ok" Section_02.js:147 19:14:25.730 "call 5 - report 21 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:25.730 "call 5 - report 22 - hazardSentences: sentences > 0" Section_02.js:147 19:14:25.730 "call 5 - report 23 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:25.730 "call 5 - report 24 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:25.735 "call 6 - report 25 - preventionSentences: START" Section_02.js:147 19:14:25.735 "call 6 - report 26 - preventionSentences: pdd ok" Section_02.js:147 19:14:25.736 "call 6 - report 27 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:25.736 "call 6 - report 28 - preventionSentences: sentences > 0" Section_02.js:147 19:14:25.736 "call 6 - report 29 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:25.737 "call 6 - report 30 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:29.055 "call 7 - report 31 - hazardSentences: START" Section_02.js:147 19:14:29.055 "call 7 - report 32 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.058 "call 7 - report 33 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.058 "call 7 - report 34 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.059 "call 7 - report 35 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:29.059 "call 7 - report 36 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:29.217 "call 8 - report 37 - hazardSentences: START" Section_02.js:147 19:14:29.217 "call 8 - report 38 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.220 "call 8 - report 39 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.221 "call 8 - report 40 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.221 "call 8 - report 41 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:29.221 "call 8 - report 42 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:29.395 "call 9 - report 43 - hazardSentences: START" Section_02.js:147 19:14:29.395 "call 9 - report 44 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.398 "call 9 - report 45 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.398 "call 9 - report 46 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.398 "call 9 - report 47 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:29.399 "call 9 - report 48 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:29.565 "call 10 - report 49 - hazardSentences: START" Section_02.js:147 19:14:29.565 "call 10 - report 50 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.569 "call 10 - report 51 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.570 "call 10 - report 52 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.570 "call 10 - report 53 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:29.570 "call 10 - report 54 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:29.720 "call 11 - report 55 - hazardSentences: START" Section_02.js:147 19:14:29.720 "call 11 - report 56 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.723 "call 11 - report 57 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.723 "call 11 - report 58 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.724 "call 11 - report 59 - hazardSentences: missing sentences 7" Section_02.js:147 19:14:29.724 "call 11 - report 60 - hazardSentences: DONE missing sentences 7" Section_02.js:147 19:14:29.850 "call 12 - report 61 - hazardSentences: START" Section_02.js:147 19:14:29.850 "call 12 - report 62 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.856 "call 12 - report 63 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.857 "call 12 - report 64 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.857 "call 12 - report 65 - hazardSentences: missing sentences 6" Section_02.js:147 19:14:29.857 "call 12 - report 66 - hazardSentences: DONE missing sentences 6" Section_02.js:147 19:14:29.961 "call 13 - report 67 - hazardSentences: START" Section_02.js:147 19:14:29.961 "call 13 - report 68 - hazardSentences: pdd ok" Section_02.js:147 19:14:29.964 "call 13 - report 69 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:29.964 "call 13 - report 70 - hazardSentences: sentences > 0" Section_02.js:147 19:14:29.964 "call 13 - report 71 - hazardSentences: missing sentences 5" Section_02.js:147 19:14:29.964 "call 13 - report 72 - hazardSentences: DONE missing sentences 5" Section_02.js:147 19:14:30.053 "call 14 - report 73 - hazardSentences: START" Section_02.js:147 19:14:30.054 "call 14 - report 74 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.060 "call 14 - report 75 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.060 "call 14 - report 76 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.060 "call 14 - report 77 - hazardSentences: missing sentences 4" Section_02.js:147 19:14:30.060 "call 14 - report 78 - hazardSentences: DONE missing sentences 4" Section_02.js:147 19:14:30.156 "call 15 - report 79 - hazardSentences: START" Section_02.js:147 19:14:30.156 "call 15 - report 80 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.161 "call 15 - report 81 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.162 "call 15 - report 82 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.162 "call 15 - report 83 - hazardSentences: missing sentences 3" Section_02.js:147 19:14:30.162 "call 15 - report 84 - hazardSentences: DONE missing sentences 3" Section_02.js:147 19:14:30.296 "call 16 - report 85 - hazardSentences: START" Section_02.js:147 19:14:30.296 "call 16 - report 86 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.300 "call 16 - report 87 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.300 "call 16 - report 88 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.300 "call 16 - report 89 - hazardSentences: missing sentences 2" Section_02.js:147 19:14:30.301 "call 16 - report 90 - hazardSentences: DONE missing sentences 2" Section_02.js:147 19:14:30.388 "call 17 - report 91 - hazardSentences: START" Section_02.js:147 19:14:30.389 "call 17 - report 92 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.392 "call 17 - report 93 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.392 "call 17 - report 94 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.392 "call 17 - report 95 - hazardSentences: missing sentences 1" Section_02.js:147 19:14:30.392 "call 17 - report 96 - hazardSentences: DONE missing sentences 1" Section_02.js:147 19:14:30.511 "call 18 - report 97 - hazardSentences: START" Section_02.js:147 19:14:30.511 "call 18 - report 98 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.514 "call 18 - report 99 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.515 "call 18 - report 100 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.515 "call 18 - report 101 - hazardSentences: missing sentences 1" Section_02.js:147 19:14:30.515 "call 18 - report 102 - hazardSentences: DONE missing sentences 1" Section_02.js:147 19:14:30.600 "call 19 - report 103 - hazardSentences: START" Section_02.js:147 19:14:30.600 "call 19 - report 104 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.605 "call 19 - report 105 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.605 "call 19 - report 106 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.605 "call 19 - report 107 - hazardSentences: missing sentences 1" Section_02.js:147 19:14:30.606 "call 19 - report 108 - hazardSentences: DONE missing sentences 1" Section_02.js:147 19:14:30.789 "call 20 - report 109 - hazardSentences: START" Section_02.js:147 19:14:30.789 "call 20 - report 110 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.793 "call 20 - report 111 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.793 "call 20 - report 112 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.793 "call 20 - report 113 - hazardSentences: missing sentences 1" Section_02.js:147 19:14:30.794 "call 20 - report 114 - hazardSentences: DONE missing sentences 1" Section_02.js:147 19:14:30.890 "call 21 - report 115 - hazardSentences: START" Section_02.js:147 19:14:30.891 "call 21 - report 116 - hazardSentences: pdd ok" Section_02.js:147 19:14:30.894 "call 21 - report 117 - hazardSentences: sentences are fresh" Section_02.js:147 19:14:30.894 "call 21 - report 118 - hazardSentences: sentences > 0" Section_02.js:147 19:14:30.894 "call 21 - report 119 - hazardSentences: no missing sentences" Section_02.js:147 19:14:31.098 "call 22 - report 120 - preventionSentences: START" Section_02.js:147 19:14:31.099 "call 22 - report 121 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.102 "call 22 - report 122 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.102 "call 22 - report 123 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.102 "call 22 - report 124 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:31.102 "call 22 - report 125 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:31.356 "call 23 - report 126 - preventionSentences: START" Section_02.js:147 19:14:31.357 "call 23 - report 127 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.360 "call 23 - report 128 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.360 "call 23 - report 129 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.360 "call 23 - report 130 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:31.361 "call 23 - report 131 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:31.386 "call 24 - report 132 - preventionSentences: START" Section_02.js:147 19:14:31.387 "call 24 - report 133 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.389 "call 24 - report 134 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.389 "call 24 - report 135 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.389 "call 24 - report 136 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:31.389 "call 24 - report 137 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:31.416 "call 25 - report 138 - preventionSentences: START" Section_02.js:147 19:14:31.417 "call 25 - report 139 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.420 "call 25 - report 140 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.420 "call 25 - report 141 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.420 "call 25 - report 142 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:31.420 "call 25 - report 143 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:31.458 "call 26 - report 144 - preventionSentences: START" Section_02.js:147 19:14:31.458 "call 26 - report 145 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.460 "call 26 - report 146 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.460 "call 26 - report 147 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.460 "call 26 - report 148 - preventionSentences: missing sentences 5" Section_02.js:147 19:14:31.460 "call 26 - report 149 - preventionSentences: DONE missing sentences 5" Section_02.js:147 19:14:31.484 "call 27 - report 150 - preventionSentences: START" Section_02.js:147 19:14:31.484 "call 27 - report 151 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.486 "call 27 - report 152 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.486 "call 27 - report 153 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.486 "call 27 - report 154 - preventionSentences: missing sentences 4" Section_02.js:147 19:14:31.486 "call 27 - report 155 - preventionSentences: DONE missing sentences 4" Section_02.js:147 19:14:31.698 "call 28 - report 156 - preventionSentences: START" Section_02.js:147 19:14:31.698 "call 28 - report 157 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.700 "call 28 - report 158 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.700 "call 28 - report 159 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.700 "call 28 - report 160 - preventionSentences: missing sentences 3" Section_02.js:147 19:14:31.701 "call 28 - report 161 - preventionSentences: DONE missing sentences 3" Section_02.js:147 19:14:31.731 "call 29 - report 162 - preventionSentences: START" Section_02.js:147 19:14:31.731 "call 29 - report 163 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.733 "call 29 - report 164 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.734 "call 29 - report 165 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.734 "call 29 - report 166 - preventionSentences: missing sentences 3" Section_02.js:147 19:14:31.734 "call 29 - report 167 - preventionSentences: DONE missing sentences 3" Section_02.js:147 19:14:31.759 "call 30 - report 168 - preventionSentences: START" Section_02.js:147 19:14:31.759 "call 30 - report 169 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.761 "call 30 - report 170 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.761 "call 30 - report 171 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.761 "call 30 - report 172 - preventionSentences: missing sentences 2" Section_02.js:147 19:14:31.762 "call 30 - report 173 - preventionSentences: DONE missing sentences 2" Section_02.js:147 19:14:31.792 "call 31 - report 174 - preventionSentences: START" Section_02.js:147 19:14:31.792 "call 31 - report 175 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.796 "call 31 - report 176 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.796 "call 31 - report 177 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.796 "call 31 - report 178 - preventionSentences: missing sentences 1" Section_02.js:147 19:14:31.796 "call 31 - report 179 - preventionSentences: DONE missing sentences 1" Section_02.js:147 19:14:31.826 "call 32 - report 180 - preventionSentences: START" Section_02.js:147 19:14:31.826 "call 32 - report 181 - preventionSentences: pdd ok" Section_02.js:147 19:14:31.828 "call 32 - report 182 - preventionSentences: sentences are fresh" Section_02.js:147 19:14:31.828 "call 32 - report 183 - preventionSentences: sentences > 0" Section_02.js:147 19:14:31.828 "call 32 - report 184 - preventionSentences: no missing sentences" Section_02.js:147 19:14:38.639 "call 32 - report 185 - preventionSentences: DONE no missing sentences" Section_02.js:147 19:14:40.678 "call 21 - report 186 - hazardSentences: DONE no missing sentences" Section_02.js:147
Correction: "In this screencast, we only see _2_ alerts stacked, ..."
|
||
Comment 7•10 years ago
|
||
alert() calls in Gecko will spin the event loop. That means that some code can actually run while the alert is up; XHR callbacks in particular can do that. So code can be reentered (not to be confused with being executed in parallel)... Thus the alert-stacking behavior observed in comment 5 is not unexpected in Gecko. That's not how alert() should behave per spec, but this is only recently specified, and we haven't aligned with the spec yet. Note that it _is_ how showModalDialog is supposed to behave per spec, though. Does the original code have any alerts involved? If not, is it possible that it's starting an async XHR and then a sync XHR? Again, a sync XHR just spins the event loop right now, so it's possible to get callbacks for an async XHR while a sync XHR is running....
Flags: needinfo?(bzbarsky)
1) Original code does not have any alerts in the paths that are executed in the example (alert is used to communicate failure to the end user only) 2) I would be highly surprised that a sync XHR call would be started after async calls. That was not the intention, in any case. But I can't say 100% sure that it doesn't happen. The other way around does happen, but could not normally intervene in the function at hand. During page setup, there are a number of potentially sync calls, that must finish before data handling starts. The function in question however is called a number of times, only in response to callbacks triggered by changes in (view)model classes (dojo/Stateful, dojo/Observable, if that says anything). These changes are all triggered by the arrival of data from the server as response to a number of concurrent async XHR-requests. The problem became apparent with a speedup of the server, that resulted in the responses coming in very close together. I understand the difference between re-entrance and parallelism, but re-entrance cannot explain yielding in the middle of a function body. It can be a consequence, not a cause. I am particularly surprised by the statement "XHR callbacks in particular can do that". Are you saying that it is to be expected that the (?) / a (?) "JavaScript thread" yields to some other "JavaScript thread" that is the result of an async XHR (without calling `yield`)?
|
|
||
Comment 9•10 years ago
|
||
In Gecko right now, if the page does a sync XHR then it's possible for certain events to fire before the send() call returns, which can lead to code being reentered. This is a bug per the spec, of course, but again the spec here is pretty new. Looking at the log from comment 0, the bug you're seeing is right here, presumably: 14:53:20.500 "CALL: 27 / 27" Section_02.js:138 14:53:20.692 "---" Section_02.js:137 14:53:20.693 "CALL: 28 / 28" Section_02.js:138 14:53:20.703 "BEFORE RENDER: 28 / 28" Section_02.js:152 14:53:20.703 "RENDER START: 28 / 28" Section_02.js:155 14:53:20.708 "RENDER END: 28 / 28" Section_02.js:162 14:53:21.409 "BEFORE RENDER: 27 / 28" Section_02.js:152 14:53:21.410 "SKIP: 27 / 28" Section_02.js:165 14:53:22.024 "RENDER END: 23 / 28" Section_02.js:162 (there was a RENDER START for "23 / 23" earlier in the log). In particular, there are two weird things here. First of all, we're clearly reentering between the RENDER START for callCounter == 23 and the RENDER END for it. Is there any code in the renderHazardOrPrevention function between those two log calls that can do a sync XHR, by any chance? The second thing we see happening is that we're reentering between the "CALL: 27 / 27" and the "BEFORE RENDER: 27 / 28". Again, is there any code in between those log calls that can do a sync XHR? In particular, can those various get(), getLabel(), getCodeRepresentation() calls trigger sync XHR?
|
Reporter | |
Comment 10•10 years ago
|
||
Short answer: not that I know of, but ... "getCodeRepresentation" and "getLabels" use i18n bundles, the dojo way. This uses lazy loading, and I presume that might be done using sync XHR. I just tried to analyse that code, but that will take me hours. Isn't there an automatic way in which we can test this? Some listener I can add or something, some test I can write?
|
|
||
Comment 11•10 years ago
|
||
If you can point me to a page that runs this sort of code, I can probably tell you whether there's sync XHR running and with what JS stack. Alternately, I could produce a build for you that spews something to the console whenever a sync XHR starts, if that would help.
|
|
Reporter | |
Comment 12•10 years ago
|
||
In trying to confirm your hunch, I tried a run without the getLabels and getCodeRepresentation calls:
_renderHazardOrPrevention: function(pddSentencesPropertyName, node) {
var callCounter = ++FF_HACK_COUNTER;
console.log("CALL: " + callCounter + " / " + FF_HACK_COUNTER);
var self = this;
var pdd = self.get("target");
if (!pdd) {
domConstruct.empty(node);
domConstruct.create("li", {innerHTML: "?Sentences?"}, node);
return;
}
var sentences = pdd.get(pddSentencesPropertyName).sort(js.sortComparable);
// if (sentences.length <= 0) {
// domConstruct.empty(node);
// domConstruct.create("li", {innerHTML: self._noEntry()}, node);
// return;
// }
console.log("BEFORE RENDER: " + callCounter + " / " + FF_HACK_COUNTER);
var lang = "en"; //self.get("lang");
if (callCounter === FF_HACK_COUNTER) {
console.log("RENDER START: " + callCounter + " / " + FF_HACK_COUNTER);
domConstruct.empty(node);
// HACK: soft spot 1
sentences.forEach(function(sentence) {
// HACK: soft spot 2a
var li = domConstruct.create("li", {className: "sentence"}, node);
// HACK: soft spot 2b
domConstruct.create("span", {className: "label", innerHTML: sentence ? "TEST"/*sentence.getCodeRepresentation(lang)*/ : "?"}, li);
// HACK: soft spot 2c
domConstruct.create("span", {className: "entry", innerHTML: sentence ? "TEST" /*sentence.getLabel(lang)*/ : "?"}, li);
});
console.log("RENDER END: " + callCounter + " / " + FF_HACK_COUNTER);
return;
}
if (callCounter !== FF_HACK_COUNTER) {
console.error("OUT OF ORDER - SKIPPED: " + callCounter + " / " + FF_HACK_COUNTER);
}
}
});
With this code, I still get OUT OF ORDER messages:
10:20:32.851 "OUT OF ORDER - SKIPPED: 20 / 32" Section_02.js:191
10:20:32.952 "BEFORE RENDER: 19 / 32" Section_02.js:173
10:20:32.952 "OUT OF ORDER - SKIPPED: 19 / 32" Section_02.js:191
10:20:33.053 "BEFORE RENDER: 18 / 32" Section_02.js:173
10:20:33.053 "OUT OF ORDER - SKIPPED: 18 / 32" Section_02.js:191
10:20:33.144 "BEFORE RENDER: 17 / 32" Section_02.js:173
10:20:33.144 "OUT OF ORDER - SKIPPED: 17 / 32" Section_02.js:191
10:20:33.243 "BEFORE RENDER: 16 / 32" Section_02.js:173
10:20:33.243 "OUT OF ORDER - SKIPPED: 16 / 32" Section_02.js:191
10:20:33.333 "BEFORE RENDER: 15 / 32" Section_02.js:173
10:20:33.333 "OUT OF ORDER - SKIPPED: 15 / 32" Section_02.js:191
10:20:33.440 "BEFORE RENDER: 14 / 32" Section_02.js:173
10:20:33.440 "OUT OF ORDER - SKIPPED: 14 / 32" Section_02.js:191
10:20:33.530 "BEFORE RENDER: 13 / 32" Section_02.js:173
10:20:33.530 "OUT OF ORDER - SKIPPED: 13 / 32" Section_02.js:191
10:20:33.620 "BEFORE RENDER: 12 / 32" Section_02.js:173
10:20:33.620 "OUT OF ORDER - SKIPPED: 12 / 32" Section_02.js:1
So it can't be calls inside those 2 methods. Now there are little suspects left.
I think we should go for option 2. Can you produce a build that reports on sync calls? (Mac please).|
|
Reporter | |
Comment 13•10 years ago
|
||
Note: I believe we are actually zooming in on the DOM manipulation. There isn't some kind of MUTEX or yield there, is there?
|
|
||
Comment 14•10 years ago
|
||
Jan, http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/bzbarsky@mozilla.com-e651c4006b2a/try-macosx64/firefox-30.0a1.en-US.mac.dmg should have a build you can try. It'll log sync XHR when it happens, along with the URL being fetched and the line/file the send() call happened on (though sadly without the full stack). Let me know what that shows? There are no mutexes in the DOM code, and the only way to yield is to explicitly spin the event loop; very few things do that.
|
|
Reporter | |
Comment 15•10 years ago
|
||
_If_ this Nightly does indeed output when sync calls happen (30.0a1 (2014-02-27)), then no, that isn't it. There are no sync calls reported whatsoever. The output of a run with the above build: "11:56:26,363 INFO - pictoperfect-config/serverBaseUrl - server base url defined: https://www.pictoperfect.com/dev/server/app/ (dev)" log4javascript_uncompressed.js:1926 "DEPRECATED: dojox/mobile/sniff Use dojo/sniff instead -- will be removed in version: 2.0" kernel.js:203 "EXPERIMENTAL: dojox.mvc -- APIs subject to change without notice." kernel.js:227 "EXPERIMENTAL: dojox.widget.Standby -- APIs subject to change without notice." kernel.js:227 "EXPERIMENTAL: dojox.fx.flip -- APIs subject to change without notice." kernel.js:227 "CALL: 1 / 1" Section_02.js:159 "CALL: 2 / 2" Section_02.js:159 "CALL: 3 / 3" Section_02.js:159 "BEFORE RENDER: 3 / 3" Section_02.js:173 "RENDER START: 3 / 3" Section_02.js:176 "RENDER END: 3 / 3" Section_02.js:187 "CALL: 4 / 4" Section_02.js:159 "BEFORE RENDER: 4 / 4" Section_02.js:173 "RENDER START: 4 / 4" Section_02.js:176 "RENDER END: 4 / 4" Section_02.js:187 "CALL: 5 / 5" Section_02.js:159 "BEFORE RENDER: 5 / 5" Section_02.js:173 "RENDER START: 5 / 5" Section_02.js:176 "RENDER END: 5 / 5" Section_02.js:187 "CALL: 6 / 6" Section_02.js:159 "BEFORE RENDER: 6 / 6" Section_02.js:173 "RENDER START: 6 / 6" Section_02.js:176 "RENDER END: 6 / 6" Section_02.js:187 "CALL: 7 / 7" Section_02.js:159 "BEFORE RENDER: 7 / 7" Section_02.js:173 "RENDER START: 7 / 7" Section_02.js:176 "RENDER END: 7 / 7" Section_02.js:187 "CALL: 8 / 8" Section_02.js:159 "BEFORE RENDER: 8 / 8" Section_02.js:173 "RENDER START: 8 / 8" Section_02.js:176 "RENDER END: 8 / 8" Section_02.js:187 "CALL: 9 / 9" Section_02.js:159 "BEFORE RENDER: 9 / 9" Section_02.js:173 "RENDER START: 9 / 9" Section_02.js:176 "RENDER END: 9 / 9" Section_02.js:187 "CALL: 10 / 10" Section_02.js:159 "BEFORE RENDER: 10 / 10" Section_02.js:173 "RENDER START: 10 / 10" Section_02.js:176 "RENDER END: 10 / 10" Section_02.js:187 "CALL: 11 / 11" Section_02.js:159 "BEFORE RENDER: 11 / 11" Section_02.js:173 "RENDER START: 11 / 11" Section_02.js:176 "RENDER END: 11 / 11" Section_02.js:187 "CALL: 12 / 12" Section_02.js:159 "BEFORE RENDER: 12 / 12" Section_02.js:173 "RENDER START: 12 / 12" Section_02.js:176 "RENDER END: 12 / 12" Section_02.js:187 "CALL: 13 / 13" Section_02.js:159 "BEFORE RENDER: 13 / 13" Section_02.js:173 "RENDER START: 13 / 13" Section_02.js:176 "RENDER END: 13 / 13" Section_02.js:187 "CALL: 14 / 14" Section_02.js:159 "BEFORE RENDER: 14 / 14" Section_02.js:173 "RENDER START: 14 / 14" Section_02.js:176 "RENDER END: 14 / 14" Section_02.js:187 "CALL: 15 / 15" Section_02.js:159 "BEFORE RENDER: 15 / 15" Section_02.js:173 "RENDER START: 15 / 15" Section_02.js:176 "CALL: 16 / 16" Section_02.js:159 "CALL: 17 / 17" Section_02.js:159 "CALL: 18 / 18" Section_02.js:159 "CALL: 19 / 19" Section_02.js:159 "CALL: 20 / 20" Section_02.js:159 "CALL: 21 / 21" Section_02.js:159 "CALL: 22 / 22" Section_02.js:159 "BEFORE RENDER: 22 / 22" Section_02.js:173 "RENDER START: 22 / 22" Section_02.js:176 "RENDER END: 22 / 22" Section_02.js:187 "CALL: 23 / 23" Section_02.js:159 "BEFORE RENDER: 23 / 23" Section_02.js:173 "RENDER START: 23 / 23" Section_02.js:176 "RENDER END: 23 / 23" Section_02.js:187 "CALL: 24 / 24" Section_02.js:159 "BEFORE RENDER: 24 / 24" Section_02.js:173 "RENDER START: 24 / 24" Section_02.js:176 "RENDER END: 24 / 24" Section_02.js:187 "CALL: 25 / 25" Section_02.js:159 "BEFORE RENDER: 25 / 25" Section_02.js:173 "RENDER START: 25 / 25" Section_02.js:176 "RENDER END: 25 / 25" Section_02.js:187 "CALL: 26 / 26" Section_02.js:159 "BEFORE RENDER: 26 / 26" Section_02.js:173 "RENDER START: 26 / 26" Section_02.js:176 "RENDER END: 26 / 26" Section_02.js:187 "CALL: 27 / 27" Section_02.js:159 "BEFORE RENDER: 27 / 27" Section_02.js:173 "RENDER START: 27 / 27" Section_02.js:176 "RENDER END: 27 / 27" Section_02.js:187 "CALL: 28 / 28" Section_02.js:159 "BEFORE RENDER: 28 / 28" Section_02.js:173 "RENDER START: 28 / 28" Section_02.js:176 "RENDER END: 28 / 28" Section_02.js:187 "CALL: 29 / 29" Section_02.js:159 "BEFORE RENDER: 29 / 29" Section_02.js:173 "RENDER START: 29 / 29" Section_02.js:176 "RENDER END: 29 / 29" Section_02.js:187 "CALL: 30 / 30" Section_02.js:159 "BEFORE RENDER: 30 / 30" Section_02.js:173 "RENDER START: 30 / 30" Section_02.js:176 "RENDER END: 30 / 30" Section_02.js:187 "CALL: 31 / 31" Section_02.js:159 "BEFORE RENDER: 31 / 31" Section_02.js:173 "RENDER START: 31 / 31" Section_02.js:176 "RENDER END: 31 / 31" Section_02.js:187 "CALL: 32 / 32" Section_02.js:159 "BEFORE RENDER: 32 / 32" Section_02.js:173 "RENDER START: 32 / 32" Section_02.js:176 "RENDER END: 32 / 32" Section_02.js:187 "BEFORE RENDER: 21 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 21 / 32" Section_02.js:191 "BEFORE RENDER: 20 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 20 / 32" Section_02.js:191 "BEFORE RENDER: 19 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 19 / 32" Section_02.js:191 "BEFORE RENDER: 18 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 18 / 32" Section_02.js:191 "BEFORE RENDER: 17 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 17 / 32" Section_02.js:191 "BEFORE RENDER: 16 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 16 / 32" Section_02.js:191 "RENDER END: 15 / 32" Section_02.js:187
|
|
Reporter | |
Comment 16•10 years ago
|
||
CORRECTION: THERE ARE SYNC CALLS They are warnings - which were filtered out. One moment ...
|
|
Reporter | |
Comment 17•10 years ago
|
||
Yes, there are sync calls there for labels: ReferenceError: reference to undefined property hasCache[name] dojo.js:135 ReferenceError: reference to undefined property config.has dojo.js:573 ReferenceError: reference to undefined property userConfig.trace dojo.js:1744 ReferenceError: reference to undefined property waiting[module.url] dojo.js:1377 ReferenceError: reference to undefined property deps[i] dojo.js:1555 ReferenceError: reference to undefined property module.executed dojo.js:1190 TypeError: anonymous function does not always return a value Deferred.js:265 SyntaxError: test for equality (==) mistyped as assignment (=)? declare.js:128 SyntaxError: test for equality (==) mistyped as assignment (=)? declare.js:146 SyntaxError: test for equality (==) mistyped as assignment (=)? declare.js:163 SyntaxError: test for equality (==) mistyped as assignment (=)? declare.js:173 TypeError: function inherited does not always return a value declare.js:86 TypeError: function inherited__debug does not always return a value declare.js:201 TypeError: anonymous function does not always return a value declare.js:335 TypeError: anonymous function does not always return a value declare.js:398 TypeError: anonymous function does not always return a value declare.js:443 ReferenceError: reference to undefined property window.navigator.msMaxTouchPoints has.js:101 ReferenceError: reference to undefined property module.provides dojo.js:1166 TypeError: anonymous function does not always return a value xhr.js:21 TypeError: anonymous function does not always return a value log4javascript_uncompressed.js:47 TypeError: anonymous function does not always return a value log4javascript_uncompressed.js:667 TypeError: anonymous function does not always return a value log4javascript_uncompressed.js:1963 TypeError: anonymous function does not always return a value log4javascript_uncompressed.js:2301 TypeError: anonymous function does not always return a value log4javascript_uncompressed.js:5281 TypeError: anonymous function does not always return a value instrumentation.js:32 ReferenceError: reference to undefined property dua.split(...)[1] sniff.js:20 TypeError: anonymous function does not always return a value _loader.js:7 TypeError: anonymous function does not always return a value _loader.js:22 TypeError: anonymous function does not always return a value dom.js:27 TypeError: anonymous function does not always return a value on.js:80 SyntaxError: test for equality (==) mistyped as assignment (=)? on.js:119 TypeError: function select does not always return a value on.js:211 TypeError: anonymous function does not always return a value on.js:314 SyntaxError: applying the 'delete' operator to an unqualified name is deprecated number.js:246 ReferenceError: reference to undefined property args[0] instrumentation.js:99 ReferenceError: reference to undefined property split[1] i18n.js:247 ReferenceError: reference to undefined property bases[mixins] declare.js:744 "12:10:16,712 INFO - pictoperfect-config/serverBaseUrl - server base url defined: https://www.pictoperfect.com/dev/server/app/ (dev)" log4javascript_uncompressed.js:1926 ReferenceError: reference to undefined property cache.c declare.js:110 ReferenceError: reference to undefined property callbacks[("_" + name)] SemanticObject.js:201 ReferenceError: reference to undefined property tokens[+ (i)] has.js:136 SyntaxError: test for equality (==) mistyped as assignment (=)? parser.js:289 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function parser.js:529 TypeError: anonymous function does not always return a value ContentPane.js:349 TypeError: anonymous function does not always return a value ContentPane.js:409 TypeError: anonymous function does not always return a value domReady.js:81 ReferenceError: reference to undefined property pseudoPluginResource.req.module dojo.js:1131 TypeError: anonymous function does not always return a value connect.js:90 SyntaxError: test for equality (==) mistyped as assignment (=)? _ContentPaneResizeMixin.js:183 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function ProductDocumentsData.js:636 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function ProductDocumentsData.js:652 TypeError: anonymous function does not always return a value css.js:20 TypeError: anonymous function does not always return a value TabBarButton.js:235 TypeError: anonymous function does not always return a value mouse.js:84 TypeError: anonymous function does not always return a value mouse.js:94 TypeError: anonymous function does not always return a value lite.js:191 ReferenceError: reference to undefined property existing.target aspect.js:79 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function definitions.js:142 ReferenceError: reference to undefined property response.options.handleAs xhr.js:35 ReferenceError: reference to undefined property response.options.handleAs handlers.js:62 TypeError: function isLinkReady does not always return a value load-css.js:157 TypeError: anonymous function does not always return a value load-css.js:222 ReferenceError: reference to undefined property features[feature] load-css.js:100 SyntaxError: test for equality (==) mistyped as assignment (=)? touch.js:64 TypeError: function marked does not always return a value touch.js:60 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function touch.js:114 TypeError: function clickKey does not always return a value a11yclick.js:36 TypeError: anonymous function does not always return a value focus.js:77 SyntaxError: test for equality (==) mistyped as assignment (=)? TextComponentMassFraction.js:57 ReferenceError: reference to undefined property EnumDef[ed]._representation EnumerationValue.js:138 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function sync.js:60 TypeError: anonymous function does not always return a value base.js:97 TypeError: anonymous function does not always return a value base.js:136 TypeError: anonymous function does not always return a value base.js:156 SyntaxError: test for equality (==) mistyped as assignment (=)? base.js:182 SyntaxError: test for equality (==) mistyped as assignment (=)? base.js:185 SyntaxError: test for equality (==) mistyped as assignment (=)? base.js:188 SyntaxError: test for equality (==) mistyped as assignment (=)? base.js:194 SyntaxError: test for equality (==) mistyped as assignment (=)? base.js:198 SyntaxError: test for equality (==) mistyped as assignment (=)? parser.js:191 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function fx.js:584 TypeError: variable doc redeclares argument put.js:17 SyntaxError: test for equality (==) mistyped as assignment (=)? put.js:154 TypeError: anonymous function does not always return a value Rule.js:41 TypeError: anonymous function does not always return a value Rule.js:137 TypeError: anonymous function does not always return a value Rule.js:169 TypeError: anonymous function does not always return a value Rule.js:143 TypeError: anonymous function does not always return a value utils.js:23 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function _atBindingMixin.js:11 SyntaxError: in strict mode code, functions may be declared only at top level or immediately within another function _atBindingMixin.js:15 TypeError: function getParent does not always return a value _atBindingMixin.js:39 TypeError: function getParent does not always return a value _atBindingMixin.js:20 ReferenceError: reference to undefined property this.constructor.extraSupportedUnits ScalarQuantitativeValue.js:54 ReferenceError: reference to undefined property config.mblApplyPageStyles common.js:277 ReferenceError: reference to undefined property r[j].href common.js:262 ReferenceError: reference to undefined property (intermediate value).debugBindings sync.js:55 ReferenceError: reference to undefined property (intermediate value).extensionPerWidget _atBindingExtension.js:7 "DEPRECATED: dojox/mobile/sniff Use dojo/sniff instead -- will be removed in version: 2.0" kernel.js:203 "EXPERIMENTAL: dojox.mvc -- APIs subject to change without notice." kernel.js:227 "EXPERIMENTAL: dojox.widget.Standby -- APIs subject to change without notice." kernel.js:227 TypeError: variable node redeclares argument Select.js:215 TypeError: anonymous function does not always return a value Keyboard.js:161 TypeError: anonymous function does not always return a value OnDemandList.js:225 TypeError: anonymous function does not always return a value OnDemandList.js:228 TypeError: anonymous function does not always return a value OnDemandList.js:600 SyntaxError: test for equality (==) mistyped as assignment (=)? popup.js:396 TypeError: anonymous function does not always return a value _MenuBase.js:288 "EXPERIMENTAL: dojox.fx.flip -- APIs subject to change without notice." kernel.js:227 TypeError: anonymous function does not always return a value List.js:424 TypeError: anonymous function does not always return a value List.js:764 TypeError: anonymous function does not always return a value List.js:774 TypeError: variable node redeclares argument _KeyNavContainer.js:124 TypeError: anonymous function does not always return a value scrollable.js:27 TypeError: anonymous function does not always return a value Memory.js:97 ReferenceError: reference to undefined property ret[name] io-query.js:87 ReferenceError: reference to undefined property callbacks[("_" + name)] Stateful.js:186 ReferenceError: reference to undefined property options.contextRequire parser.js:639 ReferenceError: reference to undefined property (intermediate value).atsignature _atBindingMixin.js:126 ReferenceError: reference to undefined property (intermediate value).atsignature _atBindingMixin.js:168 ReferenceError: reference to undefined property (intermediate value).atsignature atBindingExtension.js:47 ReferenceError: reference to undefined property options.propsThis parser.js:391 ReferenceError: reference to undefined property hash[id] registry.js:80 ReferenceError: reference to undefined property this.prevNode focus.js:57 ReferenceError: reference to undefined property obj[event] _Widget.js:34 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property this.iconNode _ItemBase.js:432 ReferenceError: reference to undefined property dm.currentTheme iconUtils.js:168 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property source.constraints sync.js:177 ReferenceError: reference to undefined property (intermediate value).getTime sync.js:74 ReferenceError: reference to undefined property this[name] Stateful.js:56 ReferenceError: reference to undefined property n[p] _WidgetsInTemplateMixin.js:63 ReferenceError: reference to undefined property this[name] _Widget.js:221 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property this[name] _WidgetBase.js:892 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property Constructor['-propagateCache-'][propName] _PropagationMixin.js:116 Empty string passed to getElementById(). lang.js:30 "CALL: 1 / 1" Section_02.js:159 "CALL: 2 / 2" Section_02.js:159 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property _attachScope[point] _AttachMixin.js:141 ReferenceError: reference to undefined property this.checked _CssStateMixin.js:161 ReferenceError: reference to undefined property a[(start + 1)] query.js:514 Empty string passed to getElementById(). lang.js:30 Synchronous XMLHttpRequest on the main thread is deprecated because of its detrimental effects to the end user's experience. For more help http://xhr.spec.whatwg.org/ xhr.js:176 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/productDocuments/msds///nls/labels.js?1.8DEV detected xhr.js:206 Empty string passed to getElementById(). lang.js:30 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/productDocuments/productionSheet///nls/labels.js?1.8DEV detected xhr.js:206 Empty string passed to getElementById(). lang.js:30 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/productDocuments/suppliersSheet///nls/labels.js?1.8DEV detected xhr.js:206 Empty string passed to getElementById(). lang.js:30 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/productDocuments/label///nls/labels.js?1.8DEV detected xhr.js:206 Empty string passed to getElementById(). lang.js:30 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/productDocuments/transportSheet///nls/labels.js?1.8DEV detected xhr.js:206 ReferenceError: reference to undefined property this[("iconNode" + n)] TabBarButton.js:230 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property this.value Output.js:67 Empty string passed to getElementById(). lang.js:30 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/productDocuments/adr/nls/labels.js?1.8DEV detected xhr.js:206 ReferenceError: reference to undefined property this.persistenceVersion VersionedPersistentObject.js:65 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property this[(type + "Node")] ListItem.js:412 ReferenceError: reference to undefined property hash[node.getAttribute(...)] registry.js:53 Empty string passed to getElementById(). lang.js:30 ReferenceError: reference to undefined property this._resizeCalled _ContentPaneResizeMixin.js:205 ReferenceError: reference to undefined property this.open _ContentPaneResizeMixin.js:136 Use of getAttributeNode() is deprecated. Use getAttribute() instead. dom-attr.js:36 ReferenceError: reference to undefined property this.curve fx.js:52 ReferenceError: reference to undefined property config.mblAndroidWorkaroundButtonStyle common.js:310 ReferenceError: reference to undefined property config.mblLoadCompatCssFiles _compat.js:618 ReferenceError: reference to undefined property previousWildExceptions[propName] SemanticObject.js:116 ReferenceError: reference to undefined property oldValue[index] SemanticObject.js:61 ReferenceError: reference to undefined property options.locale number.js:62 ReferenceError: reference to undefined property options.fractional number.js:103 ReferenceError: reference to undefined property control.currentCss MainProductDocument.js:85 ReferenceError: reference to undefined property this.binding Group.js:37 "CALL: 3 / 3" Section_02.js:159 "BEFORE RENDER: 3 / 3" Section_02.js:173 "RENDER START: 3 / 3" Section_02.js:176 "RENDER END: 3 / 3" Section_02.js:187 "CALL: 4 / 4" Section_02.js:159 "BEFORE RENDER: 4 / 4" Section_02.js:173 "RENDER START: 4 / 4" Section_02.js:176 "RENDER END: 4 / 4" Section_02.js:187 "CALL: 5 / 5" Section_02.js:159 "BEFORE RENDER: 5 / 5" Section_02.js:173 "RENDER START: 5 / 5" Section_02.js:176 "RENDER END: 5 / 5" Section_02.js:187 "CALL: 6 / 6" Section_02.js:159 "BEFORE RENDER: 6 / 6" Section_02.js:173 "RENDER START: 6 / 6" Section_02.js:176 "RENDER END: 6 / 6" Section_02.js:187 ReferenceError: reference to undefined property options.round ConsolidatedWidget.js:34 ReferenceError: reference to undefined property opt.escapeXml MultiLangFormatOutput.js:69 ReferenceError: reference to undefined property this.constraints _TextBoxMixin.js:88 "CALL: 7 / 7" Section_02.js:159 "BEFORE RENDER: 7 / 7" Section_02.js:173 "RENDER START: 7 / 7" Section_02.js:176 "RENDER END: 7 / 7" Section_02.js:187 "CALL: 8 / 8" Section_02.js:159 "BEFORE RENDER: 8 / 8" Section_02.js:173 "RENDER START: 8 / 8" Section_02.js:176 "RENDER END: 8 / 8" Section_02.js:187 "CALL: 9 / 9" Section_02.js:159 "BEFORE RENDER: 9 / 9" Section_02.js:173 "RENDER START: 9 / 9" Section_02.js:176 "RENDER END: 9 / 9" Section_02.js:187 "CALL: 10 / 10" Section_02.js:159 "BEFORE RENDER: 10 / 10" Section_02.js:173 "RENDER START: 10 / 10" Section_02.js:176 "RENDER END: 10 / 10" Section_02.js:187 "CALL: 11 / 11" Section_02.js:159 "BEFORE RENDER: 11 / 11" Section_02.js:173 "RENDER START: 11 / 11" Section_02.js:176 "RENDER END: 11 / 11" Section_02.js:187 "CALL: 12 / 12" Section_02.js:159 "BEFORE RENDER: 12 / 12" Section_02.js:173 "RENDER START: 12 / 12" Section_02.js:176 "RENDER END: 12 / 12" Section_02.js:187 "CALL: 13 / 13" Section_02.js:159 "BEFORE RENDER: 13 / 13" Section_02.js:173 "RENDER START: 13 / 13" Section_02.js:176 "RENDER END: 13 / 13" Section_02.js:187 "CALL: 14 / 14" Section_02.js:159 "BEFORE RENDER: 14 / 14" Section_02.js:173 "RENDER START: 14 / 14" Section_02.js:176 "RENDER END: 14 / 14" Section_02.js:187 "CALL: 15 / 15" Section_02.js:159 "BEFORE RENDER: 15 / 15" Section_02.js:173 "RENDER START: 15 / 15" Section_02.js:176 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/SignalWord.js?1.8DEV detected xhr.js:206 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/HazardSentence.js?1.8DEV detected xhr.js:206 "CALL: 16 / 16" Section_02.js:159 "CALL: 17 / 17" Section_02.js:159 "CALL: 18 / 18" Section_02.js:159 "CALL: 19 / 19" Section_02.js:159 "CALL: 20 / 20" Section_02.js:159 "CALL: 21 / 21" Section_02.js:159 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/HazardSentence.js?1.8DEV detected xhr.js:206 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/HazardSentence.js?1.8DEV detected xhr.js:206 ReferenceError: reference to undefined property labels[((code + "_") + extension)] Sentence.js:56 ReferenceError: reference to undefined property options.formatLength Sentence.js:74 "BEFORE RENDER: 21 / 21" Section_02.js:173 "RENDER START: 21 / 21" Section_02.js:176 "RENDER END: 21 / 21" Section_02.js:187 "BEFORE RENDER: 20 / 21" Section_02.js:173 "OUT OF ORDER - SKIPPED: 20 / 21" Section_02.js:191 "BEFORE RENDER: 19 / 21" Section_02.js:173 "OUT OF ORDER - SKIPPED: 19 / 21" Section_02.js:191 "BEFORE RENDER: 18 / 21" Section_02.js:173 "OUT OF ORDER - SKIPPED: 18 / 21" Section_02.js:191 "BEFORE RENDER: 17 / 21" Section_02.js:173 "OUT OF ORDER - SKIPPED: 17 / 21" Section_02.js:191 "BEFORE RENDER: 16 / 21" Section_02.js:173 "OUT OF ORDER - SKIPPED: 16 / 21" Section_02.js:191 "RENDER END: 15 / 21" Section_02.js:187 "CALL: 22 / 22" Section_02.js:159 "BEFORE RENDER: 22 / 22" Section_02.js:173 "RENDER START: 22 / 22" Section_02.js:176 "RENDER END: 22 / 22" Section_02.js:187 "CALL: 23 / 23" Section_02.js:159 "BEFORE RENDER: 23 / 23" Section_02.js:173 "RENDER START: 23 / 23" Section_02.js:176 "RENDER END: 23 / 23" Section_02.js:187 "CALL: 24 / 24" Section_02.js:159 "BEFORE RENDER: 24 / 24" Section_02.js:173 "RENDER START: 24 / 24" Section_02.js:176 "RENDER END: 24 / 24" Section_02.js:187 "CALL: 25 / 25" Section_02.js:159 "BEFORE RENDER: 25 / 25" Section_02.js:173 "RENDER START: 25 / 25" Section_02.js:176 "RENDER END: 25 / 25" Section_02.js:187 "CALL: 26 / 26" Section_02.js:159 "BEFORE RENDER: 26 / 26" Section_02.js:173 "RENDER START: 26 / 26" Section_02.js:176 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/PreventionSentence.js?1.8DEV detected xhr.js:206 "CALL: 27 / 27" Section_02.js:159 "BEFORE RENDER: 27 / 27" Section_02.js:173 "RENDER START: 27 / 27" Section_02.js:176 "CALL: 28 / 28" Section_02.js:159 "CALL: 29 / 29" Section_02.js:159 "CALL: 30 / 30" Section_02.js:159 "CALL: 31 / 31" Section_02.js:159 "CALL: 32 / 32" Section_02.js:159 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/PreventionSentence.js?1.8DEV detected xhr.js:206 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/nls/UNNUmber.js?1.8DEV detected xhr.js:206 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/sentence/nls/PreventionSentence.js?1.8DEV detected xhr.js:206 "BEFORE RENDER: 32 / 32" Section_02.js:173 "RENDER START: 32 / 32" Section_02.js:176 "RENDER END: 32 / 32" Section_02.js:187 Synchronous XMLHttpRequest to http://localhost/~jand/WebStorm/ECACHIM/PictoPerfect/ui/src/app/viewmodel/nls/UNClass.js?1.8DEV detected xhr.js:206 "BEFORE RENDER: 31 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 31 / 32" Section_02.js:191 "BEFORE RENDER: 30 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 30 / 32" Section_02.js:191 "BEFORE RENDER: 29 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 29 / 32" Section_02.js:191 "BEFORE RENDER: 28 / 32" Section_02.js:173 "OUT OF ORDER - SKIPPED: 28 / 32" Section_02.js:191 "RENDER END: 27 / 32" Section_02.js:187 "RENDER END: 26 / 32" Section_02.js:187
|
|
Reporter | |
Comment 18•10 years ago
|
||
Although I cannot definitely proof that this is the issue, fiddling with the code a bit to have less of these sync calls, does make the odd behaviour go away. (Of course, the app is not functional like that). All sync calls are for i18n files. There are 2 sources for that in this function: the getCodeRepresentation and getLabel calls in the actual rendering code, but also in the array sort: comparison is done on the "code representation", so the comparator method also calls getCodeRepresentation. This explains why cutting out "some" code could not pinpoint the problem, and we saw "yielding" at different places. There are 2 places where the issue occurs. In any case, these experiments support your claim. Thanks for the effort in helping to clear this mystery. Now, for a solution: * since this is an instance of "yielding", and there are no mechanisms in JavaScript for critical sections, semaphores, or such things, I assume that there is no possible complete workaround? Or does somebody have any other ideas (apart from ripping out the dojo i18n code and doing it async)? * You state that this is a "known bug" (because the spec changed); what is the bugzilla reference, and is there any ETA for a resolution? To everybody in the thread above ( pun intended :-) ): thx a million for taking this serious, although it was impossible for you to reproduce.
|
|
||
Comment 19•10 years ago
|
||
Jan, thanks for checking that! > I assume that there is no possible complete workaround? Hmm. There might be. If the caller does not depend on the _renderHazardOrPrevention function doing its work immediately (e.g. if the caller is an async callback of some sort and doesn't have any code following the function call), you could effectively roll your own critical section like so: 1) Have a global "isInCriticalSection" boolean, starting out false. 2) At entry into the function, if the boolean is true set a timeout to retry calling the function and return. 3) Set the boolean to true. 4) Do the work. 5) Set the boolean to false. This works because we're not dealing with a preemptive multitasking system; you do have run to completion except when actually doing a sync XHR. So in particular, you can't end up racing on the boolean or anything like that in the setup described above. Of course if the caller expects the function's work to be done immediately this won't work. :( > what is the bugzilla reference Bug 697151, if I understand your code right. And I just filed bug 978757 for the general problem.
Status: UNCONFIRMED → RESOLVED
Closed: 10 years ago
Resolution: --- → DUPLICATE
You need to log in
before you can comment on or make changes to this bug.
Description
•