環境
[root@localhost ~]# cat /etc/issue
Enterprise Linux Enterprise Linux Server release 5.5 (Carthage)
Kernel \r on an \m
[root@localhost ~]# uname -a
Linux localhost.localdomain 2.6.18-194.17.1.0.1.el5
SQL> select * from v$version;
BANNER
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
PL/SQL Release 11.2.0.2.0 - Production
CORE 11.2.0.2.0 Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production
[oracle@localhost OPatch]$ ./opatch lsinventory
...
Installed Top-level Products (1):
Oracle Database 11g 11.2.0.2.0
There are 1 products installed in this Oracle Home.
There are no Interim patches installed in this Oracle Home.
strace でシステムコールをトレースする
[root@localhost ~]# ps -ef|grep [t]ns
oracle 3249 1 0 19:35 ? 00:00:00 /home/oracle/app/oracle/product/11.2.0/dbhome_2/bin/tnslsnr LISTENER -inherit
- strace でリスナープロセスと fork されるプロセスのシステムコールをトレースする。
[root@localhost ~]# strace -tf -p 3249 -o strace.log
- テストケース実行後、setsockopt でどのようなソケットオプションを使用しているか調べる。
[root@localhost ~]# grep -i setsockopt strace.log
3250 20:12:35 setsockopt(14, SOL_SOCKET, SO_LINGER, {onoff=1, linger=900}, 8) = 0
3249 20:12:36 setsockopt(14, SOL_TCP, TCP_NODELAY, [1], 4) = 0
3601 20:12:36 setsockopt(14, SOL_TCP, TCP_NODELAY, [1], 4) = 0
3601 20:12:37 setsockopt(14, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
3601 20:12:37 setsockopt(14, SOL_SOCKET, SO_SNDTIMEO, "\0\0\0\0\0\0\0\0", 8) = 0
3601 20:12:37 setsockopt(14, SOL_SOCKET, SO_RCVTIMEO, "\0\0\0\0\0\0\0\0", 8) = 0
3601 20:12:37 setsockopt(14, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
3250 20:12:40 setsockopt(14, SOL_SOCKET, SO_LINGER, {onoff=1, linger=900}, 8) = 0
3249 20:12:40 setsockopt(14, SOL_TCP, TCP_NODELAY, [1], 4) = 0
3603 20:12:40 setsockopt(14, SOL_TCP, TCP_NODELAY, [1], 4) = 0
3603 20:12:40 setsockopt(14, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
3603 20:12:41 setsockopt(14, SOL_SOCKET, SO_SNDTIMEO, "\0\0\0\0\0\0\0\0", 8) = 0
3603 20:12:41 setsockopt(14, SOL_SOCKET, SO_RCVTIMEO, "\0\0\0\0\0\0\0\0", 8) = 0
3603 20:12:41 setsockopt(14, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
Oracle Net トレース・ファイルから確認する
- Oracle Database の sqlnet.ora にトレース・レベルを設定する
[oracle@localhost ~]$ cat /home/oracle/app/oracle/product/11.2.0/dbhome_2/network/admin/sqlnet.ora
TRACE_LEVEL_SERVER=16
- テストケース実行後、トレース・ファイルを確認する。
[oracle@localhost trace]$ grep testc *
orcl_ora_3564.trc:2013-04-20 20:09:41.321368 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
orcl_ora_3566.trc:2013-04-20 20:09:42.272207 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
orcl_ora_3579.trc:2013-04-20 20:10:59.363429 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
orcl_ora_3581.trc:2013-04-20 20:11:04.073404 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
orcl_ora_3590.trc:2013-04-20 20:11:35.457958 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
orcl_ora_3601.trc:2013-04-20 20:12:37.614055 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
orcl_ora_3603.trc:2013-04-20 20:12:41.459677 : nsbasic_brc:2F 2A 20 74 65 73 74 63 |/*.testc|
[oracle@localhost trace]$ grep -i tcp orcl_ora_3601.trc
2013-04-20 20:12:36.959360 : nsinh_hoff:ADR="(ADDRESS=(PROTOCOL=tcp)(DEV=14)(HOST=192.168.56.101)(PORT=1521))"
2013-04-20 20:12:36.959715 : nsc2addr:(ADDRESS=(PROTOCOL=tcp)(DEV=14)(HOST=192.168.56.101)(PORT=1521))
2013-04-20 20:12:36.966778 : nttcon:NT layer TCP/IP connection has been established.
2013-04-20 20:12:36.966984 : nttcon:set TCP_NODELAY on 14
2013-04-20 20:12:37.002025 : nsprecv:3D 74 63 70 29 28 48 4F |=tcp)(HO|
2013-04-20 20:12:37.100779 : nsgetclientaddress:Client address: "(ADDRESS=(PROTOCOL=tcp)(HOST=192.168.56.1)(PORT=1849))"
[oracle@localhost trace]$ grep -i tcp orcl_ora_3603.trc
2013-04-20 20:12:40.797698 : nsinh_hoff:ADR="(ADDRESS=(PROTOCOL=tcp)(DEV=14)(HOST=192.168.56.101)(PORT=1521))"
2013-04-20 20:12:40.798505 : nsc2addr:(ADDRESS=(PROTOCOL=tcp)(DEV=14)(HOST=192.168.56.101)(PORT=1521))
2013-04-20 20:12:40.806009 : nttcon:NT layer TCP/IP connection has been established.
2013-04-20 20:12:40.806195 : nttcon:set TCP_NODELAY on 14
2013-04-20 20:12:40.841755 : nsprecv:3D 74 63 70 29 28 48 4F |=tcp)(HO|
2013-04-20 20:12:40.941021 : nsgetclientaddress:Client address: "(ADDRESS=(PROTOCOL=tcp)(HOST=192.168.56.1)(PORT=1851))"
テスト手順
- Oracle Database の sqlnet.ora にトレース・レベル(16)を設定する。
- strace でリスナープロセスと fork されるプロセスのシステムコールをトレースする。
- テストプログラムを実行する。
exec_testcase1.bat
exec_testcase2.bat
テストに使ったファイル
set JAVA_HOME=C:\Program Files\Java\jdk1.5.0_22
set PATH=%JAVA_HOME%\bin;%PATH%
call set_env.bat
%~d0
cd %~p0
set CLASSPATH=.;ojdbc5.jar
javac TestCase1.java
pause
call set_env.bat
%~d0
cd %~p0
set CLASSPATH=.;ojdbc5.jar
javac TestCase2.java
pause
call set_env.bat
%~d0
cd %~p0
set CLASSPATH=.;ojdbc5.jar
java TestCase1
pause
call set_env.bat
%~d0
cd %~p0
set CLASSPATH=.;ojdbc5.jar
java TestCase2
pause
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.Statement;
import java.sql.ResultSet;
import java.sql.SQLException;
public class TestCase1 {
public static void main(String args[]) {
Connection conn = null;
Statement stmt = null;
ResultSet resultSet = null;
try {
Class.forName ("oracle.jdbc.driver.OracleDriver");
conn = DriverManager.getConnection("jdbc:oracle:thin:@192.168.56.101:1521:orcl","system","manager");
stmt = conn.createStatement();
resultSet = stmt.executeQuery("select /* testcase1 */ sys_context('USERENV','INSTANCE_NAME'), sys_context('USERENV','SERVER_HOST') from dual");
for(;resultSet.next();) {
System.out.println(resultSet.getString(1));
System.out.println(resultSet.getString(2));
}
try {
if (resultSet != null) {
resultSet.close();
}
} catch (SQLException e){
e.printStackTrace();
}
try {
if (stmt != null) {
stmt.close();
}
} catch (SQLException e){
e.printStackTrace();
}
} catch (SQLException e) {
System.out.println("Error code: " + e.getErrorCode());
System.out.println("SQL state: " + e.getSQLState());
e.printStackTrace();
} catch (ClassNotFoundException e) {
e.printStackTrace();
} finally {
try {
if (resultSet != null) {
resultSet.close();
}
} catch (SQLException e){
e.printStackTrace();
}
try {
if (stmt != null) {
stmt.close();
}
} catch (SQLException e){
e.printStackTrace();
}
try {
if (conn != null) {
conn.close();
}
} catch (SQLException e){
e.printStackTrace();
}
}
}
}
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.Statement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.util.Properties;
public class TestCase2 {
public static void main(String args[]) {
Connection conn = null;
Statement stmt = null;
ResultSet resultSet = null;
try {
Class.forName ("oracle.jdbc.driver.OracleDriver");
java.util.Properties info = new java.util.Properties();
info.setProperty("user", "system");
info.setProperty("password", "manager");
info.setProperty("TCP.NODELAY", "YES");
conn = DriverManager.getConnection("jdbc:oracle:thin:@192.168.56.101:1521:ORCL",info);
stmt = conn.createStatement();
resultSet = stmt.executeQuery("select /* testcase2 */ sys_context('USERENV','INSTANCE_NAME'), sys_context('USERENV','SERVER_HOST') from dual");
for(;resultSet.next();) {
System.out.println(resultSet.getString(1));
System.out.println(resultSet.getString(2));
}
try {
if (resultSet != null) {
resultSet.close();
}
} catch (SQLException e){
e.printStackTrace();
}
try {
if (stmt != null) {
stmt.close();
}
} catch (SQLException e){
e.printStackTrace();
}
} catch (SQLException e) {
System.out.println("Error code: " + e.getErrorCode());
System.out.println("SQL state: " + e.getSQLState());
e.printStackTrace();
} catch (ClassNotFoundException e) {
e.printStackTrace();
} finally {
try {
if (resultSet != null) {
resultSet.close();
}
} catch (SQLException e){
e.printStackTrace();
}
try {
if (stmt != null) {
stmt.close();
}
} catch (SQLException e){
e.printStackTrace();
}
try {
if (conn != null) {
conn.close();
}
} catch (SQLException e){
e.printStackTrace();
}
}
}
}
おまけ(ltrace でライブラリコールのトレースを取得する)
- ltrace でリスナープロセスと fork されるプロセスのライブラリコールをトレースする。
[root@localhost ~]# ltrace -tf -p 13079 -o ltrace.log
- テストケース実行後、setsockopt でどのようなソケットオプションを使用しているか調べる。
[root@localhost ~]# grep -C 2 -i setsockopt ltrace.log
13090 21:04:07 __ctype_b_loc() = 0x147ed0
13090 21:04:07 free(0x11b6d080) = <void>
13090 21:04:07 setsockopt(14, 6, 1, 0xbfaec328, 4) = 0
13090 21:04:07 malloc(4096) = 0x11b6d080
13090 21:04:07 vsnprintf("set TCP_NODELAY on 14\n", 4096, "set TCP_NODELAY on %d\n", 0xbfaec264) = 22
--
13090 21:04:08 write(8, "m}nttctl*0TgSY"1;\n", 18) = 18
13090 21:04:08 free(0x11b750d0) = <void>
13090 21:04:08 setsockopt(14, 1, 9, 0xbfaebcbc, 4) = 0
13090 21:04:08 malloc(4096) = 0x11b750d0
13090 21:04:08 vsnprintf("normal exit\n", 4096, "normal exit\n", 0xbfaebf80) = 12
--
13090 21:04:13 write(8, "W}0TgmT"1;\n", 11) = 11
13090 21:04:13 free(0x11b76110) = <void>
13090 21:04:13 setsockopt(14, 1, 21, 0xbfaf522c, 8) = 0
13090 21:04:13 malloc(4096) = 0x11b76110
13090 21:04:13 vsnprintf("entry\n", 4096, "entry\n", 0xbfaf52a0) = 6
--
13090 21:04:13 write(8, "}0TgdP"1;\n", 10) = 10
13090 21:04:13 free(0x11b76110) = <void>
13090 21:04:13 setsockopt(14, 1, 20, 0xbfaf522c, 8) = 0
13090 21:04:13 malloc(4096) = 0x11b76110
13090 21:04:13 vsnprintf("entry\n", 4096, "entry\n", 0xbfaf5224) = 6
--
13090 21:04:13 write(8, "!nttdisc*0ThdS"1;\n", 18) = 18
13090 21:04:13 free(0x11b76110) = <void>
13090 21:04:13 setsockopt(14, 1, 9, 0xbfaf520c, 4) = 0
13090 21:04:13 close(14) = 0
13090 21:04:13 malloc(4096) = 0x11b76110
--
13097 21:04:19 __ctype_b_loc() = 0x633690
13097 21:04:19 free(0x1241a080) = <void>
13097 21:04:19 setsockopt(14, 6, 1, 0xbf990628, 4) = 0
13097 21:04:19 malloc(4096) = 0x1241a080
13097 21:04:19 vsnprintf("set TCP_NODELAY on 14\n", 4096, "set TCP_NODELAY on %d\n", 0xbf990564) = 22
--
13097 21:04:20 write(8, "m}nttctl*0TgEW"1;\n", 18) = 18
13097 21:04:20 free(0x124220d0) = <void>
13097 21:04:20 setsockopt(14, 1, 9, 0xbf98ffbc, 4) = 0
13097 21:04:20 malloc(4096) = 0x124220d0
13097 21:04:20 vsnprintf("normal exit\n", 4096, "normal exit\n", 0xbf990280) = 12
--
13097 21:04:25 write(8, "W}0Tg4U"8;\n", 11) = 11
13097 21:04:25 free(0x12423110) = <void>
13097 21:04:25 setsockopt(14, 1, 21, 0xbf99952c, 8) = 0
13097 21:04:25 malloc(4096) = 0x12423110
13097 21:04:25 vsnprintf("entry\n", 4096, "entry\n", 0xbf9995a0) = 6
--
13097 21:04:25 write(8, "}0TgUT"8;\n", 10) = 10
13097 21:04:25 free(0x12423110) = <void>
13097 21:04:25 setsockopt(14, 1, 20, 0xbf99952c, 8) = 0
13097 21:04:25 malloc(4096) = 0x12423110
13097 21:04:25 vsnprintf("entry\n", 4096, "entry\n", 0xbf999524) = 6
--
13097 21:04:25 write(8, "!nttdisc*0ThAR"1;\n", 18) = 18
13097 21:04:25 free(0x12423110) = <void>
13097 21:04:25 setsockopt(14, 1, 9, 0xbf99950c, 4) = 0
13097 21:04:25 close(14) = 0
13097 21:04:25 malloc(4096) = 0