select p.spid,s.sid,s.serial# from v$session s,v$process p where s.sid=sys_context('userenv','sid') and s.paddr=p.addr;
SPID SID SERIAL#
------------------------ ---------- ----------
5439878 266 48189
---session 2
col event format a40
select event,total_waits,time_waited from v$session_event where sid=266 and event in ('SQL*Net message from client');
EVENT TOTAL_WAITS TIME_WAITED
---------------------------------------- ----------- -----------
SQL*Net message from client 14 6875
---session 1: 设定arraysize等于表的行数
set arraysize 21
select * from scott.t1;
。。。省略输出
---session 2
select event,total_waits,time_waited from v$session_event where sid=266 and event in ('SQL*Net message from client');
EVENT TOTAL_WAITS TIME_WAITED
---------------------------------------- ----------- -----------
SQL*Net message from client 17 29997
上述结果得出session 1 执行Select后"SQL*Net message from client"次数从14->17，即增加了3次，分析这3次分别在什么时候产生的，可以通过session 1的trace文件获得：
*** 2016-01-22 13:41:37.686
WAIT #4573489544: nam='SQL*Net message from client' ela= 132467556 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=11895166310146
CLOSE #4573458848:c=0,e=24,dep=0,type=0,tim=11895166311042
CLOSE #4573489544:c=0,e=45,dep=0,type=3,tim=11895166311131
=====================
PARSING IN CURSOR #4573469256 len=23 dep=0 uid=0 oct=3 lid=0 tim=11895166311320 hv=3534831217 ad='7000001ba6b8878' sqlid='1qgrwqv9b2gmj'
select * from scott.t1
END OF STMT
PARSE #4573469256:c=0,e=129,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=838529891,tim=11895166311319
EXEC #4573469256:c=0,e=63,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=838529891,tim=11895166311456
WAIT #4573469256: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=11895166311500
FETCH #4573469256:c=0,e=124,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=838529891,tim=11895166311659 <---r=1表示返回了21条里的第1条
WAIT #4573469256: nam='SQL*Net message from client' ela= 271 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=11895166311965
WAIT #4573469256: nam='SQL*Net message to client' ela= 0 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=11895166311995
FETCH #4573469256:c=0,e=49,p=0,cr=1,cu=0,mis=0,r=20,dep=0,og=1,plh=838529891,tim=11895166312036 <---r=20表示返回了21条里的后20条
STAT #4573469256 id=1 cnt=21 pid=0 pos=1 obj=41088 op='TABLE ACCESS FULL T1 (cr=3 pr=0 pw=0 time=113 us cost=3 size=357 card=21)'
WAIT #4573469256: nam='SQL*Net message from client' ela= 1102 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=11895166313235
PARSE #4573489544:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=11895166313300
WAIT #4573489544: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=11895166313634
EXEC #4573489544:c=0,e=290,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=11895166313672
第1次出现SQL*Net message from client等待事件出现在client向server端发送命令的时候；
第2次出现在server端进程返回第一行数据的时候，client端接收到第1行数据时对server端的确认响应；
第3次是client端在接收到的第2~21行数据后对server端作出的确认响应；
---session 1：从autotrace里也可以看到roundtrips=2
SYS@tstdb1-SQL> select * from scott.t1;
21 rows selected.
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
3 consistent gets
0 physical reads
0 redo size
1216 bytes sent via SQL*Net to client
520 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
21 rows processed
第(2)组：设置arraysize小于返回的行数
---session 1:
SYS@tstdb1-SQL> set arraysize 15
SYS@tstdb1-SQL> show arraysize
arraysize 15
---session 2:
SYS@tstdb1-SQL> select event,total_waits,time_waited from v$session_event where sid=266 and event in ('SQL*Net message from client');