oracle wait_time -1,个人对于v$session_wait中的WAIT_TIME,SECONDS_IN_WAIT,STATE关系的一点理解...
首先意识到一点很重要,那就是oracle会话(进程)它不仅要waiting,更要working.[@more@]
首先意识到一点很重要,那就是oracle会话(进程)它不仅要waiting,更要working.其实这就是一层窗户纸,说出来谁都明白,但之前我好象就没有意识到这一点,所以对这3个字段之间的关系似乎一直都无法理解。
从操作系统的角度来讲,oracle进程等待资源可用,等待先决动作完成,等待新的工作去做,都会使它处于被阻塞的状态;当阻塞态解除的时候,它变为可运行状态,等待被调度进程调度占有CPU;最终它被调度占有CPU,从而执行它的动作。
oracle的等待事件针对的就是被阻塞态(当然也许是它的一个很大的一个子集,但不是全集),也就是说这时会话在waiting,如果这个时候你查询v$session_wait,STATE=WAITING,SECONDS_IN_WAIT表示已经等待的时间(误差是3秒),WAIT_TIME可以不予关注(8i中这时这个值一定就是0,但9i开始不一定就是0了,所以STATE=WAITING与WAIT_TIME=0不一定就存在着对应关系)。
但如果你查询v$session_wait时,对应的进程正处于可运行态,或者正占有CPU(比如正进行LIO,HASH运算等),也就是说这时会话在working,这时v$session_wait会怎样表现这种情况呢?在v$session_wait中没有对应行数据?不!有数据,但数据是最近的上一次等待的数据(这个等待已经结束,但下一次等待还没有到来),那如何与正在等待区分呢?通过STATE字段!这种情况下STATE是除WAITING之外的3种选择值：
WAITED UNKNOWN TIME :这时WAIT_TIME=-2,表示TIMED_STATISTICS=FALSE,oracle无法确定等待时间
WAITED SHORT TIME :这时WAIT_TIME=-1,表示最近的上一次等待的时间少于1cs,SECONDS_IN_WAIT表示自最近的上一次等待开始已经经历的时间(误差是3秒)
WAITED KNOWN TIME :表示最近的上一次等待的时间>=1cs,具体时间由WAIT_TIME(单位是cs)决定,SECONDS_IN_WAIT表示自最近的上一次等待开始已经经历的时间(误差是3秒)
这时也可以从OS级查看进程状态,也可以从v$sesstat,v$sess_io等会话统计信息处查看会话是否正在处理数据,比如LIO是否持续增大,会话的CPU时间是否持续增大等.
实验代码如下：
SA调用的脚本代码(instruct.txt)：
select sid from v$mystat where rownum=1;
alter session set session_cached_cursors=100;
select name,value from v$parameter where name='session_cached_cursors';
select to_char(sysdate,'hh24:mi:ss') time from dual;
declare
v_num number(1);
begin
dbms_lock.sleep(300);
for i in 1..200000000
loop
select 1 into v_num from dual;
end loop;
end;
/
SA调用如下：
SQL> @h:instruct.txt;
SID
14
Session altered
NAME VALUE
session_cached_cursors 100
TIME
--------
16:40:42
declare
v_num number(1);
begin
dbms_lock.sleep(300);
for i in 1..200000000
loop
select 1 into v_num from dual;
end loop;
end;
SB调用代码如下(get_stat.txt):
select to_char(sysdate,'hh24:mi:ss') time from dual;
SELECT SID,SEQ#,EVENT,WAIT_TIME,SECONDS_IN_WAIT,STATE FROM v$session_wait WHERE sid=14;
SELECT SID,serial#,STATUS FROM v$session WHERE sid=14;
SELECT * FROM v$sess_io WHERE sid=14;
SELECT b.name,a.value
FROM v$sesstat a,v$statname b
WHERE sid=14 AND a.STATISTIC#=b.STATISTIC#
AND b.name IN('CPU used when call started','CPU used by this session','parse count (total)','parse count (hard)','db block gets','consistent gets');
SB调用结果如下：
SQL> @h:get_stat.txt;
TIME
--------
16:43:14
SID SEQ# EVENT WAIT_TIME SECONDS_IN_WAIT STATE
14 78 PL/SQL lock timer 0 150 WAITING
SID SERIAL# STATUS
14 29 ACTIVE
SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES CONSISTENT_CHANGES
14 28 273 10 0 0
NAME VALUE
----------------------------------------- ----------
CPU used when call started 1
CPU used by this session 1
db block gets 28
consistent gets 273
parse count (total) 62
parse count (hard) 1
SQL> @h:get_stat.txt;
TIME
--------
16:45:19
SID SEQ# EVENT WAIT_TIME SECONDS_IN_WAIT STATE
14 78 PL/SQL lock timer 0 270 WAITING
SID SERIAL# STATUS
14 29 ACTIVE
SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES CONSISTENT_CHANGES
14 28 273 10 0 0
NAME VALUE
----------------------------------------- ----------
CPU used when call started 1
CPU used by this session 1
db block gets 28
consistent gets 273
parse count (total) 62
parse count (hard) 1
这时SA正在执行dbms_lock.sleep(300);所以表现出等待事件:PL/SQL lock timer,两次调用统计视图发现它的LIO根本就没有发生变化.
但是随后调用如下：
SQL> @h:get_stat.txt;
TIME
--------
16:47:03
SID SEQ# EVENT WAIT_TIME SECONDS_IN_WAIT STATE
14 78 PL/SQL lock timer 30720 369 WAITED KNOWN TIME
SID SERIAL# STATUS
14 29 ACTIVE
SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES CONSISTENT_CHANGES
14 9936472 2484386 10 0 0
NAME VALUE
----------------------------------------- ----------
CPU used when call started 1
CPU used by this session 1
db block gets 10007508
consistent gets 2502145
parse count (total) 64
parse count (hard) 3
SQL> @h:get_stat.txt;
TIME
--------
16:54:36
SID SEQ# EVENT WAIT_TIME SECONDS_IN_WAIT STATE
14 78 PL/SQL lock timer 30720 795 WAITED KNOWN TIME
SID SERIAL# STATUS
14 29 ACTIVE
SID BLOCK_GETS CONSISTENT_GETS PHYSICAL_READS BLOCK_CHANGES CONSISTENT_CHANGES
14 68935040 17234028 10 0 0
NAME VALUE
----------------------------------------- ----------
CPU used when call started 1
CPU used by this session 1
db block gets 68982076
consistent gets 17245787
parse count (total) 64
parse count (hard)
这两次调用统计视图时,第一次时SA已经开始FOR循环,也就是说它开始working,PL/SQL lock timer等待已经结束了,但是EVENT仍是'PL/SQL lock timer',它的WAIT_TIME=30720cs,大概就等于我sleep的300s,SECONDS_IN_WAIT=369,且LIO有了明显的增加,第二次调用时EVENT仍是'PL/SQL lock timer'，WAIT_TIME=30720cs也不再变化,但SECONDS_IN_WAIT增大为795,且LIO相对于第一次有了明显的增加。