[20200320]SQL语句优化的困惑.txt

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

[20200320]SQL语句优化的困惑.txt --//三月初的一次优化. SYS@ZZZZ/dbcn> @ashtop username,sql_id "username='OOII'" trunc(sysdate) trunc(sysdate)+1     Total   Seconds     AAS %This   USERNAME SQL_ID        FIRST_SEEN          LAST_SEEN --------- ------- ------- -------- ------------- ------------------- -------------------       277      .0   30% | OOII     abnnf6rh06s6c 2020-03-02 00:02:04 2020-03-02 11:33:53       248      .0   27% | OOII     9srkzbahfjmrc 2020-03-02 00:01:07 2020-03-02 11:40:14        71      .0    8% | OOII                   2020-03-02 00:13:43 2020-03-02 11:37:48        52      .0    6% | OOII     39w37j74gyu0m 2020-03-02 00:58:34 2020-03-02 11:37:17 ... 30 rows selected. --//靠前的2条语句很容易确定优化方案,谓词建立索引就ok了.可以优化后我发现一个奇怪的情况: SYS@ZZZZ/dbcn> @ashtop username,sql_id "username='OOII'" trunc(sysdate) trunc(sysdate)+1     Total   Seconds     AAS %This   USERNAME             SQL_ID        FIRST_SEEN          LAST_SEEN --------- ------- ------- -------------------- ------------- ------------------- -------------------       144      .0   24% | OOII                               2020-03-09 00:15:00 2020-03-09 10:50:03        25      .0    4% | OOII                 g3a9ff2a5h2pq 2020-03-09 07:56:01 2020-03-09 10:40:33        19      .0    3% | OOII                 4896nn1g5m3zr 2020-03-09 08:27:42 2020-03-09 10:32:16 ... 30 rows selected. --//sql_id=NULL的对应的时间上升了.到底什么回事呢,还是我看到的情况是当天比较特殊.前段时间精力都放在网络上面. --//今天仔细分析看看. SYS@ZZZZ/dbcn> @ tpt/sqlid abnnf6rh06s6c '' Show SQL text, child cursors and execution stats for SQLID abnnf6rh06s6c child nvl('','%')   HASH_VALUE PLAN_HASH_VALUE  CH# SQL_TEXT ------------ --------------- ---- ------------------------------------------------------------------------------------------------------------------------------------------------------   3758317772      1695611142    0 select * from ( select this_.id as id6_0_, this_.biaoshi as biaoshi6_0_, this_.biaoti as biaoti6_0_, this_.huanzhe_id as huanzhe4_6_0_, this_.jcdh as                                   jcdh6_0_, this_.jcjs_time as jcjs6_6_0_, this_.jcks_id as jcks7_6_0_, this_.jcks_time as jcks8_6_0_, this_.jcsb_id as jcsb9_6_0_, this_.jcxm_ids as                                   jcxm10_6_0_, this_.jcyq as jcyq6_0_, this_.jcys as jcys6_0_, this_.jfbs as jfbs6_0_, this_.jiuzhen_id as jiuzhen14_6_0_, this_.kd_time as kd15_6_0_,                                   this_.kdks_id as kdks16_6_0_, this_.kdys as kdys6_0_, this_.left_pic as left18_6_0_, this_.right_pic as right19_6_0_, this_.state as state6_0_,                                   this_.yanbie as yanbie6_0_ from jcd this_ where this_.biaoshi=:1 order by this_.jcjs_time desc ) where rownum <= :2 --//建立索引BIAOSHI, STATE, JCJS_TIME字段索引。主要还考虑了sql_id 9srkzbahfjmrc 的情况。实际如果单独考虑这条语句建立 --//BIAOSHI, JCJS_TIME更好.优化后的情况,实际上这个查询值返回的结果经常是0。 --//注:实际开始2个索引都建立,后来我删除BIAOSHI, JCJS_TIME的索引。  CH# PARENT_HANDLE    OBJECT_HANDLE       PLAN_HASH       PARSES     H_PARSES   EXECUTIONS      FETCHES ROWS_PROCESSED ROWS_PER_FETCH      CPU_SEC CPU_SEC_EXEC      ELA_SEC ELA_SEC_EXEC         LIOS    LIOS_EXEC         PIOS        SORTS USERS_EXECUTING ---- ---------------- ---------------- ------------ ------------ ------------ ------------ ------------ -------------- -------------- ------------ ------------ ------------ ------------ ------------ ------------ ------------ ------------ ---------------    0 0000000239F96498 0000001309714680   1695611142     26629878           20     26629878     26648392        1002409   .03761611582 312815.66951 .01174679319 315071.30841  .0118314965   2139274284 80.333611893         1250     26538060               0 --//优化后执行计划: Plan hash value: 1695611142 -------------------------------------------------------------------------------------------------------------------------------------------- | Id  | Operation                      | Name                          | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |  OMem |  1Mem | Used-Mem | -------------------------------------------------------------------------------------------------------------------------------------------- |   0 | SELECT STATEMENT               |                               |        |       |    20 (100)|          |       |       |          | |*  1 |  COUNT STOPKEY                 |                               |        |       |            |          |       |       |          | |   2 |   VIEW                         |                               |     40 | 89000 |    20   (5)| 00:00:01 |       |       |          | |*  3 |    SORT ORDER BY STOPKEY       |                               |     40 |  5480 |    20   (5)| 00:00:01 |  1024 |  1024 |          | |   4 |     TABLE ACCESS BY INDEX ROWID| JCD                           |     40 |  5480 |    19   (0)| 00:00:01 |       |       |          | |*  5 |      INDEX RANGE SCAN          | I_JCD_BIAOSHI_STATE_JCJS_TIME |     40 |       |     3   (0)| 00:00:01 |  1025K|  1025K|          | -------------------------------------------------------------------------------------------------------------------------------------------- $ seq 20 | xargs -IQ echo "@tpt/ash/dashtop username,sql_id username='OOII' trunc(sysdate-20+Q) trunc(sysdate-20+Q)+1" $ seq 20 | xargs -IQ echo "@tpt/ash/dashtop username,sql_id username='OOII' trunc(sysdate-20+Q) trunc(sysdate-20+Q)+1" | sqlplus -s -l sys/PASSWORD@XXXXXX:1521/dbcn as sysdba | grep "OOII                         "    2%  OOII                                         40 2020-03-01 03:05:05 2020-03-01 16:17:29    7%  OOII                                        160 2020-03-02 08:48:43 2020-03-02 21:53:52    3%  OOII                                         60 2020-03-03 03:30:39 2020-03-03 19:23:30    4%  OOII                                         90 2020-03-04 00:27:10 2020-03-04 23:45:22    4%  OOII                                         90 2020-03-05 08:09:07 2020-03-05 23:16:04    4%  OOII                                         70 2020-03-06 01:50:54 2020-03-06 22:41:01   21%  OOII                                         80 2020-03-07 04:59:58 2020-03-07 20:33:11    6%  OOII                                         20 2020-03-08 01:43:20 2020-03-08 21:20:11   33%  OOII                                        580 2020-03-09 06:42:23 2020-03-09 20:56:15 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~     21%  OOII                                        270 2020-03-10 02:26:01 2020-03-10 22:01:23    9%  OOII                                        130 2020-03-11 01:30:07 2020-03-11 22:11:05   11%  OOII                                        130 2020-03-12 08:54:09 2020-03-12 19:50:59   14%  OOII                                        200 2020-03-13 02:12:50 2020-03-13 21:29:40   27%  OOII                                         80 2020-03-14 02:34:19 2020-03-14 16:52:30   19%  OOII                                         70 2020-03-15 01:58:51 2020-03-15 18:40:31   10%  OOII                                        290 2020-03-16 02:41:54 2020-03-16 23:14:23   18%  OOII                                        430 2020-03-17 06:34:06 2020-03-17 17:13:20   13%  OOII                                        330 2020-03-18 03:22:44 2020-03-18 21:19:41   10%  OOII                                        220 2020-03-19 01:01:38 2020-03-19 21:18:35   43%  OOII                                         30 2020-03-20 03:09:06 2020-03-20 04:16:23 --//3月9号反而cpu time上升很快。 3.14,3.15(星期6,7),3.20(当天)偏低。其它时间段比原来上升不少。 $ seq 20 | xargs -IQ echo "@tpt/ash/dashtop username,sql_id username='OOII' trunc(sysdate-20+Q) trunc(sysdate-20+Q)+1" | sqlplus -s -l sys/PASSWORD@XXXXXX:1521/dbcn as sysdba | egrep "abnnf6rh06s6c|9srkzbahfjmrc|OOII                         "   33%  OOII                 abnnf6rh06s6c          620 2020-03-01 00:00:38 2020-03-01 23:54:10   31%  OOII                 9srkzbahfjmrc          580 2020-03-01 00:31:06 2020-03-01 23:53:19    2%  OOII                                         40 2020-03-01 03:05:05 2020-03-01 16:17:29   26%  OOII                 abnnf6rh06s6c          580 2020-03-02 00:33:40 2020-03-02 23:30:17   25%  OOII                 9srkzbahfjmrc          560 2020-03-02 00:17:26 2020-03-02 23:44:51    7%  OOII                                        160 2020-03-02 08:48:43 2020-03-02 21:53:52   25%  OOII                 abnnf6rh06s6c          600 2020-03-03 00:25:11 2020-03-03 23:46:49   25%  OOII                 9srkzbahfjmrc          590 2020-03-03 00:24:21 2020-03-03 23:37:47    3%  OOII                                         60 2020-03-03 03:30:39 2020-03-03 19:23:30   26%  OOII                 abnnf6rh06s6c          670 2020-03-04 00:08:25 2020-03-04 23:25:57   23%  OOII                 9srkzbahfjmrc          580 2020-03-04 00:23:59 2020-03-04 23:41:00    4%  OOII                                         90 2020-03-04 00:27:10 2020-03-04 23:45:22   27%  OOII                 9srkzbahfjmrc          610 2020-03-05 00:26:12 2020-03-05 22:51:08   24%  OOII                 abnnf6rh06s6c          550 2020-03-05 00:12:39 2020-03-05 23:33:28    4%  OOII                                         90 2020-03-05 08:09:07 2020-03-05 23:16:04   24%  OOII                 9srkzbahfjmrc          400 2020-03-06 00:32:44 2020-03-06 16:21:09   17%  OOII                 abnnf6rh06s6c          280 2020-03-06 00:33:34 2020-03-06 11:33:17    4%  OOII                                         70 2020-03-06 01:50:54 2020-03-06 22:41:01 --//注 我3月6号上班建立的索引。   21%  OOII                                         80 2020-03-07 04:59:58 2020-03-07 20:33:11    3%  OOII                 abnnf6rh06s6c           10 2020-03-07 04:54:06 2020-03-07 04:54:06    6%  OOII                                         20 2020-03-08 01:43:20 2020-03-08 21:20:11   33%  OOII                                        580 2020-03-09 06:42:23 2020-03-09 20:56:15   21%  OOII                                        270 2020-03-10 02:26:01 2020-03-10 22:01:23    9%  OOII                                        130 2020-03-11 01:30:07 2020-03-11 22:11:05   11%  OOII                                        130 2020-03-12 08:54:09 2020-03-12 19:50:59   14%  OOII                                        200 2020-03-13 02:12:50 2020-03-13 21:29:40    2%  OOII                 abnnf6rh06s6c           30 2020-03-13 06:44:29 2020-03-13 15:02:30   27%  OOII                                         80 2020-03-14 02:34:19 2020-03-14 16:52:30    3%  OOII                 9srkzbahfjmrc           10 2020-03-14 07:35:23 2020-03-14 07:35:23 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~   19%  OOII                                         70 2020-03-15 01:58:51 2020-03-15 18:40:31    3%  OOII                 9srkzbahfjmrc           10 2020-03-15 09:44:19 2020-03-15 09:44:19 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~      10%  OOII                                        290 2020-03-16 02:41:54 2020-03-16 23:14:23   18%  OOII                                        430 2020-03-17 06:34:06 2020-03-17 17:13:20   13%  OOII                                        330 2020-03-18 03:22:44 2020-03-18 21:19:41   10%  OOII                                        220 2020-03-19 01:01:38 2020-03-19 21:18:35   24%  OOII                                         50 2020-03-20 03:09:06 2020-03-20 08:45:32 --//反到是3.14,3.15看到sql_id=9srkzbahfjmrc.不过也就是出现1次。 --//awr每秒取样1次,取样10秒放入awr报表,这样实际上10秒就是1次。 --//问题是优化为什么cpu_time反而上升呢? --//单独看sql_id = 'abnnf6rh06s6c'的情况: 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     FROM DBA_HIST_SQLSTAT s, DBA_HIST_SNAPSHOT x    WHERE     s.sql_id = 'abnnf6rh06s6c'          AND s.snap_id = x.snap_id          AND s.instance_number = x.instance_number          AND s.snap_id > 46833 ORDER BY 1;      SNAP_ID BEGIN_INTERVAL_TIME      END_INTERVAL_TIME        ELAPSED_TIME_DELTA CPU_TIME_DELTA EXECUTIONS_DELTA EXECUTIONS_TOTAL ROWS_PROCESSED_DELTA ROWS_PROCESSED_TOTAL ------------ ------------------------ ------------------------ ------------------ -------------- ---------------- ---------------- -------------------- --------------------        46833 2020-03-02 00:00:02.822  2020-03-02 01:00:24.818            26195750       26067035             1208         26100448                    0               998769        46834 2020-03-02 01:00:24.818  2020-03-02 02:00:34.263            25932063       25766090             1202         26101650                    0               998769        46835 2020-03-02 02:00:34.263  2020-03-02 03:00:07.341            25505938       25342125             1192         26102842                    0               998769        46836 2020-03-02 03:00:07.341  2020-03-02 04:00:28.718            25656006       25461121             1206         26104048                    0               998769        46837 2020-03-02 04:00:28.718  2020-03-02 05:00:49.503            25164150       25010197             1208         26105256                    0               998769        46838 2020-03-02 05:00:49.503  2020-03-02 06:00:08.663            24354532       24180336             1186         26106442                    0               998769        46839 2020-03-02 06:00:08.663  2020-03-02 07:00:04.905            24547284       24395289             1198         26107640                    0               998769        46840 2020-03-02 07:00:04.905  2020-03-02 08:00:11.333            25468829       25321159             1202         26108842                    0               998769        46846 2020-03-02 13:00:36.574  2020-03-02 14:00:48.955            25249223       25106180             1206         26116056                    1               998772        46847 2020-03-02 14:00:48.955  2020-03-02 15:00:19.667            24953683       24828239             1190         26117246                    0               998772        46853 2020-03-02 20:00:07.886  2020-03-02 21:00:28.987            24850789       24758246             1206         26124448                    0               998772        46854 2020-03-02 21:00:28.987  2020-03-02 22:00:38.943            24294364       24193323             1204         26125652                    0               998772        46855 2020-03-02 22:00:38.943  2020-03-02 23:00:12.030            24443804       24338324             1190         26126842                    0               998772        46856 2020-03-02 23:00:12.030  2020-03-03 00:00:33.484            24904103       24798227             1208         26128050                    0               998772        46857 2020-03-03 00:00:33.484  2020-03-03 01:00:55.706            24690257       24615275             1208         26129258                    0               998772        46858 2020-03-03 01:00:55.706  2020-03-03 02:00:06.009            24236144       24146328             1182         26130440                    0               998772        46859 2020-03-03 02:00:06.009  2020-03-03 03:00:13.199            25100733       24995170             1202         26131642                    0               998772        46860 2020-03-03 03:00:13.199  2020-03-03 04:00:19.833            25271305       25200152             1204         26132846                    0               998772        46861 2020-03-03 04:00:19.833  2020-03-03 05:00:18.947            25077010       24970208             1198         26134044                    0               998772        46862 2020-03-03 05:00:18.947  2020-03-03 06:00:32.586            24920416       24799221             1206         26135250                    0               998772        46863 2020-03-03 06:00:32.586  2020-03-03 07:00:39.731            24706316       24577248             1202         26136452                    0               998772        46864 2020-03-03 07:00:39.731  2020-03-03 08:00:22.933            25476935       25326159             1194         26137646                    0               998772        46870 2020-03-03 13:00:12.300  2020-03-03 14:00:24.763            24487515       24382277             1204         26144846                    0               998779        46875 2020-03-03 18:00:53.428  2020-03-03 19:00:21.705            24283814       24220310             1190         26150846                    0               998781        46877 2020-03-03 20:00:06.704  2020-03-03 21:00:03.966            24585860       24495267             1200         26153240                    0               998781        46878 2020-03-03 21:00:03.966  2020-03-03 22:00:19.050            25600065       25457126             1204         26154444                    0               998781        46879 2020-03-03 22:00:19.050  2020-03-03 23:00:24.964            25553487       25479128             1202         26155646                    0               998781        46883 2020-03-04 02:00:46.172  2020-03-04 03:00:11.461            25310335       25122174             1188         26160442                    0               998781        46884 2020-03-04 03:00:11.461  2020-03-04 04:00:32.651            25646728       25447124             1208         26161650                    0               998781        46885 2020-03-04 04:00:32.651  2020-03-04 05:00:07.159            25064696       24960187             1190         26162840                    0               998781        46886 2020-03-04 05:00:07.159  2020-03-04 06:00:13.058            25079377       24991194             1202         26164042                    0               998781        46887 2020-03-04 06:00:13.058  2020-03-04 07:00:20.348            25226813       25086182             1202         26165244                    0               998781        46888 2020-03-04 07:00:20.348  2020-03-04 08:00:25.622            26015101       25853054             1202         26166446                    0               998781        46894 2020-03-04 13:00:47.152  2020-03-04 14:00:02.982            24115730       23971313             1184         26173638                    0               998782        46895 2020-03-04 14:00:02.982  2020-03-04 15:00:09.214            25020057       24867229             1202         26174840                    0               998782        46901 2020-03-04 20:00:16.619  2020-03-04 21:00:37.542            24579114       24393293             1206         26182050                    0               998782        46902 2020-03-04 21:00:37.542  2020-03-04 22:00:54.656            24685885       24579257             1206         26183256                    1               998783        46903 2020-03-04 22:00:54.656  2020-03-04 23:00:00.693            24381874       24268315             1182         26184438                    0               998783        46904 2020-03-04 23:00:00.693  2020-03-05 00:00:08.098            24882706       24748236             1202         26185640                    0               998783        46905 2020-03-05 00:00:08.098  2020-03-05 01:00:03.310            24391892       24217327             1198         26186838                    0               998783        46906 2020-03-05 01:00:03.310  2020-03-05 02:00:21.555            24624015       24468259             1206         26188044                    0               998783        46907 2020-03-05 02:00:21.555  2020-03-05 03:00:28.294            24926209       24844209             1202         26189246                    0               998783        46908 2020-03-05 03:00:28.294  2020-03-05 04:00:07.830            24809374       24720266             1194         26190440                    0               998783        46909 2020-03-05 04:00:07.830  2020-03-05 05:00:29.404            25223881       25111191             1206         26191646                    0               998783        46910 2020-03-05 05:00:29.404  2020-03-05 06:00:50.817            24918400       24847238             1208         26192854                    0               998783        46911 2020-03-05 06:00:50.817  2020-03-05 07:00:11.754            24495585       24401302             1188         26194042                    0               998783        46912 2020-03-05 07:00:11.754  2020-03-05 08:00:02.899            25585767       25473128             1196         26195238                    0               998783        46918 2020-03-05 13:00:24.895  2020-03-05 14:00:42.177            24765453       24623245             1206         26202452                    0               998784 --// 26202452 - 26195238 = 7214 ,7214/6 = 1202.注意看BEGIN_INTERVAL_TIME的时间,上下间隔6小时,即使8-12时间段没有出现在 --//awr报表中。平均每小时的执行次数也是1200次。        46925 2020-03-05 20:00:21.952  2020-03-05 21:00:20.911            24637329       24534279             1200         26210844                    0               998785        46926 2020-03-05 21:00:20.911  2020-03-05 22:00:32.808            24829303       24694249             1204         26212048                    0               998785        46927 2020-03-05 22:00:32.808  2020-03-05 23:00:03.908            25038537       24956207             1190         26213238                    0               998785        46931 2020-03-06 02:00:08.939  2020-03-06 03:00:05.661            25670004       25501141             1198         26218038                    0               998785        46932 2020-03-06 03:00:05.661  2020-03-06 04:00:12.069            25929401       25826081             1202         26219240                    0               998785        46933 2020-03-06 04:00:12.069  2020-03-06 05:00:12.595            25194427       25037190             1201         26220441                    0               998785        46934 2020-03-06 05:00:12.595  2020-03-06 06:00:25.034            25226215       25111177             1205         26221646                    0               998785        46935 2020-03-06 06:00:25.034  2020-03-06 07:00:30.439            25031020       24905209             1200         26222846                    0               998785        46936 2020-03-06 07:00:30.439  2020-03-06 08:00:18.328            25752400       25657098             1196         26224042                    0               998785 57 rows selected. --//你可以发现CPU_time实际上每小时消耗24秒(注只要出现在awr报表中),平均每小时接近1200次,基本可以猜测每3秒执行一次,又一 --//个经典刷屏程序.你还可以发现3月6号以后这条sql语句不再出现在awr报表中,实际上正是我建立索引的时间。 --//拿BEGIN_INTERVAL_TIME3月5号的数据观察。你可以发现时间点0-7,13,20-22 实际上这些时间段正是没有业务的时间段。也就是当 --//正常业务展开时,这些语句就不再抓取到awr报表,这也是我以前优化漏掉的原因之一。 --//这也正常解析为什么3.14,3.15号抓取到sql语句的原因,星期6,7基本业务不忙。 --//同时就很好解析为什么优化后CPU_TIME反而升高的原因。 --//实际上如果大家注意ROWS_PROCESSED_DELTA列大部分的时间都是0,也就是根本没有输出。这样频繁的刷屏有意义吗?完全应该把刷 --//屏次数改为60秒应该都没有问题,开发实际上完全不考虑机器性能滥用服务器资源。 SYS@ZZZZ/dbcn> @ d_buffer abnnf6rh06s6c 60  EXECUTIONS1 BUFFER_GETS1 ELAPSED_TIME1 ROWS_PROCESSED1 ------------ ------------ ------------- ---------------     26629322   2139272613  315071268571         1002406 ... sleep 60 , waiting ....  EXECUTIONS2 BUFFER_GETS2 ELAPSED_TIME2 ROWS_PROCESSED2 ------------ ------------ ------------- ---------------     26629342   2139272673  315071269917         1002406 总buffer_gets 每次buffer_gets     执行次数   总执行时间 每次执行时间 总处理记录数 平均处理记录数 ------------- --------------- ------------ ------------ ------------ ------------ --------------            60               3           20         1346         67.3            0              0 --//再次验证3秒执行1次。 --// sql_id=9srkzbahfjmrc的情况类似,只不过改为6秒执行1次罢了。

相关推荐