Sang-Thong Chang
2009-Jun-22 05:12 UTC
[zfs-discuss] Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?
Hi all,
Under what circumstance would an exiting process open(2) and
ioctl(2) on /dev/dtrace/helper?
I have an issue here where CU was complaining that their
Oracle processes were taking a long time in ioctl(2) on
/dev/dtrace/helper during shutdown. Removing group/world
readable bit on /dev/dtrace/helper avoided the long shutdown
time.
So, the puzzling question is why /dev/dtrace/helper was being
ioctl(2)ed on?
I doubt this is a binary with USDT. truss(1M) shown the following:
Base time stamp: 1244728105.2977 [ Thu Jun 11 22:48:25 KST 2009 ]
16003/1: psargs: oraclePOM1 (LOCAL=NO)
16003/1: read(31, 0x1069F3796, 2064) (sleeping...)
...
16003/1: 1468.9156 0.0005 open("/dev/dtrace/helper",
O_RDWR) = 8
16003/1: 1477.3773 8.4617 ioctl(8,
((''d''<<24)|(''t''<<16)|(''h''<<8)|2),
0x00000000) = 0
16003/1: 1477.3781 0.0008 Received signal #14, SIGALRM
[caught]
16003/1: 1477.3783 0.0002 lwp_sigmask(SIG_SETMASK,
0x9FBEF057, 0x0000FFF7) = 0xFFBFFEFF [0x0000FFFF]
1277 */
1278 #define DTRACEHIOC ((''d'' << 24) |
(''t'' << 16) |
(''h'' << 8))
1279 #define DTRACEHIOC_ADD (DTRACEHIOC | 1) /* add
helper */
1280 #define DTRACEHIOC_REMOVE (DTRACEHIOC | 2) /*
remove helper */
ustack() from dtrace(1M) shown this was from within the
exit hanlder in exit(2).
open(/dev/dtrace/helper)
libc.so.1`open
libCrun.so.1`0xffffffff7a50aed8
libCrun.so.1`0xffffffff7a50b0f4
ld.so.1`call_fini+0xd0
ld.so.1`atexit_fini+0x80
libc.so.1`_exithandle+0x48
libc.so.1`exit+0x4
oracle`_start+0x184
It would be great if anyone can help extend my understanding
of dtrace. Thanks.
Regards
Sang Thong
-----------------------------------------------------------------
1788: oraclePOM1 (LOCAL=NO)
data model = _LP64 flags = ORPHAN|MSACCT|MSFORK
/1: flags = ASLEEP read(0x11,0x106346b16,0x810)
1788: oracleEOM1 (LOCAL=NO)
/lib/sparcv9/libumem.so.1
/oraom/app/DBMS/lib/libskgxp10.so
/oraom/app/DBMS/lib/libhasgen10.so
/opt/ORCLcluster/lib/libskgxn2.so
/oraom/app/DBMS/lib/libocr10.so
/oraom/app/DBMS/lib/libocrb10.so
/oraom/app/DBMS/lib/libocrutl10.so
/oraom/app/DBMS/lib/libjox10.so
/oraom/app/DBMS/lib/libclsra10.so
/oraom/app/DBMS/lib/libdbcfg10.so
/oraom/app/DBMS/lib/libnnz10.so
/lib/sparcv9/libkstat.so.1
/lib/sparcv9/libnsl.so.1
/lib/sparcv9/libsocket.so.1
/lib/sparcv9/libgen.so.1
/lib/sparcv9/libdl.so.1
/usr/lib/sparcv9/libsched.so.1
/lib/sparcv9/libc.so.1
/lib/sparcv9/libaio.so.1
/lib/sparcv9/librt.so.1
/lib/sparcv9/libm.so.2
/opt/SUNWcluster/lib/sparcv9/libudlm.so
/usr/cluster/lib/sparcv9/libhaops.so.1
/lib/sparcv9/libmd.so.1
/usr/cluster/lib/sparcv9/libscha.so.1
/usr/cluster/lib/sparcv9/libsecurity.so.1
/usr/cluster/lib/sparcv9/libclos.so.1
/lib/sparcv9/libdoor.so.1
/usr/lib/sparcv9/libzonecfg.so.1
/lib/sparcv9/libsecdb.so.1
/usr/lib/sparcv9/libCstd.so.1
/usr/lib/sparcv9/libCrun.so.1
/lib/sparcv9/libuuid.so.1
/lib/sparcv9/libnvpair.so.1
/lib/sparcv9/libsysevent.so.1
/lib/sparcv9/libsec.so.1
/usr/lib/sparcv9/libbrand.so.1
/usr/lib/sparcv9/libpool.so.1
/lib/sparcv9/libscf.so.1
/lib/sparcv9/libproc.so.1
/lib/sparcv9/libuutil.so.1
/usr/lib/sparcv9/libxml2.so.2
/lib/sparcv9/libcmd.so.1
/lib/sparcv9/libavl.so.1
/usr/lib/sparcv9/libexacct.so.1
/lib/sparcv9/librtld_db.so.1
/lib/sparcv9/libelf.so.1
/lib/sparcv9/libctf.so.1
/lib/sparcv9/libpthread.so.1
/usr/lib/sparcv9/libz.so.1
/platform/sun4u-us3/lib/sparcv9/libc_psr.so.1
> > Mon, 22 Jun 2009 09:06:09 KST
open(/dev/dtrace/helper)
libc.so.1`open
libCrun.so.1`0xffffffff7a50aed8
libCrun.so.1`0xffffffff7a50b0f4
ld.so.1`call_fini+0xd0
ld.so.1`atexit_fini+0x80
libc.so.1`_exithandle+0x48
libc.so.1`exit+0x4
oracle`_start+0x184
***
Sang-Thong Chang
2009-Jun-22 05:13 UTC
[zfs-discuss] Sorry, wrong alias Re: Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?
My apologies... sent to wrong alias. Sang-Thong Chang wrote:> > Hi all, > > > Under what circumstance would an exiting process open(2) and > ioctl(2) on /dev/dtrace/helper? > > > I have an issue here where CU was complaining that their > Oracle processes were taking a long time in ioctl(2) on > /dev/dtrace/helper during shutdown. Removing group/world > readable bit on /dev/dtrace/helper avoided the long shutdown > time. > > So, the puzzling question is why /dev/dtrace/helper was being > ioctl(2)ed on? > > I doubt this is a binary with USDT. truss(1M) shown the following: > > > Base time stamp: 1244728105.2977 [ Thu Jun 11 22:48:25 KST 2009 ] > 16003/1: psargs: oraclePOM1 (LOCAL=NO) > 16003/1: read(31, 0x1069F3796, 2064) (sleeping...) > ... > 16003/1: 1468.9156 0.0005 open("/dev/dtrace/helper", > O_RDWR) = 8 > 16003/1: 1477.3773 8.4617 ioctl(8, > ((''d''<<24)|(''t''<<16)|(''h''<<8)|2), 0x00000000) = 0 > 16003/1: 1477.3781 0.0008 Received signal #14, SIGALRM > [caught] > 16003/1: 1477.3783 0.0002 lwp_sigmask(SIG_SETMASK, > 0x9FBEF057, 0x0000FFF7) = 0xFFBFFEFF [0x0000FFFF] > > 1277 */ > 1278 #define DTRACEHIOC ((''d'' << 24) | (''t'' << 16) | > (''h'' << 8)) > 1279 #define DTRACEHIOC_ADD (DTRACEHIOC | 1) /* add > helper */ > 1280 #define DTRACEHIOC_REMOVE (DTRACEHIOC | 2) /* > remove helper */ > > > > ustack() from dtrace(1M) shown this was from within the > exit hanlder in exit(2). > > open(/dev/dtrace/helper) > > libc.so.1`open > libCrun.so.1`0xffffffff7a50aed8 > libCrun.so.1`0xffffffff7a50b0f4 > ld.so.1`call_fini+0xd0 > ld.so.1`atexit_fini+0x80 > libc.so.1`_exithandle+0x48 > libc.so.1`exit+0x4 > oracle`_start+0x184 > > It would be great if anyone can help extend my understanding > of dtrace. Thanks. > > Regards > Sang Thong > > > ----------------------------------------------------------------- > > 1788: oraclePOM1 (LOCAL=NO) > data model = _LP64 flags = ORPHAN|MSACCT|MSFORK > /1: flags = ASLEEP read(0x11,0x106346b16,0x810) > > 1788: oracleEOM1 (LOCAL=NO) > /lib/sparcv9/libumem.so.1 > /oraom/app/DBMS/lib/libskgxp10.so > /oraom/app/DBMS/lib/libhasgen10.so > /opt/ORCLcluster/lib/libskgxn2.so > /oraom/app/DBMS/lib/libocr10.so > /oraom/app/DBMS/lib/libocrb10.so > /oraom/app/DBMS/lib/libocrutl10.so > /oraom/app/DBMS/lib/libjox10.so > /oraom/app/DBMS/lib/libclsra10.so > /oraom/app/DBMS/lib/libdbcfg10.so > /oraom/app/DBMS/lib/libnnz10.so > /lib/sparcv9/libkstat.so.1 > /lib/sparcv9/libnsl.so.1 > /lib/sparcv9/libsocket.so.1 > /lib/sparcv9/libgen.so.1 > /lib/sparcv9/libdl.so.1 > /usr/lib/sparcv9/libsched.so.1 > /lib/sparcv9/libc.so.1 > /lib/sparcv9/libaio.so.1 > /lib/sparcv9/librt.so.1 > /lib/sparcv9/libm.so.2 > /opt/SUNWcluster/lib/sparcv9/libudlm.so > /usr/cluster/lib/sparcv9/libhaops.so.1 > /lib/sparcv9/libmd.so.1 > /usr/cluster/lib/sparcv9/libscha.so.1 > /usr/cluster/lib/sparcv9/libsecurity.so.1 > /usr/cluster/lib/sparcv9/libclos.so.1 > /lib/sparcv9/libdoor.so.1 > /usr/lib/sparcv9/libzonecfg.so.1 > /lib/sparcv9/libsecdb.so.1 > /usr/lib/sparcv9/libCstd.so.1 > /usr/lib/sparcv9/libCrun.so.1 > /lib/sparcv9/libuuid.so.1 > /lib/sparcv9/libnvpair.so.1 > /lib/sparcv9/libsysevent.so.1 > /lib/sparcv9/libsec.so.1 > /usr/lib/sparcv9/libbrand.so.1 > /usr/lib/sparcv9/libpool.so.1 > /lib/sparcv9/libscf.so.1 > /lib/sparcv9/libproc.so.1 > /lib/sparcv9/libuutil.so.1 > /usr/lib/sparcv9/libxml2.so.2 > /lib/sparcv9/libcmd.so.1 > /lib/sparcv9/libavl.so.1 > /usr/lib/sparcv9/libexacct.so.1 > /lib/sparcv9/librtld_db.so.1 > /lib/sparcv9/libelf.so.1 > /lib/sparcv9/libctf.so.1 > /lib/sparcv9/libpthread.so.1 > /usr/lib/sparcv9/libz.so.1 > /platform/sun4u-us3/lib/sparcv9/libc_psr.so.1 > > > > Mon, 22 Jun 2009 09:06:09 KST > open(/dev/dtrace/helper) > > libc.so.1`open > libCrun.so.1`0xffffffff7a50aed8 > libCrun.so.1`0xffffffff7a50b0f4 > ld.so.1`call_fini+0xd0 > ld.so.1`atexit_fini+0x80 > libc.so.1`_exithandle+0x48 > libc.so.1`exit+0x4 > oracle`_start+0x184 > > *** >
Mike Gerdts
2009-Jun-22 12:26 UTC
[zfs-discuss] Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?
On Mon, Jun 22, 2009 at 12:12 AM, Sang-Thong Chang<Sang-Thong.Chang at sun.com> wrote:> > Hi all, > > > Under what circumstance would an exiting process open(2) and > ioctl(2) on /dev/dtrace/helper?This happens if the executable or any of its shared libraries have USDT probes defined. It is coming from dtri.c, which exists on each system as /usr/lib/dtrace/$ISA/dtri.o. http://src.opensolaris.org/source/xref/onnv/onnv-gate/usr/src/lib/libdtrace/common/drti.c When an executable or library is compiled with dtrace probes, drti.o is linked into it and the dtrace_dof_fini function is executed on exit.> > I have an issue here where CU was complaining that their > Oracle processes were taking a long time in ioctl(2) on > /dev/dtrace/helper during shutdown. Removing group/world > readable bit on /dev/dtrace/helper avoided the long shutdown > time. > > So, the puzzling question is why /dev/dtrace/helper was being > ioctl(2)ed on? > > I doubt this is a binary with USDT. ?truss(1M) shown the following: > > > Base time stamp: ?1244728105.2977 ?[ Thu Jun 11 22:48:25 KST 2009 ] > 16003/1: ? ? ? ?psargs: oraclePOM1 (LOCAL=NO) > 16003/1: ? ? ? ?read(31, 0x1069F3796, 2064) ? ? (sleeping...) > ... > 16003/1: ? ? ? ?1468.9156 ? ? ? ?0.0005 open("/dev/dtrace/helper", O_RDWR) > ? ? ? ? ? ?= 8 > 16003/1: ? ? ? ?1477.3773 ? ? ? ?8.4617 ioctl(8, > ((''d''<<24)|(''t''<<16)|(''h''<<8)|2), 0x00000000) = 0 > 16003/1: ? ? ? ?1477.3781 ? ? ? ?0.0008 ? ? Received signal #14, SIGALRM > [caught] > 16003/1: ? ? ? ?1477.3783 ? ? ? ?0.0002 lwp_sigmask(SIG_SETMASK, 0x9FBEF057, > 0x0000FFF7) = 0xFFBFFEFF [0x0000FFFF] > > ? 1277 ?*/ > ? 1278 #define DTRACEHIOC ? ? ? ? ? ? ?((''d'' << 24) | (''t'' << 16) | (''h'' << > 8)) > ? 1279 #define DTRACEHIOC_ADD ? ? ? ? ?(DTRACEHIOC | 1) ? ? ? ?/* add helper > */ > ? 1280 #define DTRACEHIOC_REMOVE ? ? ? (DTRACEHIOC | 2) ? ? ? ?/* remove > helper */ > > > > ustack() from dtrace(1M) shown this was from within the > exit hanlder in exit(2). > > ?open(/dev/dtrace/helper) > > ? ? ? ? ? ? ?libc.so.1`open > ? ? ? ? ? ? ?libCrun.so.1`0xffffffff7a50aed8 > ? ? ? ? ? ? ?libCrun.so.1`0xffffffff7a50b0f4 > ? ? ? ? ? ? ?ld.so.1`call_fini+0xd0 > ? ? ? ? ? ? ?ld.so.1`atexit_fini+0x80 > ? ? ? ? ? ? ?libc.so.1`_exithandle+0x48 > ? ? ? ? ? ? ?libc.so.1`exit+0x4 > ? ? ? ? ? ? ?oracle`_start+0x184 > > It would be great if anyone can help extend my understanding > of dtrace. Thanks. > > Regards > Sang Thong > > > ----------------------------------------------------------------- > > 1788: ? oraclePOM1 (LOCAL=NO) > ? ? ? ?data model = _LP64 ?flags = ORPHAN|MSACCT|MSFORK > ?/1: ? ?flags = ASLEEP ?read(0x11,0x106346b16,0x810) > > 1788: ? oracleEOM1 (LOCAL=NO) > /lib/sparcv9/libumem.so.1 > /oraom/app/DBMS/lib/libskgxp10.so > /oraom/app/DBMS/lib/libhasgen10.so > /opt/ORCLcluster/lib/libskgxn2.so > /oraom/app/DBMS/lib/libocr10.so > /oraom/app/DBMS/lib/libocrb10.so > /oraom/app/DBMS/lib/libocrutl10.so > /oraom/app/DBMS/lib/libjox10.so > /oraom/app/DBMS/lib/libclsra10.so > /oraom/app/DBMS/lib/libdbcfg10.so > /oraom/app/DBMS/lib/libnnz10.so > /lib/sparcv9/libkstat.so.1 > /lib/sparcv9/libnsl.so.1 > /lib/sparcv9/libsocket.so.1 > /lib/sparcv9/libgen.so.1 > /lib/sparcv9/libdl.so.1 > /usr/lib/sparcv9/libsched.so.1 > /lib/sparcv9/libc.so.1 > /lib/sparcv9/libaio.so.1 > /lib/sparcv9/librt.so.1 > /lib/sparcv9/libm.so.2 > /opt/SUNWcluster/lib/sparcv9/libudlm.so > /usr/cluster/lib/sparcv9/libhaops.so.1 > /lib/sparcv9/libmd.so.1 > /usr/cluster/lib/sparcv9/libscha.so.1 > /usr/cluster/lib/sparcv9/libsecurity.so.1 > /usr/cluster/lib/sparcv9/libclos.so.1 > /lib/sparcv9/libdoor.so.1 > /usr/lib/sparcv9/libzonecfg.so.1 > /lib/sparcv9/libsecdb.so.1 > /usr/lib/sparcv9/libCstd.so.1 > /usr/lib/sparcv9/libCrun.so.1 > /lib/sparcv9/libuuid.so.1 > /lib/sparcv9/libnvpair.so.1 > /lib/sparcv9/libsysevent.so.1 > /lib/sparcv9/libsec.so.1 > /usr/lib/sparcv9/libbrand.so.1 > /usr/lib/sparcv9/libpool.so.1 > /lib/sparcv9/libscf.so.1 > /lib/sparcv9/libproc.so.1 > /lib/sparcv9/libuutil.so.1 > /usr/lib/sparcv9/libxml2.so.2 > /lib/sparcv9/libcmd.so.1 > /lib/sparcv9/libavl.so.1 > /usr/lib/sparcv9/libexacct.so.1 > /lib/sparcv9/librtld_db.so.1 > /lib/sparcv9/libelf.so.1 > /lib/sparcv9/libctf.so.1 > /lib/sparcv9/libpthread.so.1 > /usr/lib/sparcv9/libz.so.1 > /platform/sun4u-us3/lib/sparcv9/libc_psr.so.1 > >> > Mon, 22 Jun 2009 09:06:09 KST > ?open(/dev/dtrace/helper) > > ? ? ? ? ? ? ?libc.so.1`open > ? ? ? ? ? ? ?libCrun.so.1`0xffffffff7a50aed8 > ? ? ? ? ? ? ?libCrun.so.1`0xffffffff7a50b0f4 > ? ? ? ? ? ? ?ld.so.1`call_fini+0xd0 > ? ? ? ? ? ? ?ld.so.1`atexit_fini+0x80 > ? ? ? ? ? ? ?libc.so.1`_exithandle+0x48 > ? ? ? ? ? ? ?libc.so.1`exit+0x4 > ? ? ? ? ? ? ?oracle`_start+0x184 > > *** > _______________________________________________ > zfs-discuss mailing list > zfs-discuss at opensolaris.org > http://mail.opensolaris.org/mailman/listinfo/zfs-discuss >-- Mike Gerdts http://mgerdts.blogspot.com/