Techdata VINA 지식 공유

SQL에서 사용하는 Bind 변수를 알아 내기 위한 몇가지 방법

 - Create table

create table big_table as select empno , ename , job , mgr , hiredate , sal , comm , to_char(deptno) deptno from scott.emp ;

scott 유저가 기본적으로 없으신 분은 $ORACLE_HOME/rdbms/admin/utlsampl.sql 스크립트를 이용해서 생성

- 데이터 뻥튀기

Insert into big_table select * from big_table ; 이런식으로 데이터 건수를 좀 만든다. ( 7,340,032 정도 생성 후 테스트 함)

- Index 생성

create index big_table_deptno_idx on big_table(deptno) ;

- Autotrace 활성 화

$ORACLE_HOME/sqlplus/admin/plustrce.sql 스크립트를 수행 시키면 plustrace 라는 권한이 생기는데 이 권한을 일반 유저에게 주면 autotrace 기능을 사용 가능 하다.

- DBMS_XPLAN 패키지 사용

혹시나 dbms_xplan 패키지가 생성 안되신 분들은 $ORACLE_HOME/rdbms/admin/dbmsxpln.sql 사용

- Plan table 생성

@$ORACLE_HOME/rdbms/admin/utlxplan.sql 스크립트를 이용하여 PLAN_TABLE 생성
 

여기까지 준비가 완료 되었으면 본격적으로 BInd 변수 확인하는 방법을 알아 보도록 하자

1. Plan 확인 방법

Autotrace와 dbms_xplan을 이용하여 Plan을 확인

00:45:27 BSTAR 3048>set autotrace trace exp
00:45:38 BSTAR 3048>var b1 number ;    <-- 변수 선언
00:45:47 BSTAR 3048>exec :b1 := 40 ;    <-- 변수 값 지정

PL/SQL 처리가 정상적으로 완료되었습니다.

경   과: 00:00:00.01
00:45:56 BSTAR 3048>SELECT * FROM big_table WHERE deptno = :b1 ;
경   과: 00:00:00.00

Execution Plan
----------------------------------------------------------
Plan hash value: 724613332

--------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name                 | Rows  | Bytes | Cost (%CPU)| Time   |
--------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                      |   140K|    12M| 10597   (1)| 00:02:08 |   1 |  TABLE ACCESS BY INDEX ROWID| BIG_TABLE            |   140K|    12M| 10597   (1)| 00:02:08 |*  2 |   INDEX RANGE SCAN          | BIG_TABLE_DEPTNO_IDX | 56243 |       |  9555   (1)| 00:01:55 --------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("DEPTNO"=:B1)

Note
-----
   - dynamic sampling used for this statement

00:46:16 BSTAR 3048>set autotrace off
00:46:26 BSTAR 3048>
00:46:27 BSTAR 3048>explain plan for SELECT * FROM big_table WHERE deptno = :b1 ;

해석되었습니다.

경   과: 00:00:00.01
00:47:01 BSTAR 3048>select * from table(dbms_xplan.display) ;

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------
Plan hash value: 724613332

--------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name                 | Rows  | Bytes | Cost (%CPU)| Time   |
--------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                      |   140K|    12M| 10597   (1)| 00:02:08 |   1 |  TABLE ACCESS BY INDEX ROWID| BIG_TABLE            |   140K|    12M| 10597   (1)| 00:02:08 |*  2 |   INDEX RANGE SCAN          | BIG_TABLE_DEPTNO_IDX | 56243 |       |  9555   (1)| 00:01:55 --------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("DEPTNO"=:B1)

Note
-----
   - dynamic sampling used for this statement

18 개의 행이 선택되었습니다.

경   과: 00:00:00.06
00:47:15 BSTAR 3048>

2. Bind 변수 값 확인 방법 #1 ( 10046 Trace 이용 )

세션에서 10046 Event를 이용하여 BInd 변수를 확인해 보자.

00:52:31 BSTAR 2028>var b1 number
00:52:42 BSTAR 2028>exec :b1 := 40 ;

PL/SQL 처리가 정상적으로 완료되었습니다.

경   과: 00:00:00.00

00:05:45 BSTAR 4080>alter session set tracefile_identifier='TEST' ;

세션이 변경되었습니다.

경   과: 00:00:00.00
00:52:49 BSTAR 2028>alter session set events '10046 trace name context forever , level 4 ' ;

세션이 변경되었습니다.

경   과: 00:00:00.01
00:53:16 BSTAR 2028>SELECT * FROM big_table WHERE deptno = :b1 ;

선택된 레코드가 없습니다.

경   과: 00:00:19.11
00:53:47 BSTAR 2028>alter session set events '10046 trace name context off' ;

세션이 변경되었습니다.

이제 udump에 가서 트레이스 파일이름에 TEST가 붙은 파일을 열어보자

=====================
PARSING IN CURSOR #2 len=43 dep=0 uid=64 oct=3 lid=64 tim=2669424238 hv=536337181 ad='27e06380'
SELECT * FROM big_table where deptno = :b1 
END OF STMT
PARSE #2:c=0,e=68,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2669424234
BINDS #2:
kkscoacd
 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=0835c364  bln=22  avl=02  flg=05
  value=40
