ablog

不器用で落着きのない技術者のメモ

id:wmo6hash's OOW Unconference を自前環境でやってみる

Oracle

id:wmo6hash's OOW Unconference を自前環境でちょっとやってみた。

リスナーを起動する。

$ lsnrctl start

LSNRCTL for Solaris: Version 10.2.0.4.0 - Production on 09-MAY-2009 11:59:02

Copyright (c) 1991, 2007, Oracle.  All rights reserved.

Starting /export/home/oracle/product/10.2.0/db_1/bin/tnslsnr: please wait...

TNSLSNR for Solaris: Version 10.2.0.4.0 - Production
Log messages written to /export/home/oracle/product/10.2.0/db_1/network/log/listener.log
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=solaris101)(PORT=1521)))

Connecting to (ADDRESS=(PROTOCOL=tcp)(HOST=)(PORT=1521))
STATUS of the LISTENER
------------------------
Alias                     LISTENER
Version                   TNSLSNR for Solaris: Version 10.2.0.4.0 - Production
Start Date                09-MAY-2009 11:59:02
Uptime                    0 days 0 hr. 0 min. 0 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Listener Log File         /export/home/oracle/product/10.2.0/db_1/network/log/listener.log
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=solaris101)(PORT=1521)))
The listener supports no services
The command completed successfully

リスナーログを見てみると、

$ listener.log 

TNSLSNR for Solaris: Version 10.2.0.4.0 - Production on 09-MAY-2009 11:59:02

Copyright (c) 1991, 2007, Oracle.  All rights reserved.

Log messages written to /export/home/oracle/product/10.2.0/db_1/network/log/listener.log
Trace information written to /export/home/oracle/product/10.2.0/db_1/network/trace/listener.trc
Trace level is currently 0

Started with pid=987
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=solaris101)(PORT=1521)))
Listener completed notification to CRS on start

TIMESTAMP * CONNECT DATA [* PROTOCOL INFO] * EVENT [* SID] * RETURN CODE
WARNING: Subscription for node down event still pending
09-MAY-2009 11:59:02 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=solaris101)(USER=oracle))(COMMAND=status)(ARGUMENTS=64)(SERVICE=LISTENER)(VERSION=169870336)) * status * 0
-bash-3.00$ pwd
/export/home/oracle/product/10.2.0/db_1/network/log

リスナーのプロセスIDは 987 か。
リスナープロセスのスタックトレースを表示してみる。

#pstack 987
987:    /export/home/oracle/product/10.2.0/db_1/bin/tnslsnr LISTENER -inherit
-----------------  lwp# 1 / thread# 1  --------------------
 fdfd8da5 pollsys  (817fd28, 3, 0, 0)
 fdf7f502 poll     (817fd28, 3, ffffffff) + 52
 fe5753c0 ntevpque (8177c00, ffffffff, 8042be0) + 60
 fe57351c ntevque  (8177c00, ffffffff, 8042be0) + a0
 fe554e10 nsevwait (80ee880, 8043608, 804360c, 0, 80434dc) + 14c
 080611f4 nsglma   (8043640, 0, 8047b98) + 10b4
 080585c2 main     (3, 8047b8c, 8047b9c) + 52
 080584da ???????? (3, 8047c68, 8047c9c, 8047ca5, 0, 8047cae)
-----------------  lwp# 2 / thread# 2  --------------------
 fdfd8095 nanosleep (fd73ef78, fd73ef80)
 fee2453f ons_receivethread (8042bdc) + 287
 fdfd59b9 _thr_setup (fd630200) + 4e
 fdfd5ca0 _lwp_start (fd630200, 0, 0, fd73eff8, fdfd5ca0, fd630200)
-----------------  lwp# 3 / thread# 3  --------------------
 fdfd5d19 lwp_park (0, 0, 0)
 fdfd0500 cond_wait_queue (80a80e0, 80a6920, 0) + 5e
 fdfd09d4 _cond_wait (80a80e0, 80a6920) + 64
 fdfd0a16 cond_wait (80a80e0, 80a6920) + 21
 fdfd0a4f pthread_cond_wait (80a80e0, 80a6920) + 1b
 fee24d84 ons_recvthread_getsocket (0, fd630a00, fe04c000, 0, fe04c000, fd62efdc) + 58
 fee25128 ons_sendthread (8042bdc) + 138
 fdfd59b9 _thr_setup (fd630a00) + 4e
 fdfd5ca0 _lwp_start (fd630a00, 0, 0, fd62eff8, fdfd5ca0, fd630a00)

リスナープロセスのプロセスをトレースしてみる。

