Closed Bug 580458 Opened 12 years ago Closed 12 years ago

JS_TriggerOperationCallback is being called during SunSpider tests

Categories

(Core :: JavaScript Engine, defect)

x86
macOS
defect
Not set
normal

Tracking

()

RESOLVED FIXED
Tracking Status
blocking2.0 --- betaN+

People

(Reporter: sayrer, Assigned: igor)

References

Details

(Whiteboard: fixed-in-tracemonkey)

Attachments

(2 files, 2 obsolete files)

I found that we occasionally get very high variance on some SunSpider tests. Usually in string-tagcloud and string-validate-input, sometimes in regex-dna.

Here are the individual scores from a recent SunSpider run:

  string-tagcloud:       [81,78,79,79,160,79,170,78,78,162]
  string-validate-input: [113,21,108,21,21,21,21,21,21,22]

We get a tagcloud average score of 104.4ms, when we should get an 80 or so. We get a validate-input average score of 39.0ms when we should get a 21 or so.

I've discovered that JS_TriggerOperationCallback is being called repeatedly during some runs of the test, and that matches up with the outlier test scores. I will attach a log.
Assignee: general → igor
Attached file Log of test run
I added printfs to JS_TriggerOperationCallback, JS_GC, and CycleCollector::BeginCollection. I also added printfs to the SunSpider harness to record starting and stopping of tests.

The log shows occasional bursts of 32 calls to JS_TriggerOperationCallback, while tests are executing.
blocking2.0: --- → betaN+
Adding more windows gets some really bad stuff to happen:

"string-validate-input":[24,21,20,21,20,21,21,375,21,20]

a 350ms delay is going to be user visible jankiness, so we have to fix this for sure.
here's where it comes from:

#0  JS_TriggerOperationCallback (cx=0x116b83e80) at /Users/sayrer/dev/tracemonkey/js/src/jsapi.cpp:4862
#1  in js_TriggerAllOperationCallbacks at /Users/sayrer/dev/tracemonkey/js/src/jscntxt.cpp:1939
#2  in JSContext::checkMallocGCPressure at /Users/sayrer/dev/tracemonkey/js/src/jscntxt.cpp:2193
#3  in JSScope::create at jscntxt.h:1982
#4  in js_GetMutableScope

mrbkap says js_TriggerAllOperationCallbacks is bogus
(In reply to comment #3)
> mrbkap says js_TriggerAllOperationCallbacks is bogus

So, in particular: the operation callback API is mostly timing based; we only added the memory stuff in later. Further, the memory stuff is more runtime- or application-wide rather than context based. So, we end up calling an API hook on contexts that are not in requests (which, in itself, is odd) and doing the exact work that we want to do (sending memory pressure signals) N times over (where N is the number of contexts in existence). Is there any reason we couldn't introduce a second hook lowMemory or only call the branch callback once per memory pressure notification?
(In reply to comment #4)
> So, we end up calling an API hook
> on contexts that are not in requests (which, in itself, is odd) and doing the
> exact work that we want to do (sending memory pressure signals) N times over
> (where N is the number of contexts in existence).

A context outside a request can enter or leave the request at any time. If, for example, a web worker needs a GC run on the main thread, triggering callback on all contexts for the main thread ensures that that GC would run. But for the typical case of the GC request from the main thread this is suboptimal. This can be fixed via either of:

1. Moving the callback to JSThread and the flag that triggers it. This avoids multiple triggers of the callback on the main thread but may require some adjustments in the API. For example, JSThread is not exposed currently but we may need to provide something like OnNewThread notification that can be used to setup the callback. 

2. If the above is not desirable, for at least the current thread the callback can be triggered for cx in the request. Then it would be necessary to ensure execution of the callback before that cx leaves or suspends its request. Doing that for non-current thread is problematic as other threads could be outside a request.

> Is there any reason we
> couldn't introduce a second hook lowMemory?

Such hock still would need to trigger the callback to suspend the requests for all running contexts so we end up again in this bug.
(In reply to comment #4)
> So, in particular: the operation callback API is mostly timing based; we only
> added the memory stuff in later.

The callback is also scheduled when the GC allocator detects on trace that the GC heap size reaches the maximum. As the traced code could not tolerate the last-ditch GC, the solution for that was to ask the trace to leave ASAP via the callback trigger.
Attached patch v1 (obsolete) — Splinter Review
The patch moves operationCallbackFlag into JSThreadData while keeping the callback itself in JSContext. This way no API changes are necessary while  js_TriggerAllOperationCallbacks needs to eunumerate over few JSThreadData instances. Note that traced code does not need to do an extra cx->thread load to get the flag. The trace is thread-local so it can embed JSThreadData pointer directly.
Any speedup from the constant address load on trace?

/be
(In reply to comment #8)
> Any speedup from the constant address load on trace?

I see no changes. This is not surprising since the old way of checking *cx is not much different from doing *const_address as cx is likely available in a register.
Depends on: 580803
Attached patch v2 (obsolete) — Splinter Review
Patch that passes tests.
Attachment #459015 - Attachment is obsolete: true
Attachment #459403 - Flags: review?(mrbkap)
Comment on attachment 459403 [details] [diff] [review]
v2

I want to look at this too
Attachment #459403 - Flags: review?(gal)
Comment on attachment 459403 [details] [diff] [review]
v2

Looks great.
Attachment #459403 - Flags: review?(gal) → review+
Comment on attachment 459403 [details] [diff] [review]
v2

Nit: s/jsint/int32/ just to line up with Nanojit a bit better?

/be
Comment on attachment 459403 [details] [diff] [review]
v2

This patch doesn't seem to help with variability in SunSpider.
Comment on attachment 459403 [details] [diff] [review]
v2

>diff --git a/js/src/jsapi.cpp b/js/src/jsapi.cpp
>-    JS_ATOMIC_SET(&cx->operationCallbackFlag, 1);
>+    JSThreadData *td;
>+#ifdef JS_THREADSAFE
>+    JSThread *thread = cx->thread;
>+    if (!thread)
>+        return;
>+    td = &thread->data;
>+#else
>+    td = JS_THREAD_DATA(cx);
>+#endif
>+
>+    JS_THREAD_DATA(cx)->triggerOperationCallback();

Either we don't need |td|, or you should use td instead of JS_THREAD_DATA on the last line here.
Attachment #459403 - Flags: review?(mrbkap) → review+
(In reply to comment #15)
> Either we don't need |td|, or you should use td instead of JS_THREAD_DATA on
> the last line here.

Nice catch, thanks!
(In reply to comment #14)
> Comment on attachment 459403 [details] [diff] [review]
> v2
> 
> This patch doesn't seem to help with variability in SunSpider.

But that can be due to the GC call. Could you check if the GC runs at all?
(In reply to comment #17)
> But that can be due to the GC call. Could you check if the GC runs at all?

I mean that in the comment 0 you mentioned that JS_GC was instrumented while the callback implementation calls js_GC.
Attached patch v3Splinter Review
In v2 I have missed that js_NudgeOtherContexts and NudgeThread are no longer necessary. This version fixes that.
Attachment #459403 - Attachment is obsolete: true
Attachment #459589 - Flags: review?(mrbkap)
Attachment #459589 - Flags: review?(mrbkap) → review+
http://hg.mozilla.org/tracemonkey/rev/cb3ed8e233b8
Whiteboard: fixed-in-tracemonkey
http://hg.mozilla.org/mozilla-central/rev/cb3ed8e233b8

Further work is going on in bug 598650
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.