Optimize JSStackFrame::CreateStack

RESOLVED FIXED in mozilla29

Status

()

Core
DOM
RESOLVED FIXED
4 years ago
4 years ago

People

(Reporter: jandem, Assigned: bz)

Tracking

unspecified
mozilla29
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite -

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [qa-])

Attachments

(7 attachments, 7 obsolete attachments)

2.53 KB, patch
khuey
: review+
Details | Diff | Splinter Review
11.08 KB, patch
Details | Diff | Splinter Review
5.17 KB, patch
Details | Diff | Splinter Review
11.91 KB, patch
khuey
: review+
Details | Diff | Splinter Review
3.02 KB, patch
khuey
: review+
Details | Diff | Splinter Review
1.61 KB, text/html
Details
2.00 KB, patch
Bobby Holley (parental leave - send mail for anything urgent)
: review+
Details | Diff | Splinter Review
(Reporter)

Description

4 years ago
See discussion in bug 929950.

JSStackFrame::CreateStack calls DescribeStack to get a stack trace from JS, then it allocates a JSStackFrame for every frame and does a bunch of other slow stuff like strlen(filename) and calling some JS API functions.

It would be nice if we could avoid the copying completely and had methods on JSStackFrame to get the line number, file name etc only when we actually need them.
I agree that if we could do it lazily that would rock.  How can we keep the relevant JS data structures alive and in the right state?

The filenames are not too bad: we can just keep and trace the JSScripts involved.  Similar for the function name bits, if we just keep the functions alive.  But what about line numbers?  That is, can we avoid the DescribeStack call somehow, or should we still do it but then pretty much try to do nothing else?
(Reporter)

Comment 2

4 years ago
(In reply to Boris Zbarsky [:bz] from comment #1)
> The filenames are not too bad: we can just keep and trace the JSScripts
> involved.  Similar for the function name bits, if we just keep the functions
> alive.  But what about line numbers?

If we store the JSScript anyway, we might as well store the jsbytecode *pc (or "uint32_t offset" if we don't want to expose jsbytecode). Then it's just a matter of calling PCToLineNumber(script, offset) once we add that function to the API.
(Reporter)

Comment 3

4 years ago
(In reply to Boris Zbarsky [:bz] from comment #1)
> That is, can we avoid the
> DescribeStack call somehow, or should we still do it but then pretty much
> try to do nothing else?

I think we still need it. But DescribeStack itself could also be a bit smarter, for instance we probably don't need that js_new<JS::StackDescription>() and the frames Vector could malloc/realloc less...
OK.  So in an ideal world, I think this would look like so:

1)  We still call DescribeStack.
2)  This hands back some data structure we can just trace or whatnot to keep the relevant
    bits alive.
3)  The data structure stores whatever it needs to store to produce the stack information
    on demand.
4)  When we need the stack information, we ask this data structure.

right?  So if the exception is caught and then ignored we only do the DescribeStack work.
So I just did a profile of the testcase in bug 922048, or rather one particular selector in it that throws.  I did that with the patch in bug 932870 applied.

About 21.8% of the time was spent under DocumebtBinding::genericMethod.  20.4% was under DocumentBinding::querySelectorAll.  Of that, 19.1% was under dom::Throw.  If I focus on dom::Throw, so that all percentages are of the time spent under there, I see:

 50% JS::DescribeStack.  This breaks down as:
  19% js::PCToLineNumber (almost entirely self time, and in particular at least half
      the SN_DELTA(), SN_IS_TERMINATOR(), SN_NEXT() bits).
  16% js::ScriptFrameIter::operator++ (mostly under InlineFrameIteratorMaybeGC::resetOn
      doing osiIndex, findNextFrame, ionScript(), etc).
  10% VectorBase::growStorageBy (looks like malloc and free; Vector never uses
      realloc???).

So yeah, nixing the malloc/realloc costs and the eager line number computations would help a good bit with that part.

We also have:

 8% malloc calls from JSStackFrame::CreateStack.
 5% nsMemory::Clone calls from the same.
 2% free() calls from the same.
 2% JS::FreeStackDescription calls from same.

Overall, 74% of the time under Throw() is under JSStackFrame::CreateStack.

