網路傳輸時間和客戶端處理時間的界定（批處理應用）
批處理的測試案例構造：
簡單的採用Jmeter來進行測試，類似於實現下面簡單的邏輯：
declare
l_n number;
begin
for i 1..300 loop
select 1 into l_n from dual;
dbms_lock.sleep(1);
end loop;
end;
/
用以下指令碼來獲取資料：
declare
-- Local variables here
i integer;
n integer;
m number;
begin
-- Test statements here
--select sid,serial# into m,n from v$session where program is null;
m:=135;
n:=39;
delete from mc$sess_time_model;
delete from mc$system_event;
delete from mc$sesstat;
delete from mc$session_event;
insert into mc$sess_time_model select 0,a.* from v$sess_time_model a where sid=m;
insert into mc$system_event select 0,a.* from v$system_event a;
insert into mc$session_event select 0,a.* from v$session_event a where sid=m;
insert into mc$sesstat select 0,a.* from v$sesstat a where sid=m;
commit;
dbms_monitor.session_trace_enable(m,n,true);
dbms_lock.sleep(300);
dbms_monitor.session_trace_disable(m,n);
insert into mc$sess_time_model select 1,a.* from v$sess_time_model a where sid=m;
insert into mc$system_event select 1,a.* from v$system_event a;
insert into mc$session_event select 1,a.* from v$session_event a where sid=m;
insert into mc$sesstat select 1,a.* from v$sesstat a where sid=m;
commit;
end;
/
以下是獲取資料的結果：
v$sess_time_model的快照比較
1 DB time 3551790
2 DB CPU 1014006
3 parse time elapsed 84637
4 sql execute elapsed time 1269753
v$sesstat的快照比較
3 session logical reads 8601
4 CPU used when call started 23
5 CPU used by this session 23
6 DB time 18
22 execute count 5734
23 bytes sent via SQL*Net to client 825563
24 bytes received via SQL*Net from client 361242
25 SQL*Net roundtrips to/from client 8601
v$session_event的快照比較
4 SQL*Net message to client 8601 3
5 SQL*Net message from client 8601 29651
v$system_event的快照比較
24 SQL*Net message to client 9187 3
25 SQL*Net message from client 9192 211455
26 SQL*Net more data from client 1 0
27 SQL*Net break/reset to client 20 0
v$sqlarea的快照比較
FETCHS EXECUTES BUFFER_GETS DB_TIME CPU_TIME ROWS_PROCESSED
1 2867 2867 8601 515830 78000 2867
v$event_histogram的快照比較
1 SQL*Net message from client 1 6225
2 SQL*Net message from client 2 25
3 SQL*Net message from client 4 10
4 SQL*Net message from client 8 3
5 SQL*Net message from client 16 2
6 SQL*Net message from client 64 3
7 SQL*Net message from client 128 2865
8 SQL*Net message from client 256 2
9 SQL*Net message from client 2048 1
10 SQL*Net message from client 16384 30
11 SQL*Net message from client 32768 4
12 SQL*Net message from client 65536 19
13 SQL*Net message from client 131072 2
14 SQL*Net message from client 524288 1
v$eventmetric的最近2分鐘
NAME NUM_SESS_WAITING TIME_WAITED WAIT_COUNT
1 SQL*Net message from client 15 41622.2885 1878
2 SQL*Net message from client 14 65794.8271 1860
10046跟蹤事件資訊
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2869 0.09 0.08 0 0 0 0
Execute 5738 0.01 0.18 0 0 0 0
Fetch 5738 0.03 0.49 0 8607 0 5738
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 14345 0.14 0.76 0 8607 0 5738
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 8607 0.00 0.02
SQL*Net message from client 8607 0.26 296.41
很明顯的可以看到v$sysstat和v$sess_time_model計算CPU和DB time有所不同，兩者的差異很大。
在一個300秒的快照區間內，可以看到以下基本資料：
DB time:= 3551790 = 3.5秒
也就是資料庫的處理時間的花銷為0.38秒，其他時間都應該為網路傳輸和客戶端處理。
SQL*Net message from client ： =296s
從絕對的最終數字驗證，DB time的計算還是比較準確的。而SQL*Net message from client基本表示了網路傳輸以及客戶端處理的時間。也就是在批處理中可以採用：SQL*Net message from client來代表客戶端處理，當然為了更加準確應該做如下描述：
SQL*Net message from client + SQL*Net message to client + SQL*Net more data to client + SQL*Net more data from client，在網路速度正常的情況下，其他三項基本可以忽略，但是當網路速度緩慢的時候其他三項可能將會產生比較大的影響，在網路傳輸不足以支撐網路快取的時候，將導致to事件阻塞。
1 DB time 3551790
2 DB CPU 1014006
3 parse time elapsed 84637
4 sql execute elapsed time 1269753
3.55-1.02 = 2.53s
從常規而言，這個2.35s表示等待時間，但不知道等什麼，可能是不可計數的等待事件被過濾掉了。
同樣可以看到在SQL層面也存在著這個問題：
FETCHS EXECUTES BUFFER_GETS DB_TIME CPU_TIME ROWS_PROCESSED
1 2867 2867 8601 515830 78000 2867
db_time:= 0.52s
cpu_time:=0.078s，同樣存在著有時間花在等待之上。
關閉10046事件之後發現：
1 DB time 2540195
2 DB CPU 2527216
3 parse time elapsed 85226
4 sql execute elapsed time 703491
現在可以認為：10046事件引起了一些額外的開銷，這些開銷導致了變更。
不管結果變化如何，有一點可以完全確認在批處理業務中，可以採用SQL*Net Message from client事件的等待時間來表示客戶端處理。
另外，我們可以看到：執行了5734次，網路互動了8601次，我們固定延時時間為100ms，可以發現等待事件柱狀圖集中在1ms和128ms，128ms對應了100ms的延遲，1ms對應正常的網路應答互動。
簡單的採用Jmeter來進行測試，類似於實現下面簡單的邏輯：
declare
l_n number;
begin
for i 1..300 loop
select 1 into l_n from dual;
dbms_lock.sleep(1);
end loop;
end;
/
用以下指令碼來獲取資料：
declare
-- Local variables here
i integer;
n integer;
m number;
begin
-- Test statements here
--select sid,serial# into m,n from v$session where program is null;
m:=135;
n:=39;
delete from mc$sess_time_model;
delete from mc$system_event;
delete from mc$sesstat;
delete from mc$session_event;
insert into mc$sess_time_model select 0,a.* from v$sess_time_model a where sid=m;
insert into mc$system_event select 0,a.* from v$system_event a;
insert into mc$session_event select 0,a.* from v$session_event a where sid=m;
insert into mc$sesstat select 0,a.* from v$sesstat a where sid=m;
commit;
dbms_monitor.session_trace_enable(m,n,true);
dbms_lock.sleep(300);
dbms_monitor.session_trace_disable(m,n);
insert into mc$sess_time_model select 1,a.* from v$sess_time_model a where sid=m;
insert into mc$system_event select 1,a.* from v$system_event a;
insert into mc$session_event select 1,a.* from v$session_event a where sid=m;
insert into mc$sesstat select 1,a.* from v$sesstat a where sid=m;
commit;
end;
/
以下是獲取資料的結果：
v$sess_time_model的快照比較
1 DB time 3551790
2 DB CPU 1014006
3 parse time elapsed 84637
4 sql execute elapsed time 1269753
v$sesstat的快照比較
3 session logical reads 8601
4 CPU used when call started 23
5 CPU used by this session 23
6 DB time 18
22 execute count 5734
23 bytes sent via SQL*Net to client 825563
24 bytes received via SQL*Net from client 361242
25 SQL*Net roundtrips to/from client 8601
v$session_event的快照比較
4 SQL*Net message to client 8601 3
5 SQL*Net message from client 8601 29651
v$system_event的快照比較
24 SQL*Net message to client 9187 3
25 SQL*Net message from client 9192 211455
26 SQL*Net more data from client 1 0
27 SQL*Net break/reset to client 20 0
v$sqlarea的快照比較
FETCHS EXECUTES BUFFER_GETS DB_TIME CPU_TIME ROWS_PROCESSED
1 2867 2867 8601 515830 78000 2867
v$event_histogram的快照比較
1 SQL*Net message from client 1 6225
2 SQL*Net message from client 2 25
3 SQL*Net message from client 4 10
4 SQL*Net message from client 8 3
5 SQL*Net message from client 16 2
6 SQL*Net message from client 64 3
7 SQL*Net message from client 128 2865
8 SQL*Net message from client 256 2
9 SQL*Net message from client 2048 1
10 SQL*Net message from client 16384 30
11 SQL*Net message from client 32768 4
12 SQL*Net message from client 65536 19
13 SQL*Net message from client 131072 2
14 SQL*Net message from client 524288 1
v$eventmetric的最近2分鐘
NAME NUM_SESS_WAITING TIME_WAITED WAIT_COUNT
1 SQL*Net message from client 15 41622.2885 1878
2 SQL*Net message from client 14 65794.8271 1860
10046跟蹤事件資訊
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2869 0.09 0.08 0 0 0 0
Execute 5738 0.01 0.18 0 0 0 0
Fetch 5738 0.03 0.49 0 8607 0 5738
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 14345 0.14 0.76 0 8607 0 5738
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 8607 0.00 0.02
SQL*Net message from client 8607 0.26 296.41
很明顯的可以看到v$sysstat和v$sess_time_model計算CPU和DB time有所不同，兩者的差異很大。
在一個300秒的快照區間內，可以看到以下基本資料：
DB time:= 3551790 = 3.5秒
也就是資料庫的處理時間的花銷為0.38秒，其他時間都應該為網路傳輸和客戶端處理。
SQL*Net message from client ： =296s
從絕對的最終數字驗證，DB time的計算還是比較準確的。而SQL*Net message from client基本表示了網路傳輸以及客戶端處理的時間。也就是在批處理中可以採用：SQL*Net message from client來代表客戶端處理，當然為了更加準確應該做如下描述：
SQL*Net message from client + SQL*Net message to client + SQL*Net more data to client + SQL*Net more data from client，在網路速度正常的情況下，其他三項基本可以忽略，但是當網路速度緩慢的時候其他三項可能將會產生比較大的影響，在網路傳輸不足以支撐網路快取的時候，將導致to事件阻塞。
1 DB time 3551790
2 DB CPU 1014006
3 parse time elapsed 84637
4 sql execute elapsed time 1269753
3.55-1.02 = 2.53s
從常規而言，這個2.35s表示等待時間，但不知道等什麼，可能是不可計數的等待事件被過濾掉了。
同樣可以看到在SQL層面也存在著這個問題：
FETCHS EXECUTES BUFFER_GETS DB_TIME CPU_TIME ROWS_PROCESSED
1 2867 2867 8601 515830 78000 2867
db_time:= 0.52s
cpu_time:=0.078s，同樣存在著有時間花在等待之上。
關閉10046事件之後發現：
1 DB time 2540195
2 DB CPU 2527216
3 parse time elapsed 85226
4 sql execute elapsed time 703491
現在可以認為：10046事件引起了一些額外的開銷，這些開銷導致了變更。
不管結果變化如何，有一點可以完全確認在批處理業務中，可以採用SQL*Net Message from client事件的等待時間來表示客戶端處理。
另外，我們可以看到：執行了5734次，網路互動了8601次，我們固定延時時間為100ms，可以發現等待事件柱狀圖集中在1ms和128ms，128ms對應了100ms的延遲，1ms對應正常的網路應答互動。
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/92650/viewspace-775240/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- 網路傳輸時間和客戶端處理時間的界定（互動式應用）客戶端
- 網路傳輸時間以及Client的處理的測試方案client
- 客戶端無法同步時間伺服器問題處理客戶端伺服器
- 字串和日期時間的處理字串
- PHP 時間處理PHP
- java時間處理Java
- ORACLE 處理時間Oracle
- bash時間處理
- 批處理獲得系統當前時間之前n天的時間
- [windows]批處理獲取時間的long型值Windows
- python 時間處理Python
- 時間處理函式函式
- Python的時間、日期和時間戳的處理辦法Python時間戳
- 用批處理實現的刪除特定時間以前的檔案
- JavaScript字串和時間處理隨筆JavaScript字串
- 日期和時間的儲存與處理
- oracle對於時間間隔的處理Oracle
- 日期時間處理包 Carbon
- 時間序列資料的處理
- iOS 關於時間的處理iOS
- Java中對時間的處理Java
- Java 日期和時間 API：實用技巧與示例 - 輕鬆處理日期和時間JavaAPI
- Calendar類在Java中的應用與日期時間處理Java
- 數字轉時間間隔格式處理
- Java8中的時間處理Java
- jackson時間格式的處理
- ASP.Net中的時間處理ASP.NET
- Laravel日期時間處理包 CarbonLaravel
- Spring mvc時間格式處理SpringMVC
- python時間處理詳解Python
- oracle時間日常處理小結Oracle
- gc current request等待時間處理GC
- 傳輸表空間及問題處理
- 批處理以當前時間為檔名建立檔案
- Windows批處理中獲取系統日期、時間戳記Windows時間戳
- 使用waitfor time和waitfor delay在一定時間間隔下定時執行批處理AI
- LocalDate，LocalDateTime和處理時間、日期工具類LDA
- 記一次客戶DB CPU短時間內衝高至99%處理