thr3ads.net - zfs discuss - [zfs-discuss] Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper? [Jun 2009]

If this information is useful, please help other people find it:
Share via:

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

head link

[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

head link

[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/

zfs discuss - Jun 2009 - Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?

[zfs-discuss] Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?

[zfs-discuss] Sorry, wrong alias Re: Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?

[zfs-discuss] Why Oracle process open(2)/ioctl(2) /dev/dtrace/helper?