ITPub博客

首页 > 数据库 > Oracle > [20200422]优化的困惑9.txt

[20200422]优化的困惑9.txt

原创 Oracle 作者:lfree 时间:2020-04-22 10:55:46 0 删除 编辑

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

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/267265/viewspace-2687572/,如需转载,请注明出处,否则将追究法律责任。

全部评论
熟悉oracle相关技术,擅长sql优化,rman备份与恢复,熟悉linux shell编程。

注册时间:2008-01-03

  • 博文量
    2699
  • 访问量
    6485201