记一次失效存储过程编译经历

最新推荐文章于 2021-04-07 22:23:50 发布

crc_2013

最新推荐文章于 2021-04-07 22:23:50 发布

阅读量411

点赞数

文章标签：数据库

记一次失效存储过程编译经历

早上刚到工作现场，接到地市发来BQQ信息：能帮忙看看这个过程lyyyy.p_yyy_jtcp执行了多长时间了么？

连上系统看看当前等待事件吧，这么多

没看出和过程异常相关的等待事件，通过查看v$db_object_cache，当前被用的过程还真不少，恰好有客户反映有问题的过程

SQL> select name from v$db_object_cache where locks > 0 and pins > 0 and type='PROCEDURE';

NAME

---------------------------------------

P_MON_SUBS_GPRSTC

PM_SUBS_REWARD_TD

P_B_HF

PWLL_YZDH_MX

P_ZJW_SETUP_20131231

P_LN_GROUPJTCP

PSS_INSLOG

P_LZF_JTDJ

PSS_GETNEWBUSISTAT

P_VPMN_FAMILY

P_SCB_4G

P_YYY_JTCP

PSS_IBMSPRO

PXZW_SCB_JK_ALL

52 rows selected.

再次确认过程在library cache中的状态

SQL> select name,STATUS from v$db_object_cache where locks > 0 and pins > 0 and type='PROCEDURE' and name='P_YYY_JTCP';

NAME STATUS

--------------------------------------

P_YYY_JTCP INVALID_UNAUTH

状态是INVALID_UNAUTH，没注意过这结果代表什么意思，难道失效了？验证下

SQL>select owner,object_name,object_type,status from dba_objects where object_name='P_YYY_JTCP';

OWNER OBJECT_NAME OBJECT_TYPE STATUS

------------------- -------

SYSTEM P_YYY_JTCP PROCEDURE INVALID

LYYYY P_YYY_JTCP PROCEDURE INVALID

过程果真失效了。告诉客户后，他说他来编译下，可等了会又反映：无法编译。

SQL> alter procedure lyyyy.p_yyy_jtcp compile;

^Calter procedure lyyyy.p_yyy_jtcp compile

ERROR at line 1:

ORA-01013: user requested cancel of current operation

我试了下，还真的不行，看来有锁，别等了，hang分析下试试。新开一个session，旧窗口执行编译过程，新窗口做hang分析

Session1:

SQL> alter procedure lyyyy.p_yyy_jtcp compile;

等待ing

Procedure altered.（执行kill -9 56228 后，编译通过）

SQL> /

Procedure altered.

Session 2:

SQL> oradebug setmypid

Statement processed.

SQL> oradebug unlimit

Statement processed.

SQL> oradebug hanganalyze 3

Hang Analysis in /oracle/app/oracle/diag/rdbms/lyjs1/olyjs1/trace/olyjs1_ora_13863.trc

SQL> oradebug tracefile_name

/oracle/app/oracle/diag/rdbms/lyjs1/olyjs1/trace/olyjs1_ora_13863.trc

如下是trc文件内容

Chain [a]就不管了，反正不是自己负责的系统，客户要求做什么就做什么吧，看下chain[b]

下面是部分内容

-------------------------------------------------------------------------------

Chain 2:

-------------------------------------------------------------------------------

Oracle session identified by:

{

instance: 1 (lyjs1.olyjs1)

os id: 12982

process id: 179, oracle@c4olyjs1 (TNS V1-V3)

session id: 1240

session serial #: 15325

}

is waiting for 'library cache lock' with wait info:

{

p1: 'handle address'=0x55b49f880

p2: 'lock address'=0x48458daf8

p3: '100*mode+namespace'=0xff7f00010003

time in wait: 20.409815 sec

timeout after: never

wait id: 92

blocking: 0 sessions

current sql: alter procedure lyyyy.p_yyy_jtcp compile

short stack: ksedsts()+461<-ksdxfstk()+32<-ksdxcb()+1876<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+1865<-kslwaitctx()+163<-ksfwaitctx()+14<-kglLockWait()+837<-kgllkal()+1147<-kglLock()+1426<-kglget()+343<-kkdllk0()+435<-kkdlGetCodeObject()+307<-kkpalt()+334<-opiexe()+17850<-opiosq0()+3870<-kpooprx()+274<-kpoal8()+829<-opiodr()+916<-ttcpip()+2242<-opitsk()+1673<-opiino()+966<-opiodr()+916<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+252<-main()+201<-__libc_start_main()+253<-_star

wait history:

* time between current wait and wait #1: 0.002393 sec

1. event: 'SQL*Net message from client'

time waited: 1 min 3 sec

wait id: 91 p1: 'driver id'=0x62657100

p2: '#bytes'=0x1

* time between wait #1 and #2: 0.000074 sec

2. event: 'SQL*Net message to client'

time waited: 0.000001 sec

wait id: 90 p1: 'driver id'=0x62657100

p2: '#bytes'=0x1

* time between wait #2 and #3: 0.000012 sec

3. event: 'SQL*Net break/reset to client'

time waited: 0.000186 sec

wait id: 89 p1: 'driver id'=0x62657100

p2: 'break?'=0x0

}

