19C中的SERVICE_NAME

我们在12c之前的版本,添加或修改应用SERVICE_NAME的方式是通过修改数据库参数”SERVICE_NAMES”,但是此参数意在19c版本中废弃,并且再次利用此参数会出现alter session set container=pdb命令失效,无法在sqlplus中切换PDB的影响

官方文档提示:

Note:The SERVICE_NAMES initialization parameter is deprecated in Oracle Database 19c and may be desupported in a future release.
Use of the SERVICE_NAMES parameter is no longer actively supported. It must not be used for high availability (HA) deployments and it is not supported for HA operations. This restriction includes FAN, load balancing, FAILOVER_TYPE, FAILOVER_RESTORE, SESSION_STATE_CONSISTENCY, and any other uses.

To manage your services, Oracle recommends that you instead use the SRVCTL command-line utility, the GDSCTL command-line utility, or the DBMS_SERVICE PL/SQL package.

实验测试过程:

SQL> select name,open_mode,database_role from v$database;

NAME               OPEN_MODE                                DATABASE_ROLE
------------------ ---------------------------------------- --------------------------------
ALBERTCDB           READ WRITE                               PRIMARY

SQL> show parameter service 

NAME                                 TYPE                   VALUE
------------------------------------ ---------------------- ------------------------------
service_names                        string                 ALBERTCDB
SQL> show pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED
---------- ------------------------------ ---------- ----------
         2 PDB$SEED                       READ ONLY  NO
         3 PDB9A                          READ WRITE NO
         4 PDB113A                        READ WRITE NO
SQL> 

监听注册SERVICE情况,pdb9a与pdb113a默认serivce已注册并且可以正常对外提供服务:
Service "+ASM" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_ARC" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_DATA" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_MGMT" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_OCR" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_REDO" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_VOTE" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "c36f7bedb52420e5e053d06c050a5e9a" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "c3d979c76e1b0f6de053d06c050a6730" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDB" has 2 instance(s).
  Instance "ALBERTCDB2", status UNKNOWN, has 1 handler(s) for this service...
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDBXDB" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDB_CFG" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDB_dgmgrl" has 1 instance(s).
  Instance "ALBERTCDB2", status UNKNOWN, has 1 handler(s) for this service...
Service "pdb113a" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "pdb9a" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
The command completed successfully

正常切换PDB:
SQL> alter session set container=PDB9A;

Session altered.

SQL> alter session set container=PDB113A;

Session altered.

修改SERVICE_NAMES参数,添加ALBERT的应用SERVICE:
SQL> show parameter service

NAME                                 TYPE                   VALUE
------------------------------------ ---------------------- ------------------------------
service_names                        string                 ALBERTCDB

SQL> alter system set service_names='ALBERTCDB,albert';

System altered.

SQL>
SQL>
SQL> show parameter service

NAME                                 TYPE                   VALUE
------------------------------------ ---------------------- ------------------------------
service_names                        string                 ALBERTCDB,albert

修改完毕后,可以看到监听中PDB默认的SERVICE已经不见了:
Services Summary...
Service "+ASM" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_ARC" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_DATA" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_MGMT" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_OCR" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_REDO" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "+ASM_DG_VOTE" has 1 instance(s).
  Instance "+ASM2", status READY, has 1 handler(s) for this service...
Service "albert" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDB" has 2 instance(s).
  Instance "ALBERTCDB2", status UNKNOWN, has 1 handler(s) for this service...
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDBXDB" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDB_CFG" has 1 instance(s).
  Instance "ALBERTCDB2", status READY, has 1 handler(s) for this service...
Service "ALBERTCDB_dgmgrl" has 1 instance(s).
  Instance "ALBERTCDB2", status UNKNOWN, has 1 handler(s) for this service...
The command completed successfully

并且CDB中是无法切换PDB的:
SQL> alter session set container=PDB9A;
ERROR:
ORA-44787: Service cannot be switched into.


SQL> alter session set container=PDB113A;
ERROR:
ORA-44787: Service cannot be switched into.

修复方式为:
将SERVICE_NAMES中将SERVICE取出,并且重启CDB

此时需要重启CDB
SQL> 
SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area 1.3100E+11 bytes
Fixed Size                 23312360 bytes
Variable Size            3.3286E+10 bytes
Database Buffers         9.7442E+10 bytes
Redo Buffers              245121024 bytes
Database mounted.
Database opened.

SQL> alter session set container=PDB9A;

Session altered.

SQL> alter session set container=PDB113A;

Session altered.

Top N需求SQL优化提升案例

前几日,朋友发来微信,测试系统中抓到一条即将上线的SQL,严重消耗数据库资源,SQL执行计划如下:

SELECT DT,TI,ST CONT,ANCT,PIID,CID FROM 
       (SELECT A.ID,a.INFO, 
             TO_CHAR(A.DT,'YYYY')||'年'||TO_CHAR(A.DT,'MM')||'月'||TO_CHAR(A.DT,'DD')||'日' AS DT,
             A.TI,
             A.MED,
             A.AT,
             B.ID AS CONT_ID,  
             to_char(SUBSTR(regexp_REPLACE(B.CONT, '\s',''),1,100)) AS ST, 
             E.ANNT,
             E.ID PIID,
             ROW_NUMBER() OVER(ORDER BY A.DT DESC,A.ID DESC)AS RN    
         FROM NWBAS A
         JOIN BASTXT B ON A.ID = B.OID
         JOIN NWSANN E ON A.ID=E.OID
       WHERE  EXISTS(SELECT 1 FROM NWSTYP C WHERE A.ID = C.ORID AND SUBSTR(C.code,1,2) in(11,12,13))        
              and a.PIC=1
       order by A.dt DESC
       )WHERE RN <=4;
---------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name            | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
---------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                 |      1 |        | 36016 (100)|          |      4 |00:00:04.52 |     267K|  74660 |
|*  1 |  VIEW                          |                 |      1 |   5237 | 36016   (1)| 00:07:13 |      4 |00:00:04.52 |     267K|  74660 |
|*  2 |   WINDOW SORT PUSHED RANK      |                 |      1 |   5237 | 36016   (1)| 00:07:13 |      5 |00:00:04.51 |     266K|  74660 |
|   3 |    NESTED LOOPS                |                 |      1 |   5237 | 36016   (1)| 00:07:13 |  67739 |00:00:04.38 |     266K|  74660 |
|   4 |     NESTED LOOPS               |                 |      1 |   5237 | 36016   (1)| 00:07:13 |  67739 |00:00:03.88 |     198K|  74660 |
|*  5 |      HASH JOIN                 |                 |      1 |   5237 | 27234   (1)| 00:05:27 |  67741 |00:00:03.59 |   93944 |  74660 |
|*  6 |       HASH JOIN RIGHT SEMI     |                 |      1 |  71164 | 25527   (1)| 00:05:07 |  68836 |00:00:03.36 |   91427 |  74660 |
|*  7 |        INDEX FAST FULL SCAN    | NWSTYP          |      1 |  71211 |  4120   (2)| 00:00:50 |    753K|00:00:02.14 |   16744 |      0 |
|*  8 |        TABLE ACCESS FULL       | NWSBAS          |      1 |   1281K| 21403   (1)| 00:04:17 |    102K|00:00:00.78 |   74683 |  74660 |
|   9 |       TABLE ACCESS FULL        | NWSANN          |      1 |  94294 |   653   (1)| 00:00:08 |  97456 |00:00:00.09 |    2517 |      0 |
|* 10 |      INDEX UNIQUE SCAN         | BASTXT          |  67741 |      1 |     1   (0)| 00:00:01 |  67739 |00:00:00.26 |     104K|      0 |
|  11 |     TABLE ACCESS BY INDEX ROWID| BASTXT          |  67739 |      1 |     2   (0)| 00:00:01 |  67739 |00:00:00.48 |   67813 |      0 |
---------------------------------------------------------------------------------------------------------------------------------------------

