If I run a very simple C++ programme and trace calls the malloc as shown below
the output shows that the stack is inside libc.so.1 whenever malloc is called.
dtrace -c "a.out" -n ''pid$target:libc:malloc:entry
{ustack();}''
dtrace: description ''pid$target:libc:malloc:entry '' matched 1
probe
CPU ID FUNCTION:NAME
0 48927 malloc:entry
libc.so.1`malloc
libCrun.so.1`void*operator new(unsigned)+0x2c
libCstd.so.1`void std::locale::init()+0x34
libCstd.so.1`std::istream::basic_istream(std::ios_base::EmptyCtor)+0x84
libCstd.so.1`__SLIP.INIT_A+0x4c
libCstd.so.1`void __STATIC_CONSTRUCTOR()+0x4
libCstd.so.1`_init+0x1e0
ld.so.1`call_init+0x1a0
ld.so.1`elf_bndr+0x420
ld.so.1`elf_rtbndr+0x10
libCrun.so.1`0xff1ea8ac
libCrun.so.1`void __Cimpl::cplus_init()+0x48
libCrun.so.1`_init+0xc8
ld.so.1`call_init+0x1a0
ld.so.1`elf_bndr+0x420
ld.so.1`elf_rtbndr+0x10
a.out`0x210fc
libCstd_isa.so.1`_init+0x94
ld.so.1`call_init+0x1a0
ld.so.1`setup+0x13ac
etc.
I also have a JVM running. The pid is 10529. If I run the same dtrace on that
process I get the output below. To me this suggests that process has a module
called 2 and module called libjvm.so both of which have a function called
malloc.
dtrace -p 10529 -n ''pid$target:libc:malloc:entry {ustack();}''
dtrace: description ''pid$target:libc:malloc:entry '' matched 1
probe
CPU ID FUNCTION:NAME
0 47002 malloc:entry
2`malloc
libjvm.so`__1cCosGmalloc6FI_pv_+0x20
libjvm.so`__1cICHeapObj2n6FI_pv_+0x14
libjvm.so`__1cLvframeArraybAmigrate_monitors_off_stack6M_v_+0x40
libjvm.so`__1cODeoptimizationYfetch_unroll_info_helper6FpnKJavaThread__pn0ALUnrollBlock__+0x138
libjvm.so`__1cODeoptimizationNuncommon_trap6FpnKJavaThread_i_pn0ALUnrollBlock__+0xb70
0xf3c32f1c
0xf3c35f58
0xf49743e0
0xf49cf598
0xf3c5e738
0xf3c0020c
libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x27c
libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandle_4pnRJavaCallArguments_pnGThread__v_+0x164
libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_+0x6c
libjvm.so`__1cMthread_entry6FpnKJavaThread_pnGThread__v_+0x128
libjvm.so`__1cKJavaThreadDrun6M_v_+0x284
libjvm.so`java_start+0x134
libjvm.so`_lwp_start
0 47002 malloc:entry
libjvm.so`malloc
libjvm.so`__1cCosGmalloc6FI_pv_+0x20
libjvm.so`__1cMMonitorChunk2t5B6Mi_v_+0x20
libjvm.so`__1cLvframeArraybAmigrate_monitors_off_stack6M_v_+0x54
libjvm.so`__1cODeoptimizationYfetch_unroll_info_helper6FpnKJavaThread__pn0ALUnrollBlock__+0x138
libjvm.so`__1cODeoptimizationNuncommon_trap6FpnKJavaThread_i_pn0ALUnrollBlock__+0xb70
0xf3c32f1c
0xf3c35f58
0xf49743e0
0xf49cf598
0xf3c5e738
0xf3c0020c
libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x27c
libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandle_4pnRJavaCallArguments_pnGThread__v_+0x164
libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_+0x6c
libjvm.so`__1cMthread_entry6FpnKJavaThread_pnGThread__v_+0x128
libjvm.so`__1cKJavaThreadDrun6M_v_+0x284
libjvm.so`java_start+0x134
libjvm.so`_lwp_start
However, if I run pldd on pid 10529 and run nm on each module the only malloc
function which is not undefined is in libc.so.1. This is more inline with my
expectations.
for f in $(pldd 10529|grep -v ^10529)
do
nm ./$f |c++filt | grep "|malloc"
if [[ $? = 0 ]]
then
echo $f
fi
done
[381] | 193328| 0|FUNC |GLOB |0 |UNDEF |malloc
/omcsw/27.0.1.34.01/lib/3pt/bes/bin/partition
[30577] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/omcsw/27.0.1.34.01/lib/3pt/jre/lib/sparc/server/libjvm.so
[6431] | 344152| 104|FUNC |GLOB |0 |9 |malloc
[2394] | 0| 0|FILE |LOCL |0 |ABS |malloc.c
/lib/libc.so.1
[288] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/usr/lib/libCrun.so.1
[425] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libsocket.so.1
[4658] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libnsl.so.1
[143] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libmp.so.2
[590] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libscf.so.1
[335] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libuutil.so.1
[3620] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libm.so.2
[4387] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/omcsw/27.0.1.34.01/lib/3pt/enjin/lib/libjvi6.0.5.so
[230] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/librt.so.1
[260] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/libaio.so.1
[283] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc
/lib/nss_files.so.1
How should I interpet the output from ustack?
Is there an explanation as to why ustack thinks that it can be in a function in
libjvm that is undefined?
Has a probe really fired for a function outside libc.so.1? Or it down to the way
DTrace picks the names up and is there any control over this?
This message posted from opensolaris.org
There''s a bug here in the symbol name resolution. It doesn''t look like you''re picking up a probe from another library -- just that the malloc function is getting misreported. Unfortunately, I can''t reproduce this on a JVM or any other process. Can you give me more information about your configuration? Does it always happen? Adam On Thu, Sep 28, 2006 at 09:39:37AM -0700, J.J. Shore wrote:> If I run a very simple C++ programme and trace calls the malloc as shown below > the output shows that the stack is inside libc.so.1 whenever malloc is called. > > dtrace -c "a.out" -n ''pid$target:libc:malloc:entry {ustack();}'' > dtrace: description ''pid$target:libc:malloc:entry '' matched 1 probe > CPU ID FUNCTION:NAME > 0 48927 malloc:entry > libc.so.1`malloc > libCrun.so.1`void*operator new(unsigned)+0x2c > libCstd.so.1`void std::locale::init()+0x34 > libCstd.so.1`std::istream::basic_istream(std::ios_base::EmptyCtor)+0x84 > libCstd.so.1`__SLIP.INIT_A+0x4c > libCstd.so.1`void __STATIC_CONSTRUCTOR()+0x4 > libCstd.so.1`_init+0x1e0 > ld.so.1`call_init+0x1a0 > ld.so.1`elf_bndr+0x420 > ld.so.1`elf_rtbndr+0x10 > libCrun.so.1`0xff1ea8ac > libCrun.so.1`void __Cimpl::cplus_init()+0x48 > libCrun.so.1`_init+0xc8 > ld.so.1`call_init+0x1a0 > ld.so.1`elf_bndr+0x420 > ld.so.1`elf_rtbndr+0x10 > a.out`0x210fc > libCstd_isa.so.1`_init+0x94 > ld.so.1`call_init+0x1a0 > ld.so.1`setup+0x13ac > > etc. > > I also have a JVM running. The pid is 10529. If I run the same dtrace on that > process I get the output below. To me this suggests that process has a module > called 2 and module called libjvm.so both of which have a function called malloc. > > dtrace -p 10529 -n ''pid$target:libc:malloc:entry {ustack();}'' > dtrace: description ''pid$target:libc:malloc:entry '' matched 1 probe > CPU ID FUNCTION:NAME > 0 47002 malloc:entry > 2`malloc > libjvm.so`__1cCosGmalloc6FI_pv_+0x20 > libjvm.so`__1cICHeapObj2n6FI_pv_+0x14 > libjvm.so`__1cLvframeArraybAmigrate_monitors_off_stack6M_v_+0x40 > libjvm.so`__1cODeoptimizationYfetch_unroll_info_helper6FpnKJavaThread__pn0ALUnrollBlock__+0x138 > libjvm.so`__1cODeoptimizationNuncommon_trap6FpnKJavaThread_i_pn0ALUnrollBlock__+0xb70 > 0xf3c32f1c > 0xf3c35f58 > 0xf49743e0 > 0xf49cf598 > 0xf3c5e738 > 0xf3c0020c > libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x27c > libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandle_4pnRJavaCallArguments_pnGThread__v_+0x164 > libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_+0x6c > libjvm.so`__1cMthread_entry6FpnKJavaThread_pnGThread__v_+0x128 > libjvm.so`__1cKJavaThreadDrun6M_v_+0x284 > libjvm.so`java_start+0x134 > libjvm.so`_lwp_start > > 0 47002 malloc:entry > libjvm.so`malloc > libjvm.so`__1cCosGmalloc6FI_pv_+0x20 > libjvm.so`__1cMMonitorChunk2t5B6Mi_v_+0x20 > libjvm.so`__1cLvframeArraybAmigrate_monitors_off_stack6M_v_+0x54 > libjvm.so`__1cODeoptimizationYfetch_unroll_info_helper6FpnKJavaThread__pn0ALUnrollBlock__+0x138 > libjvm.so`__1cODeoptimizationNuncommon_trap6FpnKJavaThread_i_pn0ALUnrollBlock__+0xb70 > 0xf3c32f1c > 0xf3c35f58 > 0xf49743e0 > 0xf49cf598 > 0xf3c5e738 > 0xf3c0020c > libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x27c > libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandle_4pnRJavaCallArguments_pnGThread__v_+0x164 > libjvm.so`__1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_+0x6c > libjvm.so`__1cMthread_entry6FpnKJavaThread_pnGThread__v_+0x128 > libjvm.so`__1cKJavaThreadDrun6M_v_+0x284 > libjvm.so`java_start+0x134 > libjvm.so`_lwp_start > > However, if I run pldd on pid 10529 and run nm on each module the only malloc > function which is not undefined is in libc.so.1. This is more inline with my > expectations. > > for f in $(pldd 10529|grep -v ^10529) > do > nm ./$f |c++filt | grep "|malloc" > if [[ $? = 0 ]] > then > echo $f > fi > done > > [381] | 193328| 0|FUNC |GLOB |0 |UNDEF |malloc > /omcsw/27.0.1.34.01/lib/3pt/bes/bin/partition > [30577] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /omcsw/27.0.1.34.01/lib/3pt/jre/lib/sparc/server/libjvm.so > [6431] | 344152| 104|FUNC |GLOB |0 |9 |malloc > [2394] | 0| 0|FILE |LOCL |0 |ABS |malloc.c > /lib/libc.so.1 > [288] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /usr/lib/libCrun.so.1 > [425] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libsocket.so.1 > [4658] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libnsl.so.1 > [143] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libmp.so.2 > [590] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libscf.so.1 > [335] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libuutil.so.1 > [3620] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libm.so.2 > [4387] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /omcsw/27.0.1.34.01/lib/3pt/enjin/lib/libjvi6.0.5.so > [230] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/librt.so.1 > [260] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/libaio.so.1 > [283] | 0| 0|FUNC |GLOB |0 |UNDEF |malloc > /lib/nss_files.so.1 > > How should I interpet the output from ustack? > Is there an explanation as to why ustack thinks that it can be in a function in libjvm that is undefined? > Has a probe really fired for a function outside libc.so.1? Or it down to the way > DTrace picks the names up and is there any control over this? > > > This message posted from opensolaris.org > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org-- Adam Leventhal, Solaris Kernel Development http://blogs.sun.com/ahl
Just to summarize for anyone who is interested. Adam believes the problem is
down to bug 6296612 on T1000 and T2000 boxes.
Hey Joe,
Am I correct that this is a T1000 or T2000 box?
I think this is the same issue we saw in libproc as described in this bug:
6296612 plockstat dumps core on second call
I code reviewed a fix for this about a month ago -- it should be available in
OpenSolaris pretty soon. I''ve poked the responsible engineer, and
I''ll confirm that his fix addresses this.
For the time being, rest assured that DTrace is putting probes at the right
places, but ustack is being stymied by incorrect symbol to name resolution.
Adam
This message posted from opensolaris.org