Outside of that:

 6% the GetService call for nsXPConnect in dom::GetCurrentJSStack(!).  Filed bug 932886.
 1% NS_IsMainThread calls in the same place.
 2% dom::Exception::Initialize (mostly a GetFileName call on the JSStackFrame; why?).
    We should be able to do this stuff (getting the filename and lineno) lazily, I
    think.
 5-6% various call overhead, since the C++ stack here ends up 4-5 levels deep.
 8% under dom::ThrowExceptionObject.  This has 2% checks for system principal,
    3% creating the JS reflector for the C++ DOMException object, some more mainthread
    checks, etc.

We'll definitely want to at least change Initialize to not eagerly grab the filename/lineno if we make all that computation lazy.
Depends on: 932886
Some patches coming up that make the testcase in bug about 100ms faster for me.

They're not done yet, and in particular the tracing of the stack bits is not hooked up.  I'd appreciate it if someone more familiar with CC and Heap and such took a look at that part and made whatever changes we need to JS::StackDescription here.
Created attachment 8347903 [details] [diff] [review]
part 1.  Make FrameDescription compute the line number lazily.
Attachment #8347903 - Flags: review?(jdemooij)
Assignee: nobody → bzbarsky
Status: NEW → ASSIGNED
Created attachment 8347904 [details] [diff] [review]
part 2.  Create a refcounted object to manage the lifetime of a JS::StackDescription.
Created attachment 8347905 [details] [diff] [review]
part 3.  Make JSStackFrame get information from the JS stack lazily.
Attachment #8347905 - Flags: review?(khuey)
Attachment #8347904 - Flags: feedback?(terrence)
Attachment #8347904 - Flags: feedback?(khuey)
Created attachment 8347906 [details] [diff] [review]
part 4.  Allocate the caller JSStackFrames lazily.
Attachment #8347906 - Flags: review?(khuey)
Created attachment 8347907 [details] [diff] [review]
part 5.  Don't eagerly grab file/line info when constructing an Exception.

Kyle, is it ok to start using the filename/lineno of the location we picked up off the stack in the case when aLocation was null in Initialize?  If not, we can just add a boolean that tracks which codepath we took
Attachment #8347907 - Flags: review?(khuey)
Also, we should seriously think about converting this stuff to nsString and away from char*!

With the above patches, if I do something like comment 5 and focus on dom::Throw, we're up to 57% of the time under JS::DescriptStack and overall time has dropped by about 12%.
(Reporter)

Comment 13

4 years ago
Comment on attachment 8347903 [details] [diff] [review]
part 1.  Make FrameDescription compute the line number lazily.

Review of attachment 8347903 [details] [diff] [review]:
-----------------------------------------------------------------

Looks great, just some JS style nits. Thanks for doing this.