EXEC #2:c=15625,e=6031,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2669434735
*** 2008-04-11 00:00:57.703
FETCH #2:c=4062500,e=25353648,p=85106,cr=86476,cu=0,mis=0,r=0,dep=0,og=1,tim=2694789310
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=54789 op='TABLE ACCESS FULL BIG_TABLE (cr=86476 pr=85106 pw=0 time=25353646 us)'
*** 2008-04-11 00:09:46.875
=====================

- 초 간단 설명 -

hv=536337181 : v$sqlarea 영역안의 hash_value값과 일치

ad=27e06380 :  v$sqlarea 영역안의 address 값과 일치

oacdty=02   : bind 변수의 데이터 타입을 나타냄   ( 01 : varchar2 / 02 : number / 96 : char )

value=40  :  변수 값

e=25353648 : elapsed time

cr=86476     : Logical Read량 (86476 blocks)

TABLE ACCESS FULL BIG_TABLE : Table full Scan을 수행 했다는 뜻 ^^* 

 tkprof수행 결과를 추가해 보면

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.01       0.00          0          0          0           0
Fetch        1      4.06      25.35      85106      86476          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      4.07      25.35      85106      86476         0          0

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS
Parsing user id: 64 

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  TABLE ACCESS FULL BIG_TABLE (cr=86476 pr=85106 pw=0 time=25353646 us)

쿼리를 수행하는데 25.35초가 소요 되었으며 읽은 블록 수는 86,476 블록이고 Return된 데이터 건수는 0 건이다.

그런데 여기서 이상한 점을 발견할 수 있다. 발견하신 분은 대단하십니다 ~~!!!

분명 1 에서 plan을 수행해 보면 index Scan을 하도록 플랜이 나왔는데 실제 수행 결과를 확인해 보면 full table scan을 하고 있다 .

즉, 가장 흔한 runtime 실행 계획과 수행 전 실행계획이 틀린 경우이다. 원인은 숫자형이 문자형보다 우선(?)시 되어 문자가 숫자로 변형이 이루어 지기 때문이다. 즉 인덱스 컬럼에 변형이 가해지는 결과여서 인덱스를 사용 못하게 되는 것이다.

그럼 수행중인 다른 세션의 SQL에 대하여 BInd 변수를 알고 싶으면 다음의 몇가지 방법을 사용

3. 다른 세션에서 수행중인 SQL의 바인드 확인(oradebug)

모니터링을 하다가 수행중인 SQL이 아무래도 의심스러워서 Bind변수값과 Plan을 확인해 보고자 한다면 가장 간단하게 oradebug 를 사용할 수 있다.

여기선 OS Process ID를 사용해보도록 하자.

테스트 시나리오

- 세션1 : 바인드 변수를 사용하는 쿼리를 수행중임 ( O/S Process ID 는 2092 임)

- 세션2 : 모니터링 중 세션1 쿼리가 오래 수행되어서 플랜과 bind 변수를 확인하고자 10046  Trace를 수행 함.

- 세션1

01:24:02 BSTAR 2092>var b1 number ;
01:24:10 BSTAR 2092>exec :b1 := 40 ;

PL/SQL 처리가 정상적으로 완료되었습니다.

경   과: 00:00:00.00
01:24:16 BSTAR 2092>SELECT empno , ename , sal , deptno FROM big_table WHERE deptno = :b1 ;

선택된 레코드가 없습니다.

경   과: 00:00:20.06

- 세션2

01:24:18 SYS 3672>oradebug setospid 2092
Oracle pid: 19, Windows thread id: 2092, image: ORACLE.EXE (SHAD)
01:24:22 SYS 3672>oradebug event 10046 trace name context forever , level 4
명령문을 처리했습니다.
01:24:52 SYS 3672>oradebug close_trace

설명 세션1에서 수행중인 SQL이 오래 걸리는 것을 확인하고 DBA세션인 세션2에서 10046 Trace를 수행함.

트레이스 파일을 확인해 보면 어떤 결과가 있을까요 ? 트레이스 파일을 확인해 보면 내가 원하는 쿼리 및 Bind변수는 구경(?)도 못할 것이다.

즉 10046 Trace에서 Bind 변수를 얻을 수 있는 방법은 해당 SQL이 파싱단계를 거치기 전에 수행 하여야지만 SQL구문 및 Bind 변수를 확인 할수 있다.

그럼 oradebug를 이용해서 수행 중인 SQL의 Bind 변수 확인은 불가능 한 것인가 ?

이럴 경우 processstate를 이용하는 방법이 있다. 

01:51:28 SYS 3672>oradebug setospid 340
Oracle pid: 19, Windows thread id: 340, image: ORACLE.EXE (SHAD)
01:53:16 SYS 3672>oradebug dump processstate 10
명령문을 처리했습니다.
01:53:25 SYS 3672>oradebug tracefile_name
c:\oracle\product\10.2.0\admin\bstar\udump\bstar_ora_340.trc

트래이스 파일을 열어 보면 세션에서 사용한 커서 정보를 확인 할 수 있다.