问题SQL单次消耗需要267K的逻辑读,大致需要4秒左右执行完成,并且执行计划中多数步骤中评估行数与实际返回行数严重不符,ID=10、11两步NESTED LOOP BASTXT表被驱动6万多次,效率低下。但是此SQL的逻辑是利用分析函数 ROW_NUMBER() OVER(ORDER BY A.DT DESC,A.ID DESC) 排序后,最终取4行而已,那么其实就是一个取Top N的SQL,可以将SQL改写为如下形式:

 SELECT created,object_name,owner,namespace FROM
       (SELECT /*+ INDEX_DESC(A t1_idx01) use_nl(A) use_nl(B) use_nl(C) use_nl(E) leading(A C B E)*/  A.object_id,
             A.object_name,
             a.CREATED,
             A.owner,
             B.object_id AS CONT_ID,
             E.namespace,
             E.OBJECT_ID PICTURE_ID
         FROM T1 A
         JOIN T2 B ON A.object_id = B.object_id
         JOIN T3 E ON A.object_id=E.object_id
        JOIN (SELECT DISTINCT D.OBJECT_ID FROM T4 D WHERE D.namespace in(29,30)) C on A.OBJECT_ID=C.OBJECT_ID
              where A.TEMPORARY='N'
       ORDER BY A.CREATED DESC,A.object_id DESC,A.LAST_DDL_TIME DESC --依照原SQL逻辑 order by A.LAST_DDL_TIME DESC其实可以去掉,此处加order by没有意义
       ) WHERE rownum <=4;
create index t1_idx01 on t1(TEMPORARY,CREATED,object_id,LAST_DDL_TIME,0);
create index t2_idx02 on t2(object_id,0);
create index t3_idx03 on t3(object_id,0);
create index t4_idx01 on t4(object_id,namespace,0);
利用索引有序特性,因SQL选择性很差,大部分记录都满足SQL关联条件,理想中的执行计划利用INDEX RANGE SCAN DESCENDING降序扫描,扫描少数记录后便满足需求停止扫描 count stop by key
-----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name     | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |          |      1 |        |    33 (100)|          |      4 |00:00:00.01 |     344 |      7 |
|*  1 |  COUNT STOPKEY                    |          |      1 |        |            |          |      4 |00:00:00.01 |     344 |      7 |
|   2 |   VIEW                            |          |      1 |      5 |    33   (0)| 00:00:01 |      4 |00:00:00.01 |     344 |      7 |
|   3 |    NESTED LOOPS SEMI              |          |      1 |      5 |    33   (0)| 00:00:01 |      4 |00:00:00.01 |     344 |      7 |
|   4 |     NESTED LOOPS                  |          |      1 |      5 |    23   (0)| 00:00:01 |   1056 |00:00:00.01 |     331 |      4 |
|   5 |      NESTED LOOPS                 |          |      1 |      6 |    12   (0)| 00:00:01 |   1057 |00:00:00.01 |     170 |      0 |
|   6 |       TABLE ACCESS BY INDEX ROWID | T1       |      1 |      8 |     4   (0)| 00:00:01 |   1163 |00:00:00.01 |      88 |      0 |
|*  7 |        INDEX RANGE SCAN DESCENDING| T1_IDX01 |      1 |      8 |     3   (0)| 00:00:01 |   1163 |00:00:00.01 |      10 |      0 |
|*  8 |       INDEX RANGE SCAN            | T2_IDX02 |   1163 |      1 |     1   (0)| 00:00:01 |   1057 |00:00:00.01 |      82 |      0 |
|   9 |      TABLE ACCESS BY INDEX ROWID  | T3       |   1057 |      1 |     2   (0)| 00:00:01 |   1056 |00:00:00.01 |     161 |      4 |
|* 10 |       INDEX RANGE SCAN            | T3_IDX03 |   1057 |      1 |     1   (0)| 00:00:01 |   1056 |00:00:00.01 |      88 |      4 |
|  11 |     VIEW PUSHED PREDICATE         |          |   1056 |      2 |     2   (0)| 00:00:01 |      4 |00:00:00.01 |      13 |      3 |
|* 12 |      INDEX RANGE SCAN             | T4_IDX01 |   1056 |      2 |     2   (0)| 00:00:01 |      4 |00:00:00.01 |      13 |      3 |
-----------------------------------------------------------------------------------------------------------------------------------------

目标SQL优化后执行计划如下,单次执行只需要2000多个buffer,执行时间只需要几个毫秒即可

--------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name               | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
--------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |                    |      1 |        |   228 (100)|          |      4 |00:00:00.05 |    2905 |    780 |
|*  1 |  COUNT STOPKEY                   |                    |      1 |        |            |          |      4 |00:00:00.05 |    2905 |    780 |
|   2 |   VIEW                           |                    |      1 |      4 |   228   (0)| 00:00:03 |      4 |00:00:00.05 |    2905 |    780 |
|   3 |    NESTED LOOPS SEMI             |                    |      1 |      4 |   228   (0)| 00:00:03 |      4 |00:00:00.04 |    1631 |      0 |
|   4 |     NESTED LOOPS                 |                    |      1 |      4 |   216   (0)| 00:00:03 |      8 |00:00:00.04 |    1616 |      0 |
|   5 |      NESTED LOOPS                |                    |      1 |     55 |   104   (0)| 00:00:02 |      8 |00:00:00.04 |    1595 |      0 |
|   6 |       TABLE ACCESS BY INDEX ROWID| NWSBAS             |      1 |   1282K|    12   (0)| 00:00:01 |      8 |00:00:00.04 |    1571 |      0 |
|*  7 |        INDEX FULL SCAN DESCENDING| IDX_NWSBAS_01      |      1 |     64 |     3   (0)| 00:00:01 |      8 |00:00:00.04 |    1566 |      0 |
|   8 |       TABLE ACCESS BY INDEX ROWID| BASTXT             |      8 |      1 |     2   (0)| 00:00:01 |      8 |00:00:00.01 |      24 |      0 |
|*  9 |        INDEX UNIQUE SCAN         | BASTXT             |      8 |      1 |     1   (0)| 00:00:01 |      8 |00:00:00.01 |      16 |      0 |
|  10 |      TABLE ACCESS BY INDEX ROWID | NWSANN             |      8 |      1 |     3   (0)| 00:00:01 |      8 |00:00:00.01 |      21 |      0 |
|* 11 |       INDEX RANGE SCAN           | NWSANN             |      8 |      1 |     2   (0)| 00:00:01 |      8 |00:00:00.01 |      17 |      0 |
|  12 |     VIEW PUSHED PREDICATE        |                    |      8 |      1 |     3   (0)| 00:00:01 |      4 |00:00:00.01 |      15 |      0 |
|* 13 |      INDEX RANGE SCAN            | NWSTYP             |      8 |      1 |     3   (0)| 00:00:01 |      4 |00:00:00.01 |      15 |      0 |
--------------------------------------------------------------------------------------------------------------------------------------------------

SQL中or操作借助改写提升效率案例一则

昨日,朋友发来一则SQL询问有没有什么优化思路,并反馈给我Oracle 的STA给出的SQL”优化”建议是加并行操作提升SQL响应时间,SQL 脱敏后TEXT与执行计划如下:

SELECT A.ID,
       C.ANN AS FILENAME,
       B.CNT AS CONT,
       A.TT,
       A.INFO,
       A.U_TIME AS PUB_DT
FROM A
LEFT JOIN  B ON A.ID = B.O_ID
AND B.CNT IS NOT NULL
LEFT JOIN  C ON C.O_ID = A.ID
WHERE A.U_TIME > NVL(TO_DATE(:1 , 'yyyy-MM-dd HH24:mi:ss'), DATE '2015-01-01')
  OR B.U_TIME > NVL(TO_DATE(:2 , 'yyyy-MM-dd HH24:mi:ss'), DATE '2015-01-01')