::: js/public/OldDebugAPI.h
@@ +33,2 @@
>  {
> +public:

Nit: indent the "public:" and "private:" labels in this class with two spaces.

@@ +40,5 @@
> +    {
> +    }
> +
> +    unsigned lineno()
> +    {

Nit: { can go after lineno(), so "unsigned lineno() {", same for script() and fun() below.

@@ +49,5 @@
> +        return lineno_;
> +    }
> +
> +    JSScript * script() const
> +    {

Nit: no space after *, same for fun() below.

@@ +60,5 @@
> +    }
> +
> +private:
> +    JSScript* script_;
> +    JSFunction* fun_;

Nit: * goes before script_ and fun_, like pc_ below.
Attachment #8347903 - Flags: review?(jdemooij) → review+
Comment on attachment 8347904 [details] [diff] [review]
part 2.  Create a refcounted object to manage the lifetime of a JS::StackDescription.

Review of attachment 8347904 [details] [diff] [review]:
-----------------------------------------------------------------

f=me We discussed on IRC and this strategy seems totally reasonable.
Attachment #8347904 - Flags: feedback?(terrence) → feedback+
Created attachment 8348307 [details] [diff] [review]
part 2.  Create a refcounted object to manage the lifetime of a JS::StackDescription.   terrence
Attachment #8348307 - Flags: review?(terrence)
Attachment #8348307 - Flags: review?(continuation)
Attachment #8347904 - Attachment is obsolete: true
Attachment #8347904 - Flags: feedback?(khuey)
Comment on attachment 8348307 [details] [diff] [review]
part 2.  Create a refcounted object to manage the lifetime of a JS::StackDescription.   terrence

Review of attachment 8348307 [details] [diff] [review]:
-----------------------------------------------------------------

This looks awesome! r=me
Attachment #8348307 - Flags: review?(terrence) → review+
Comment on attachment 8348307 [details] [diff] [review]
part 2.  Create a refcounted object to manage the lifetime of a JS::StackDescription.   terrence

Review of attachment 8348307 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/bindings/Exceptions.cpp
@@ +205,5 @@
>  
> +class StackDescriptionOwner {
> +public:
> +  StackDescriptionOwner(JS::StackDescription* aDescription)
> +    : mDescription(aDescription)

You need mozilla::HoldJSObjects(this) in the ctor and mozilla::DropJSObjects(this) in the dtor, so these DescriptionOwners will actually get registered as JS holders, which will make them get traced by the GC and CC.

This probably doesn't show up in testing because the lifetime of these objects is stack-limited.  The CC probably won't even run unless you get a nested event loop in there somehow.

I mean, really, you probably want some kind of Rooted<JS::StackDescription> class because this is stack-scoped, but that's going to be a whole other pile of macros to learn so this is fine with me.

::: js/src/vm/OldDebugAPI.cpp
@@ +990,5 @@
>  JS_PUBLIC_API(void)
>  JS::FreeStackDescription(JSContext *cx, JS::StackDescription *desc)
>  {
> +    for (size_t i = 0; i < desc->nframes; ++i)
> +        desc->frames[i].~FrameDescription();

Lovely. I guess this is what you get when you combine C and C++ code.

::: xpcom/glue/nsCycleCollectionParticipant.cpp
@@ +99,5 @@
>    mCallback(p->get(), name, closure);
>  }
> +
> +void
> +TraceCallbackFunc::Trace(JS::Heap<JSFunction*>* p, const char* name, void* closure) const

maybe put this next to the case for JSObject because it is also a JSObject and thus their definitions will look the same?
Attachment #8348307 - Flags: review?(terrence)
Attachment #8348307 - Flags: review?(continuation)
Attachment #8348307 - Flags: review+
Comment on attachment 8348307 [details] [diff] [review]
part 2.  Create a refcounted object to manage the lifetime of a JS::StackDescription.   terrence

I'm not sure what happened there.
Attachment #8348307 - Flags: review?(terrence)
> mozilla::HoldJSObjects(this) in the ctor and mozilla::DropJSObjects(this) in the dtor

Aha!  I knew I was missing something.

> because this is stack-scoped

The whole point of this bug is to stop it being stack-scoped.

> maybe put this next to the case for JSObject

Will do.
(In reply to Boris Zbarsky [:bz] from comment #19)
> The whole point of this bug is to stop it being stack-scoped.
Ah, great!  Sorry, for some reason I didn't notice this was only patch 2 and not the last patch.
Created attachment 8348344 [details] [diff] [review]
Part 2 updated to review comments
Attachment #8348307 - Attachment is obsolete: true
Created attachment 8348453 [details] [diff] [review]
part 3.  Make JSStackFrame get information from the JS stack lazily.
Attachment #8348453 - Flags: review?(khuey)
Attachment #8347905 - Attachment is obsolete: true
Attachment #8347905 - Flags: review?(khuey)
Created attachment 8348897 [details] [diff] [review]
Part 2 updated with some null-checks try caught
Attachment #8348344 - Attachment is obsolete: true
Created attachment 8348898 [details] [diff] [review]
Part 1 updated to review comments
Attachment #8347903 - Attachment is obsolete: true
Created attachment 8348899 [details] [diff] [review]
part 3.  Make JSStackFrame get information from the JS stack lazily.
Attachment #8348899 - Flags: review?(khuey)
Attachment #8348453 - Attachment is obsolete: true
Attachment #8348453 - Flags: review?(khuey)
Created attachment 8348900 [details] [diff] [review]
part 4.  Allocate the caller JSStackFrames lazily.
Attachment #8348900 - Flags: review?(khuey)
Attachment #8347906 - Attachment is obsolete: true
Attachment #8347906 - Flags: review?(khuey)
Depends on: 951511
Created attachment 8356109 [details]
Performance testcase
Comment on attachment 8348899 [details] [diff] [review]
part 3.  Make JSStackFrame get information from the JS stack lazily.

Review of attachment 8348899 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/bindings/Exceptions.cpp
@@ +308,5 @@
> +  size_t mIndex;
> +
> +  bool mFilenameValid;
> +  bool mFunnameValid;
> +  bool mLinenoValid;

nullptr and 0 are valid values.  I would call these mFooInitialized.

@@ +392,5 @@
> +      }
> +    }
> +    mFilenameValid = true;
> +  }
> +  return mFilename;

super-nit: \n before return

@@ +462,5 @@
> +    JS::FrameDescription& desc = mStackDescription->FrameAt(mIndex);
> +    mLineno = desc.lineno();
> +    mLinenoValid = true;
> +  }
> +  return mLineno;

