結論としては、SQL が遅いようなので、別途SQL単体でチューニングが必要と思われる。
調べたときにやったことをメモっておく。
- top
$ top top - 14:40:47 up 52 days, 3:14, 9 users, load average: 2.30, 2.13, 1.76 Tasks: 182 total, 3 running, 179 sleeping, 0 stopped, 0 zombie Cpu(s): 57.4%us, 2.3%sy, 0.0%ni, 1.8%id, 37.6%wa, 0.2%hi, 0.7%si, 0.0%st Mem: 2075600k total, 2023152k used, 52448k free, 5908k buffers Swap: 2096472k total, 294468k used, 1802004k free, 1760204k cached 8091 oracle 25 0 2192m 340m 307m R 92.1 16.8 1871:23 oracle 1867 oracle 16 0 2146m 202m 200m R 16.6 10.0 0:35.72 oracle 1865 oracle 15 0 24156 9188 5172 S 7.6 0.4 0:16.72 sqlldr 30534 oracle 16 0 2161m 38m 37m S 2.3 1.9 171:07.91 oracle ...
- vmstat
$ vmstat 5 12 procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ r b swpd free buff cache si so bi bo in cs us sy id wa st 1 0 294436 58776 5636 1759900 3 2 88 141 3 1 12 2 73 13 0 1 0 294436 58776 5652 1759968 0 0 2 38 1015 51 50 0 48 2 0 1 0 294436 58280 5652 1760904 0 0 3 226 1016 61 50 0 46 4 0 1 1 294436 57908 5668 1761320 0 0 0 125 1016 54 50 0 47 3 0 1 0 294436 57784 5684 1761384 0 0 3 46 1013 54 50 0 47 2 0 1 0 294436 56792 5700 1762396 0 0 3 350 1024 74 50 0 39 10 0 1 0 294436 56296 5720 1762844 0 0 2 118 1017 56 50 0 47 3 0 1 0 294436 56172 5728 1762904 0 0 2 49 1013 50 50 0 48 2 0 1 0 294436 55304 5736 1763856 0 0 2 238 1020 61 50 0 46 4 0 1 0 294436 54808 5752 1764312 0 0 3 127 1014 56 50 0 47 3 0 1 0 294436 54808 5768 1764328 0 0 3 59 1017 58 50 0 48 2 0 1 0 294436 53596 5772 1765264 0 0 3 816 1029 81 50 0 38 11 0
- sar
$ sar -P ALL ... 12:30:01 CPU %user %nice %system %iowait %steal %idle 12:40:01 all 50.04 0.00 0.04 2.40 0.00 47.52 12:40:01 0 0.12 0.00 0.06 4.79 0.00 95.03 12:40:01 1 99.97 0.00 0.03 0.00 0.00 0.00 12:50:01 all 50.02 0.00 0.05 2.39 0.00 47.54 12:50:01 0 0.07 0.00 0.06 4.79 0.00 95.07 12:50:01 1 99.97 0.00 0.03 0.00 0.00 0.00 13:00:01 all 50.02 0.00 0.04 2.27 0.00 47.67 13:00:01 0 0.07 0.00 0.05 4.54 0.00 95.33 13:00:01 1 99.97 0.00 0.03 0.00 0.00 0.00 13:10:01 all 50.19 0.00 0.11 2.61 0.00 47.10 13:10:01 0 0.43 0.00 0.17 5.20 0.00 94.19 13:10:01 1 99.95 0.00 0.04 0.01 0.00 0.00 13:20:01 all 50.03 0.00 0.04 2.11 0.00 47.82 13:20:01 0 0.08 0.00 0.06 4.22 0.00 95.65 13:20:01 1 99.97 0.00 0.03 0.00 0.00 0.00 13:30:01 all 50.04 1.31 0.11 2.26 0.00 46.27 13:30:01 0 0.12 2.63 0.19 4.53 0.00 92.54 13:30:01 1 99.97 0.00 0.03 0.00 0.00 0.00 13:40:01 all 50.03 0.00 0.04 2.16 0.00 47.77 13:40:01 0 0.08 0.00 0.06 4.33 0.00 95.53 13:40:01 1 99.97 0.00 0.03 0.00 0.00 0.00 13:50:01 all 50.05 0.00 0.04 2.13 0.00 47.78 13:50:01 0 0.12 0.00 0.06 4.26 0.00 95.56 13:50:01 1 99.98 0.00 0.02 0.00 0.00 0.00 14:00:01 all 50.11 0.00 0.10 2.70 0.00 47.09 14:00:01 0 0.28 0.00 0.15 5.40 0.00 94.17 14:00:01 1 99.94 0.00 0.04 0.00 0.00 0.02 14:10:02 all 71.79 0.00 2.44 19.12 0.00 6.65 14:10:02 0 70.53 0.00 1.94 15.50 0.00 12.04 14:10:02 1 73.05 0.00 2.94 22.75 0.00 1.26 14:20:01 all 51.30 0.00 0.45 8.17 0.00 40.08 14:20:01 0 95.35 0.00 0.25 2.64 0.00 1.76 14:20:01 1 7.25 0.00 0.65 13.70 0.00 78.40 14:30:01 all 50.06 0.58 0.10 6.14 0.00 43.11 14:30:01 0 100.00 0.00 0.00 0.00 0.00 0.00 14:30:01 1 0.13 1.16 0.20 12.29 0.00 86.22 14:40:01 all 71.14 0.72 2.25 18.22 0.00 7.67 14:40:01 0 83.07 0.00 1.67 14.09 0.00 1.17 14:40:01 1 59.22 1.43 2.83 22.35 0.00 14.17 Average: all 50.66 0.22 0.22 2.98 0.00 45.92 Average: 0 8.94 0.41 0.28 4.88 0.00 85.49 Average: 1 92.38 0.03 0.17 1.08 0.00 6.34
- プロセス
$ sqlplus / as sysdba set pagesize 1000 set linesize 300 col spid for 99999 col sid for 9999 col serial# for 99999 col username for a14 col program for a50 col machine for a50 col osuser for a20 select proc.spid, ses.sid, ses.serial#, ses.username, ses.status, ses.program, ses.machine, ses.osuser, ses.process from v$session ses, v$process proc where ses.paddr = proc.addr order by ses.username, ses.status; SPID SID SERIAL# USERNAME STATUS PROGRAM MACHINE OSUSER PROCESS ------------ ----- ------- -------------- -------- -------------------------------------------------- -------------------------------------------------- -------------------- ------------ 8091 242 41837 SCOTT ACTIVE sqlplus@******************************** (TNS V ********************************* oracle 8089 ... 30 rows selected.
- プロセスの親子関係を調べる。
$ pstree -alp ... | |-bash,7762 | | `-****_******.sh,29045 ******** | | `-transaction_dat,29828 ******** | | `-*******_******_,8085 ******** | | `-sqlplus,8089 -s
- ロックの状況を調べる
$ sqlplus / as sysdba set feedback off set pagesize 9999 set linesize 2000 set trimspool on set trimout on col block for 9999 col sid for 9999 col status for a8 col machine for a9 col username for a9 col type for a2 col lmode for 99 col request for 99 col program for a10 col serialno for 999999 col lock_time for a10 col sql for a100 select a.blocking_session block, a.sid sid, a.status status, substr(a.machine, 1,9) machine, a.username username, b.type type, b.lmode lmode, b.request request, a.program program, a.serial# serialno, to_char(b.ctime/60, '9990.9') lock_time, c.sql_text sql from v$session a, v$lock b, v$sqlarea c where a.sid=b.sid and a.sql_address = c.address; BLOCK SID STATUS MACHINE USERNAME TY LMODE REQUEST PROGRAM SERIALNO LOCK_TIME SQL ----- ----- -------- --------- --------- -- ----- ------- ---------- -------- ---------- ----------------------------- 242 ACTIVE ********* SCOTT TM 2 0 sqlplus@** 41837 1930.1 UPDATE ******** 242 ACTIVE ********* SCOTT TM 3 0 sqlplus@** 41837 202.6 UPDATE ******** 242 ACTIVE ********* SCOTT TM 3 0 sqlplus@** 41837 202.8 UPDATE ******** 242 ACTIVE ********* SCOTT TM 3 0 sqlplus@** 41837 202.6 UPDATE ******** 242 ACTIVE +******** SCOTT TX 6 0 sqlplus@** 41837 1919.1 UPDATE ********
- 実行計画を調べる。
SQL> select sql_address, sql_hash_value from v$session where sid=242 and serial#=41837; SQL_ADDR SQL_HASH_VALUE -------- -------------- 9E2DA380 2857543126 SET LINESIZE 200 COLUMN ID FORMAT 999 COLUMN OPERATION FORMAT A60 COLUMN OBJECT FORMAT A30 COLUMN COST FORMAT 9999 COLUMN BYTES FORMAT 99999 SELECT ID, DECODE( OPTIMIZER, 'ANALYZED', LPAD( ' ', DEPTH * 3, ' ' ) || OPERATION || ' ' || NVL2( OPTIONS, OPTIONS, null ), NULL, LPAD( ' ', DEPTH * 3, ' ' ) || OPERATION || ' ' || OPTIONS, LPAD( ' ', DEPTH * 3, ' ' ) || OPERATION ) OPERATION, DECODE( OPTIMIZER, 'ANALYZED', OBJECT_NAME, NULL, OBJECT_NAME, 'Optimizer = ' || OPTIMIZER ) OBJECT, COST, BYTES FROM V$SQL_PLAN WHERE ADDRESS = '9E2DA380' AND HASH_VALUE = 2857543126 AND CHILD_NUMBER = 0 ORDER BY ADDRESS, HASH_VALUE, CHILD_NUMBER, ID; ID OPERATION OBJECT COST BYTES ---- ------------------------------------------------------------ ------------------------------ ----- ------ 0 UPDATE STATEMENT Optimizer = ALL_ROWS 3 1 UPDATE *******_******_DETAIL 2 MERGE JOIN SEMI 3 65 3 TABLE ACCESS BY INDEX ROWID *******_******_DETAIL 0 52 4 INDEX FULL SCAN *******_******_DETAIL_PK 0 5 SORT UNIQUE 3 13 6 VIEW VW_SQ_1 2 13 7 NESTED LOOPS 2 103 8 NESTED LOOPS 1 95 9 MERGE JOIN CARTESIAN 0 87 10 TABLE ACCESS BY INDEX ROWID *******_******_DETAIL 0 61 11 INDEX RANGE SCAN *******_******_DETAIL_UK 0 12 BUFFER SORT 0 26 13 INDEX RANGE SCAN *******_******_UK1 0 26 14 TABLE ACCESS BY INDEX ROWID ******_******_LOG 1 8 15 INDEX UNIQUE SCAN ******_******_LOG_PK 0 16 TABLE ACCESS BY INDEX ROWID ******_******_LOG 1 8 17 INDEX UNIQUE SCAN ******_******_LOG_PK 0 18 HASH GROUP BY 2 185 19 NESTED LOOPS 2 185 20 NESTED LOOPS 1 177 21 NESTED LOOPS 1 69 22 TABLE ACCESS BY INDEX ROWID *******_******_DETAIL 0 61 23 INDEX RANGE SCAN *******_******_DETAIL_UK 0 24 TABLE ACCESS BY INDEX ROWID ******_******_LOG 1 9320 25 INDEX UNIQUE SCAN ******_******_LOG_PK 0 26 TABLE ACCESS BY INDEX ROWID *******_****** 0 39 27 INDEX FULL SCAN *******_******_PK 0 28 TABLE ACCESS BY INDEX ROWID ******_******_LOG 1 8 29 INDEX UNIQUE SCAN ******_******_LOG_PK 0
- SQL のどのあたりを実行中か調べる。
SQL> oradebug setospid 8091 Oracle pid: 17, Unix process pid: 8091, image: oracle@********* SQL> oradebug short_stack ksdxfstk()+19<-ksdxcb()+1321<-sspuser()+102<-kdsgrp()+261<-kdsfbr()+162<-qertbFetchByRowID()+683<-qerjotFetch()+232<-qerjotFetch()+232<-qerjotFetch()+232<-qerghFetch()+195<-subsr1()+161<-subsr3()+245<-evaopn2()+3242<-evaopn2()+330<-upderh()+135<-__PGOSF250_upduaw()+107<-kdusru()+439<-kauupd()+323<-updrow()+1362<-__PGOSF286_qerupRowProcedure()+62<-qerupFetch()+510<-updaul()+900<-updThreePhaseExe()+277<-updexe()+283<-opiexe()+4165<-opipls()+1033<-opiodr()+976<-__PGOSF112_rpidrus()+159<-skgmstack()+139<-rpidru()+98<-rpiswu2()+334<-rpidrv()+1199<-psddr0()+392<-psdnal()+308<-pevm_EXECC()+296<-__PGOSF12_pfrinstr_EXECC()+63<-pfrrun_no_tool()+45<-pfrrun()+765<-plsql_run()+736<-peicnt()+242<-kkxexe()+389<-opiexe()+4265<-kpoal8()+2089<-opiodr()+976<-ttcpip()+1085<-opitsk()+1054<-opiino()+821<-opiodr()+976<-opidrv()+466<-sou2o()+91<-opimai_real()+117<-main()+111<-__libc_start_main()+220
う〜ん、
qertbFetchByRowID()+683<- ← TABLE ACCESS BY INDEX ROWID qerjotFetch()+232<- ← NESTED LOOPS qerjotFetch()+232<- ← NESTED LOOPS qerjotFetch()+232<- ← NESTED LOOPS qerghFetch()+195<- ← HASH GROUP BY
みたいなことかなぁ
