Oracle RAC Study之--Cache Fusion
15:56:13 SYS@ prod2>select instance_name from v$instance;INSTANCE_NAME
----------------
prod2
15:46:28 SYS@ prod2>alter session set events '10046 trace name context forever,level 12';
Session altered.
15:46:44 SYS@ prod2>select /*+ on_the_other_node */ count(*) from t1;
COUNT(*)
----------
50392
15:47:24 SYS@ prod2>alter session set events '10046 trace name context off';
Session altered.
$ls -lt /u01/app/oracle/admin/prod/udump/|more
total 344
-rw-r----- 1 oracle oinstall 3920 Nov 17 15:47 prod2_ora_606458.trc
-rw-r----- 1 oracle oinstall 6220 Nov 17 15:39 prod2_ora_393270.trc
查看trace结果：
$tkprof /u01/app/oracle/admin/prod/udump/prod2_ora_606458.trc /home/oracle/trc.txt
TKPROF: Release 10.2.0.1.0 - Production on Mon Nov 17 15:48:03 2014
Copyright (c) 1982, 2005, Oracle.All rights reserved.
select /*+ on_the_other_node */ count(*)
from
t1
call count cpu elapsed disk query current rows
------- -------------- ---------- ---------- ---------- --------------------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.05 0.35 693 697 0 1
------- -------------- ---------- ---------- ---------- --------------------
total 4 0.05 0.35 693 697 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Rows Row Source Operation
----------------------------------------------------------
1SORT AGGREGATE (cr=697 pr=693 pw=0 time=356121 us)
50392 TABLE ACCESS FULL T1 (cr=697 pr=693 pw=0 time=12651 us)
Elapsed times include waiting on following events:
Event waited on Times Max. WaitTotal Waited
---------------------------------------- Waited----------------------
SQL*Net message to client 2 0.00 0.00
gc cr grant 2-way 1 0.00 0.00
db file sequential read 1 0.00 0.00
gc cr multi block request 46 0.00 0.03
db file scattered read 52 0.05 0.27
SQL*Net message from client 2 0.00 0.00
********************************************************************************
可以看到，在Instance 2上出现了大量‘gc cr multi block request'事件，说明大部分数据块是从node 1（Instance 1）上传递过来的。
但也在node 2上有一部分磁盘I/O（disk=693）,说明一部分数据从本地读取。
通过trace源文件，查看：
select /*+ on_the_other_node */ count(*) from t1
END OF STMT
PARSE #1:c=0,e=339,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=26779237777
BINDS #1:
EXEC #1:c=0,e=135,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=26779237991
WAIT #1: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=26779238042
WAIT #1: nam='gc cr grant 2-way' ela= 670 p1=1 p2=60945 p3=4 obj#=52686 tim=26779239211
WAIT #1: nam='db file sequential read' ela= 5910 file#=1 block#=60945 blocks=1 obj#=52686 tim=26779245166
WAIT #1: nam='gc cr multi block request' ela= 898 file#=1 block#=60952 class#=1 obj#=52686 tim=26779246461
WAIT #1: nam='db file scattered read' ela= 4083 file#=1 block#=60946 blocks=7 obj#=52686 tim=26779250635
WAIT #1: nam='gc cr multi block request' ela= 720 file#=1 block#=60960 class#=1 obj#=52686 tim=26779251880
WAIT #1: nam='gc cr multi block request' ela= 182 file#=1 block#=60960 class#=1 obj#=52686 tim=26779252115
WAIT #1: nam='db file scattered read' ela= 4897 file#=1 block#=60953 blocks=8 obj#=52686 tim=26779257069
WAIT #1: nam='gc cr multi block request' ela= 880 file#=1 block#=60968 class#=1 obj#=52686 tim=26779258422
WAIT #1: nam='db file scattered read' ela= 7796 file#=1 block#=60961 blocks=8 obj#=52686 tim=26779266300
WAIT #1: nam='gc cr multi block request' ela= 877 file#=1 block#=60976 class#=1 obj#=52686 tim=26779267650
WAIT #1: nam='db file scattered read' ela= 8525 file#=1 block#=60969 blocks=8 obj#=52686 tim=26779276258
WAIT #1: nam='gc cr multi block request' ela= 948 file#=1 block#=60984 class#=1 obj#=52686 tim=26779277666
WAIT #1: nam='gc cr multi block request' ela= 78 file#=1 block#=60984 class#=1 obj#=52686 tim=26779277795
WAIT #1: nam='db file scattered read' ela= 4645 file#=1 block#=60977 blocks=8 obj#=52686 tim=26779282501
WAIT #1: nam='gc cr multi block request' ela= 757 file#=1 block#=60992 class#=1 obj#=52686 tim=26779283757
WAIT #1: nam='db file scattered read' ela= 7600 file#=1 block#=60985 blocks=8 obj#=52686 tim=26779291441
WAIT #1: nam='gc cr multi block request' ela= 862 file#=1 block#=61000 class#=1 obj#=52686 tim=26779292778
WAIT #1: nam='db file scattered read' ela= 4774 file#=1 block#=60993 blocks=8 obj#=52686 tim=26779297636
WAIT #1: nam='gc cr multi block request' ela= 873 file#=1 block#=61008 class#=1 obj#=52686 tim=26779298953
WAIT #1: nam='db file scattered read' ela= 4615 file#=1 block#=61001 blocks=8 obj#=52686 tim=26779303648
WAIT #1: nam='gc cr multi block request' ela= 870 file#=1 block#=61016 class#=1 obj#=52686 tim=26779304979
WAIT #1: nam='db file scattered read' ela= 2009 file#=1 block#=61009 blocks=8 obj#=52686 tim=26779307065
WAIT #1: nam='gc cr multi block request' ela= 741 file#=1 block#=61024 class#=1 obj#=52686 tim=26779308335
WAIT #1: nam='db file scattered read' ela= 2562 file#=1 block#=61017 blocks=8 obj#=52686 tim=26779310984
WAIT #1: nam='gc cr multi block request' ela= 871 file#=1 block#=61032 class#=1 obj#=52686 tim=26779312325
WAIT #1: nam='db file scattered read' ela= 2115 file#=1 block#=61025 blocks=8 obj#=52686 tim=26779314521
WAIT #1: nam='gc cr multi block request' ela= 857 file#=1 block#=61040 class#=1 obj#=52686 tim=26779315819
WAIT #1: nam='db file scattered read' ela= 2060 file#=1 block#=61033 blocks=8 obj#=52686 tim=26779317956
WAIT #1: nam='gc cr multi block request' ela= 845 file#=1 block#=61048 class#=1 obj#=52686 tim=26779319241
WAIT #1: nam='db file scattered read' ela= 2770 file#=1 block#=61041 blocks=8 obj#=52686 tim=26779322090
WAIT #1: nam='gc cr multi block request' ela= 586 file#=1 block#=61055 class#=1 obj#=52686 tim=26779323145
WAIT #1: nam='gc cr multi block request' ela= 94 file#=1 block#=61054 class#=1 obj#=52686 tim=26779323281
WAIT #1: nam='db file scattered read' ela= 9974 file#=1 block#=61049 blocks=8 obj#=52686 tim=26779333323
WAIT #1: nam='db file scattered read' ela= 5632 file#=1 block#=61057 blocks=8 obj#=52686 tim=26779339348
WAIT #1: nam='db file scattered read' ela= 2081 file#=1 block#=61065 blocks=8 obj#=52686 tim=26779341785
WAIT #1: nam='gc cr multi block request' ela= 1438 file#=1 block#=61208 class#=1 obj#=52686 tim=26779343792
WAIT #1: nam='db file scattered read' ela= 4347 file#=1 block#=61193 blocks=16 obj#=52686 tim=26779348250
WAIT #1: nam='gc cr multi block request' ela= 715 file#=1 block#=61224 class#=1 obj#=52686 tim=26779349686
WAIT #1: nam='gc cr multi block request' ela= 407 file#=1 block#=61224 class#=1 obj#=52686 tim=26779350147
WAIT #1: nam='db file scattered read' ela= 3475 file#=1 block#=61209 blocks=16 obj#=52686 tim=26779353704
WAIT #1: nam='gc cr multi block request' ela= 1351 file#=1 block#=61240 class#=1 obj#=52686 tim=26779355740
WAIT #1: nam='db file scattered read' ela= 3359 file#=1 block#=61225 blocks=16 obj#=52686 tim=26779359216
WAIT #1: nam='gc cr multi block request' ela= 713 file#=1 block#=61256 class#=1 obj#=52686 tim=26779360637
WAIT #1: nam='gc cr multi block request' ela= 403 file#=1 block#=61256 class#=1 obj#=52686 tim=26779361094
WAIT #1: nam='db file scattered read' ela= 2935 file#=1 block#=61241 blocks=16 obj#=52686 tim=26779364111
WAIT #1: nam='gc cr multi block request' ela= 1307 file#=1 block#=61272 class#=1 obj#=52686 tim=26779366106
WAIT #1: nam='db file scattered read' ela= 8885 file#=1 block#=61257 blocks=16 obj#=52686 tim=26779375104
WAIT #1: nam='gc cr multi block request' ela= 754 file#=1 block#=61288 class#=1 obj#=52686 tim=26779376579
WAIT #1: nam='gc cr multi block request' ela= 370 file#=1 block#=61288 class#=1 obj#=52686 tim=26779377005
WAIT #1: nam='db file scattered read' ela= 3442 file#=1 block#=61273 blocks=16 obj#=52686 tim=26779380530
WAIT #1: nam='gc cr multi block request' ela= 1323 file#=1 block#=61304 class#=1 obj#=52686 tim=26779382541
WAIT #1: nam='db file scattered read' ela= 2887 file#=1 block#=61289 blocks=16 obj#=52686 tim=26779385540
WAIT #1: nam='gc cr multi block request' ela= 746 file#=1 block#=61311 class#=1 obj#=52686 tim=26779386964
WAIT #1: nam='db file scattered read' ela= 3422 file#=1 block#=61305 blocks=16 obj#=52686 tim=26779390477
WAIT #1: nam='db file scattered read' ela= 3364 file#=1 block#=61321 blocks=16 obj#=52686 tim=26779394422
WAIT #1: nam='db file scattered read' ela= 3418 file#=1 block#=61337 blocks=16 obj#=52686 tim=26779398408
WAIT #1: nam='db file scattered read' ela= 7254 file#=1 block#=61353 blocks=16 obj#=52686 tim=26779406214
WAIT #1: nam='db file scattered read' ela= 3403 file#=1 block#=61369 blocks=16 obj#=52686 tim=26779410176
WAIT #1: nam='db file scattered read' ela= 7044 file#=1 block#=61385 blocks=16 obj#=52686 tim=26779417779
WAIT #1: nam='db file scattered read' ela= 7282 file#=1 block#=61401 blocks=16 obj#=52686 tim=26779425628
WAIT #1: nam='db file scattered read' ela= 3874 file#=1 block#=61417 blocks=16 obj#=52686 tim=26779430050
WAIT #1: nam='gc cr multi block request' ela= 967 file#=1 block#=61448 class#=1 obj#=52686 tim=26779431766
WAIT #1: nam='db file scattered read' ela= 3433 file#=1 block#=61433 blocks=16 obj#=52686 tim=26779435300
WAIT #1: nam='gc cr multi block request' ela= 1315 file#=1 block#=61464 class#=1 obj#=52686 tim=26779437308
WAIT #1: nam='db file scattered read' ela= 3388 file#=1 block#=61449 blocks=16 obj#=52686 tim=26779440806
WAIT #1: nam='gc cr multi block request' ela= 727 file#=1 block#=61480 class#=1 obj#=52686 tim=26779442228
WAIT #1: nam='gc cr multi block request' ela= 419 file#=1 block#=61480 class#=1 obj#=52686 tim=26779442701
WAIT #1: nam='db file scattered read' ela= 5163 file#=1 block#=61465 blocks=16 obj#=52686 tim=26779447957
WAIT #1: nam='gc cr multi block request' ela= 1319 file#=1 block#=61496 class#=1 obj#=52686 tim=26779449987
WAIT #1: nam='db file scattered read' ela= 2761 file#=1 block#=61481 blocks=16 obj#=52686 tim=26779452861
WAIT #1: nam='gc cr multi block request' ela= 715 file#=1 block#=61512 class#=1 obj#=52686 tim=26779454292
WAIT #1: nam='gc cr multi block request' ela= 405 file#=1 block#=61512 class#=1 obj#=52686 tim=26779454753
WAIT #1: nam='db file scattered read' ela= 3434 file#=1 block#=61497 blocks=16 obj#=52686 tim=26779458272
WAIT #1: nam='gc cr multi block request' ela= 1308 file#=1 block#=61528 class#=1 obj#=52686 tim=26779460269
WAIT #1: nam='db file scattered read' ela= 2761 file#=1 block#=61513 blocks=16 obj#=52686 tim=26779463140
WAIT #1: nam='gc cr multi block request' ela= 727 file#=1 block#=61544 class#=1 obj#=52686 tim=26779464570
WAIT #1: nam='gc cr multi block request' ela= 402 file#=1 block#=61544 class#=1 obj#=52686 tim=26779465029
WAIT #1: nam='db file scattered read' ela= 3372 file#=1 block#=61529 blocks=16 obj#=52686 tim=26779468487
WAIT #1: nam='gc cr multi block request' ela= 1337 file#=1 block#=61560 class#=1 obj#=52686 tim=26779470506
WAIT #1: nam='db file scattered read' ela= 2804 file#=1 block#=61545 blocks=16 obj#=52686 tim=26779473420
WAIT #1: nam='gc cr multi block request' ela= 741 file#=1 block#=61567 class#=1 obj#=52686 tim=26779474836
WAIT #1: nam='db file scattered read' ela= 7761 file#=1 block#=61561 blocks=16 obj#=52686 tim=26779482689
WAIT #1: nam='db file scattered read' ela= 3177 file#=1 block#=61577 blocks=16 obj#=52686 tim=26779486442
WAIT #1: nam='db file scattered read' ela= 3289 file#=1 block#=61593 blocks=16 obj#=52686 tim=26779490280
WAIT #1: nam='db file scattered read' ela= 2727 file#=1 block#=61609 blocks=16 obj#=52686 tim=26779493546
WAIT #1: nam='db file scattered read' ela= 2709 file#=1 block#=61625 blocks=16 obj#=52686 tim=26779496825
WAIT #1: nam='db file scattered read' ela= 3334 file#=1 block#=61641 blocks=16 obj#=52686 tim=26779500720
WAIT #1: nam='db file scattered read' ela= 3257 file#=1 block#=61657 blocks=16 obj#=52686 tim=26779504537
WAIT #1: nam='db file scattered read' ela= 2735 file#=1 block#=61673 blocks=16 obj#=52686 tim=26779507829
WAIT #1: nam='gc cr multi block request' ela= 954 file#=1 block#=61704 class#=1 obj#=52686 tim=26779509463
WAIT #1: nam='db file scattered read' ela= 8587 file#=1 block#=61689 blocks=16 obj#=52686 tim=26779518146
WAIT #1: nam='gc cr multi block request' ela= 1386 file#=1 block#=61720 class#=1 obj#=52686 tim=26779520274
WAIT #1: nam='db file scattered read' ela= 57988 file#=1 block#=61705 blocks=16 obj#=52686 tim=26779578384
WAIT #1: nam='gc cr multi block request' ela= 907 file#=1 block#=61736 class#=1 obj#=52686 tim=26779580432
WAIT #1: nam='gc cr multi block request' ela= 323 file#=1 block#=61736 class#=1 obj#=52686 tim=26779580830
WAIT #1: nam='db file scattered read' ela= 3431 file#=1 block#=61721 blocks=16 obj#=52686 tim=26779584371
WAIT #1: nam='gc cr multi block request' ela= 2595 file#=1 block#=61752 class#=1 obj#=52686 tim=26779587917
WAIT #1: nam='db file scattered read' ela= 3418 file#=1 block#=61737 blocks=16 obj#=52686 tim=26779591482
WAIT #1: nam='gc cr multi block request' ela= 757 file#=1 block#=61757 class#=1 obj#=52686 tim=26779592898
WAIT #1: nam='db file scattered read' ela= 928 file#=1 block#=61753 blocks=5 obj#=52686 tim=26779593962
FETCH #1:c=50000,e=356115,p=693,cr=697,cu=0,mis=0,r=1,dep=0,og=1,tim=26779594203
WAIT #1: nam='SQL*Net message from client' ela= 485 driver id=1650815232 #bytes=1 p3=0 obj#=52686 tim=26779594899
FETCH #1:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=26779594986
WAIT #1: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=52686 tim=26779595018
WAIT #1: nam='SQL*Net message from client' ela= 490 driver id=1650815232 #bytes=1 p3=0 obj#=52686 tim=26779595585
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=697 pr=693 pw=0 time=356121 us)'
STAT #1 id=2 cnt=50392 pid=1 pos=1 obj=52686 op='TABLE ACCESS FULL T1 (cr=697 pr=693 pw=0 time=12651 us)'
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=52686 tim=26779595906
*** 2014-11-17 15:53:32.816
WAIT #0: nam='SQL*Net message from client' ela= 22469814 driver id=1650815232 #bytes=1 p3=0 obj#=52686 tim=26802065757
=====================
页:
[1]