here too

@@ +491,5 @@
>  NS_IMETHODIMP JSStackFrame::ToString(char** _retval)
>  {
>    const char* frametype = IsJSFrame() ? "JS" : "native";
> +  const char* filename = GetFilename() ? GetFilename() : "<unknown filename>";
> +  const char* funname = GetFunname() ? GetFunname() : "<TOP_LEVEL>";

Calling the function twice is kind of ugly.  Can we do

const char* foo = GetFoo();
if (!foo) {
  foo = "<default foo>";
}
?

@@ +521,4 @@
>  
> +  // We create one dummy frame at the end (why?), so go up through
> +  // desc->nframes+1
> +  for (size_t i = 0; i < desc->nframes+1; i++) {

super-nit: spaces around +

@@ +532,2 @@
>      }
> +    last.swap(frame);

\n after }
Attachment #8348899 - Flags: review?(khuey) → review+
Comment on attachment 8348900 [details] [diff] [review]
part 4.  Allocate the caller JSStackFrames lazily.

Review of attachment 8348900 [details] [diff] [review]:
-----------------------------------------------------------------

nice.
Attachment #8348900 - Flags: review?(khuey) → review+
Comment on attachment 8347907 [details] [diff] [review]
part 5.  Don't eagerly grab file/line info when constructing an Exception.

Review of attachment 8347907 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/base/DOMException.cpp
@@ +567,1 @@
>    return mLineNumber;

\n after }
Attachment #8347907 - Flags: review?(khuey) → review+
Some of the comments on part 3 are in code that is removed in part 4, so I guess you can just ignore those.
   https://hg.mozilla.org/integration/mozilla-inbound/rev/db68ac22b042
   https://hg.mozilla.org/integration/mozilla-inbound/rev/a3427a45608d
   https://hg.mozilla.org/integration/mozilla-inbound/rev/e0de03b97222
   https://hg.mozilla.org/integration/mozilla-inbound/rev/b6d1eaed0807
   https://hg.mozilla.org/integration/mozilla-inbound/rev/8e95a6fcee23

with the comments addressed.
Flags: in-testsuite-
Target Milestone: --- → mozilla29
Created attachment 8356995 [details] [diff] [review]
Followup fix for an issue that somehow got missed in the try runs I did
Attachment #8356995 - Flags: review?(bobbyholley+bmo)
I pushed that followup as https://hg.mozilla.org/integration/mozilla-inbound/rev/1ff331377910 to get the tree less orange and open.
Comment on attachment 8356995 [details] [diff] [review]
Followup fix for an issue that somehow got missed in the try runs I did

Review of attachment 8356995 [details] [diff] [review]:
-----------------------------------------------------------------

As discussed on IRC, this is ok for the interim, but we really should make sure that our pushing semantics are preserved.

bz is going to add a ThreadsafeAutoJSContext and ThreadsafeAutoSafeJSContext tomorrow.
Attachment #8356995 - Flags: review?(bobbyholley+bmo) → review+
https://hg.mozilla.org/mozilla-central/rev/db68ac22b042
https://hg.mozilla.org/mozilla-central/rev/a3427a45608d
https://hg.mozilla.org/mozilla-central/rev/e0de03b97222
https://hg.mozilla.org/mozilla-central/rev/b6d1eaed0807
https://hg.mozilla.org/mozilla-central/rev/8e95a6fcee23
https://hg.mozilla.org/mozilla-central/rev/1ff331377910
Status: ASSIGNED → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
> bz is going to add a ThreadsafeAutoJSContext and ThreadsafeAutoSafeJSContext tomorrow.

What's a few weeks between friends?  Bug 963895.

Updated

4 years ago
Whiteboard: [qa-]
You need to log in before you can comment on or make changes to this bug.