SQL*Net message from client

SQL*Net message from client

如果程序通过游标取数，但是程序处理数据的速度远远落后于取数的速度的话，监控用户进程会发现其长时间的INACTIVE，一直等待程序再次取数，并在SQL*Net message from client上等待

下面是一个例子，通过游标一次取3W条数据，然后SLEEP 60秒以模拟对数据的处理
为了模拟用户程序连接，使用了一个DBLINK连接到本数据库。这样可以避免看到的是进程在PL/SQL lock timer上等待

declare
  type demo_array_type is varray(3001) of big_table%rowtype;
  demo_array demo_array_type;
  cursor c1 is select /*+parallel(a,8)*/* from big_table@myself a;
  rows int:=3000;
begin
  open c1;
  loop
    fetch c1 bulk collect into demo_array limit rows;
    dbms_output.put_line(c1%rowcount);
    exit when c1%notfound;
    dbms_lock.sleep(60);
  end loop;
  close c1;
end;
/

然后看看SQL运行情况
SQL>  select decode(a.QCSERIAL#, null, 'PARENT', 'CHILD') stmt_level,
  2         a.SID,
  3         a.SERIAL#,
  4         b.USERNAME,
  5         b.OSUSER,
  6         b.SQL_HASH_VALUE,
  7         b.SQL_ADDRESS,
  8         a.DEGREE,
  9         a.REQ_DEGREE
 10    from v$px_session a, v$session b
 11   where a.SID = b.SID
 12   order by a.QCSID, stmt_level desc;
 
STMT_LEVEL        SID    SERIAL# USERNAME                       OSUSER                         SQL_HASH_VALUE SQL_ADDRESS     DEGREE REQ_DEGREE
---------- ---------- ---------- ------------------------------ ------------------------------ -------------- ----------- ---------- ----------
PARENT            142         43 CTAIS2                         zhangqiaoc                         2230467307 28176C40              
CHILD             140          7 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8
CHILD             137         10 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8
CHILD             146         13 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8
CHILD             141         11 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8
CHILD             144         36 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8
CHILD             135          6 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8
CHILD             139          7 CTAIS2                         zhangqiaoc                         2230467307 28176C40             7          8

可以看到该进程SID为142，然后通过对v$session每秒采样

BEGIN
  FOR i IN 1..300 LOOP
    INSERT INTO  zq_test SELECT * FROM v$session WHERE sid=142;
    dbms_lock.sleep(1);
    COMMIT;
  END LOOP;
END;
/

对结果进行分析
SQL> SELECT seq#,status,event,COUNT(*) FROM zq_test GROUP BY seq#,status,event ORDER BY seq#;
 
      SEQ# STATUS   EVENT                                                              COUNT(*)
---------- -------- ---------------------------------------------------------------- ----------
       440 INACTIVE SQL*Net message from client                                              10
       626 INACTIVE SQL*Net message from client                                              60
       830 INACTIVE SQL*Net message from client                                              60
      1031 INACTIVE SQL*Net message from client                                              60
      1223 INACTIVE SQL*Net message from client                                              60
      1432 INACTIVE SQL*Net message from client                                              50

看到在300秒的采样周期，每次采样时SESSION都是INACTIVE的，每60秒取一次数据，取数据时起会短暂的ACTIVE，然后传输数据，其SEQ#才会变化

然后找个SEQ#看看

SQL> SELECT seconds_in_wait FROM zq_test WHERE seq#=1031 ORDER BY seconds_in_wait;
 
SECONDS_IN_WAIT
---------------
              0
              1
              2
              3
              4
              5
         ......
             54
             55
             56
             57
             58
             59
 
60 rows selected

可以看到，这个进程一直在SQL*Net message from client上等待，其一直在这个空闲的等待上等待用户再次发出取数请求

由于这个SQL是并行的，我们看看并行进程的等待：

SQL> SELECT sid,program,sql_id,event
  2    FROM V$SESSION
  3   WHERE SID IN (140, 137, 146, 141, 144, 135, 139)
  4  ;
 
       SID PROGRAM                                          SQL_ID        EVENT
---------- ------------------------------------------------ ------------- ----------------------------------------------------------------
       135 oracle@centos (P000)                             a7zu8q62g4frb PX Deq Credit: send blkd
       137 oracle@centos (P002)                             a7zu8q62g4frb PX Deq Credit: send blkd
       139 oracle@centos (P003)                             a7zu8q62g4frb PX Deq Credit: send blkd
       140 oracle@centos (P001)                             a7zu8q62g4frb PX Deq Credit: send blkd
       141 oracle@centos (P005)                             a7zu8q62g4frb PX Deq Credit: send blkd
       144 oracle@centos (P006)                             a7zu8q62g4frb PX Deq Credit: send blkd
       146 oracle@centos (P004)                             a7zu8q62g4frb PX Deq Credit: send blkd

可以看到，并行查询子进程一直在PX Deq Credit: send blkd这个等待上等待

可以看出，造成PX Deq Credit: send blkd 等待的原因是并行查询父进程需要数据的速度，远远落后于子进程给出数据的数据，子进程只好停止等待父进程

这也说明了，此时并行查询可能并不合理

如果这时，对用户进程142进行sql_trace，可以看到每一个取数周期：

WAIT #1: nam='SQL*Net message from client' ela= 58598185 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1268773245364423
WAIT #1: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1268773245364594
WAIT #1: nam='SQL*Net more data to client' ela= 13 driver id=1413697536 #bytes=2002 p3=0 obj#=-1 tim=1268773245364722
WAIT #1: nam='SQL*Net more data to client' ela= 15 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245364840
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2000 p3=0 obj#=-1 tim=1268773245364921
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245364998
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245365056
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245365088
WAIT #1: nam='PX Deq: Execute Reply' ela= 125 sleeptime/senderid=200 passes=3 p3=0 obj#=-1 tim=1268773245365240
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2010 p3=0 obj#=-1 tim=1268773245365305
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245365350
WAIT #1: nam='PX Deq: Execute Reply' ela= 51 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245365427
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245365492
WAIT #1: nam='PX Deq: Execute Reply' ela= 37 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245365556
WAIT #1: nam='SQL*Net more data to client' ela= 16 driver id=1413697536 #bytes=1996 p3=0 obj#=-1 tim=1268773245365608
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245365695
WAIT #1: nam='PX Deq: Execute Reply' ela= 45 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245365770
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=1997 p3=0 obj#=-1 tim=1268773245365838
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245365873
WAIT #1: nam='PX Deq: Execute Reply' ela= 37 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245365937
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245366002
WAIT #1: nam='PX Deq: Execute Reply' ela= 37 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245366066
WAIT #1: nam='SQL*Net more data to client' ela= 17 driver id=1413697536 #bytes=2020 p3=0 obj#=-1 tim=1268773245366118
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245366206
WAIT #1: nam='PX Deq: Execute Reply' ela= 105 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245366340
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=1982 p3=0 obj#=-1 tim=1268773245366399
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245366439
WAIT #1: nam='PX Deq: Execute Reply' ela= 38 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245366503
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245366595
WAIT #1: nam='PX Deq: Execute Reply' ela= 48 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245366720
WAIT #1: nam='SQL*Net more data to client' ela= 13 driver id=1413697536 #bytes=2020 p3=0 obj#=-1 tim=1268773245366796
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245366837
WAIT #1: nam='PX Deq: Execute Reply' ela= 39 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245366903
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245366968
WAIT #1: nam='PX Deq: Execute Reply' ela= 41 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245367037
WAIT #1: nam='SQL*Net more data to client' ela= 3 driver id=1413697536 #bytes=1982 p3=0 obj#=-1 tim=1268773245367072
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245367164
WAIT #1: nam='PX Deq: Execute Reply' ela= 40 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245367234
WAIT #1: nam='SQL*Net more data to client' ela= 11 driver id=1413697536 #bytes=2004 p3=0 obj#=-1 tim=1268773245367303
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245367345
WAIT #1: nam='PX Deq: Execute Reply' ela= 40 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245367413
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2016 p3=0 obj#=-1 tim=1268773245367475
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245367508
WAIT #1: nam='PX Deq: Execute Reply' ela= 36 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245367572
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245367670
WAIT #1: nam='PX Deq: Execute Reply' ela= 50 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245367750
WAIT #1: nam='SQL*Net more data to client' ela= 11 driver id=1413697536 #bytes=1983 p3=0 obj#=-1 tim=1268773245367804
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245367860
WAIT #1: nam='PX Deq: Execute Reply' ela= 38 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245367924
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245367990
WAIT #1: nam='PX Deq: Execute Reply' ela= 43 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245368059
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245368123
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245368187
WAIT #1: nam='PX Deq: Execute Reply' ela= 45 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245368262
WAIT #1: nam='SQL*Net more data to client' ela= 6 driver id=1413697536 #bytes=2006 p3=0 obj#=-1 tim=1268773245368496
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245368539
WAIT #1: nam='PX Deq: Execute Reply' ela= 73 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245368642
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245368714
WAIT #1: nam='PX Deq: Execute Reply' ela= 40 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245368784
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=2014 p3=0 obj#=-1 tim=1268773245368828
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245368887
WAIT #1: nam='PX Deq: Execute Reply' ela= 40 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245368956
WAIT #1: nam='SQL*Net more data to client' ela= 6 driver id=1413697536 #bytes=1983 p3=0 obj#=-1 tim=1268773245369015
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245369050
WAIT #1: nam='PX Deq: Execute Reply' ela= 40 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245369152
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245369247
WAIT #1: nam='PX Deq: Execute Reply' ela= 42 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245369315
WAIT #1: nam='SQL*Net more data to client' ela= 3 driver id=1413697536 #bytes=2008 p3=0 obj#=-1 tim=1268773245369356
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245369409
WAIT #1: nam='PX Deq: Execute Reply' ela= 40 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245369476
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=1995 p3=0 obj#=-1 tim=1268773245369544
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245369778
WAIT #1: nam='PX Deq: Execute Reply' ela= 51 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245369858
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245369945
WAIT #1: nam='PX Deq: Execute Reply' ela= 37 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245370009
WAIT #1: nam='SQL*Net more data to client' ela= 11 driver id=1413697536 #bytes=2013 p3=0 obj#=-1 tim=1268773245370050
WAIT #1: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245370135
WAIT #1: nam='PX Deq: Execute Reply' ela= 298 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245370464
WAIT #1: nam='SQL*Net more data to client' ela= 6 driver id=1413697536 #bytes=1998 p3=0 obj#=-1 tim=1268773245370519
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1268773245370635
WAIT #1: nam='PX Deq: Execute Reply' ela= 438 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1268773245371104
WAIT #1: nam='SQL*Net more data to client' ela= 3 driver id=1413697536 #bytes=1991 p3=0 obj#=-1 tim=1268773245371211
WAIT #1: nam='SQL*Net more data to client' ela= 18 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245376080
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=2005 p3=0 obj#=-1 tim=1268773245376740
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=2010 p3=0 obj#=-1 tim=1268773245377815
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=1988 p3=0 obj#=-1 tim=1268773245378598
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=2028 p3=0 obj#=-1 tim=1268773245379263
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=1976 p3=0 obj#=-1 tim=1268773245380283
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=2015 p3=0 obj#=-1 tim=1268773245381324
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=1985 p3=0 obj#=-1 tim=1268773245381999
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=2021 p3=0 obj#=-1 tim=1268773245382761
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=1982 p3=0 obj#=-1 tim=1268773245383609
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2005 p3=0 obj#=-1 tim=1268773245384184
WAIT #1: nam='SQL*Net more data to client' ela= 3 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245384959
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=2014 p3=0 obj#=-1 tim=1268773245385969
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=2003 p3=0 obj#=-1 tim=1268773245386824
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=1981 p3=0 obj#=-1 tim=1268773245387712
WAIT #1: nam='SQL*Net more data to client' ela= 10 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245389541
WAIT #1: nam='SQL*Net more data to client' ela= 28 driver id=1413697536 #bytes=2006 p3=0 obj#=-1 tim=1268773245400998
WAIT #1: nam='SQL*Net more data to client' ela= 10 driver id=1413697536 #bytes=2002 p3=0 obj#=-1 tim=1268773245404409
WAIT #1: nam='SQL*Net more data to client' ela= 9 driver id=1413697536 #bytes=2005 p3=0 obj#=-1 tim=1268773245405657
WAIT #1: nam='SQL*Net more data to client' ela= 9 driver id=1413697536 #bytes=1991 p3=0 obj#=-1 tim=1268773245406724
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=2009 p3=0 obj#=-1 tim=1268773245408103
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=1993 p3=0 obj#=-1 tim=1268773245409274
WAIT #1: nam='SQL*Net more data to client' ela= 23 driver id=1413697536 #bytes=2010 p3=0 obj#=-1 tim=1268773245416493
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=1992 p3=0 obj#=-1 tim=1268773245416980
WAIT #1: nam='SQL*Net more data to client' ela= 12 driver id=1413697536 #bytes=2007 p3=0 obj#=-1 tim=1268773245418582
WAIT #1: nam='SQL*Net more data to client' ela= 7 driver id=1413697536 #bytes=2012 p3=0 obj#=-1 tim=1268773245419555
WAIT #1: nam='SQL*Net more data to client' ela= 10 driver id=1413697536 #bytes=1985 p3=0 obj#=-1 tim=1268773245419956
WAIT #1: nam='SQL*Net more data to client' ela= 7 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245420921
WAIT #1: nam='SQL*Net more data to client' ela= 8 driver id=1413697536 #bytes=2000 p3=0 obj#=-1 tim=1268773245421652
WAIT #1: nam='SQL*Net more data to client' ela= 10 driver id=1413697536 #bytes=2014 p3=0 obj#=-1 tim=1268773245422361
WAIT #1: nam='SQL*Net more data to client' ela= 6 driver id=1413697536 #bytes=1988 p3=0 obj#=-1 tim=1268773245422875
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245423680
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=2001 p3=0 obj#=-1 tim=1268773245424761
WAIT #1: nam='SQL*Net more data to client' ela= 13 driver id=1413697536 #bytes=2026 p3=0 obj#=-1 tim=1268773245425847
WAIT #1: nam='SQL*Net more data to client' ela= 4 driver id=1413697536 #bytes=1977 p3=0 obj#=-1 tim=1268773245426323
WAIT #1: nam='SQL*Net more data to client' ela= 6 driver id=1413697536 #bytes=2019 p3=0 obj#=-1 tim=1268773245426740
WAIT #1: nam='SQL*Net more data to client' ela= 5 driver id=1413697536 #bytes=1983 p3=0 obj#=-1 tim=1268773245427218
FETCH #1:c=13998,e=62723,p=0,cr=0,cu=0,mis=0,r=3000,dep=0,og=1,tim=1268773245427265

先在SQL*Net message from client上等待58598185，为59秒，然后准备传输数据，然后传输
每次FETCH完成后，都会等一分钟左右，再次输出TRC

可以看看和网络相关的等待
SQL> SELECT NAME,wait_class FROM v$event_name WHERE NAME LIKE 'SQL*Net%';
 
NAME                                                             WAIT_CLASS
---------------------------------------------------------------- ----------------------------------------------------------------
SQL*Net message to client                                        Network
SQL*Net message to dblink                                        Network
SQL*Net more data to client                                      Network
SQL*Net more data to dblink                                      Network
SQL*Net message from client                                      Idle
SQL*Net more data from client                                    Network
SQL*Net message from dblink                                      Idle
SQL*Net more data from dblink                                    Network
SQL*Net break/reset to client                                    Application
SQL*Net break/reset to dblink                                    Application

SQL*Net message from client，SQL*Net message from dblink  都属于空闲等待，而不代表网络问题
这说明服务器端在等待用户操作

而其他等待才是网络瓶颈/应用问题造成的

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/8242091/viewspace-688457/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/8242091/viewspace-688457/