[20250418]绑定变量太多的分析(21c).txt

--//前几天测试，执行绑定变量很多的sql语句，发现无法看出在绑定变量替换时，执行"缓慢"的原因，没有相关等待事件。
--//再次尝试分析这种情况：

1.环境：
SCOTT@book01p> @ ver2
==============================
PORT_STRING                   : x86_64/Linux 2.4.xx
VERSION                       : 21.0.0.0.0
BANNER                        : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL                   : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY                 : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID                        : 0
PL/SQL procedure successfully completed.

2.建立测试环境：

create table t as select * from all_objects;
create unique index i_t_object_id on t(object_id);
--//分析略。

$ cat a.txt
set pagesize 0
set head off
set feedback off
set verify off
set timing off
spool b1.txt
select 'set termout off'  from dual;
select 'variable b'||to_char(level)||' number;'  from dual connect by level<=&1;
select 'begin'  from dual;
select ':b'||to_char(level)||' :='|| to_char(level)||';'  from dual connect by level<=&1;
select 'end;'  from dual;
select '/' from dual ;
select 'set termout on' txt from dual;
spool off

spool b2.txt
--select 'set timing on' txt from dual;
select 'select count(data_object_id) from t where (1,object_id) in (' txt from dual ;
select '(1,:b'||to_char(level)||'),' txt from dual connect by level<=&&1 -1 ;
select '(1,:b'||to_char(&&1)||'));' txt from dual ;
--select 'set timing off' txt from dual;
spool off

set pagesize 9999
set head on
set feedback on

SCOTT@book01p> @ a.txt 1000
--//输出略。这样建立2个文本b1.txt,b2.txt .
--//采用集合的比较，这样可以突破in list 1000个值的限制。

3.分析：
SCOTT@book01p> @ spid
==============================
SID                           : 16
SERIAL#                       : 56356
PROCESS                       : 4086
SERVER                        : DEDICATED
SPID                          : 4088
PID                           : 64
P_SERIAL#                     : 4
KILL_COMMAND                  : alter system kill session '16,56356' immediate;
PL/SQL procedure successfully completed.

SCOTT@book01p> @ a.txt 1000
SCOTT@book01p> @ b1.txt
SCOTT@book01p> @ b2.txt
COUNT(DATA_OBJECT_ID)
---------------------
                  824

$ uniq -c loop5x.txt
  10099 /

SCOTT@book01p> @ loop5x.txt

--//打开另外session，执行如下：

SYS@book> @ ost 16 0 20000

