Under osx 10.6.5:
~ $ sudo dtrace -n ''pid$target:libc::entry { @[probefunc] = count();
}'' -c
date
Tue Dec 7 11:40:59 PST 2010
dtrace: invalid probe specifier pid$target:libc::entry { @[probefunc] count();
}: probe description pid94942:libc::entry does not match any probes
This is an example straight from the dtrace book which claims to test under
osx, so I''m guessing that something broke in osx?
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20101207/ff28d58b/attachment.html>
When you say "straight from the dtrace book", I assume you mean
the soon-to-be-published book?
If that is the case, please allow me to clarify. Not every invocation of dtrace,
both one-liners and scripts, that are in the book (and there are hundreds) is
tested and guaranteed to work under all three operating systems
(Solaris, OS X, FreeBSD). In fact, some will not work across different Solaris
releases, depending on (for example) which provider is used.
We are very clear in the book with our examples about the differences in
the underlying implementations. There are a great many scripts and one-liners
in the book that will only work on Solaris.
The good news is that, in addition to the actual examples, there is a lot of
emphasis on methodology in the book, such that you can use DTrace
to figure out which probes/modules, etc, you should be instrumenting
based on the problem you are trying to solve or what you are trying
to observe.
For example, if you change your D to;
pid$target:::entry { @[probemod] = count(); }''
You will see what the actual module names are available for you
to instrument.
Binaries on OS X link to libSystem.B.dylib for common functions.
Thanks
/jim
On Dec 7, 2010, at 3:09 PM, Hans Stimer wrote:
> Under osx 10.6.5:
>
> ~ $ sudo dtrace -n ''pid$target:libc::entry { @[probefunc] =
count(); }'' -c date
> Tue Dec 7 11:40:59 PST 2010
> dtrace: invalid probe specifier pid$target:libc::entry { @[probefunc] =
count(); }: probe description pid94942:libc::entry does not match any probes
>
> This is an example straight from the dtrace book which claims to test under
osx, so I''m guessing that something broke in osx?
> _______________________________________________
> dtrace-discuss mailing list
> dtrace-discuss at opensolaris.org
I am cross-posting back to dtrace-discuss, since the Apple folks listen... I''m not sure what your hello world program is doing. I tried the same thing with compiled C code. The problem I ran into with hello world, and with the date example, is the program is executing and completing before dtrace can instrument it. Adding a sleep(1); to the hello world program and I get expected output. This does not happen on Solaris. I expect it''s due to implementation differences in the pid provider between the operating systems. In any event, it seems on OS X using the pid provider on a binary the runs for less than a second does not give the pid provider time to instrument the code. That''s not necessarily an issue (at least for me), since I never need to chase performance problems on something that runs in a few hundred milliseconds.... ;^) /jim dtrace''ing hello world with a 1 second sleep; macosx> dtrace -n ''pid$target:::entry'' -c ./hw dtrace: description ''pid$target:::entry'' matched 7950 probes Hello World dtrace: pid 16109 has exited CPU ID FUNCTION:NAME 0 27974 ImageLoaderMachO::getExportedSymbolAddress(ImageLoader::Symbol const*, ImageLoader::LinkContext const&, ImageLoader const*) con:entry 0 27973 ImageLoaderMachO::getSymbolAddress(ImageLoader::Symbol const*, ImageLoader const*, ImageLoader::LinkContext const&) const:entry 0 28101 ImageLoaderMachOCompressed::exportedSymbolAddress(ImageLoader::Symbol const*) const:entry 0 27982 ImageLoaderMachO::bindLocation(ImageLoader::LinkContext const&, unsigned long, unsigned long, ImageLoader const*, unsigned char:entry 0 30491 puts:entry 0 28559 strlen:entry 0 28719 __sfvwrite:entry 0 29640 __swsetup:entry 0 28749 __sinit:entry 0 28571 sysconf:entry 0 28750 getrlimit:entry 0 28751 __getrlimit:entry 0 29641 __smakebuf:entry 0 29642 __swhatbuf:entry 0 28684 fstat$INODE64:entry 0 29812 isatty:entry 0 28723 ioctl:entry 0 28724 __ioctl:entry 0 28549 malloc:entry 0 28574 malloc_zone_malloc:entry 0 28575 szone_malloc:entry 0 28576 szone_malloc_should_clear:entry 0 28640 small_malloc_from_free_list:entry 0 28553 allocate_pages:entry 0 28554 mmap:entry 0 28555 __mmap:entry 0 28578 munmap:entry 0 28578 munmap:entry 0 29393 memchr:entry 0 28523 memcpy:entry 0 29393 memchr:entry 0 28523 memcpy:entry 0 29719 __fflush:entry 0 29643 __sflush:entry 0 29644 _swrite:entry 0 29645 __swrite:entry 0 29646 write$NOCANCEL:entry 0 28463 stub helpers:entry 0 51054 dyld_stub_binder:entry 0 28697 _dyld_fast_stub_entry(void*, long):entry 0 27717 dyld::fastBindLazySymbol(ImageLoader**, unsigned long):entry 0 28106 ImageLoaderMachOCompressed::doBindFastLazySymbol(unsigned int, ImageLoader::LinkContext const&):entry 0 28010 ImageLoaderMachO::segActualLoadAddress(unsigned int) const:entry 0 28074 ImageLoaderMachOCompressed::segmentCommandOffsets() const:entry 0 28090 ImageLoaderMachOCompressed::resolve(ImageLoader::LinkContext const&, char const*, unsigned char, int, ImageLoader const**, Imag:entry 0 28075 ImageLoaderMachOCompressed::libImage(unsigned int) const:entry 0 28088 ImageLoaderMachOCompressed::resolveTwolevel(ImageLoader::LinkContext const&, ImageLoader const*, bool, char const*, ImageLoader:entry 0 28002 ImageLoaderMachO::findExportedSymbol(char const*, bool, ImageLoader const**) const:entry 0 28102 ImageLoaderMachOCompressed::findExportedSymbol(char const*, ImageLoader const**) const:entry 0 27974 ImageLoaderMachO::getExportedSymbolAddress(ImageLoader::Symbol const*, ImageLoader::LinkContext const&, ImageLoader const*) con:entry 0 27973 ImageLoaderMachO::getSymbolAddress(ImageLoader::Symbol const*, ImageLoader const*, ImageLoader::LinkContext const&) const:entry 0 28101 ImageLoaderMachOCompressed::exportedSymbolAddress(ImageLoader::Symbol const*) const:entry 0 27982 ImageLoaderMachO::bindLocation(ImageLoader::LinkContext const&, unsigned long, unsigned long, ImageLoader const*, unsigned char:entry 0 28726 exit:entry 0 28727 __cxa_finalize:entry 0 27719 dyld::runTerminators(void*):entry 0 27701 dyld::notifyBatchPartial(dyld_image_states, bool, char const* (*)(dyld_image_states, unsigned int, dyld_image_info const*)):entry 0 28728 pthread_key_delete:entry 0 126037 __tcf_0:entry 0 29716 _cleanup:entry 0 29717 _fwalk:entry 0 29643 __sflush:entry 0 29643 __sflush:entry 0 29643 __sflush:entry 0 28729 _exit:entry 2 50753 cerror:entry 2 28752 cthread_set_errno_self:entry 2 28614 __error:entry 2 28614 __error:entry 2 28463 stub helpers:entry 2 51054 dyld_stub_binder:entry 2 28697 _dyld_fast_stub_entry(void*, long):entry 2 27717 dyld::fastBindLazySymbol(ImageLoader**, unsigned long):entry 2 28106 ImageLoaderMachOCompressed::doBindFastLazySymbol(unsigned int, ImageLoader::LinkContext const&):entry 2 28010 ImageLoaderMachO::segActualLoadAddress(unsigned int) const:entry 2 28074 ImageLoaderMachOCompressed::segmentCommandOffsets() const:entry 2 28090 ImageLoaderMachOCompressed::resolve(ImageLoader::LinkContext const&, char const*, unsigned char, int, ImageLoader const**, Imag:entry 2 28075 ImageLoaderMachOCompressed::libImage(unsigned int) const:entry 2 28088 ImageLoaderMachOCompressed::resolveTwolevel(ImageLoader::LinkContext const&, ImageLoader const*, bool, char const*, ImageLoader:entry 2 28002 ImageLoaderMachO::findExportedSymbol(char const*, bool, ImageLoader const**) const:entry 2 28102 ImageLoaderMachOCompressed::findExportedSymbol(char const*, ImageLoader const**) const:entry On Dec 7, 2010, at 5:09 PM, Hans Stimer wrote:> Thank you for the quick response. I tried a number of things and got some interesting results. In short: > > 1) pid doesn''t work with -c date, but does seem to work with other executables. On osx date is an executable and not a script or built in. > 2) pid doesn''t let you instrument all entries; I created a hello world program and dtrace didn''t return for over 5 minutes > > * Modify to point to hello world program: > $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c ./out > dtrace: description ''pid$target:::entry '' matched 7947 probes > ^C > I gave it over 5 minutes and it didn''t return > > * Trace everything connected to date: > $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c date > Tue Dec 7 13:49:34 PST 2010 > dtrace: invalid probe specifier pid$target:::entry { trace(arg0); }: failed to create entry probe for ''stub_binding_helper'': No such process > > * Find entry points for date > $ sudo dtrace -ln ''pid$target:::entry,pid$target:::return'' -c date > Tue Dec 7 13:52:55 PST 2010 > dtrace: invalid probe specifier pid$target:::entry,pid$target:::return: failed to create entry probe for ''stub_binding_helper'': No such process > > * Find entry points for hello world program: > $ sudo dtrace -ln ''pid$target:::entry,pid$target:::return'' -c ./out > ID PROVIDER MODULE FUNCTION NAME > 144623 pid95634 dyld stub_binding_helper entry > 144624 pid95634 dyld dyld_func_lookup entry > 144625 pid95634 dyld offset_to_dyld_all_image_infos entry > 144626 pid95634 dyld _dyld_start entry > 144627 pid95634 dyld dyld_fatal_error entry > . > . > . > > * Find entry points for top: > $ sudo dtrace -ln ''pid$target:::entry,pid$target:::return'' -c top > ID PROVIDER MODULE FUNCTION NAME > 36684 pid95691 dyld _dyld_start entry > 36685 pid95691 dyld std::vector<dyld_image_info, std::allocator<dyld_image_info> >::erase(__gnu_cxx::__normal_iterator<dyld_image_info*, std::vecto entry > 36686 pid95691 dyld std::_Vector_base<dyld_image_info, std::allocator<dyld_image_info> >::~_Vector_base() entry > 36687 pid95691 dyld dyld_fatal_error entry > . > . > . > > > > On Tue, Dec 7, 2010 at 12:27 PM, Jim Mauro <james.mauro at oracle.com> wrote: > > When you say "straight from the dtrace book", I assume you mean > the soon-to-be-published book? > > If that is the case, please allow me to clarify. Not every invocation of dtrace, > both one-liners and scripts, that are in the book (and there are hundreds) is > tested and guaranteed to work under all three operating systems > (Solaris, OS X, FreeBSD). In fact, some will not work across different Solaris > releases, depending on (for example) which provider is used. > > We are very clear in the book with our examples about the differences in > the underlying implementations. There are a great many scripts and one-liners > in the book that will only work on Solaris. > > The good news is that, in addition to the actual examples, there is a lot of > emphasis on methodology in the book, such that you can use DTrace > to figure out which probes/modules, etc, you should be instrumenting > based on the problem you are trying to solve or what you are trying > to observe. > > For example, if you change your D to; > > pid$target:::entry { @[probemod] = count(); }'' > > You will see what the actual module names are available for you > to instrument. > > Binaries on OS X link to libSystem.B.dylib for common functions. > > Thanks > /jim > > On Dec 7, 2010, at 3:09 PM, Hans Stimer wrote: > > > Under osx 10.6.5: > > > > ~ $ sudo dtrace -n ''pid$target:libc::entry { @[probefunc] = count(); }'' -c date > > Tue Dec 7 11:40:59 PST 2010 > > dtrace: invalid probe specifier pid$target:libc::entry { @[probefunc] = count(); }: probe description pid94942:libc::entry does not match any probes > > > > This is an example straight from the dtrace book which claims to test under osx, so I''m guessing that something broke in osx? > > _______________________________________________ > > dtrace-discuss mailing list > > dtrace-discuss at opensolaris.org > >-------------- next part -------------- An HTML attachment was scrubbed... URL: <http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20101207/b27d4db1/attachment-0001.html>
Interesting. My expectation was that it would work like gdb i.e. that the
app would not run until gdb was in full control. For me, -c implies that
behavior.
I tried putting in a sleep for 10 seconds; still nothing:
$ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c
./out
On Tue, Dec 7, 2010 at 6:53 PM, Jim Mauro <james.mauro at oracle.com>
wrote:
>
> I am cross-posting back to dtrace-discuss, since the Apple folks listen...
>
> I''m not sure what your hello world program is doing. I tried the
same thing
> with compiled C code.
>
> The problem I ran into with hello world, and with the date example, is
> the program is executing and completing before dtrace can
> instrument it. Adding a sleep(1); to the hello world program and
> I get expected output.
>
> This does not happen on Solaris. I expect it''s due to
implementation
> differences in the pid provider between the operating systems.
>
> In any event, it seems on OS X using the pid provider on a binary
> the runs for less than a second does not give the pid provider
> time to instrument the code.
>
> That''s not necessarily an issue (at least for me), since I never
need
> to chase performance problems on something that runs in
> a few hundred milliseconds....
>
> ;^)
>
> /jim
>
> dtrace''ing hello world with a 1 second sleep;
>
> macosx> dtrace -n ''pid$target:::entry'' -c ./hw
> dtrace: description ''pid$target:::entry'' matched 7950
probes
> Hello World
> dtrace: pid 16109 has exited
> CPU ID FUNCTION:NAME
> 0 27974 ImageLoaderMachO::getExportedSymbolAddress(ImageLoader::Symbol
> const*, ImageLoader::LinkContext const&, ImageLoader const*) con:entry
> 0 27973 ImageLoaderMachO::getSymbolAddress(ImageLoader::Symbol const*,
> ImageLoader const*, ImageLoader::LinkContext const&) const:entry
> 0 28101
> ImageLoaderMachOCompressed::exportedSymbolAddress(ImageLoader::Symbol
> const*) const:entry
> 0 27982 ImageLoaderMachO::bindLocation(ImageLoader::LinkContext
const&,
> unsigned long, unsigned long, ImageLoader const*, unsigned char:entry
> 0 30491 puts:entry
> 0 28559 strlen:entry
> 0 28719 __sfvwrite:entry
> 0 29640 __swsetup:entry
> 0 28749 __sinit:entry
> 0 28571 sysconf:entry
> 0 28750 getrlimit:entry
> 0 28751 __getrlimit:entry
> 0 29641 __smakebuf:entry
> 0 29642 __swhatbuf:entry
> 0 28684 fstat$INODE64:entry
> 0 29812 isatty:entry
> 0 28723 ioctl:entry
> 0 28724 __ioctl:entry
> 0 28549 malloc:entry
> 0 28574 malloc_zone_malloc:entry
> 0 28575 szone_malloc:entry
> 0 28576 szone_malloc_should_clear:entry
> 0 28640 small_malloc_from_free_list:entry
> 0 28553 allocate_pages:entry
> 0 28554 mmap:entry
> 0 28555 __mmap:entry
> 0 28578 munmap:entry
> 0 28578 munmap:entry
> 0 29393 memchr:entry
> 0 28523 memcpy:entry
> 0 29393 memchr:entry
> 0 28523 memcpy:entry
> 0 29719 __fflush:entry
> 0 29643 __sflush:entry
> 0 29644 _swrite:entry
> 0 29645 __swrite:entry
> 0 29646 write$NOCANCEL:entry
> 0 28463 stub helpers:entry
> 0 51054 dyld_stub_binder:entry
> 0 28697 _dyld_fast_stub_entry(void*, long):entry
> 0 27717 dyld::fastBindLazySymbol(ImageLoader**, unsigned long):entry
> 0 28106 ImageLoaderMachOCompressed::doBindFastLazySymbol(unsigned int,
> ImageLoader::LinkContext const&):entry
> 0 28010 ImageLoaderMachO::segActualLoadAddress(unsigned int)
> const:entry
> 0 28074 ImageLoaderMachOCompressed::segmentCommandOffsets() const:entry
> 0 28090 ImageLoaderMachOCompressed::resolve(ImageLoader::LinkContext
> const&, char const*, unsigned char, int, ImageLoader const**,
Imag:entry
> 0 28075 ImageLoaderMachOCompressed::libImage(unsigned int) const:entry
> 0 28088
> ImageLoaderMachOCompressed::resolveTwolevel(ImageLoader::LinkContext
const&,
> ImageLoader const*, bool, char const*, ImageLoader:entry
> 0 28002 ImageLoaderMachO::findExportedSymbol(char const*, bool,
> ImageLoader const**) const:entry
> 0 28102 ImageLoaderMachOCompressed::findExportedSymbol(char const*,
> ImageLoader const**) const:entry
> 0 27974 ImageLoaderMachO::getExportedSymbolAddress(ImageLoader::Symbol
> const*, ImageLoader::LinkContext const&, ImageLoader const*) con:entry
> 0 27973 ImageLoaderMachO::getSymbolAddress(ImageLoader::Symbol const*,
> ImageLoader const*, ImageLoader::LinkContext const&) const:entry
> 0 28101
> ImageLoaderMachOCompressed::exportedSymbolAddress(ImageLoader::Symbol
> const*) const:entry
> 0 27982 ImageLoaderMachO::bindLocation(ImageLoader::LinkContext
const&,
> unsigned long, unsigned long, ImageLoader const*, unsigned char:entry
> 0 28726 exit:entry
> 0 28727 __cxa_finalize:entry
> 0 27719 dyld::runTerminators(void*):entry
> 0 27701 dyld::notifyBatchPartial(dyld_image_states, bool, char const*
> (*)(dyld_image_states, unsigned int, dyld_image_info const*)):entry
> 0 28728 pthread_key_delete:entry
> 0 126037 __tcf_0:entry
> 0 29716 _cleanup:entry
> 0 29717 _fwalk:entry
> 0 29643 __sflush:entry
> 0 29643 __sflush:entry
> 0 29643 __sflush:entry
> 0 28729 _exit:entry
> 2 50753 cerror:entry
> 2 28752 cthread_set_errno_self:entry
> 2 28614 __error:entry
> 2 28614 __error:entry
> 2 28463 stub helpers:entry
> 2 51054 dyld_stub_binder:entry
> 2 28697 _dyld_fast_stub_entry(void*, long):entry
> 2 27717 dyld::fastBindLazySymbol(ImageLoader**, unsigned long):entry
> 2 28106 ImageLoaderMachOCompressed::doBindFastLazySymbol(unsigned int,
> ImageLoader::LinkContext const&):entry
> 2 28010 ImageLoaderMachO::segActualLoadAddress(unsigned int)
> const:entry
> 2 28074 ImageLoaderMachOCompressed::segmentCommandOffsets() const:entry
> 2 28090 ImageLoaderMachOCompressed::resolve(ImageLoader::LinkContext
> const&, char const*, unsigned char, int, ImageLoader const**,
Imag:entry
> 2 28075 ImageLoaderMachOCompressed::libImage(unsigned int) const:entry
> 2 28088
> ImageLoaderMachOCompressed::resolveTwolevel(ImageLoader::LinkContext
const&,
> ImageLoader const*, bool, char const*, ImageLoader:entry
> 2 28002 ImageLoaderMachO::findExportedSymbol(char const*, bool,
> ImageLoader const**) const:entry
> 2 28102 ImageLoaderMachOCompressed::findExportedSymbol(char const*,
> ImageLoader const**) const:entry
>
> On Dec 7, 2010, at 5:09 PM, Hans Stimer wrote:
>
> Thank you for the quick response. I tried a number of things and got some
> interesting results. In short:
>
> 1) pid doesn''t work with -c date, but does seem to work with other
> executables. On osx date is an executable and not a script or built in.
> 2) pid doesn''t let you instrument all entries; I created a hello
world
> program and dtrace didn''t return for over 5 minutes
>
> * Modify to point to hello world program:
> $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c
./out
> dtrace: description ''pid$target:::entry '' matched 7947
probes
> ^C
> I gave it over 5 minutes and it didn''t return
>
> * Trace everything connected to date:
> $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c
date
> Tue Dec 7 13:49:34 PST 2010
> dtrace: invalid probe specifier pid$target:::entry { trace(arg0); }: failed
> to create entry probe for ''stub_binding_helper'': No such
process
>
> * Find entry points for date
> $ sudo dtrace -ln
''pid$target:::entry,pid$target:::return'' -c date
> Tue Dec 7 13:52:55 PST 2010
> dtrace: invalid probe specifier pid$target:::entry,pid$target:::return:
> failed to create entry probe for ''stub_binding_helper'':
No such process
>
> * Find entry points for hello world program:
> $ sudo dtrace -ln
''pid$target:::entry,pid$target:::return'' -c ./out
> ID PROVIDER MODULE FUNCTION NAME
> 144623 pid95634 dyld stub_binding_helper entry
> 144624 pid95634 dyld dyld_func_lookup entry
> 144625 pid95634 dyld offset_to_dyld_all_image_infos entry
> 144626 pid95634 dyld _dyld_start entry
> 144627 pid95634 dyld dyld_fatal_error entry
> .
> .
> .
>
> * Find entry points for top:
> $ sudo dtrace -ln
''pid$target:::entry,pid$target:::return'' -c top
> ID PROVIDER MODULE FUNCTION NAME
> 36684 pid95691 dyld _dyld_start entry
> 36685 pid95691 dyld std::vector<dyld_image_info,
> std::allocator<dyld_image_info>
> >::erase(__gnu_cxx::__normal_iterator<dyld_image_info*, std::vecto
entry
> 36686 pid95691 dyld std::_Vector_base<dyld_image_info,
> std::allocator<dyld_image_info> >::~_Vector_base() entry
> 36687 pid95691 dyld dyld_fatal_error entry
> .
> .
> .
>
>
>
> On Tue, Dec 7, 2010 at 12:27 PM, Jim Mauro <james.mauro at
oracle.com> wrote:
>
>>
>> When you say "straight from the dtrace book", I assume you
mean
>> the soon-to-be-published book?
>>
>> If that is the case, please allow me to clarify. Not every invocation
of
>> dtrace,
>> both one-liners and scripts, that are in the book (and there are
hundreds)
>> is
>> tested and guaranteed to work under all three operating systems
>> (Solaris, OS X, FreeBSD). In fact, some will not work across different
>> Solaris
>> releases, depending on (for example) which provider is used.
>>
>> We are very clear in the book with our examples about the differences
in
>> the underlying implementations. There are a great many scripts and
>> one-liners
>> in the book that will only work on Solaris.
>>
>> The good news is that, in addition to the actual examples, there is a
lot
>> of
>> emphasis on methodology in the book, such that you can use DTrace
>> to figure out which probes/modules, etc, you should be instrumenting
>> based on the problem you are trying to solve or what you are trying
>> to observe.
>>
>> For example, if you change your D to;
>>
>> pid$target:::entry { @[probemod] = count(); }''
>>
>> You will see what the actual module names are available for you
>> to instrument.
>>
>> Binaries on OS X link to libSystem.B.dylib for common functions.
>>
>> Thanks
>> /jim
>>
>> On Dec 7, 2010, at 3:09 PM, Hans Stimer wrote:
>>
>> > Under osx 10.6.5:
>> >
>> > ~ $ sudo dtrace -n ''pid$target:libc::entry { @[probefunc]
= count(); }''
>> -c date
>> > Tue Dec 7 11:40:59 PST 2010
>> > dtrace: invalid probe specifier pid$target:libc::entry {
@[probefunc] >> count(); }: probe description pid94942:libc::entry does
not match any probes
>> >
>> > This is an example straight from the dtrace book which claims to
test
>> under osx, so I''m guessing that something broke in osx?
>> > _______________________________________________
>> > dtrace-discuss mailing list
>> > dtrace-discuss at opensolaris.org
>>
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20101207/da8ba8c9/attachment-0001.html>
Hans, This is a bug in the OS X dtrace: <rdar://problem/7037927> Dtrace finishes execution of binary before creating probes when using -c option There is a "workaround" of sorts, which is adding the following flags: -xevaltime=exec -Z That tells dtrace to start tracing from the very beginning of the target process spawn, which is why you need the -Z flag, because the process will not have loaded any libraries at that time, and normally probes won''t be matching that are expected to match. In your case, using pid$target:::entry, you might get away with the -Z flag :-) James M On Dec 7, 2010, at 8:28 PM, Hans Stimer wrote:> Interesting. My expectation was that it would work like gdb i.e. that the app would not run until gdb was in full control. For me, -c implies that behavior. > > I tried putting in a sleep for 10 seconds; still nothing: > > $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c ./out > > On Tue, Dec 7, 2010 at 6:53 PM, Jim Mauro <james.mauro at oracle.com> wrote: > > I am cross-posting back to dtrace-discuss, since the Apple folks listen... > > I''m not sure what your hello world program is doing. I tried the same thing > with compiled C code. > > The problem I ran into with hello world, and with the date example, is > the program is executing and completing before dtrace can > instrument it. Adding a sleep(1); to the hello world program and > I get expected output. > > This does not happen on Solaris. I expect it''s due to implementation > differences in the pid provider between the operating systems. > > In any event, it seems on OS X using the pid provider on a binary > the runs for less than a second does not give the pid provider > time to instrument the code. > > That''s not necessarily an issue (at least for me), since I never need > to chase performance problems on something that runs in > a few hundred milliseconds.... > > ;^) > > /jim > > dtrace''ing hello world with a 1 second sleep; > > macosx> dtrace -n ''pid$target:::entry'' -c ./hw > dtrace: description ''pid$target:::entry'' matched 7950 probes > Hello World > dtrace: pid 16109 has exited > CPU ID FUNCTION:NAME > 0 27974 ImageLoaderMachO::getExportedSymbolAddress(ImageLoader::Symbol const*, ImageLoader::LinkContext const&, ImageLoader const*) con:entry > 0 27973 ImageLoaderMachO::getSymbolAddress(ImageLoader::Symbol const*, ImageLoader const*, ImageLoader::LinkContext const&) const:entry > 0 28101 ImageLoaderMachOCompressed::exportedSymbolAddress(ImageLoader::Symbol const*) const:entry > 0 27982 ImageLoaderMachO::bindLocation(ImageLoader::LinkContext const&, unsigned long, unsigned long, ImageLoader const*, unsigned char:entry > 0 30491 puts:entry > 0 28559 strlen:entry > 0 28719 __sfvwrite:entry > 0 29640 __swsetup:entry > 0 28749 __sinit:entry > 0 28571 sysconf:entry > 0 28750 getrlimit:entry > 0 28751 __getrlimit:entry > 0 29641 __smakebuf:entry > 0 29642 __swhatbuf:entry > 0 28684 fstat$INODE64:entry > 0 29812 isatty:entry > 0 28723 ioctl:entry > 0 28724 __ioctl:entry > 0 28549 malloc:entry > 0 28574 malloc_zone_malloc:entry > 0 28575 szone_malloc:entry > 0 28576 szone_malloc_should_clear:entry > 0 28640 small_malloc_from_free_list:entry > 0 28553 allocate_pages:entry > 0 28554 mmap:entry > 0 28555 __mmap:entry > 0 28578 munmap:entry > 0 28578 munmap:entry > 0 29393 memchr:entry > 0 28523 memcpy:entry > 0 29393 memchr:entry > 0 28523 memcpy:entry > 0 29719 __fflush:entry > 0 29643 __sflush:entry > 0 29644 _swrite:entry > 0 29645 __swrite:entry > 0 29646 write$NOCANCEL:entry > 0 28463 stub helpers:entry > 0 51054 dyld_stub_binder:entry > 0 28697 _dyld_fast_stub_entry(void*, long):entry > 0 27717 dyld::fastBindLazySymbol(ImageLoader**, unsigned long):entry > 0 28106 ImageLoaderMachOCompressed::doBindFastLazySymbol(unsigned int, ImageLoader::LinkContext const&):entry > 0 28010 ImageLoaderMachO::segActualLoadAddress(unsigned int) const:entry > 0 28074 ImageLoaderMachOCompressed::segmentCommandOffsets() const:entry > 0 28090 ImageLoaderMachOCompressed::resolve(ImageLoader::LinkContext const&, char const*, unsigned char, int, ImageLoader const**, Imag:entry > 0 28075 ImageLoaderMachOCompressed::libImage(unsigned int) const:entry > 0 28088 ImageLoaderMachOCompressed::resolveTwolevel(ImageLoader::LinkContext const&, ImageLoader const*, bool, char const*, ImageLoader:entry > 0 28002 ImageLoaderMachO::findExportedSymbol(char const*, bool, ImageLoader const**) const:entry > 0 28102 ImageLoaderMachOCompressed::findExportedSymbol(char const*, ImageLoader const**) const:entry > 0 27974 ImageLoaderMachO::getExportedSymbolAddress(ImageLoader::Symbol const*, ImageLoader::LinkContext const&, ImageLoader const*) con:entry > 0 27973 ImageLoaderMachO::getSymbolAddress(ImageLoader::Symbol const*, ImageLoader const*, ImageLoader::LinkContext const&) const:entry > 0 28101 ImageLoaderMachOCompressed::exportedSymbolAddress(ImageLoader::Symbol const*) const:entry > 0 27982 ImageLoaderMachO::bindLocation(ImageLoader::LinkContext const&, unsigned long, unsigned long, ImageLoader const*, unsigned char:entry > 0 28726 exit:entry > 0 28727 __cxa_finalize:entry > 0 27719 dyld::runTerminators(void*):entry > 0 27701 dyld::notifyBatchPartial(dyld_image_states, bool, char const* (*)(dyld_image_states, unsigned int, dyld_image_info const*)):entry > 0 28728 pthread_key_delete:entry > 0 126037 __tcf_0:entry > 0 29716 _cleanup:entry > 0 29717 _fwalk:entry > 0 29643 __sflush:entry > 0 29643 __sflush:entry > 0 29643 __sflush:entry > 0 28729 _exit:entry > 2 50753 cerror:entry > 2 28752 cthread_set_errno_self:entry > 2 28614 __error:entry > 2 28614 __error:entry > 2 28463 stub helpers:entry > 2 51054 dyld_stub_binder:entry > 2 28697 _dyld_fast_stub_entry(void*, long):entry > 2 27717 dyld::fastBindLazySymbol(ImageLoader**, unsigned long):entry > 2 28106 ImageLoaderMachOCompressed::doBindFastLazySymbol(unsigned int, ImageLoader::LinkContext const&):entry > 2 28010 ImageLoaderMachO::segActualLoadAddress(unsigned int) const:entry > 2 28074 ImageLoaderMachOCompressed::segmentCommandOffsets() const:entry > 2 28090 ImageLoaderMachOCompressed::resolve(ImageLoader::LinkContext const&, char const*, unsigned char, int, ImageLoader const**, Imag:entry > 2 28075 ImageLoaderMachOCompressed::libImage(unsigned int) const:entry > 2 28088 ImageLoaderMachOCompressed::resolveTwolevel(ImageLoader::LinkContext const&, ImageLoader const*, bool, char const*, ImageLoader:entry > 2 28002 ImageLoaderMachO::findExportedSymbol(char const*, bool, ImageLoader const**) const:entry > 2 28102 ImageLoaderMachOCompressed::findExportedSymbol(char const*, ImageLoader const**) const:entry > > On Dec 7, 2010, at 5:09 PM, Hans Stimer wrote: > >> Thank you for the quick response. I tried a number of things and got some interesting results. In short: >> >> 1) pid doesn''t work with -c date, but does seem to work with other executables. On osx date is an executable and not a script or built in. >> 2) pid doesn''t let you instrument all entries; I created a hello world program and dtrace didn''t return for over 5 minutes >> >> * Modify to point to hello world program: >> $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c ./out >> dtrace: description ''pid$target:::entry '' matched 7947 probes >> ^C >> I gave it over 5 minutes and it didn''t return >> >> * Trace everything connected to date: >> $ sudo dtrace -n ''pid$target:::entry { trace(arg0); }'' -c date >> Tue Dec 7 13:49:34 PST 2010 >> dtrace: invalid probe specifier pid$target:::entry { trace(arg0); }: failed to create entry probe for ''stub_binding_helper'': No such process >> >> * Find entry points for date >> $ sudo dtrace -ln ''pid$target:::entry,pid$target:::return'' -c date >> Tue Dec 7 13:52:55 PST 2010 >> dtrace: invalid probe specifier pid$target:::entry,pid$target:::return: failed to create entry probe for ''stub_binding_helper'': No such process >> >> * Find entry points for hello world program: >> $ sudo dtrace -ln ''pid$target:::entry,pid$target:::return'' -c ./out >> ID PROVIDER MODULE FUNCTION NAME >> 144623 pid95634 dyld stub_binding_helper entry >> 144624 pid95634 dyld dyld_func_lookup entry >> 144625 pid95634 dyld offset_to_dyld_all_image_infos entry >> 144626 pid95634 dyld _dyld_start entry >> 144627 pid95634 dyld dyld_fatal_error entry >> . >> . >> . >> >> * Find entry points for top: >> $ sudo dtrace -ln ''pid$target:::entry,pid$target:::return'' -c top >> ID PROVIDER MODULE FUNCTION NAME >> 36684 pid95691 dyld _dyld_start entry >> 36685 pid95691 dyld std::vector<dyld_image_info, std::allocator<dyld_image_info> >::erase(__gnu_cxx::__normal_iterator<dyld_image_info*, std::vecto entry >> 36686 pid95691 dyld std::_Vector_base<dyld_image_info, std::allocator<dyld_image_info> >::~_Vector_base() entry >> 36687 pid95691 dyld dyld_fatal_error entry >> . >> . >> . >> >> >> >> On Tue, Dec 7, 2010 at 12:27 PM, Jim Mauro <james.mauro at oracle.com> wrote: >> >> When you say "straight from the dtrace book", I assume you mean >> the soon-to-be-published book? >> >> If that is the case, please allow me to clarify. Not every invocation of dtrace, >> both one-liners and scripts, that are in the book (and there are hundreds) is >> tested and guaranteed to work under all three operating systems >> (Solaris, OS X, FreeBSD). In fact, some will not work across different Solaris >> releases, depending on (for example) which provider is used. >> >> We are very clear in the book with our examples about the differences in >> the underlying implementations. There are a great many scripts and one-liners >> in the book that will only work on Solaris. >> >> The good news is that, in addition to the actual examples, there is a lot of >> emphasis on methodology in the book, such that you can use DTrace >> to figure out which probes/modules, etc, you should be instrumenting >> based on the problem you are trying to solve or what you are trying >> to observe. >> >> For example, if you change your D to; >> >> pid$target:::entry { @[probemod] = count(); }'' >> >> You will see what the actual module names are available for you >> to instrument. >> >> Binaries on OS X link to libSystem.B.dylib for common functions. >> >> Thanks >> /jim >> >> On Dec 7, 2010, at 3:09 PM, Hans Stimer wrote: >> >> > Under osx 10.6.5: >> > >> > ~ $ sudo dtrace -n ''pid$target:libc::entry { @[probefunc] = count(); }'' -c date >> > Tue Dec 7 11:40:59 PST 2010 >> > dtrace: invalid probe specifier pid$target:libc::entry { @[probefunc] = count(); }: probe description pid94942:libc::entry does not match any probes >> > >> > This is an example straight from the dtrace book which claims to test under osx, so I''m guessing that something broke in osx? >> > _______________________________________________ >> > dtrace-discuss mailing list >> > dtrace-discuss at opensolaris.org >> >> > > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org-------------- next part -------------- An HTML attachment was scrubbed... URL: <http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20101208/09906d0c/attachment-0001.html>