[20200422]优化的困惑9.txt 1.环境: --//生产系统一条语句优化: SYS@aaa.bbb.ccc.ddd:1521/xxxx> @ ver1 PORT_STRING VERSION BANNER ------------------------------ -------------- -------------------------------------------------------------------------------- x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production 2.问题提出: SYS@aaa.bbb.ccc.ddd:1521/xxxx> @ bind_cap 0pv15fhky1mbp '' C200 --------------------------------------------------------------------------------------------------------------------------- select * from yf_zyfymx a ,gy_ksdm b ,yk_typk c ,yk_cddz d , zy_fyfs e ,gy_ygdm f , zy_bqyz g ,yk_ypsx h,yf_fyjl,zy_brry i where a.yfsb in (3,6,168,202) and a.lybq = b.ksdm(+) and a.ypxh=c.ypxh(+) and a.ypcd = d.ypcd(+) and a.fyfs = e.fyfs(+) and yf_fyjl.fygh = f.ygdm(+) and a.yzxh = g.jlxh(+) and c.ypsx = h.ypsx(+) and a.jlid = yf_fyjl.jlid and a.zyh = i.zyh and a.jfrq >=:V00001 and a.jfrq <=:V00002 and a.yfsb =:V00003 --//注:我屏蔽了select的输出,不然太长。因为前面有条件a.yfsb in (3,6,168,202),参数:V00003仅仅有4个值,其它查询没有意义。 SQL_ID CHILD_NUMBER WAS NAME POSITION MAX_LENGTH LAST_CAPTURED DATATYPE_STRING VALUE_STRING ------------- ------------ --- ------- -------- ---------- ------------------- --------------- ------------------- 0pv15fhky1mbp 1 YES :V00001 1 7 2020-04-15 11:03:16 DATE 2020/04/15 10:40:00 YES :V00002 2 7 2020-04-15 11:03:16 DATE 2020/04/15 11:10:00 YES :V00003 3 32 2020-04-15 11:03:16 VARCHAR2(32) 3 --//:V00003类型不一致,当然不存在隐式转换。 SELECT a.yfsb, COUNT (*) FROM yf_zyfymx a WHERE a.yfsb IN (3 ,6 ,168 ,202) AND a.jfrq >= :V00001 AND a.jfrq <= :V00002 GROUP BY a.yfsb --//:V00001='2020/4/20' :V00002='2020/4/21' yfsb COUNT (*) ---- ---------- 168 246 3 16006 ------------- 16252 --//很明显先判断一下是否有记录再执行不是更好,无语!!这样的开发。 SYS@aaa.bbb.ccc.ddd:1521/xxxx> @ sqlh 0pv15fhky1mbp 47815 SNAP_ID BEGIN_INTERVAL_TIME END_INTERVAL_TIME ELAPSED_TIME_DELTA CPU_TIME_DELTA EXECUTIONS_DELTA EXECUTIONS_TOTAL ROWS_PROCESSED_DELTA ---------- ------------------------ ------------------------ ------------------ -------------- ---------------- ---------------- -------------------- 47815 2020-04-11 22:00:33.205 2020-04-11 23:00:11.171 77305614 76502443 10148 3471387 0 47816 2020-04-11 23:00:11.171 2020-04-12 00:00:33.554 78762529 77146263 9772 3481159 77265 &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&& 47817 2020-04-12 00:00:33.554 2020-04-12 01:00:55.316 79698729 78911938 10244 3491403 0 47818 2020-04-12 01:00:55.316 2020-04-12 02:00:02.557 77782026 76700327 10040 3501443 0 47819 2020-04-12 02:00:02.557 2020-04-12 03:00:11.449 78392037 77706131 10284 3511727 0 47820 2020-04-12 03:00:11.449 2020-04-12 04:00:04.897 77951636 77013260 10256 3521983 0 47821 2020-04-12 04:00:04.897 2020-04-12 05:00:26.140 79284005 78441221 10315 3532298 0 47822 2020-04-12 05:00:26.140 2020-04-12 06:00:33.121 75621658 74918675 10316 3542615 0 47823 2020-04-12 06:00:33.121 2020-04-12 07:00:14.794 76024490 75267525 10204 3552819 0 47824 2020-04-12 07:00:14.794 2020-04-12 08:00:40.550 78478204 77405210 10288 3563107 0 47825 2020-04-12 08:00:40.550 2020-04-12 09:00:03.609 71477866 70448285 7368 3570475 311456 47826 2020-04-12 09:00:03.609 2020-04-12 10:00:29.058 75565743 74416741 7316 3577791 247379 47827 2020-04-12 10:00:29.058 2020-04-12 11:00:05.131 54699291 54021800 3723 3581514 896001 47828 2020-04-12 11:00:05.131 2020-04-12 12:00:13.032 56923578 56115482 3770 3585284 971092 47829 2020-04-12 12:00:13.032 2020-04-12 13:00:19.053 66883283 65913008 7243 3592527 484604 47830 2020-04-12 13:00:19.053 2020-04-12 14:00:02.974 77323469 76399481 10152 3602679 0 47831 2020-04-12 14:00:02.974 2020-04-12 15:00:25.524 62687385 62025504 6788 3609467 573251 47832 2020-04-12 15:00:25.524 2020-04-12 16:00:39.410 54376940 53754789 4309 3613776 872211 47833 2020-04-12 16:00:39.410 2020-04-12 17:00:11.224 74709067 73850647 8035 3621811 186361 47834 2020-04-12 17:00:11.224 2020-04-12 18:00:34.592 79454220 78601120 8408 3630219 156722 47835 2020-04-12 18:00:34.592 2020-04-12 19:00:57.794 79709597 78668081 9856 3640075 24733 47836 2020-04-12 19:00:57.794 2020-04-12 20:00:05.229 77679974 76605261 10036 3650111 0 47837 2020-04-12 20:00:05.229 2020-04-12 21:00:12.091 78478535 77334332 10212 3660323 0 47838 2020-04-12 21:00:12.091 2020-04-12 22:00:06.550 77915975 77098351 10180 3670503 0 47839 2020-04-12 22:00:06.550 2020-04-12 23:00:24.720 78337885 77504187 10260 3680763 0 47840 2020-04-12 23:00:24.720 2020-04-13 00:00:32.607 76569619 75435638 9712 3690475 88086 47841 2020-04-13 00:00:32.607 2020-04-13 01:00:16.075 77560589 76732269 10156 3700631 0 47842 2020-04-13 01:00:16.075 2020-04-13 02:00:39.514 78160623 77193285 10288 3710919 0 47843 2020-04-13 02:00:39.514 2020-04-13 03:00:01.429 76569806 75558571 10164 3721083 0 47844 2020-04-13 03:00:01.429 2020-04-13 04:00:25.450 77262567 76407464 10352 3731435 0 47845 2020-04-13 04:00:25.450 2020-04-13 05:00:05.978 75981865 75228525 10244 3741679 0 47846 2020-04-13 05:00:05.978 2020-04-13 06:00:11.718 76143971 75326497 10320 3751999 0 47847 2020-04-13 06:00:11.718 2020-04-13 07:00:17.928 76246463 75361499 10308 3762307 0 47848 2020-04-13 07:00:17.928 2020-04-13 08:00:25.242 78490760 77512139 10248 3772555 0 47855 2020-04-13 14:00:01.435 2020-04-13 15:00:07.140 54149061 53527948 5161 3799025 623722 47859 2020-04-13 18:00:25.749 2020-04-13 19:00:18.455 76528305 75133560 8432 3823108 70867 47860 2020-04-13 19:00:18.455 2020-04-13 20:00:40.796 80899369 79554844 10256 3833364 0 47861 2020-04-13 20:00:40.796 2020-04-13 21:00:05.055 78852603 77844112 10092 3843456 0 47862 2020-04-13 21:00:05.055 2020-04-13 22:00:28.237 78983338 78134077 10288 3853744 0 47863 2020-04-13 22:00:28.237 2020-04-13 23:00:51.579 79394076 78499021 10240 3863984 0 47864 2020-04-13 23:00:51.579 2020-04-14 00:00:05.458 78122714 76913323 9508 3873492 93354 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 47865 2020-04-14 00:00:05.458 2020-04-14 01:00:11.595 79517395 78623065 10176 3883668 0 47866 2020-04-14 01:00:11.595 2020-04-14 02:00:02.545 79332367 78198129 10148 3893816 0 47867 2020-04-14 02:00:02.545 2020-04-14 03:00:25.675 79285749 78342053 10292 3904108 0 47868 2020-04-14 03:00:25.675 2020-04-14 04:00:33.929 78827499 77876098 10260 3914368 0 47869 2020-04-14 04:00:33.929 2020-04-14 05:00:12.936 77876738 77011275 10192 3924560 0 47870 2020-04-14 05:00:12.936 2020-04-14 06:00:35.252 76343115 75591573 10364 3934924 0 47871 2020-04-14 06:00:35.252 2020-04-14 07:00:53.471 76432578 75506602 10340 3945264 0 47872 2020-04-14 07:00:53.471 2020-04-14 08:00:22.150 77639049 76855340 10015 3955279 372 49 rows selected. --//你可以发现这个又是一个经典的刷屏语句。可以发现非业务时间的ROWS_PROCESSED_DELTA=0,而执行次数可以达到10XXX,达到1秒执行3次,而在业务时间由于有 --//数据输出这样执行次数有所减少。看到这样的语句真心无语,这么频繁的执行有用吗?减少到5秒甚至10秒1次,对业务有影响吗? --//我顺便执行select * from GV$OPEN_CURSOR where sql_id='0pv15fhky1mbp',几乎很难抓取到输出。有点奇怪,实际上登录时间时间"很长"。 --//如果在执行前加入判断:比如对a.yfsb 等于202,6的情况。 select count(*) from yf_zyfymx a where and a.jfrq >=:V00001 and a.jfrq <=:V00002 and a.yfsb =:V00003 and rownum<=1; --//count(*) > 0 再执行该语句不是能大大较少不必要的执行吗,而且可以在特定的时段先判断是否有记录,在选择执行. --//遇到这样开发团队真心无语。 --//有点吃惊的是23点时段突然出现输出,因为查询条件已经限制了a.yfsb in (3,6,168,202)仅仅可以是这4个值。而且对方带入的参数是字符类型的, --//当然不会发生隐式转换。这个是本文主要探查原因。实际上我查询23:00-0点时间段是没有数据生成的。为什么23点-0点有输出呢? 3.首先确定带入绑定变量值: SYS@aaa.bbb.ccc.ddd:1521/xxxx> @ hide bind_cap NAME DESCRIPTION DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD ------------------------------- ----------------------------------------------------------- ------------- ------------- ------------ ----- --------- _cursor_bind_capture_area_size maximum size of the cursor bind capture area TRUE 400 400 FALSE IMMEDIATE _cursor_bind_capture_interval interval (in seconds) between two bind capture for a cursor TRUE 900 900 FALSE IMMEDIATE cursor_bind_capture_destination Allowed destination for captured bind variables TRUE memory+disk memory+disk TRUE IMMEDIATE --//_cursor_bind_capture_interval = 900,也就是15分钟。 $ (echo set head off ;seq 10 | xargs -IQ echo -e "@bind_cap 0pv15fhky1mbp '' ;\n host sleep 900") | sqlplus -s -l / as sysdba SQL_ID CHILD_NUMBER WAS NAME POSITION MAX_LENGTH LAST_CAPTURED DATATYPE_STRING VALUE_STRING ------------- ------------ --- ------- -------- ---------- ------------------- --------------- ------------------- 0pv15fhky1mbp 0 YES :V00001 1 7 2020-04-14 08:38:43 DATE 2020/04/14 08:20:00 YES :V00002 2 7 2020-04-14 08:38:43 DATE 2020/04/14 08:50:00 YES :V00003 3 32 2020-04-14 08:38:43 VARCHAR2(32) 3 0pv15fhky1mbp 0 YES :V00001 1 7 2020-04-14 08:53:43 DATE 2020/04/14 08:30:00 YES :V00002 2 7 2020-04-14 08:53:43 DATE 2020/04/14 09:00:00 YES :V00003 3 32 2020-04-14 08:53:43 VARCHAR2(32) 3 0pv15fhky1mbp 0 YES :V00001 1 7 2020-04-14 09:08:43 DATE 2020/04/14 08:50:00 YES :V00002 2 7 2020-04-14 09:08:43 DATE 2020/04/14 09:20:00 YES :V00003 3 32 2020-04-14 09:08:43 VARCHAR2(32) 3 0pv15fhky1mbp 0 YES :V00001 1 7 2020-04-14 09:23:43 DATE 2020/04/14 09:00:00 YES :V00002 2 7 2020-04-14 09:23:43 DATE 2020/04/14 09:30:00 YES :V00003 3 32 2020-04-14 09:23:43 VARCHAR2(32) 202 0pv15fhky1mbp 0 YES :V00001 1 7 2020-04-14 09:38:43 DATE 2020/04/14 09:20:00 YES :V00002 2 7 2020-04-14 09:38:43 DATE 2020/04/14 09:50:00 YES :V00003 3 32 2020-04-14 09:38:43 VARCHAR2(32) 3 0pv15fhky1mbp 0 YES :V00001 1 7 2020-04-14 09:53:44 DATE 2020/04/14 09:30:00 YES :V00002 2 7 2020-04-14 09:53:44 DATE 2020/04/14 10:00:00 YES :V00003 3 32 2020-04-14 09:53:44 VARCHAR2(32) 3 --//注:字段头信息是我加上的. --//你可以看出实际上900秒取样。而且查询时间间隔都是30分钟。我估计10分钟10分钟往前推。 --//比如到了2020/04/14 09:00:00,可能查询时间范围就变成了2020/04/14 08:40:00 -- 2020/04/14 09:10:00. 4.跟踪sql语句: $ cat sqltt.txt ALTER SYSTEM SET EVENTS 'sql_trace [sql: sql_id=&&1] bind=true, wait=true'; host sleep &&2 ALTER SYSTEM SET EVENTS 'sql_trace off'; $ at 22:59 at> sqlplus sys/xxxx@RAC1/xxxx as sysdba @sqltt.txt 0pv15fhky1mbp 4000 at> <EOT> job 9 at 2020-04-21 22:59 $ at 22:59 at> sqlplus sys/xxxx@RAC2/xxxx as sysdba @sqltt.txt 0pv15fhky1mbp 4000 at> <EOT> job 10 at 2020-04-21 22:59 $ ls -ltr *.trc | egrep "2020-04-21 2[23]:" | awk '{print $8}' | xargs -IQ grep -l 0pv15fhky1mbp Q | xargs -IQ ls -l Q | column -t -rw-r----- 1 oracle asmadmin 12314360 Apr 21 23:01 xxxx1_ora_100285.trc -rw-r----- 1 oracle asmadmin 2007848 Apr 21 23:01 xxxx1_ora_110493.trc -rw-r----- 1 oracle asmadmin 55606528 Apr 21 23:11 xxxx1_ora_110896.trc -rw-r----- 1 oracle asmadmin 1089426 Apr 21 23:11 xxxx1_ora_121108.trc -rw-r----- 1 oracle asmadmin 45385673 Apr 21 23:21 xxxx1_ora_121298.trc -rw-r----- 1 oracle asmadmin 233683 Apr 21 23:22 xxxx1_ora_1412.trc -rw-r----- 1 oracle asmadmin 51884128 Apr 21 23:32 xxxx1_ora_1557.trc -rw-r----- 1 oracle asmadmin 151934 Apr 21 23:32 xxxx1_ora_12609.trc -rw-r----- 1 oracle asmadmin 55306341 Apr 21 23:42 xxxx1_ora_12057.trc -rw-r----- 1 oracle asmadmin 55168324 Apr 21 23:52 xxxx1_ora_22546.trc $ ls -ltr *.trc | egrep "2020-04-22 0[09]:" | awk '{print $8}' | xargs -IQ grep -l 0pv15fhky1mbp Q | xargs -IQ ls -l Q | column -t -rw-r----- 1 oracle asmadmin 30947031 Apr 22 00:02 xxxx1_ora_100426.trc -rw-r----- 1 oracle asmadmin 32015029 Apr 22 00:03 xxxx1_ora_101674.trc -rw-r----- 1 oracle asmadmin 11539852 Apr 22 00:05 xxxx1_ora_111835.trc --//注意ls我定义别名,不过过滤失效。 $ alias ls alias ls='ls --color=auto --time-style=+"%Y-%m-%d %H:%M:%S"' --//从转储的时间可以看出可以看出大概10分钟出现2个。不知道为什么23:52仅仅出现1次。 $ ls -ltr *.trc | egrep "2020-04-21 2[23]:" | awk '{print $8}' | xargs -IQ grep -l 0pv15fhky1mbp Q > /tmp/ee1.txt $ ls -ltr *.trc | egrep "2020-04-22" | awk '{print $8}' | xargs -IQ grep -l 0pv15fhky1mbp Q >> /tmp/ee1.txt --//保存要分析的文件到/tmp/ee1.txt $ cat /tmp/ee1.txt | xargs -IQ bash -c "echo Q;grep 0pv15fhky1mbp Q| awk '{print \$4}'| uniq -c " xxxx1_ora_100285.trc 373 #140591307300936 xxxx1_ora_110493.trc 1 #140598307647200 3 #140598304752672 56 #140598304958360 xxxx1_ora_110896.trc 4 #140494626705520 1015 #140494629561936 665 #140494629449952 xxxx1_ora_121108.trc 1 #140728840941280 3 #140728838009888 28 #140728838215576 xxxx1_ora_121298.trc 4 #139667546106672 1011 #139667543239512 358 #139667545993440 xxxx1_ora_1412.trc 1 #139828203548384 2 #139828200666144 4 #139828200871832 xxxx1_ora_1557.trc 4 #139877515651888 896 #139877512797016 672 #139877515538656 xxxx1_ora_12609.trc 4 #140073655200560 xxxx1_ora_12057.trc 1 #139989832756960 3 #139989829825568 92 #139989830031256 911 #139989832754768 669 #139989832642784 xxxx1_ora_22546.trc 164 #140508294618304 839 #140508297487952 669 #140508297375968 xxxx1_ora_100426.trc 613 #140102612521760 323 #140102614724832 xxxx1_ora_101674.trc 2 #139754577412208 517 #139754580272720 449 #139754580160736 xxxx1_ora_111835.trc 1 #140062327762656 3 #140062324818976 48 #140062325024664 295 #140062327760464 $ cat /tmp/ee1.txt | xargs -IQ egrep 'value="4/2[12]/2020 ' Q | sort | uniq -c 16 value="4/21/2020 0:0:0" ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 1317 value="4/21/2020 22:40:0" 1684 value="4/21/2020 22:50:0" 1180 value="4/21/2020 23:0:0" 2997 value="4/21/2020 23:10:0" 3360 value="4/21/2020 23:20:0" 2844 value="4/21/2020 23:30:0" 3167 value="4/21/2020 23:40:0" 1676 value="4/21/2020 23:50:0" 16 value="4/21/2020 23:59:0" ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 1664 value="4/22/2020 0:0:0" 1487 value="4/22/2020 0:10:0" --//"出现16次value="4/21/2020 0:0:0",value="4/21/2020 23:59:0".这验证了为什么23点-24点之间为什么会有输出。在这个时间段重新做了显示全天的记录。 --//有点奇怪的是为什么是23:59:0,而不是23:59:59,这样可能出现"漏"显示的问题吗?开发犯的一个小错误。 $ cat /tmp/ee1.txt | xargs -IQ grep -l "4/21/2020 23:59:0" Q | xargs -IQ ls -l Q | column -t -rw-r----- 1 oracle asmadmin 45385673 Apr 21 23:21 xxxx1_ora_121298.trc -rw-r----- 1 oracle asmadmin 233683 Apr 21 23:22 xxxx1_ora_1412.trc -rw-r----- 1 oracle asmadmin 51884128 Apr 21 23:32 xxxx1_ora_1557.trc --//这就解析为什么前面的从转储的时间可以看出可以看出大概10分钟出现2个以及为什么23:52仅仅出现1次。 --//还有点奇怪的是开始执行时间在23:22. $ echo "@sqlh 0pv15fhky1mbp 48008" | sqlplus -s -l sys/xxxx@aaa.bbb.ccc.ddd:1521/xxxx as sysdba | grep "[0-9] 23:" | grep -v "[0-9] 22:" SNAP_ID BEGIN_INTERVAL_TIME END_INTERVAL_TIME ELAPSED_TIME_DELTA CPU_TIME_DELTA EXECUTIONS_DELTA EXECUTIONS_TOTAL ROWS_PROCESSED_DELTA BUFFER_GETS_DELTA ---------- ------------------------ ------------------------ ------------------ -------------- ---------------- ---------------- -------------------- ----------------- 48008 2020-04-19 23:00:03.764 2020-04-20 00:00:10.952 62219860 61717604 9736 914331 95400 1487682 48032 2020-04-20 23:00:06.684 2020-04-21 00:00:30.205 74459773 73336848 9684 1116347 81260 1300126 48056 2020-04-21 23:00:24.524 2020-04-22 00:00:01.172 96387435 94893606 9512 1317543 67344 1075667 --//修改绑定变量,注解and a.yfsb =:V00003. :V00001 := '2020/04/21 00:00:00'; :V00002 := '2020/04/22 00:00:00'; --//返回16836。67344/16836 = 4 ,4个值, 4*4=16.正好验证sqlh脚本的输出。 --//另外我也测了其它时间段: :V00001 := '2020/04/17 00:00:00'; :V00002 := '2020/04/18 00:00:00'; --//返回17480 --//87400/17480 = 5 :V00001 := '2020/04/16 00:00:00'; :V00002 := '2020/04/17 00:00:00'; --//返回16925,84625/16925 = 5 :V00001 := '2020/04/15 00:00:00'; :V00002 := '2020/04/16 00:00:00'; --//返回16791,83955/16791 = 5. :V00001 := '2020/04/14 00:00:00'; :V00002 := '2020/04/15 00:00:00'; --//返回16341, 98046/16341 = 6. :V00001 := '2020/04/13 00:00:00'; :V00002 := '2020/04/14 00:00:00'; -//返回15559,93354/15559 = 6 --//OK,已经可以确定在这个时间段扫描4,5,6次(乘以4次),整个日期范围内的情况。基本可以确定为什么23-24点之间有输出的原因。 5.看看每个跟踪文件的执行时间范围: $ cat /tmp/ee1.txt | xargs -IQ bash -c "echo Q;grep 0pv15fhky1mbp Q| awk '{print \$10}' | sed -n '1p;\$p'|cut -f2 -d'=' |xargs -IQ xdate Q" xxxx1_ora_100285.trc 2020-04-21 22:59:03.894046000 2020-04-21 23:01:17.199957000 xxxx1_ora_110493.trc 2020-04-21 23:01:18.549278000 2020-04-21 23:01:38.494729000 --//以上2个可能从中间开始跟踪,无法判断。 xxxx1_ora_110896.trc 2020-04-21 23:01:39.846533000 2020-04-21 23:11:38.378720000 --//10分钟。 xxxx1_ora_121108.trc 2020-04-21 23:11:39.728799000 2020-04-21 23:11:49.975829000 --//10分钟。 xxxx1_ora_121298.trc 2020-04-21 23:11:51.324993000 2020-04-21 23:21:33.854756000 --//10分钟。 xxxx1_ora_1412.trc 2020-04-21 23:22:07.700456000 2020-04-21 23:22:14.392132000 --//7分钟 xxxx1_ora_1557.trc 2020-04-21 23:22:15.776580000 2020-04-21 23:32:15.813717000 --//10分钟。 xxxx1_ora_12609.trc 2020-04-21 23:32:51.766126000 2020-04-21 23:32:51.880844000 xxxx1_ora_12057.trc 2020-04-21 23:32:17.175933000 2020-04-21 23:42:17.501154000 --//10分钟。 xxxx1_ora_22546.trc 2020-04-21 23:42:18.855909000 2020-04-21 23:52:18.644104000 --//10分钟。 xxxx1_ora_100426.trc 2020-04-21 23:52:19.996287000 2020-04-22 00:02:18.424764000 --//10分钟。 xxxx1_ora_101674.trc 2020-04-21 23:53:42.268303000 2020-04-22 00:03:40.605847000 --//10分钟。 xxxx1_ora_111835.trc 2020-04-22 00:03:41.955328000 2020-04-22 00:05:44.846208000 --//关闭跟踪。 --//估计10分钟一个循环。tmd垃圾的刷屏软件。看看扫描:V00003 顺序。 $ grep 0pv15fhky1mbp xxxx1_ora_100285.trc | awk '{print $4}' | uniq | xargs -IQ egrep -A15 "BINDS Q" xxxx1_ora_100285.trc | egrep "Bind#|value="| paste - - | sort | uniq -c 373 Bind#0 value="4/21/2020 22:40:0" 373 Bind#1 value="4/21/2020 23:10:0" 93 Bind#2 value="168" 94 Bind#2 value="202" 93 Bind#2 value="3" 93 Bind#2 value="6" --//执行373次,而且可以猜测BIND#2的值是循环执行的。93*4+1 = 373. $ grep 0pv15fhky1mbp xxxx1_ora_100285.trc | awk '{print $4}' | uniq | xargs -IQ egrep -A15 "BINDS Q" xxxx1_ora_100285.trc | egrep -A5 "Bind#2" | grep "value=" | paste - - - - | uniq -c 93 value="202" value="3" value="6" value="168" 1 value="202" --//看看下一个是否从value="3"开始。 $ grep 0pv15fhky1mbp xxxx1_ora_110493.trc | awk '{print $4}' | uniq | xargs -IQ egrep -A15 "BINDS Q" xxxx1_ora_110493.trc | egrep -A5 "Bind#2" | grep "value=" | paste - - - - | uniq -c 15 value="3" value="6" value="168" value="202" $ grep 0pv15fhky1mbp xxxx1_ora_1557.trc | awk '{print $4}' | uniq | xargs -IQ egrep -A15 "BINDS Q" xxxx1_ora_1557.trc | egrep -A5 "Bind#2" | grep "value=" | paste - - - - | uniq -c 393 value="3" value="6" value="168" value="202" --//基本可以确定是一个循环刷屏软件。 $ grep 0pv15fhky1mbp xxxx1_ora_110493.trc | awk '{print $10}' | cut -f2 -d'=' | xargs -IQ xdate Q > /tmp/ee2.txt $ cat /tmp/ee2.txt | xargs -I{} date -d "{}" "+%Y-%m-%d:%T.%N %s.%N" | awk 'NR==1 {a=$1;b=$2} NR>1 {print $1,"-",a,$2-b;a=$1;b=$2}' 2020-04-21:23:01:18.572442000 - 2020-04-21:23:01:18.549278000 0.023164 2020-04-21:23:01:18.593294000 - 2020-04-21:23:01:18.572442000 0.0208519 2020-04-21:23:01:18.657183000 - 2020-04-21:23:01:18.593294000 0.063889 2020-04-21:23:01:19.965149000 - 2020-04-21:23:01:18.657183000 1.30797 2020-04-21:23:01:19.987112000 - 2020-04-21:23:01:19.965149000 0.0219631 2020-04-21:23:01:20.008268000 - 2020-04-21:23:01:19.987112000 0.0211561 2020-04-21:23:01:20.076245000 - 2020-04-21:23:01:20.008268000 0.067977 2020-04-21:23:01:21.388697000 - 2020-04-21:23:01:20.076245000 1.31245 2020-04-21:23:01:21.410812000 - 2020-04-21:23:01:21.388697000 0.022115 2020-04-21:23:01:21.432424000 - 2020-04-21:23:01:21.410812000 0.0216122 2020-04-21:23:01:21.495844000 - 2020-04-21:23:01:21.432424000 0.0634198 2020-04-21:23:01:22.797844000 - 2020-04-21:23:01:21.495844000 1.302 2020-04-21:23:01:22.819725000 - 2020-04-21:23:01:22.797844000 0.0218811 2020-04-21:23:01:22.841356000 - 2020-04-21:23:01:22.819725000 0.021631 2020-04-21:23:01:22.905724000 - 2020-04-21:23:01:22.841356000 0.064368 2020-04-21:23:01:24.209283000 - 2020-04-21:23:01:22.905724000 1.30356 2020-04-21:23:01:24.230426000 - 2020-04-21:23:01:24.209283000 0.021143 2020-04-21:23:01:24.256038000 - 2020-04-21:23:01:24.230426000 0.0256119 2020-04-21:23:01:24.326223000 - 2020-04-21:23:01:24.256038000 0.0701849 2020-04-21:23:01:25.647111000 - 2020-04-21:23:01:24.326223000 1.32089 2020-04-21:23:01:25.672147000 - 2020-04-21:23:01:25.647111000 0.0250361 2020-04-21:23:01:25.694435000 - 2020-04-21:23:01:25.672147000 0.0222878 2020-04-21:23:01:25.759965000 - 2020-04-21:23:01:25.694435000 0.0655301 2020-04-21:23:01:27.063004000 - 2020-04-21:23:01:25.759965000 1.30304 2020-04-21:23:01:27.090415000 - 2020-04-21:23:01:27.063004000 0.027411 2020-04-21:23:01:27.111800000 - 2020-04-21:23:01:27.090415000 0.021385 2020-04-21:23:01:27.175630000 - 2020-04-21:23:01:27.111800000 0.0638301 2020-04-21:23:01:28.479110000 - 2020-04-21:23:01:27.175630000 1.30348 2020-04-21:23:01:28.500069000 - 2020-04-21:23:01:28.479110000 0.0209589 2020-04-21:23:01:28.521447000 - 2020-04-21:23:01:28.500069000 0.021378 2020-04-21:23:01:28.585815000 - 2020-04-21:23:01:28.521447000 0.064368 2020-04-21:23:01:29.895066000 - 2020-04-21:23:01:28.585815000 1.30925 2020-04-21:23:01:29.917030000 - 2020-04-21:23:01:29.895066000 0.0219641 2020-04-21:23:01:29.939078000 - 2020-04-21:23:01:29.917030000 0.022048 2020-04-21:23:01:30.005716000 - 2020-04-21:23:01:29.939078000 0.066638 2020-04-21:23:01:31.303372000 - 2020-04-21:23:01:30.005716000 1.29766 2020-04-21:23:01:31.324338000 - 2020-04-21:23:01:31.303372000 0.0209661 2020-04-21:23:01:31.345285000 - 2020-04-21:23:01:31.324338000 0.020947 2020-04-21:23:01:31.415500000 - 2020-04-21:23:01:31.345285000 0.070215 2020-04-21:23:01:32.717882000 - 2020-04-21:23:01:31.415500000 1.30238 2020-04-21:23:01:32.739167000 - 2020-04-21:23:01:32.717882000 0.0212851 2020-04-21:23:01:32.759835000 - 2020-04-21:23:01:32.739167000 0.020668 2020-04-21:23:01:32.825428000 - 2020-04-21:23:01:32.759835000 0.065593 2020-04-21:23:01:34.129409000 - 2020-04-21:23:01:32.825428000 1.30398 2020-04-21:23:01:34.150984000 - 2020-04-21:23:01:34.129409000 0.021575 2020-04-21:23:01:34.172687000 - 2020-04-21:23:01:34.150984000 0.021703 2020-04-21:23:01:34.238400000 - 2020-04-21:23:01:34.172687000 0.0657129 2020-04-21:23:01:35.542766000 - 2020-04-21:23:01:34.238400000 1.30437 2020-04-21:23:01:35.564471000 - 2020-04-21:23:01:35.542766000 0.0217049 2020-04-21:23:01:35.585334000 - 2020-04-21:23:01:35.564471000 0.0208631 2020-04-21:23:01:35.651166000 - 2020-04-21:23:01:35.585334000 0.0658319 2020-04-21:23:01:36.951535000 - 2020-04-21:23:01:35.651166000 1.30037 2020-04-21:23:01:36.972524000 - 2020-04-21:23:01:36.951535000 0.0209889 2020-04-21:23:01:36.995122000 - 2020-04-21:23:01:36.972524000 0.022598 2020-04-21:23:01:37.062274000 - 2020-04-21:23:01:36.995122000 0.067152 2020-04-21:23:01:38.378726000 - 2020-04-21:23:01:37.062274000 1.31645 2020-04-21:23:01:38.402667000 - 2020-04-21:23:01:38.378726000 0.023941 2020-04-21:23:01:38.425964000 - 2020-04-21:23:01:38.402667000 0.0232971 2020-04-21:23:01:38.494729000 - 2020-04-21:23:01:38.425964000 0.0687649 --//可以看出4个值循环,然后sleep大约1秒(估计),然后继续循环。 --//一般1.4秒执行4次。3600/1.4*4 = 10285.7次。这样与前面的推测基本一致,基本确定1个小时内平均每秒3次的情况。 $ grep 0pv15fhky1mbp xxxx1_ora_110896.trc | awk '{print $10}' | cut -f2 -d'=' | xargs -IQ xdate Q > /tmp/ee3.txt $ cat /tmp/ee3.txt | xargs -I{} date -d "{}" "+%Y-%m-%d:%T.%N %s.%N" | awk 'NR==1 {a=$1;b=$2} NR>1 {print $1,"-",a,$2-b;a=$1;b=$2}' | head -12 2020-04-21:23:01:39.871090000 - 2020-04-21:23:01:39.846533000 0.0245569 2020-04-21:23:01:39.906213000 - 2020-04-21:23:01:39.871090000 0.0351231 2020-04-21:23:01:39.978123000 - 2020-04-21:23:01:39.906213000 0.0719099 2020-04-21:23:01:41.957241000 - 2020-04-21:23:01:39.978123000 1.97912 2020-04-21:23:01:41.978752000 - 2020-04-21:23:01:41.957241000 0.0215108 2020-04-21:23:01:42.000375000 - 2020-04-21:23:01:41.978752000 0.0216231 2020-04-21:23:01:42.067666000 - 2020-04-21:23:01:42.000375000 0.067291 2020-04-21:23:01:43.362773000 - 2020-04-21:23:01:42.067666000 1.29511 2020-04-21:23:01:43.383414000 - 2020-04-21:23:01:43.362773000 0.0206411 2020-04-21:23:01:43.404418000 - 2020-04-21:23:01:43.383414000 0.021004 2020-04-21:23:01:43.468162000 - 2020-04-21:23:01:43.404418000 0.0637441 2020-04-21:23:01:44.770544000 - 2020-04-21:23:01:43.468162000 1.30238 xargs: date: terminated by signal 13 --//基本可以认定我的判断。 --//即使业务高峰也可以修改为5秒1个循环,根本对业务完全不会有任何影响。10秒都可以。有必要这样做吗? --//像这样的语句你越优化消耗资源越大,执行"越"慢效果越好。 --//附上脚本: $ cat sqlh.sql column BEGIN_INTERVAL_TIME format a24 column END_INTERVAL_TIME format a24 SELECT s.SNAP_ID ,x.BEGIN_INTERVAL_TIME ,x.END_INTERVAL_TIME ,ELAPSED_TIME_DELTA ,CPU_TIME_DELTA ,EXECUTIONS_DELTA ,EXECUTIONS_TOTAL ,ROWS_PROCESSED_DELTA ,BUFFER_GETS_DELTA FROM DBA_HIST_SQLSTAT s, DBA_HIST_SNAPSHOT x WHERE s.sql_id = '&&1' AND s.snap_id = x.snap_id AND s.instance_number = x.instance_number AND s.snap_id >= nvl('&&2',0) ORDER BY 1; $ cat $(which xdate) #! /bin/bash # /bin/date -d "1970-01-01 00:00:00 UTC $( echo "scale=6; $1/1000000" |bc -l) seconds" +"%Y-%m-%d %T.%N" /bin/date -d "@$( echo "scale=6; $1/1000000" |bc -l)" +"%Y-%m-%d %T.%N"
[20200422]优化的困惑9.txt
来源:这里教程网
时间:2026-03-03 15:30:10
作者:
编辑推荐:
下一篇:
相关推荐
-
雷神推出 MIX PRO II 迷你主机:基于 Ultra 200H,玻璃上盖 + ARGB 灯效
2 月 9 日消息,雷神 (THUNDEROBOT) 现已宣布推出基于英
-
制造商 Musnap 推出彩色墨水屏电纸书 Ocean C:支持手写笔、第三方安卓应用
2 月 10 日消息,制造商 Musnap 现已在海外推出一款 Oce
热文推荐
- Oracle 19C+13.4EMCC数据库监控
Oracle 19C+13.4EMCC数据库监控
26-03-03 - Oracle GoldenGate 11g官方文档Administrator’s Guide续一
- Oracle 19C+13.4EMCC主机监控
Oracle 19C+13.4EMCC主机监控
26-03-03 - [20200424]跟踪特定sql语句以及v$open_cursor视图(再补充).txt
- Oracle 19C OGG基础运维-05DDL操作同步
Oracle 19C OGG基础运维-05DDL操作同步
26-03-03 - Oracle 19C OGG基础运维-06增加复制表
Oracle 19C OGG基础运维-06增加复制表
26-03-03 - Oracle 19C OGG基础运维-07减少复制表
Oracle 19C OGG基础运维-07减少复制表
26-03-03 - Oracle 19C OGG基础运维-08Error code [942]
- Oracle 19C OGG基础运维-09OGG-15121错误
Oracle 19C OGG基础运维-09OGG-15121错误
26-03-03 - 疫情后时代,招投标形势将如何?
疫情后时代,招投标形势将如何?
26-03-03
