Closed Bug 403132 Opened 13 years ago Closed 12 years ago

DTrace function probes are double-counting invocations


(Core :: JavaScript Engine, defect)

Not set





(Reporter: myk, Assigned: sayrer)



(1 file, 3 obsolete files)

The js_calltime.d DTrace script in the DTrace Toolkit reports twice as many invocations of functions as are actually taking place, and the following script shows twice as many function entries/exits:

dtrace -Z -n 'javascript*:::function-entry,javascript*:::function-return { @[probename, copyinstr(arg2)] = count(); } END { printa(" %-16s %-32s %@8d\n", @); }'

I confirmed the problem by adding a dump statement to a function and counting the number of times the message in the statement appeared on the console.  It appeared half as many times as DTrace says the function was invoked.

I noticed this on Mac OS X, but bgregg said on IRC that he thinks this isn't platform specific and that "the probe macros in jsinterp.c may need to be juggled (again)".
It's not a problem with the placement in jsinterp.c.

I checked this by calling printf whenever we called function-entry/function-exit. The probe is only getting called once, but showing up twice in dtrace.
Attached file probes showing up twice (obsolete) —
OK, that's just the *enabled macros. 
Short story: It looks like there is a bug in the Apple linker involving its DTrace logic and -dead_strip.  If you rebuild libmozjs.dylib without "-Wl,-dead_strip", you should be golden.

Longer story:

I wrote a limited DOF parser (DTrace Object Format) and ran it against libmozjs.dylib.  As built by default (with -dead_strip), each probe offset or probe enable offset has twice as many entries as it 'should' show up.  (The offsets referenced by the dof_probe are sometimes duplicated outright, but may also be different.  However, I haven't 'pierced' that offset semantically, so the differing offsets may still be equivalent.)  'Should' in this case is compared against the baseline of linking without dead_strip...

There are two distinct code paths that detect the magic ___dtrace* symbols in the linker, depending on whether dead-strip is enabled.  I haven't learned enough about the linker logic to posit an actual cause with confidence, though I have suspicions that are probably wrong and so I won't mention them.

Possible solution:

A delightful Makefile hack that interposes a filter-out command to remove the dead_strip command, predicated on having dtrace probes enabled.  We could also fix Apple's linker or figure out how to structure things so as to not trigger the problem.  Those seem like more work, though.  We could also add a post-processing pass that corrects the resulting problems in the DOF, but that seems more evil than the Makefile solution.
The aforementioned 'possible solution'.  Since the -dead_strip comes from configure and the problem case is only when DTrace is involved, it doesn't make sense to do any global disabling of -dead_strip (at a configure level).  Having configure detect the -dead_strip problem seems wildly non-trivial, leaving some other centralization of logic in as the most obvious candidate for a better solution.  But the in question already is explicitly aware of the DTrace stuff going on, so I'm going to argue this is a reasonable fix for now.

My DOF reader code (python) is here:
Attachment #321461 - Flags: review?(crowder)
Attachment #321461 - Flags: review?(ted.mielczarek)
Attachment #321461 - Flags: review?(crowder)
Attachment #321461 - Flags: review+
Ugh. Can we detect the bug in gcc by version number or something? I'd be much happier with a configure test.
The configure test is easy.  For now, all versions of the linker (not gcc) that are capable of doing the DTrace magic should have the bug, which means OS X 10.5.*.  The issue is that I assume we don't want to turn off dead_strip for libraries that don't have DTrace probes, so the ideal configure solution would presumably also involve changes to to only disable dead_strip when DTrace is involved.  This would likely entail refactoring much of the DTrace logic in js/src/ into

Does that sound like a viable solution (configure detects the problem, have moot the flag when appropriate), or did you have something else in mind?
Maybe we should skip -dead_strip when building with DTrace. That's not such a big deal. I want to add other probes, in libxul. Anyone know of an Apple bug on this?
That works for me.
Attached patch disable -dead_strip in configure (obsolete) — Splinter Review
not sure if this is the right way to do it, but it seems to work
Assignee: general → sayrer
Attachment #324264 - Flags: review?(ted.mielczarek)
Comment on attachment 324264 [details] [diff] [review]
disable -dead_strip in configure

There's already an --enable-dtrace, maybe you missed it because it's AC_ARG_ENABLE (I have no idea why, probably some Sun guy's patch). Otherwise I basically approve of this patch.
Attachment #324264 - Flags: review?(ted.mielczarek) → review-
turns out my first patch doesn't link libxul. I fixed that, and I'm using the test from above. as soon as I get my mbp to wake up, I'll have a final patch.
Comment on attachment 321461 [details] [diff] [review]
filter-out dead_strip argument to LD for OS X with DTrace enabled

Waiting on sayrer's patch.
Attachment #321461 - Flags: review?(ted.mielczarek) → review-
Comment on attachment 301945 [details]
probes showing up twice

this is actually fine, it's in the object files that problem lies.
Attachment #301945 - Attachment is obsolete: true
Attachment #321461 - Attachment is obsolete: true
Attachment #324264 - Attachment is obsolete: true
Attached patch finalSplinter Review
Attachment #324291 - Flags: review?(ted.mielczarek)
Attachment #324291 - Flags: review?(ted.mielczarek) → review+
Closed: 12 years ago
Resolution: --- → FIXED
Thanks and great work for finding a fix!
Flags: in-testsuite-
Flags: in-litmus-
You need to log in before you can comment on or make changes to this bug.