-- oStackProf v1.2 - EXPERIMENTAL script by Tanel Poder ( https://tanelpoder.com )

WARNING! This script can crash the target process on Oracle 9.2 on Windows
and maybe other versions/platforms as well. Test this script out thorouhgly
in your dev environment first!
Hit CTRL+C to cancel, ENTER to continue...

Sampling...

--//按ctrl+c中断。
--//简单说明就是执行oradebug setospid <spid>,不断调用oradebug short_stack，收集stack信息。
--//脚本原始来源 Tanel Poder，最后调用python分析，我的python可能版本太低执行报错，我取消了最后python的执行。

$ sort ostackprof_4088.txt| uniq -c | sort -nr >| aaa.txt

$ head -6 aaa.txt
   7418 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-read()+14<-read()+85<-snttread()+16<-nttfprd()+293<-nsbasic_brc()+357<-nioqrc()+495<-opikndf2()+1078<-opitsk()+920<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
    188 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-read()+16<-read()+85<-snttread()+16<-nttfprd()+293<-nsbasic_brc()+357<-nioqrc()+495<-opikndf2()+1078<-opitsk()+920<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
     17 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-write()+16<-snttwrite()+16<-nttfpwr()+215<-nsbasic_bsd()+416<-nioqrc()+300<-opikndf2()+1078<-opitsk()+920<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
     17 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-opiltc()+436<-kxsBindBufferSetUp()+196<-kxsxsi()+1025<-opiexe()+4791<-kpoal8()+2237<-opiodr()+1256<-ttcpip()+1257<-opitsk()+1906<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
     11 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-qerilnil()+223<-qerilFetch()+219<-qergsFetchSimple()+7593<-qergsFetch()+263<-opifch2()+3564<-kpoal8()+4232<-opiodr()+1256<-ttcpip()+1257<-opitsk()+1906<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
      7 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-qetlbr()+940<-qertbFetchByRowID()+6820<-qerilFetch()+143<-qergsFetchSimple()+7593<-qergsFetch()+263<-opifch2()+3564<-kpoal8()+4232<-opiodr()+1256<-ttcpip()+1257<-opitsk()+1906<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
--//仔细阅读Tanel Poder ，stack_helper.py脚本，应该从__sighandler开始。
--//大部分__sighandler()<-read()+14 的情况，说明绑定变量太多，抓取short_stack的执行堆栈，都是集中在read的调用与执行上.
--//不熟悉这类问题的分析，仅仅作为参考。

$ ./lookup.awk ksedsts
ksedsts : kernel service error debug dump the call stack short stack

$ ./lookup.awk ksdxcb
ksdxcb : kernel service debug internal errors ksdx callback for sosd layer signal handler

$ ./lookup.awk sspuser
sspuser : operating system dependent system process management handle SIGUSR2 for Oracle

$ cat  ostackprof_4088.txt |  sed "s/<-/\n/g" | sort | uniq -c | sort -nr | head -40
   9005 opiodr()+1256
   8320 ssthrdmain()+412
   8320 sspuser()+213
   8320 sou2o()+165
   8320 __sighandler()
   8320 opimai_real()+400
   8320 opiino()+1008
   8320 opidrv()+1067
   8320 main()+292
   8320 __libc_start_main()+245
   8320 ksedsts()+418
   8320 ksdxcb()+2187
   7623 opitsk()+920
   7623 opikndf2()+1078
   7606 snttread()+16
   7606 read()+85
   7606 nttfprd()+293
   7606 nsbasic_brc()+357
   7606 nioqrc()+495
   7418 read()+14
    693 opitsk()+1906
    686 ttcpip()+1257
    433 kpoal8()+4232
    425 qergsFetch()+263
    425 opifch2()+3564
    424 qergsFetchSimple()+7593
    224 kpoal8()+2237
    217 qerilFetch()+143
    188 read()+16
    175 qerilFetch()+312
    165 qertbStart()+2515
    117 opiexe()+7793
    116 selexe0()+1002
    116 qergsStart()+1360
    113 qerilStart()+456
    111 qerilInitializeInList()+1924
     89 qerilSortSingleCol()+403
     81 qertbFetchByRowID()+13464
     80 qerpfStart()+447
     75 qerpfStart()+585

$ cat  ostackprof_4088.txt |  sed "s/<-/\n/g" | sed "s/+.*$//" |sort | uniq -c | sort -nr | head -40
  15212 read()
   9006 opiodr()
   8320 ssthrdmain()
   8320 sspuser()
   8320 sou2o()
   8320 __sighandler()
   8320 opitsk()
   8320 opimai_real()
   8320 opiino()
   8320 opidrv()
   8320 main()
   8320 __libc_start_main()
   8320 ksedsts()
   8320 ksdxcb()
   7625 opikndf2()
   7623 nioqrc()
   7606 snttread()
   7606 nttfprd()
   7606 nsbasic_brc()
    693 ttcpip()
    685 kpoal8()
    433 opifch2()
    425 qergsFetchSimple()
    425 qergsFetch()
    424 qerilFetch()
    224 opiexe()
    217 qertbFetchByRowID()
    178 qertbStart()
    164 qerpfStart()
    117 selexe0()
    116 qerilStart()
    116 qergsStart()
    113 qerilInitializeInList()
    111 qerilSortSingleCol()
     89 kgwsins()
     81 qerpfFetch()
     80 qerpfInit()
     75 qerixStart()
     74 qerixFetchUniqueIndex()
     74 kxsxsi()
    
4.多个会话同时执行的情况如何：

$ sort ostackprof_6361.txt | uniq -c | sort -nr
    521 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-read()+14<-read()+85<-snttread()+16<-nttfprd()+293<-nsbasic_brc()+357<-nioqrc()+495<-opikndf2()+1078<-opitsk()+920<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
      2 ksedsts()+418<-ksdxcb()+2187<-sspuser()+213<-__sighandler()<-read()+16<-read()+85<-snttread()+16<-nttfprd()+293<-nsbasic_brc()+357<-nioqrc()+495<-opikndf2()+1078<-opitsk()+920<-opiino()+1008<-opiodr()+1256<-opidrv()+1067<-sou2o()+165<-opimai_real()+400<-ssthrdmain()+412<-main()+292<-__libc_start_main()+245
--//抓取到的都是以上2行。

$ cat  ostackprof_6361.txt |  sed "s/<-/\n/g"  |sort | uniq -c | sort -nr | head -40
    523 ssthrdmain()+412
    523 sspuser()+213
    523 sou2o()+165
    523 snttread()+16
    523 __sighandler()
    523 read()+85
    523 opitsk()+920
    523 opiodr()+1256
    523 opimai_real()+400
    523 opikndf2()+1078
    523 opiino()+1008
    523 opidrv()+1067
    523 nttfprd()+293
    523 nsbasic_brc()+357
    523 nioqrc()+495
    523 main()+292
    523 __libc_start_main()+245
    523 ksedsts()+418
    523 ksdxcb()+2187
    521 read()+14
      2 read()+16

5.附上修改ost.sql代码：
$ cat ost.sql
-------------------------------------------------------------------------------------
--
-- File name:   oStackProfU.sql ( Oradebug short_Stack Profiler )
-- Purpose:     Take target process stack samples and show an execution profile
--
-- Author:      Tanel Poder
-- Copyright:   2008 Tanel Poder. All rights reserved. More info at http://tanelpoder.com
--              Licensed under the Apache License, Version 2.0. See LICENSE.txt for terms & conditions.
--
-- Usage:       @ostackprofu <sid> <interval> <#samples>
--
--              @ostackprofu  148 0 100
--
--                - takes 100 stack samples of server process tied to SID 148
--                  with not waiting between samples
--
--              @ostackprofu  148 0.1 60

--                - takes 60 stack samples of process tied to sid 148 with 0.1
--                  second interval
--
-- Updates:     Version 1.2 - support also Unix/Mac clients via Python based stack_helper
--
-- Other:       WARNING!!! This tool is experimental and not meant for use in
--                         production environments. This is due oradebug short_stack
--                         being somewhat unstable on some platforms and it has
--                         event crashed target processes on Windows platforms (9.2)
--
--                         Use an OS stack sampler instead when need to diagnose
--                         production issues (and test even those well in dev)
--
--
--              Note that this script uses a stack_helper.py Python script for post
--              processing oradebug short_stack output. Therefore you need to run
--              it on a Unix/Linux/Mac SQLPLUS client with python installed. The
--              server can be on any platforms as long as it supports oradebug
--              short_stack - 10.2 on Solaris x64 doesn't seem to support it though,
--              but you have DTrace there anyway ;)
--
-------------------------------------------------------------------------------------
PROMPT
PROMPT -- oStackProf v1.2 - EXPERIMENTAL script by Tanel Poder ( https://tanelpoder.com )
PROMPT
PROMPT WARNING! This script can crash the target process on Oracle 9.2 on Windows
PROMPT and maybe other versions/platforms as well. Test this script out thorouhgly
PROMPT in your dev environment first!
PAUSE  Hit CTRL+C to cancel, ENTER to continue...

SET TERMOUT OFF FEEDBACK OFF VERIFY OFF

DEF ostackprof_sid=&1
DEF ostackprof_interval=&2
DEF ostackprof_samples=&3

COL spid NEW_VALUE ostackprof_spid
SELECT spid FROM v$process WHERE addr = (SELECT /*+ NO_UNNEST */ paddr FROM v$session WHERE sid = &1);
COL spid CLEAR

ORADEBUG SETOSPID &ostackprof_spid

SELECT
    'oradebug short_stack'||
    DECODE(TO_NUMBER(&ostackprof_interval),
        0, '',
        chr(13)||chr(10)||'exec dbms_lock.sleep('||TO_CHAR(&ostackprof_interval)||')'
    ) cmd
FROM
    (select 1 from dual CONNECT BY level <= &ostackprof_samples)
.

SPOOL ostackprof_&ostackprof_spid..tmp
SET HEADING OFF
PROMPT spool ostackprof_&ostackprof_spid..txt
/
PROMPT spool off
SET HEADING ON
SPOOL OFF

SET TERMOUT ON
PROMPT Sampling...
SET TERMOUT OFF
@ostackprof_&ostackprof_spid..tmp

SET TERMOUT ON FEEDBACK ON