and is blocked by

=> Oracle session identified by:

{

instance: 1 (lyjs1.olyjs1)

os id: 12701

process id: 201, oracle@c4olyjs1

session id: 228

session serial #: 42525

}

which is waiting for 'library cache pin' with wait info:

{

p1: 'handle address'=0x55b49f880

p2: 'pin address'=0x4ffbfe620

p3: '100*mode+namespace'=0xff7f00010003

time in wait: 14 min 25 sec

timeout after: 34.163003 sec

wait id: 243

blocking: 1 session

current sql: <none: error encountered - unable to get kgl lock no-wait>

short stack: ksedsts()+461<-ksdxfstk()+32<-ksdxcb()+1876<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+1865<-kslwaitctx()+163<-ksfwaitctx()+14<-kglpnal()+2001<-kglpin()+1425<-kkdllk0()+963<-kkdlGetCodeObject()+307<-kkpcrt()+292<-opiexe()+17871<-opiosq0()+3870<-kpooprx()+274<-kpoal8()+829<-opiodr()+916<-ttcpip()+2242<-opitsk()+1673<-opiino()+966<-opiodr()+916<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+252<-main()+201<-__libc_start_main()+253<-_start()+37

wait history:

* time between current wait and wait #1: 0.004319 sec

1. event: 'SQL*Net more data from client'

time waited: 0.000073 sec

wait id: 242 p1: 'driver id'=0x54435000

p2: '#bytes'=0x15

* time between wait #1 and #2: 0.000004 sec

2. event: 'SQL*Net more data from client'

time waited: 0.000088 sec

wait id: 241 p1: 'driver id'=0x54435000

p2: '#bytes'=0x7

* time between wait #2 and #3: 0.000005 sec

3. event: 'SQL*Net more data from client'

time waited: 0.000073 sec

wait id: 240 p1: 'driver id'=0x54435000

p2: '#bytes'=0x3a

}

and is blocked by

=> Oracle session identified by:

{

instance: 1 (lyjs1.olyjs1)

os id: 56228

process id: 120, oracle@c4olyjs1 (TNS V1-V3)

session id: 1357

session serial #: 29397

}

which is waiting for 'db file sequential read' with wait info:

{

p1: 'file#'=0x4e

p2: 'block#'=0x258f17

p3: 'blocks'=0x1

time in wait: 0.015336 sec

timeout after: never

wait id: 885257

blocking: 2 sessions

current sql: UPDATE LYLSS.LSS_JTCPTJ T SET (T.BBLJ,T.BBNEW)=(SELECT SUM(CASE WHEN TT.PRODID='pg.vo.berry.bl' AND TT.MEMSERVNUMBER IS NOT NULL THEN 1 END) BB, SUM(CASE WHEN TT.PRODID='pg.vo.berry.bl' AND TRUNC(TT.VPMNJRSJ,'mm')=TRUNC(SYSDATE-1,'mm') AND TT.MEMSERVNUMBER IS NOT NULL THEN 1 END) BBNEW FROM LYYYY.YYY_TEMPJTCP TT WHERE

short stack: ksedsts()+461<-ksdxfstk()+32<-ksdxcb()+1876<-sspuser()+112<-__sighandler()<-pread64()+19<-ksfd_skgfqio()+191<-ksfd_skgfrvio()+2864<-ksfd_vio()+493<-ksfdvread()+216<-kcfrbd1()+1865<-kcbz_table_scan_read()+3392<-kcbzibmlt()+2992<-kcbzib()+4478<-kcbgtcr()+28214<-ktrget3()+621<-ktrget2()+126<-kdst_fetch()+637<-kdstf01001010000km()+3613<-kdsttgr()+53205<-qertbFetch()+2206<-qernsFetch()+591<-subsr1()+237<-subsr3()+288<-evaopn3()+2537<-upderhFastPath()+775<-upduawFastPath()+153<-kdusru()+594<-updrowFastPath()+1209<-qerup

wait history:

* time between current wait and wait #1: 0.000319 sec

1. event: 'db file scattered read'

time waited: 0.037597 sec

wait id: 885256 p1: 'file#'=0x4e

p2: 'block#'=0x258f13

p3: 'blocks'=0x3

* time between wait #1 and #2: 0.000430 sec

2. event: 'db file scattered read'

time waited: 0.062052 sec

wait id: 885255 p1: 'file#'=0x4e

p2: 'block#'=0x258f0c