-------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name            | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
-------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                 |      1 |        |   337K(100)|          |   6187 |00:00:47.88 |     670K|    636K|
|   1 |  NESTED LOOPS OUTER          |                 |      1 |     48 |   337K  (1)| 01:07:29 |   6187 |00:00:47.88 |     670K|    636K|
|*  2 |   FILTER                     |                 |      1 |        |            |          |   6187 |00:00:47.61 |     641K|    636K|
|*  3 |    HASH JOIN OUTER           |                 |      1 |     48 |   337K  (1)| 01:07:27 |   5594K|00:00:46.87 |     641K|    636K|
|   4 |     TABLE ACCESS FULL        | A               |      1 |   5442K| 52131   (1)| 00:10:26 |   5592K|00:00:06.88 |     200K|    200K|
|*  5 |     TABLE ACCESS FULL        | B               |      1 |   2442K|   142K  (1)| 00:28:36 |   2460K|00:00:24.05 |     441K|    436K|
|   6 |   TABLE ACCESS BY INDEX ROWID| C               |   6187 |      1 |     3   (0)| 00:00:01 |   5657 |00:00:00.25 |   29121 |     0 |
|*  7 |    INDEX RANGE SCAN          | C               |   6187 |      1 |     2   (0)| 00:00:01 |   5657 |00:00:00.18 |   23463 |     0 |
-------------------------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   2 - filter(("A"."U_TIME">TO_DATE(' 2021-03-17 13:38:11', 'syyyy-mm-dd hh24:mi:ss') OR "B"."U_TIME">TO_DATE('2021-03-17
              13:38:11', 'syyyy-mm-dd hh24:mi:ss')))
   3 - access("A"."ID"="B"."O_ID")
   5 - filter("B"."CNT" IS NOT NULL)
   7 - access("C"."O_ID"="A"."ID")

从真实的执行计划中看到最终反馈6188行记录,并且资源消耗(buffer gets和reads)高达600K+,这个资源消耗,SQL执行了47s并不奇怪。SQL逻辑并不复杂,并且SQL中存在or的操作,并且朋友反馈如果传值为空可以不用考虑,这种情况基本不会出现,并且经过确认Utime字段上存在索引的,那么我们可以考虑将此SQL进行拆分,同时考虑到or的每一个步骤都返回行数不大的情况下,用到索引,将or改写成union all+lnnvl的形式:

SELECT /*+        gather_plan_statistics  */ A.ID,
                                             C.ANN AS FILENAME,
                                             B.CNT AS CONT,
                                             A.TT,
                                             A.INFO,
                                             A.U_TIME AS PUB_DT
FROM A
LEFT JOIN B ON A.ID = B.O_ID
AND B.CNT IS NOT NULL
LEFT JOIN C ON C.O_ID = A.ID
WHERE A.U_TIME > NVL(TO_DATE('2021-03-17 13:38:11' , 'yyyy-MM-dd HH24:mi:ss'), DATE'2015-01-01')
UNION ALL
SELECT A.ID,
       C.ANN AS FILENAME,
       B.CNT AS CONT,
       A.TT,
       A.INFO,
       A.U_TIME AS PUB_DT
FROM A
LEFT JOIN B ON A.ID = B.O_ID
AND B.CNT IS NOT NULL
LEFT JOIN C ON C.O_ID = A.ID
WHERE B.U_TIME > NVL(TO_DATE('2021-03-17 13:38:11', 'yyyy-MM-dd HH24:mi:ss'), DATE '2015-01-01')
  AND LNNVL(A.U_TIME > NVL(TO_DATE('2021-03-17 13:38:11' , 'yyyy-MM-dd HH24:mi:ss'), DATE'2015-01-01'));

-------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name                | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads |
-------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                     |      1 |        |   170 (100)|          |   6187 |00:00:00.75 | 66639 |      2 |
|   1 |  UNION-ALL                     |                     |      1 |        |            |          |   6187 |00:00:00.75 | 66639 |      2 |
|   2 |   NESTED LOOPS OUTER           |                     |      1 |     17 |    94   (0)| 00:00:02 |   5253 |00:00:00.55 | 45122 |      2 |
|   3 |    NESTED LOOPS OUTER          |                     |      1 |     17 |    48   (0)| 00:00:01 |   5253 |00:00:00.33 | 27337 |      2 |
|   4 |     TABLE ACCESS BY INDEX ROWID| A                   |      1 |     17 |     6   (0)| 00:00:01 |   5253 |00:00:00.09 | 10508 |      0 |
|*  5 |      INDEX RANGE SCAN          | A_UPD               |      1 |     17 |     3   (0)| 00:00:01 |   5253 |00:00:00.05 |  5255 |      0 |
|*  6 |     TABLE ACCESS BY INDEX ROWID| B                   |   5253 |      1 |     3   (0)| 00:00:01 |   4749 |00:00:00.23 | 16829 |      2 |
|*  7 |      INDEX RANGE SCAN          | B_TXT               |   5253 |      1 |     2   (0)| 00:00:01 |   4749 |00:00:00.12 | 12079 |      1 |
|   8 |    TABLE ACCESS BY INDEX ROWID | C                   |   5253 |      1 |     3   (0)| 00:00:01 |   4798 |00:00:00.20 | 17785 |      0 |
|*  9 |     INDEX RANGE SCAN           | C                   |   5253 |      1 |     2   (0)| 00:00:01 |   4798 |00:00:00.13 | 12987 |      0 |
|  10 |   NESTED LOOPS OUTER           |                     |      1 |     14 |    75   (0)| 00:00:01 |    934 |00:00:00.15 | 21517 |      0 |
|  11 |    NESTED LOOPS                |                     |      1 |     14 |    37   (0)| 00:00:01 |    934 |00:00:00.09 | 17148 |      0 |
|* 12 |     TABLE ACCESS BY INDEX ROWID| B                   |      1 |     14 |     9   (0)| 00:00:01 |   5591 |00:00:00.04 |  3535 |      0 |
|* 13 |      INDEX RANGE SCAN          | B_UPD               |      1 |     14 |     3   (0)| 00:00:01 |   5591 |00:00:00.01 |   978 |      0 |
|* 14 |     TABLE ACCESS BY INDEX ROWID| A                   |   5591 |      1 |     2   (0)| 00:00:01 |    934 |00:00:00.05 | 13613 |      0 |
|* 15 |      INDEX UNIQUE SCAN         | PK_A                |   5591 |      1 |     1   (0)| 00:00:01 |   5590 |00:00:00.03 |  8023 |      0 |
|  16 |    TABLE ACCESS BY INDEX ROWID | C                   |    934 |      1 |     3   (0)| 00:00:01 |    859 |00:00:00.05 |  4369 |      0 |
|* 17 |     INDEX RANGE SCAN           | C                   |    934 |      1 |     2   (0)| 00:00:01 |    859 |00:00:00.04 |  3510 |      0 |
-------------------------------------------------------------------------------------------------------------------------------------------------

恰好被驱动的表连接列中均有索引,经过优化后SQL,并且带入多个变量测试,耗时效率不到1秒。

SQL优化,写法很关键

近期听到一位Oracle业界前辈,说道:”SQL优化,关键在写法”。我在生产过程中碰到的SQL问题,因为写法有误造成SQL产生严重的性能问题非常多,开发人员可能更关心我的代码功能是否实现,SQL上线前因测试系统环境、数据量与生产存在差异,导致SQL在生产上实际运行时效率远远小于预期,前几天,碰到如下这个SQL案例,个人感觉非常典型,SQL写法很关键!

SELECT count(*)
FROM pnrresultdata
WHERE TO_NUMBER(SYSDATE - CREATEtime)* 86400 > 5*60
  AND TO_NUMBER(SYSDATE - CREATEtime)* 86400 < 4*60*60
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

SQL逻辑很简单,只是单纯输出一下符合条件的count(*),资源消耗如下图所示

然而,表中CREATETIME字段选择性很好,NUM_ROWS:64186660 NDV:2497536,此字段上没有索引,但是因为写法问题,常规组合索引中包含此字段也没有办法利用上索引,非常常见的原因:字段上参与了运算。

将SQL等价改写为:

SELECT count(*)
FROM pnrresultdata
WHERE CREATETIME < SYSDATE - interval '5' MINUTE
  AND CREATETIME > SYSDATE - interval '4' hour
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

原SQL执行计划,采用了ISSUCCESS列上的低效索引:

-------------------------------------
SQL_ID  76d58v13x8z90, child number 0
-------------------------------------
SELECT count(*)
FROM pnrresultdata
WHERE TO_NUMBER(SYSDATE - CREATEtime)* 86400 > 5*60
  AND TO_NUMBER(SYSDATE - CREATEtime)* 86400 < 4*60*60
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

Plan hash value: 3822156680

-----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name                    | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                         |      1 |        |       | 14814 (100)|          |      1 |00:00:01.03 |     296K|   4761 |
|   1 |  SORT AGGREGATE              |                         |      1 |      1 |    26 |            |          |      1 |00:00:01.03 |     296K|   4761 |
|*  2 |   TABLE ACCESS BY INDEX ROWID| PNRRESULTDATA           |      1 |      1 |    26 | 14814   (1)| 00:02:58 |    429 |00:00:01.03 |     296K|   4761 |
|*  3 |    INDEX RANGE SCAN          | PNRRESULTDATA_ISSUCCESS |      1 |    452K|       |  2765   (1)| 00:00:34 |    413K|00:00:00.06 |    2949 |     34 |
-----------------------------------------------------------------------------------------------------------------------------------------------------------

2 - filter(("USERNAME"='baosheng_dps' AND "POSTTYPE"='R' AND TO_NUMBER(SYSDATE@!-"CREATETIME")*86400>300 AND
              TO_NUMBER(SYSDATE@!-"CREATETIME")*86400<14400 AND "GETTIME">0))
   3 - access("ISSUCCESS"=0)

改写后,因其他字段缺失索引,目前状态仍不为最佳,同时出现了BITMAP CONVERSION

-------------------------------------
SQL_ID  00xz7m7u33wgg, child number 1
-------------------------------------
SELECT count(*)
FROM pnrresultdata
WHERE CREATETIME < SYSDATE - interval '5' MINUTE
  AND CREATETIME > SYSDATE - interval '4' hour
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

Plan hash value: 2537524006

------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name                     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                          |      1 |        |       |  9313 (100)|          |      1 |00:00:00.23 |    4339 |   1531 |
|   1 |  SORT AGGREGATE                    |                          |      1 |      1 |    26 |            |          |      1 |00:00:00.23 |    4339 |   1531 |
|*  2 |   FILTER                           |                          |      1 |        |       |            |          |    429 |00:00:00.23 |    4339 |   1531 |
|*  3 |    TABLE ACCESS BY INDEX ROWID     | PNRRESULTDATA            |      1 |    429 | 11154 |  9313   (1)| 00:01:52 |    429 |00:00:00.23 |    4339 |   1531 |
|   4 |     BITMAP CONVERSION TO ROWIDS    |                          |      1 |        |       |            |          |   1164 |00:00:00.23 |    3477 |   1531 |
|   5 |      BITMAP AND                    |                          |      1 |        |       |            |          |      1 |00:00:00.23 |    3477 |   1531 |
|   6 |       BITMAP CONVERSION FROM ROWIDS|                          |      1 |        |       |            |          |      6 |00:00:00.06 |    1937 |      0 |
|*  7 |        INDEX RANGE SCAN            | PNRRESULTDATA_ISSUCCESS  |      1 |    452K|       |  2765   (1)| 00:00:34 |    288K|00:00:00.03 |    1937 |      0 |
|   8 |       BITMAP CONVERSION FROM ROWIDS|                          |      1 |        |       |            |          |      2 |00:00:00.17 |    1540 |   1531 |
|   9 |        SORT ORDER BY               |                          |      1 |        |       |            |          |    177K|00:00:00.16 |    1540 |   1531 |
|* 10 |         INDEX RANGE SCAN           | PNRRESULTDATA_CREATETIME |      1 |    452K|       |  1593   (1)| 00:00:20 |    177K|00:00:00.10 |    1540 |   1531 |
------------------------------------------------------------------------------------------------------------------------------------------------------------------

结合字段的选择性与在索引中的过滤必要,需要创建:

create index t1_idx01 on t1(username,postType,isSuccess,CREATEtime) &tablespace parallel ∥

MRP0进程Hung?

前天晚上,同事发来微信求助,监控到一套2节点数据库RAC 数据库主备库同步状态异常,并且同事经过分析发现造成此问题的是因为Dataguard MRP0进程存在,但是停止在某一个seqence#上,应用的sequnce#与block不进行恢复。

随即登录备库数据库查看同步状态,发现MRP0进程停滞在sequnce:197788与block:186030上,实际上并没有进行“APPLYING_LOG”。

SQL> set linesize 200
select process,status,client_process,thread#,sequence#,block#,active_agents,known_agents from gv$managed_standby where process in ('LNS','RFS','MRP0') and  THREAD# <> 0
SQL>   2  ;

PROCESS   STATUS       CLIENT_P    THREAD#  SEQUENCE#     BLOCK# ACTIVE_AGENTS KNOWN_AGENTS
--------- ------------ -------- ---------- ---------- ---------- ------------- ------------
RFS       IDLE         LGWR              1     199217     123144             0            0
RFS       IDLE         LGWR              2     142409      77956             0            0
MRP0      APPLYING_LOG N/A               1     197788     186030             9            9

此日志197788归档日志文件存在与备库,并且同事反馈尝试alter database register logfile、主库RMAN重新恢复此197788归档日志,均无效。

查询v$archived_log确认197788这个归档文件为20210109 15:00左右主库产生的,分别查看一下主库/备库的alert日志,看看那时数据库有无异常情况发生:

节点1,传输至备时出现异常:
Thread 1 advanced to log sequence 197788 (LGWR switch)
  Current log# 5 seq# 197788 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_5.287.1003922183
  Current log# 5 seq# 197788 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_5.286.1003922183
Sat Jan 09 15:32:25 2021
Archived Log entry 275332 added for thread 1 sequence 197787 ID 0x9c755e67 dest 1:
Sat Jan 09 15:32:25 2021
ARCj: Standby redo logfile selected for thread 1 sequence 197787 for destination LOG_ARCHIVE_DEST_2
Sat Jan 09 15:33:14 2021
LNS: Standby redo logfile selected for thread 1 sequence 197788 for destination LOG_ARCHIVE_DEST_2
Sat Jan 09 15:43:17 2021
Thread 1 advanced to log sequence 197789 (LGWR switch)
  Current log# 1 seq# 197789 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_1.295.1003922179
  Current log# 1 seq# 197789 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_1.294.1003922179
Sat Jan 09 15:43:17 2021
Archived Log entry 275335 added for thread 1 sequence 197788 ID 0x9c755e67 dest 1:
Sat Jan 09 15:47:06 2021
WARN: ARC1: Terminating pid 4047 hung on an I/O operation
Killing 1 processes with pids 4047 (Process by index) in order to remove hung processes. Requested by OS process 31580 on instance 1
ARC1: Error 16198 due to hung I/O operation to LOG_ARCHIVE_DEST_2
ARCo: Standby redo logfile selected for thread 1 sequence 197788 for destination LOG_ARCHIVE_DEST_2

节点2,传输至备库时出现异常:
Sat Jan 09 15:47:15 2021
Archived Log entry 275337 added for thread 2 sequence 141662 ID 0x9c755e67 dest 1:
Sat Jan 09 15:47:35 2021
WARN: ARC2: Terminating pid 27590 hung on an I/O operation
Killing 1 processes with pids 27590 (Process by index) in order to remove hung processes. Requested by OS process 27465 on instance 2
ARC2: Error 16198 due to hung I/O operation to LOG_ARCHIVE_DEST_2
Sat Jan 09 15:47:37 2021
NSA2 started with pid=29, OS id=2625
Sat Jan 09 15:47:42 2021


备库节点:
Archived Log entry 77427 added for thread 1 sequence 197786 ID 0x9c755e67 dest 1:
Media Recovery Log /oracle/archive_Travelskydba/Travelskydba/2_141661_853598219.arc
Media Recovery Waiting for thread 2 sequence 141662 (in transit)
Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937
Media Recovery Waiting for thread 1 sequence 197788 (in transit)
Recovery of Online Redo Log: Thread 1 Group 7 Seq 197788 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_7.282.1003923169
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_7.280.1003923169

备库节点在1月9日 16:24:31时已经应用完成197788日志
Sat Jan 09 16:24:31 2021
Media Recovery Log /oracle/archive_Travelskydba/Travelskydba/1_197788_853598219.arc

197788这个日志已经应用完毕,并且197789日志也完好的存在与备库节点 ,那么很有可能目前备库MRP0进程不工作的原因是在等其他日志应用完毕,。备库应用日志需要连续,那么是否有可能其他节点或本节点的其他日志?

我们可以利用主库如下sql查询进行确认:

SQL> SELECT FIRST_CHANGE#,
       THREAD#,
       DEST_ID,
       STATUS,
       FAL,
       APPLIED,
       DELETED,
       to_char(FIRST_TIME,'yyyymmdd hh24:mi:ss') FIRST_TIME,
       to_char(COMPLETION_TIME,'yyyymmdd hh24:mi:ss') COMPLETION_TIME,
       sequence#
FROM v$archived_log
WHERE to_char(COMPLETION_TIME,'yyyymmdd hh24:mi:ss') BETWEEN '20210109 15:00:17' AND '20210109 16:00:17'  order by 1,5  2    3    4    5    6    7    8    9   10   11   12  ;

   FIRST_CHANGE#          THREAD#          DEST_ID S FAL APPLIED   DEL FIRST_TIME        COMPLETION_TIME          SEQUENCE#
---------------- ---------------- ---------------- - --- --------- --- ----------------- ----------------- ----------------
   9555246783243                2                2 A NO  YES       NO  20210109 14:32:30 20210109 15:04:31           141659
   9555246783243                2                1 D NO  NO        YES 20210109 14:32:30 20210109 15:04:32           141659
   9555247407959                1                1 D NO  NO        YES 20210109 14:54:15 20210109 15:04:31           197783
   9555247407959                1                2 A NO  YES       NO  20210109 14:54:15 20210109 15:04:31           197783
   9555247700807                1                2 A NO  YES       NO  20210109 15:04:30 20210109 15:15:10           197784
   9555247700807                1                1 D NO  NO        YES 20210109 15:04:30 20210109 15:15:10           197784
   9555247701783                2                2 A NO  YES       NO  20210109 15:04:31 20210109 15:32:20           141660
   9555247701783                2                1 D NO  NO        YES 20210109 15:04:31 20210109 15:32:21           141660
   9555248017764                1                1 D NO  NO        YES 20210109 15:15:10 20210109 15:25:40           197785
   9555248017764                1                2 A NO  YES       NO  20210109 15:15:10 20210109 15:25:40           197785
   9555248313954                1                2 A NO  YES       NO  20210109 15:25:40 20210109 15:33:14           197786
   9555248313954                1                1 D NO  NO        YES 20210109 15:25:40 20210109 15:32:19           197786
   9555248508993                1                1 D NO  NO        YES 20210109 15:32:19 20210109 15:32:25           197787
   9555248508993                1                2 A YES YES       NO  20210109 15:32:19 20210109 15:32:26           197787
   9555248509181                2                1 D NO  NO        YES 20210109 15:32:20 20210109 15:32:23           141661
   9555248509181                2                2 A NO  YES       NO  20210109 15:32:20 20210109 15:32:23           141661
   9555248510236                2                1 D NO  NO        YES 20210109 15:32:23 20210109 15:47:15           141662
   9555248510774                1                1 D NO  NO        YES 20210109 15:32:25 20210109 15:43:17           197788
   9555248831803                1                1 D NO  NO        YES 20210109 15:43:17 20210109 15:47:14           197789
   9555248831803                1                2 A YES NO        NO  20210109 15:43:17 20210109 15:52:30           197789
   9555248943929                1                1 D NO  NO        YES 20210109 15:47:14 20210109 15:52:14           197790
   9555248944032                2                1 D NO  NO        YES 20210109 15:47:15 20210109 15:47:42           141663
   9555248944032                2                2 A YES NO        NO  20210109 15:47:15 20210109 15:53:18           141663
   9555248950448                2                1 D NO  NO        YES 20210109 15:47:42 20210109 15:53:18           141664
   9555248950448                2                2 A YES NO        NO  20210109 15:47:42 20210109 15:55:13           141664

25 rows selected.

上述查询确认后,每个sequence应当归档到dest_id=1(本地),dest_id=2(备库),但是发现thread 2的141662,未显示归档到DEST_ID=2,并且下一个日志便是197788
Media Recovery Log /oracle/archive_Travelskydba/Travelskydba/2_141661_853598219.arc
Media Recovery Waiting for thread 2 sequence 141662 (in transit)
Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937
Media Recovery Waiting for thread 1 sequence 197788 (in transit)
Recovery of Online Redo Log: Thread 1 Group 7 Seq 197788 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_7.282.1003923169
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_7.280.1003923169
Sat Jan 09 15:49:02 2021
RFS[31]: Possible network disconnect with primary database
后续,备库一值在读取141662这个日志文件,但

Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937

Mon Jan 18 20:42:42 2021
Managed Standby Recovery starting Real Time Apply
Parallel Media Recovery started with 8 slaves
Waiting for all non-current ORLs to be archived...
All non-current ORLs have been archived.
Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937

此时,主库141662这个归档认为已经传输到备库并且已经删除,但备库实际并未接收到。Threa#1 的197788无法应用的根因为Thread# 2 归档141662并未应用。

让同事将141662归档从主库归档备份中恢复出来 ,拷贝至备库注册或等待备库(fal_client)从主库(fal_server)中获取。同事恢复此归档文件后,备库MRP0进程立即开始工作,进行正常的日志应用,同时主库的v$archived_log中的日志记录变成了复合预期的状态:

SQL> SELECT FIRST_CHANGE#,
       THREAD#,
       DEST_ID,
       STATUS,
       FAL,
       APPLIED,
       DELETED,
       to_char(FIRST_TIME,'yyyymmdd hh24:mi:ss') FIRST_TIME,
       to_char(COMPLETION_TIME,'yyyymmdd hh24:mi:ss') COMPLETION_TIME,
       sequence#
FROM v$archived_log
WHERE sequence#=141662  2    3    4    5    6    7    8    9   10   11   12  ;

   FIRST_CHANGE#          THREAD#          DEST_ID S FAL APPLIED   DEL FIRST_TIME        COMPLETION_TIME          SEQUENCE#
---------------- ---------------- ---------------- - --- --------- --- ----------------- ----------------- ----------------
   9555248510236                2                1 D NO  NO        YES 20210109 15:32:23 20210109 15:47:15           141662
   9555248510236                2                1 A NO  NO        NO  20210109 15:32:23 20210118 21:39:53           141662
   9555248510236                2                2 A YES YES       NO  20210109 15:32:23 20210118 21:40:33           141662

利用sysmetric_history与dba_hist_event_histogram定位IO性能问题

近期发现,公司生产4套数据库从12月9日起,每周三22:00-22:30时间段均有应用事务DML缓慢的现象,IO等待事件明显增多:

IO等待类事件明显均有显著抬头的现象,例如log file sync等,但是我们如何定位是否真正的数据库IO真正出现问题?是因还是果?是否是io requeset变多还是IO真正出现问题?

问题时间段的AWR:

AWR中的Avg Wait极有可能被平均
另外一套库的显示的较为直观,log file sync平均等待高达17ms之多

换一个角度,我们从Oracle提供的数据库内部的v$metric_history与dba_hist_sysmetric_history动态视图中可以从“ Average Synchronous Single-Block Read Latency、I/O Megabytes per Second、I/O Requests per Second”等指标中辅助定位:

select to_char(end_time, 'yyyymmdd hh24:mi:ss') as time,
       max(case
             when metric_name = 'Average Synchronous Single-Block Read Latency' then
              round(value,2)
             else null
           end) as "Single Block Read Latency",
       max(case
             when metric_name = 'I/O Megabytes per Second' then
              round(value,2)
             else null
           end) as "IO Megabytes per Second",
       max(case
             when metric_name = 'I/O Requests per Second' then
              round(value,2)
             else null
           end) as "I/O Requests per Second"
  from dba_hist_sysmetric_history where instance_number=1 and to_char(end_time, 'yyyymmdd hh24:mi:ss') between '20210106 22:00:00' and '20210106 23:00:00'
 group by to_char(end_time, 'yyyymmdd hh24:mi:ss') order by 1

TIME              Single Block Read Latency IO Megabytes per Second I/O Requests per Second
----------------- ------------------------- ----------------------- -----------------------
20210106 21:00:44                      1.75                   23.69                 2060.17
20210106 21:01:44                       2.1                   13.32                 1474.73
20210106 21:02:43                      1.99                    18.6                 1716.56
20210106 21:03:43                      1.43                   11.54                 1089.31
20210106 21:04:43                      1.69                   20.77                 1567.28
20210106 21:05:43                      1.61                   17.92                 1806.92
20210106 21:06:44                      2.21                   27.95                 2466.91
20210106 21:07:44                      1.63                   11.29                 1052.18
20210106 21:08:44                      2.01                   17.23                 1729.85
20210106 21:09:43                      1.63                   12.53                  1309.2
20210106 21:10:43                      1.36                   15.53                 1180.81
20210106 21:11:43                      2.57                   12.97                 1399.38
20210106 21:12:43                      1.42                   16.71                 1323.95
20210106 21:13:44                      1.65                   10.37                 1367.22
20210106 21:14:44                      1.42                   20.49                    1493
20210106 21:15:44                      1.66                    8.21                 1186.28
20210106 21:16:43                      2.39                   23.23                 2012.56
20210106 21:17:43                       1.3                   11.34                 1219.04
20210106 21:18:43                      1.15                   15.06                 1219.79
20210106 21:19:43                      1.66                       7                 1057.58
20210106 21:20:44                      1.38                   19.74                 1402.93
20210106 21:21:44                      2.59                    7.66                 1086.08
20210106 21:22:44                      1.22                   16.51                 1307.65
20210106 21:23:43                      1.39                   12.68                 1391.17
20210106 21:24:43                      1.43                   15.38                 1255.99
20210106 21:25:43                      1.37                   13.82                 1489.76
20210106 21:26:44                       1.9                   24.64                 2456.92
20210106 21:27:44                      1.49                    7.35                 1232.54
20210106 21:28:44                      1.06                   50.22                  1287.7
20210106 21:29:44                      2.06                   31.16                 1516.66
20210106 21:30:43                      1.21                   67.67                 1750.49
20210106 21:31:43                      2.52                   67.19                  1398.3
20210106 21:32:43                      1.68                   38.94                 1831.17
20210106 21:33:44                      1.46                    9.81                 1366.68
20210106 21:34:44                      1.61                   17.64                 1447.77
20210106 21:35:44                      1.52                   15.25                 1860.36
20210106 21:36:44                      1.61                   26.07                 2350.26
20210106 21:37:43                      2.18                   11.01                 1161.19
20210106 21:38:43                      1.38                   16.08                 1438.71
20210106 21:39:44                      1.56                   10.44                 1005.47
20210106 21:40:44                      1.23                   15.76                 1202.61
20210106 21:41:44                      2.21                    8.56                 1374.73
20210106 21:42:44                      1.71                    19.9                 1298.54
20210106 21:43:44                      1.49                    9.08                 1196.41
20210106 21:44:43                      1.79                   18.07                 1715.96
20210106 21:45:43                      1.86                   11.46                 1055.36
20210106 21:46:44                      1.36                   22.71                  1960.6
20210106 21:47:44                      1.13                    27.1                 1589.31
20210106 21:48:44                      1.39                   18.62                 1142.78
20210106 21:49:44                      1.88                    6.48                  904.06
20210106 21:50:44                      1.22                   20.12                  1420.4
20210106 21:51:43                      1.79                    7.54                 1054.08
20210106 21:52:44                      1.32                   16.79                 1246.04
20210106 21:53:44                       1.5                   12.89                 1509.54
20210106 21:54:44                      1.59                   14.58                  961.99
20210106 21:55:44                      1.75                    8.41                 1114.03
20210106 21:56:44                      1.42                   29.02                 2388.62
20210106 21:57:44                       1.7                    6.22                  815.38
20210106 21:58:43                      1.36                   14.27                 1024.69
20210106 21:59:44                      1.89                   10.66                 1133.77
20210106 22:00:44                      1.02                   52.87                 3232.29
20210106 22:01:44                       .71                   94.45                 4846.43
20210106 22:02:44                      5.28                   83.54                 2627.49
20210106 22:03:44                      7.04                   69.19                 2067.08
20210106 22:04:44                      7.07                   74.68                 2382.61
20210106 22:05:43                      4.87                   79.73                 2654.56
20210106 22:06:44                      5.94                   90.77                 3937.21
20210106 22:07:44                      8.01                   31.11                 1074.18
20210106 22:08:44                      6.16                   26.27                 1639.99
20210106 22:09:44                      2.71                    31.5                 1797.32
20210106 22:10:44                      5.12                   37.47                 1533.45
20210106 22:11:44                      5.04                   62.63                 1520.07
20210106 22:12:44                      3.81                   35.91                 1402.06
20210106 22:13:44                      3.66                   18.25                 1626.73
20210106 22:14:44                      3.01                   61.43                  2179.6
20210106 22:15:44                      2.59                   75.41                 1789.91
20210106 22:16:44                      3.13                    91.9                 2745.88
20210106 22:17:44                      2.97                   86.56                  1798.5
20210106 22:18:45                      2.33                   84.64                 1505.69
20210106 22:19:44                      1.74                    72.1                 1378.42
20210106 22:20:44                      1.84                   91.02                 1957.69
20210106 22:21:44                      2.72                   68.14                 1447.02
20210106 22:22:44                      2.18                   80.76                 1649.19
20210106 22:23:44                      2.75                   75.58                 1676.43
20210106 22:24:44                       2.2                   36.45                 1502.78
20210106 22:25:45                      2.21                   21.77                 1429.71
20210106 22:26:44                      2.61                   40.56                 2667.25
20210106 22:27:44                      2.09                   19.95                 1068.11
20210106 22:28:44                      1.39                   57.66                 1419.02
20210106 22:29:44                      1.61                   44.66                 1701.81
20210106 22:30:44                       1.2                   74.61                 2328.65
20210106 22:31:45                      1.29                   83.01                 2020.88
20210106 22:32:45                       .76                   94.96                 2706.07
20210106 22:33:44                      1.02                   22.84                 2032.87
20210106 22:34:44                       .74                   58.67                 2297.62
20210106 22:35:44                      1.76                   81.66                 1727.17
20210106 22:36:44                       .58                    66.2                 4839.24
20210106 22:37:44                       .87                   29.04                 1617.19
20210106 22:38:45                      1.54                   53.16                 1539.99
20210106 22:39:45                      1.21                    51.9                  1420.5
20210106 22:40:44                         1                   49.76                 1646.52
20210106 22:41:44                      2.23                   74.05                 1761.78
20210106 22:42:44                      1.17                  146.94                 1505.77
20210106 22:43:44                      1.39                   75.94                 1620.12
20210106 22:44:45                      1.07                   73.43                 2045.32
20210106 22:45:45                       .44                   82.36                 2572.26
20210106 22:46:44                         2                   54.02                 1909.32
20210106 22:47:44                      1.61                   43.08                 1479.45
20210106 22:48:44                      1.29                   47.81                 1296.04
20210106 22:49:44                      1.39                    50.6                 1337.25
20210106 22:50:44                       1.3                   55.93                 1497.06
20210106 22:51:45                      1.85                   43.28                 1074.38
20210106 22:52:45                      1.06                   93.48                 1559.25
20210106 22:53:44                      1.17                   39.43                 2132.45
20210106 22:54:44                       .54                   50.37                 2259.39
20210106 22:55:44                      1.35                   47.12                 1347.34
20210106 22:56:44                      2.09                   57.55                 2647.21
20210106 22:57:45                      1.33                   46.67                  980.51
20210106 22:58:45                       .68                   74.52                 1480.33
20210106 22:59:45                      1.19                    51.5                 1871.55

可以从上述三个指标中观察,Single Block Read Latency高的时候,IO请求量并不匹配,并非因为IO请求量导致IO效率下降,延时变高。
延时指标高,IO量并不大
继续阅读

诡异的ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O

今年以来,公司多套RAC数据库(版本:11.2.0.4)ASM实例频繁报出ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O错误。这些数据库早在2016年时印象中便出现了此类报错,并且报错并非单个数据库偶发现象,而是大面积爆发,从3月至今仍然有些许数据库会抛出零星错误出现。

什么是ORA-27090?<参考 Doc ID 579108.1 >文中提到,此类报错的原因是操作系统异步IO请求参数 aio-max-nr 过低并且需要调整并发未完成的异步请求数目,避免异步IO请求失败的情况, Oracle官方文档中的建议值如下:

The "aio-max-nr" kernel limit is too low.
io_setup(4096, 0x66e1588) = -1 EAGAIN (Resource temporarily unavailable),

但是很诡异的是,我们的数据库早在2016年左右(第一次触发此问题)时,已经将该参数调整至4194304,理论上是不应该触发异步IO不足的问题。并且此报错风险性较高,ASM实例异步IO失败会导致数据库面临crash问风险,例如DBWR将脏块落盘(数据文件)时,如果此时DBWR进程无法进行时,数据库崩溃等其他异常行为会有极大可能性的。虽然可以将systcl.conf中的aio-max-nr一直调大,但是总归不是长久之计,并且在某年某月时会再次“爆发”。

最可怕的是,通过分析alert中的trace文件时,并没有发现任何有价值信息,所有的线索就是异步IO请求超过最大限制,导致某些IO请求失败抛出错误。。。

通过查看cat /proc/sys/fs/aio-nr查看当前的异步IO请求数量,此值偶尔下降但总量一直处于增长态势, 此时严重怀疑是否数据库中有某些进程执行异步IO请求后并没有释放IO描述符?造成异步IO描述符泄露?

我们数据库集群后发现异步IO请求变回归到正常范围内,但是态势仍然处于上升趋势:

ora11g@travelskydba-rac$ cat /proc/sys/fs/aio-nr 
22784
继续阅读

ORA-00704: bootstrap process failure故障修复

近日,同事反馈一套测试测试数据库宕机,进行重启数据库操作时发现数据库无法open,抛出ORA-00704: bootstrap process failure错误,版本为11.2.0.4

SQL> startup;
ORACLE instance started.

Total System Global Area 1068937216 bytes
Fixed Size		    2260088 bytes
Variable Size		  671089544 bytes
Database Buffers	  390070272 bytes
Redo Buffers		    5517312 bytes
Database mounted.
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-00704: bootstrap process failure
ORA-00604: error occurred at recursive SQL level 1
ORA-00942: table or view does not exist
Process ID: 57338
Session ID: 96 Serial number: 3

错误一并抛出了ORA-00942: table or view does not exist错误,应该是系统表丢失导致的bootstrap失败,并且alert日志中没有任何其他日志输出。

将数据库启动到nomount与mount状态,利用10046 event跟踪bootstrap过程:
SQL> oradebug setmypid
Statement processed.
SQL> oradebug tracefile_name
/opt/app/ora11g/albert/diag/rdbms/prod3/PROD3/trace/PROD3_ora_57585.trc
SQL> oradebug event 10046 trace name context forever,level 12;
Statement processed.
SQL> alter database mount;

Database altered.

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-00704: bootstrap process failure
ORA-00604: error occurred at recursive SQL level 1
ORA-00942: table or view does not exist
Process ID: 57585
Session ID: 96 Serial number: 3

访问/opt/app/ora11g/albert/diag/rdbms/prod3/PROD3/trace/PROD3_ora_57585.trc发现访问access$表时抛出异常:

继续阅读

核心系统表关联顺序错误导致的低效SQL

同事发来一个核心业务库的TOP SQL,占据并浪费了大量的服务器CPU资源,此SQL执效率信息如下:

SELECT a.ID,
       a.SEG_FLIGHT_ID,
       a.SEG_DEP_STATION_CODE,
       a.SEG_ARR_STATION_CODE,
       a.SEG_CLASS_SEQUENCE,
       a.SEG_TRAFFIC_RESTRICTION_CODE,
       a.SEG_DEP_TERMINAL,
       a.SEG_ARR_TERMINAL,
       a.SEG_OC_TYPE,
       a.SEG_OC_MAP_NUMBER,
       a.SEG_OC_CLASS_MAPPING,
       a.SEG_DATA_SOURCE
FROM T_SEGMENT a,
  (SELECT id
   FROM
     (SELECT t.id
      FROM T_FLIGHT t,
           T_TASK ta
      WHERE 1=1
        AND ta.id IN ('11008',
                      '11003',
                      '11014',
                      '11012',
                      '14001',
                      '11001')
        AND t.FLT_AIRLINE_CODE = ta.FLT_AIRLINE_CODE
        AND t.FLT_FLIGHT_NO = ta.FLT_FLIGHT_NO
        AND t.FLT_FLIGHT_DATE = ta.FLT_FLIGHT_DATE
        AND t.FLT_OC_FLIGHT_ID IS NULL
        AND t.IS_VALID = 1
        AND nullif('AAAA',t.FLT_OFFICE) IS NOT NULL )
   LEFT JOIN t_dep_schema s ON id = s.flt_id
   WHERE s.flt_id IS NULL
     OR (s.flt_id IS NOT NULL
         AND (s.FLT_IN_TCARD_PROCESS_FLAG ='N'
              OR s.FLT_IN_TCARD_PROCESS_FLAG IS NULL))
     OR (s.flt_id IS NOT NULL
         AND (s.FLT_IN_INIT_PROCESS_FLAG IS NULL
              OR s.FLT_IN_INIT_PROCESS_FLAG ='N')) ) f
WHERE 1=1
  AND a.SEG_FLIGHT_ID = f.ID
  AND a.IS_VALID = 1

SQL执行计划如下:

从执行计划中看到,估算行数与实际行数差别巨大,实际行数只是899行,但是NESTED LOOP之后估算结果集为46K,并且TASK表与S表选择了HASH JOIN,在未收集个性化扩展统计信息的情况,针对这种复杂情况,估算不准的情况是比较常见的,通常需要利用HINT来调整表连接顺序来优化。此SQL的涉及表都不存在索引缺失的情况,只是行数估算错误导致表连接顺序有误,从而选择了低效的执行计划。

继续阅读

原平均1762秒提升至0.035秒的TOP SQL优化处理过程

同事在日常巡检中发现一套数据库资源瓶颈严重,如下图所示:

活动会话多数在等待read by other session与CPU,根据硬件,多数为SQL问题导致,协助同事最终定位了TOP SQL,该SQL执行计划与执行效率信息如下图所示:

从执行计划中得知,最消耗资源的为TABLE ACCESS FULL全表扫描这步,该SQL有上百行,截取执行计划中此步SQL_TEXT如下:

PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  2pzyb63zhr1qp, child number 0
-------------------------------------
SELECT *
FROM
  (SELECT iti.owner,
          iti.object_name,
          iti.object_type,
          iti.OBJECT_ID,
          iti.DATA_OBJECT_ID,
          iti.STATUS,
          iti.CREATED,
          iti.LAST_DDL_TIME,
          iti.SECONDARY,
          iti.NAMESPACE,
          iti.EDITION_NAME
   FROM t iti
   WHERE iti.OBJECT_ID > 88
     AND iti.object_type != 'INDEX'
   ORDER BY iti.CREATED DESC)
WHERE ROWNUM<=100

Plan hash value: 3299198703

------------------------------------------------------------------------------------------------------------------
| Id  | Operation               | Name | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |      |      1 |        |   657K(100)|          |    100 |00:00:07.90 |     263K|
|*  1 |  COUNT STOPKEY          |      |      1 |        |            |          |    100 |00:00:07.90 |     263K|
|   2 |   VIEW                  |      |      1 |     15M|   657K  (1)| 02:11:28 |    100 |00:00:07.90 |     263K|
|*  3 |    SORT ORDER BY STOPKEY|      |      1 |     15M|   657K  (1)| 02:11:28 |    100 |00:00:07.90 |     263K|
|*  4 |     TABLE ACCESS FULL   | T    |      1 |     15M| 71738   (1)| 00:14:21 |     17M|00:00:03.36 |     263K|
------------------------------------------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1
   2 - SEL$2 / from$_subquery$_001@SEL$1
   3 - SEL$2
   4 - SEL$2 / iti@SEL$2

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(ROWNUM<=100)
   3 - filter(ROWNUM<=100)

可以看到,该SQL用了232K个BUFFER,大约用了7秒多的时间。根据SQL逻辑,我们可以建立created,object_id两个字段索引,使得执行计划只扫描100行所需要的buffer,理想执行计划是走索引的INDEX FULL SCAN DESCENDING,A-ROWS只有100:

SQL> create index t_idx01 on t(created,object_id);

Index created.

再次测试SQL:

SQL>
SELECT *
FROM
  (SELECT iti.owner,
          iti.object_name,
          iti.object_type,
          iti.OBJECT_ID,
          iti.DATA_OBJECT_ID,
          iti.STATUS,
          iti.CREATED,
          iti.LAST_DDL_TIME,
          iti.SECONDARY,
          iti.NAMESPACE,
          iti.EDITION_NAME
   FROM t iti
   WHERE iti.OBJECT_ID > 88
     AND iti.object_type != 'INDEX'
   ORDER BY iti.CREATED DESC)
WHERE ROWNUM<=100


PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  2pzyb63zhr1qp, child number 0
-------------------------------------
SELECT *
FROM
  (SELECT iti.owner,
          iti.object_name,
          iti.object_type,
          iti.OBJECT_ID,
          iti.DATA_OBJECT_ID,
          iti.STATUS,
          iti.CREATED,
          iti.LAST_DDL_TIME,
          iti.SECONDARY,
          iti.NAMESPACE,
          iti.EDITION_NAME
   FROM t iti
   WHERE iti.OBJECT_ID > 88
     AND iti.object_type != 'INDEX'
   ORDER BY iti.CREATED DESC)
WHERE ROWNUM<=100

Plan hash value: 4274603649

------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name    | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |         |      1 |        |     4 (100)|          |    100 |00:00:00.01 |     110 |      2 |
|*  1 |  COUNT STOPKEY                |         |      1 |        |            |          |    100 |00:00:00.01 |     110 |      2 |
|   2 |   VIEW                        |         |      1 |     15M|     4   (0)| 00:00:01 |    100 |00:00:00.01 |     110 |      2 |
|*  3 |    TABLE ACCESS BY INDEX ROWID| T       |      1 |     15M|     4   (0)| 00:00:01 |    100 |00:00:00.01 |     110 |      2 |
|*  4 |     INDEX FULL SCAN DESCENDING| T_IDX01 |      1 |      1 |     3   (0)| 00:00:01 |    100 |00:00:00.01 |      10 |      2 |
------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(ROWNUM<=100)
   3 - filter("iti"."OBJECT_TYPE"<>'INDEX')
   4 - access("iti"."OBJECT_ID">88)
       filter("iti"."OBJECT_ID">88)

我们看到,执行计划自动选择了INDEX FULL SCAN DESCENDING,无需单独指定降序扫描,优化器会自动选择此方式;A-ROWS只有100行(需求是order by + 小于等于100 row),相对于非全表扫描后过滤出100行的方式,BUFFER GET只需要110个即可。

在生产库上创建索引后性能对比:

最终执行计划如下:


-----------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name                    | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
-----------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |                         |      1 |        |  1181 (100)|          |    104 |00:00:00.02 |    2476 |
|*  1 |  FILTER                           |                         |      1 |        |            |          |    104 |00:00:00.02 |    2476 |
|   2 |   NESTED LOOPS                    |                         |      1 |    496 |  1181   (1)| 00:00:15 |    508 |00:00:00.01 |    1542 |
|   3 |    NESTED LOOPS                   |                         |      1 |     89 |   673   (0)| 00:00:09 |    100 |00:00:00.01 |     963 |
|   4 |     VIEW                          |                         |      1 |    100 |    94   (0)| 00:00:02 |    100 |00:00:00.01 |     401 |
|*  5 |      COUNT STOPKEY                |                         |      1 |        |            |          |    100 |00:00:00.01 |     401 |
|   6 |       VIEW                        |                         |      1 |    100 |    94   (0)| 00:00:02 |    100 |00:00:00.01 |     401 |
|*  7 |        TABLE ACCESS BY INDEX ROWID| ITINE                   |      1 |     22M|    94   (0)| 00:00:02 |    100 |00:00:00.01 |     401 |
|*  8 |         INDEX SKIP SCAN DESCENDING| ITIN_IDX_01             |      1 |    104 |     3   (0)| 00:00:01 |    100 |00:00:00.01 |     301 |
|*  9 |     TABLE ACCESS BY INDEX ROWID   | SPNR                    |    100 |      1 |     6   (0)| 00:00:01 |    100 |00:00:00.01 |     562 |
|* 10 |      INDEX RANGE SCAN             | SPNR_PK                 |    100 |      9 |     3   (0)| 00:00:01 |    960 |00:00:00.01 |     291 |
|* 11 |    TABLE ACCESS BY INDEX ROWID    | ITINE                   |    100 |      6 |     6   (0)| 00:00:01 |    508 |00:00:00.01 |     579 |
|* 12 |     INDEX RANGE SCAN              | ITINE_PK                |    100 |      6 |     3   (0)| 00:00:01 |    508 |00:00:00.01 |     271 |
|* 13 |   TABLE ACCESS BY INDEX ROWID     | ITINE                   |    404 |      1 |     4   (0)| 00:00:01 |      0 |00:00:00.01 |     934 |
|* 14 |    INDEX UNIQUE SCAN              | ITINE_PK                |    404 |      1 |     3   (0)| 00:00:01 |    404 |00:00:00.01 |     530 |
-----------------------------------------------------------------------------------------------------------------------------------------------