# truss -p 987
/2:     nanosleep(0xFD73EF78, 0xFD73EF80)               = 0
/2:     so_socket(PF_INET, SOCK_STREAM, IPPROTO_TCP, "", SOV_DEFAULT) = 14
/2:     fcntl(14, F_SETFD, 0x00000001)                  = 0
/2:     connect(14, 0xFD73EFA0, 16, SOV_DEFAULT)        Err#146 ECONNREFUSED
/2:     shutdown(14, SHUT_RDWR, SOV_DEFAULT)            Err#134 ENOTCONN
/2:     close(14)                                       = 0
/3:     lwp_park(0x00000000, 0)         (sleeping...)
/1:     pollsys(0x0817FD28, 3, 0x00000000, 0x00000000) (sleeping...)
/2:     nanosleep(0xFD73EF78, 0xFD73EF80) (sleeping...)
/2:     nanosleep(0xFD73EF78, 0xFD73EF80)               = 0
/2:     so_socket(PF_INET, SOCK_STREAM, IPPROTO_TCP, "", SOV_DEFAULT) = 14
/2:     fcntl(14, F_SETFD, 0x00000001)                  = 0
/2:     connect(14, 0xFD73EFA0, 16, SOV_DEFAULT)        Err#146 ECONNREFUSED
/2:     shutdown(14, SHUT_RDWR, SOV_DEFAULT)            Err#134 ENOTCONN
/2:     close(14)                                       = 0
/2:     nanosleep(0xFD73EF78, 0xFD73EF80) (sleeping...)
/2:     nanosleep(0xFD73EF78, 0xFD73EF80)               = 0
/2:     so_socket(PF_INET, SOCK_STREAM, IPPROTO_TCP, "", SOV_DEFAULT) = 14
/2:     fcntl(14, F_SETFD, 0x00000001)                  = 0
/2:     connect(14, 0xFD73EFA0, 16, SOV_DEFAULT)        Err#146 ECONNREFUSED
/2:     shutdown(14, SHUT_RDWR, SOV_DEFAULT)            Err#134 ENOTCONN
/2:     close(14)                                       = 0
/2:     nanosleep(0xFD73EF78, 0xFD73EF80) (sleeping...)
/2:     nanosleep(0xFD73EF78, 0xFD73EF80)               = 0
/2:     so_socket(PF_INET, SOCK_STREAM, IPPROTO_TCP, "", SOV_DEFAULT) = 14
/2:     fcntl(14, F_SETFD, 0x00000001)                  = 0
/2:     connect(14, 0xFD73EFA0, 16, SOV_DEFAULT)        Err#146 ECONNREFUSED
/2:     shutdown(14, SHUT_RDWR, SOV_DEFAULT)            Err#134 ENOTCONN
/2:     close(14)                               
（中略）
↓ リモートホストから「telnet 192.168.45.101 1521」を実行してみる。。。
/1:     pollsys(0x0817FD28, 3, 0x00000000, 0x00000000)  = 1
/1:     getsockname(10, 0x08041800, 0x08041838, SOV_DEFAULT) = 0
/1:     getpeername(10, 0x08041800, 0x08041838, SOV_DEFAULT) Err#134 ENOTCONN
/1:     accept(10, 0x08041800, 0x08041850, SOV_DEFAULT) = 14
/1:     getsockname(14, 0x08041810, 0x08041850, SOV_DEFAULT) = 0
/1:     ioctl(14, FIONBIO, 0x0804185C)                  = 0
/1:     getsockopt(14, SOL_SOCKET, SO_SNDBUF, 0x080418E8, 0x080418E0, SOV_DEFAULT) = 0
/1:     getsockopt(14, SOL_SOCKET, SO_RCVBUF, 0x080418E8, 0x080418E0, SOV_DEFAULT) = 0
/1:     setsockopt(14, tcp, TCP_NODELAY, 0x080418F0, 4, SOV_DEFAULT) = 0
/1:     fcntl(14, F_SETFD, 0x00000001)                  = 0
/1:     sigaction(SIGPIPE, 0x08041840, 0x080418F0)      = 0
/1:     pollsys(0x0817FD28, 4, 0x08042348, 0x00000000) (sleeping...)
（中略）
↓「control + ]」、「quit」で、telnet を終了すると。。。
/1:     pollsys(0x0817FD28, 4, 0x08042348, 0x00000000)  = 1
/1:     read(14, 0x0823B2D6, 8208)                      = 0
/1:     close(14)                                       = 0
/1:     lseek(6, 19968, SEEK_SET)                       = 19968
/1:     read(6, "\f\0 504\0\0 P\0 604\0\0".., 512)      = 512
/1:     llseek(3, 0, SEEK_CUR)                          = 1725
/1:     write(3, " 0 9 - M A Y - 2 0 0 9  ".., 29)      = 29
/1:     lseek(6, 37888, SEEK_SET)                       = 37888
/1:     read(6, "\b\0CC /\0\0 8\0D4 0\0\0".., 512)      = 512
/1:     llseek(3, 0, SEEK_CUR)                          = 1754
/1:     write(3, " T N S - 1 2 5 0 2 :   T".., 61)      = 61
/1:     pollsys(0x0817FD28, 3, 0x00000000, 0x00000000) (sleeping...)

ここで、リスナーログを見てみると、

09-MAY-2009 12:22:53 * <unknown connect data> * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.45.1)(PORT=50810)) * establish * <unknown sid> * 12525
TNS-12525: TNS:listener has not received client's request in time allowed
 TNS-12535: TNS:operation timed out
  TNS-12606: TNS: Application timeout occurred
09-MAY-2009 12:24:54 * service_update * orcl * 0
09-MAY-2009 12:28:54 * 12502
TNS-12502: TNS:listener received no CONNECT_DATA from client

続きはまた今度。


[参考]
Oracle OpenWorld Unconference 2009/04/24(金)16:20〜のセッション - wmo6hash::blog
＠IT：/procによるLinuxチューニング ［前編］（2/2）
http://docs.sun.com/app/docs/doc/819-0381/6n2qghhkd?a=view
http://docs.sun.com/app/docs/doc/819-0381/rfsrefer-44?l=Ja&a=view