[20200422]优化的困惑9.txt

来源:这里教程网 时间:2026-03-03 15:30:10 作者:

[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"

相关推荐