DTrace function probes are double-counting invocations

RESOLVED FIXED

Status

()

RESOLVED FIXED
11 years ago
10 years ago

People

(Reporter: myk, Assigned: sayrer)

Tracking

unspecified
PowerPC
Mac OS X
Points:
---
Bug Flags:
in-testsuite -
in-litmus -

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 3 obsolete attachments)

(Reporter)

Description

11 years ago
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)".
(Assignee)

Comment 1

11 years ago
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.
(Assignee)

Comment 2

11 years ago
Created attachment 301945 [details]
probes showing up twice
(Assignee)

Comment 3

11 years ago
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.
Created attachment 321461 [details] [diff] [review]
filter-out dead_strip argument to LD for OS X with DTrace enabled

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 rules.mk as the most obvious candidate for a better solution.  But the Makefile.in 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: http://hg.mozilla.org/users/bugmail_asutherland.org/dofread/
Attachment #321461 - Flags: review?(crowder)

Updated

11 years ago
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 rules.mk to only disable dead_strip when DTrace is involved.  This would likely entail refactoring much of the DTrace logic in js/src/Makefile.in into rules.mk.

Does that sound like a viable solution (configure detects the problem, have rules.mk moot the flag when appropriate), or did you have something else in mind?
(Assignee)

Comment 8

10 years ago
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.
(Assignee)

Comment 10

10 years ago
Created attachment 324264 [details] [diff] [review]
disable -dead_strip in configure

not sure if this is the right way to do it, but it seems to work
Assignee: general → sayrer
Status: NEW → ASSIGNED
(Assignee)

Updated

10 years ago
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-
(Assignee)

Comment 12

10 years ago
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-
(Assignee)

Comment 14

10 years ago
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
(Assignee)

Updated

10 years ago
Attachment #321461 - Attachment is obsolete: true
(Assignee)

Updated

10 years ago
Attachment #324264 - Attachment is obsolete: true
(Assignee)

Comment 15

10 years ago
Created attachment 324291 [details] [diff] [review]
final
Attachment #324291 - Flags: review?(ted.mielczarek)
Attachment #324291 - Flags: review?(ted.mielczarek) → review+
(Assignee)

Updated

10 years ago
Status: ASSIGNED → RESOLVED
Last Resolved: 10 years ago
Resolution: --- → FIXED

Comment 16

10 years ago
Thanks and great work for finding a fix!

Updated

10 years ago
Flags: in-testsuite-
Flags: in-litmus-
You need to log in before you can comment on or make changes to this bug.