4. 다른 세션의 바인드 변수 확인 ( v$sql_bind_capture  뷰 이용)

우선 v$sqlare나 기타 sql관련 뷰에서 hash value AND address 또는 sql_id를 확인하자

02:18:56 SYS 3672>SELECT sql_id , sql_text , hash_value , address FROM v$sqlarea
02:21:03   2  WHERE sql_text like 'SELECT * FROM big_table where deptno = :b1%' ;

SQL_ID                     SQL_TEXT                                                                      HASH_VALUE           ADDRESS
------------ ------------------------------------------------ --------------------- --------
5t4387sgzgqsx    SELECT * FROM big_table where deptno = :b1                           536337181            27E06380

SELECT * FROM v$sql_bind_capture
WHERE sql_id = '5t4387sgzgqsx'

OR

SELECT * FROM v$sql_bind_capture
WHERE hash_value = '536337181'
AND   address = '27E06380'  수행해 보자

NAME         CHILD_NUMBER   POSITION  DATATYPE_STRING     WAS_CAPTURED     VALUE_STRING
-------- ------------ ---------- ---------------- --------------   ------------
:B1                      1                1              NUMBER                    YES                      40

위와 같이 결과를 얻을 수 있다.

child_number : 해당 SQL의 Child Number Count

position : 하나의 SQL에 여러개의 Bind변수를 사용할 경우 (1 ~ n )

datatype_string : bind 변수 데이터 타입

value_string : 바인드 변수 값

5. dbms_xplan 패키지 사용

sql_id를 알 경우 쉽게 확인 가능 단, v$sql_plan 뷰로 조회가 되지 않는 경우 확인 불가 !!!

v$sql_bind_captuer 뷰에 데이터가 있어도 v$sql_plan뷰에 해당 sql_id나 hash_value의 SQL이 존재 하지 않으면 사용 못함

위와 같은 경우는 다음과 같은 에러가 발생 함

02:30:36 SYS 3672>select * from table(dbms_xplan.display_cursor('5t4387sgzgqsx' ,1,'typical +peeked_binds'));

PLAN_TABLE_OUTPUT
------------------------------------------------------------------
SQL_ID  5t4387sgzgqsx, child number 1

SELECT * FROM big_table where deptno = :b1

NOTE: cannot fetch plan for SQL_ID: 5t4387sgzgqsx, CHILD_NUMBER: 1
      Please verify value of SQL_ID and CHILD_NUMBER;
      It could also be that the plan is no longer in cursor cache (check v$sql_plan)

 정상적인 플랜 및 바인드 변수가 존재 할 경우

dbms_xplan.display_cursor( 'sql_id' , child_number , 'option')

 02:35:03 SYS 3672>select * from table(dbms_xplan.display_cursor('726g67b2tbpv6' ,0,'typical +peeked_binds')) ;

PLAN_TABLE_OUTPUT

--------------------------------------------------
SQL_ID  726g67b2tbpv6, child number 0
-------------------------------------
SELECT empno , ename , sal , deptno FROM big_table WHERE deptno = :b1

Plan hash value: 3993303771

-------------------------------------------------------------------------------
| Id  | Operation         | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |           |       |       | 24708 (100)|          |
|*  1 |  TABLE ACCESS FULL| BIG_TABLE |   956 | 52580 | 24708   (5)| 00:04:57 |
-------------------------------------------------------------------------------

Peeked Binds (identified by position):
--------------------------------------

   1 - :B1 (NUMBER): 40

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(TO_NUMBER("DEPTNO")=:B1)   <--- Full Scan 하게 된 원인

Note
-----
   - dynamic sampling used for this statement

27 개의 행이 선택되었습니다.

경   과: 00:00:00.32
02:35:04 SYS 3672>select * from table(dbms_xplan.display_cursor('726g67b2tbpv6' ,0,'all +peeked_binds')) ;

PLAN_TABLE_OUTPUT

--------------------------------------------------
SQL_ID  726g67b2tbpv6, child number 0
-------------------------------------
SELECT empno , ename , sal , deptno FROM big_table WHERE deptno = :b1

Plan hash value: 3993303771

-------------------------------------------------------------------------------
| Id  | Operation         | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |           |       |       | 24708 (100)|          |
|*  1 |  TABLE ACCESS FULL| BIG_TABLE |   956 | 52580 | 24708   (5)| 00:04:57 |
-------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1 / BIG_TABLE@SEL$1

Peeked Binds (identified by position):
--------------------------------------

   1 - :B1 (NUMBER): 40

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(TO_NUMBER("DEPTNO")=:B1)          <-- Full Scan 하게 된 원인

Column Projection Information (identified by operation id):
-----------------------------------------------------------

   1 - "EMPNO"[NUMBER,22], "ENAME"[VARCHAR2,10], "SAL"[NUMBER,22],
       "DEPTNO"[VARCHAR2,40]

Note
-----
   - dynamic sampling used for this statement

38 개의 행이 선택되었습니다.

경   과: 00:00:00.12
02:38:28 SYS 3672>

위와 같은 방법을 이용하여 SQL Plan 및 Bind 변수를 확인 할 수 있다.