High Sync ASM rebalance Waits When DB is Promoted to 13c EM

High number of Sync ASM rebalance waits were observed on the database after it was promoted to the EM 13.4The below SQLS were identified as the two SQLs causing most of the waits.
6zcsw17mp4k2y

SELECT pdb.name, m.tablespace_name, ROUND(m.used_percent, :"SYS_B_0"), ROUND((m.tablespace_size - m.used_space)*t.block_size/:"SYS_B_1"/:"SYS_B_2", :"SYS_B_3") mb_free
FROM cdb_tablespace_usage_metrics m, cdb_tablespaces t,
(SELECT con_id, name
FROM v$containers ) pdb
WHERE t.contents = :"SYS_B_4" AND t.tablespace_name = m.tablespace_name AND m.con_id = t.con_id AND m.con_id = pdb.con_id

1pc09k1rjgtwu

SELECT pdb.name, m.tablespace_name, ROUND(m.used_percent, :"SYS_B_0"), ROUND((m.tablespace_size - m.used_space)*t.block_size/:"SYS_B_1"/:"SYS_B_2", :"SYS_B_3") mb_free
FROM cdb_tablespace_usage_metrics m, cdb_tablespaces t, v$parameter p,
(SELECT con_id, name
FROM v$containers) pdb
WHERE p.name = :"SYS_B_4" AND p.value != :"SYS_B_5" AND t.contents = :"SYS_B_6" AND t.tablespace_name = m.tablespace_name AND m.con_id = t.con_id AND m.con_id = pdb.con_id

This appear to be a known issue as per 2375714.1 although the SQL on the doc 2375714.1 is different.



Solution for above is to set the hiddden parameter "_use_cached_asm_free_space" to true on the database instance.
Oracle support confirmed the hidden parameter setting is valid for 19c CDB as well.
After setting it the Sync ASM rebalance waits reduced.

Useful Metalink notes
EM13c Space Monitoring Query (sqlid=69p6my4hpdm3j) On dba_tablespace_usage_metrics Timed Out after Db Upgraded To 12.2 [ID 2375714.1]

Upgarding Recovery Catalog

The version of the recovery catalog schema must be greater than or equal to the version of the RMAN client connecting to it. More on the rman compatability could be found on the backup and recovery reference.
The recovery catalog schema version is not same as the database version. For example the database could be 19.7 and recovery catalog could be 19.08.00.00. Recovery catalog version could be found by connecting to the recovery catalog using sqlplus as the recovery catalog owner.

sqlplus  reco/password_here

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Jan 5 20:00:14 2021
Version 19.8.0.0.0

Enter password:
Last Successful login time: Tue Jan 05 2021 19:45:02 +00:00

Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.8.0.0.0

SQL>  select * from rcver;

VERSION
---------------
19.08.00.00.00

When the recovery catalog schema version is higher than the client version following message is shown when connecting to the recovery catalog.

rman target / catalog reco@recotns
connected to target database: DB1 (DBID=123490689)
recovery catalog database Password:
connected to recovery catalog database
recovery catalog schema version 19.08.00.00. is newer than RMAN version

As recovery catalog schema is higher this is not an issue. On the other hand if rman client is higher than the recovery catalog schema following message is shown when connecting to it.

rman  catalog /@recotns

Recovery Manager: Release 19.0.0.0.0 - Production on Tue Jan 5 20:33:13 2021
Version 19.9.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

connected to recovery catalog database
PL/SQL package RECOCAT.DBMS_RCVCAT version 19.08.00.00. in RCVCAT database is not current
PL/SQL package RECOCAT.DBMS_RCVMAN version 19.08.00.00 in RCVCAT database is not current

In this case client version is 19.9 and is higher than the recovery catalog schema version which is 19.08.00.00.
This happens when Oracle home is patched with RU. In this case (also mentioned as part of patch Readme document) the recovery catalog must be upgraded.



To upgrade the recovery catalog schema connect to it using rman from the higher version client and run the upgrade catalog command twice.

rman  catalog /@recotns

Recovery Manager: Release 19.0.0.0.0 - Production on Tue Jan 5 20:33:13 2021
Version 19.9.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

connected to recovery catalog database
PL/SQL package RECOCAT.DBMS_RCVCAT version 19.08.00.00. in RCVCAT database is not current
PL/SQL package RECOCAT.DBMS_RCVMAN version 19.08.00.00 in RCVCAT database is not current

RMAN>  UPGRADE CATALOG;

recovery catalog owner is RECO
enter UPGRADE CATALOG command again to confirm catalog upgrade

RMAN>  UPGRADE CATALOG;

recovery catalog upgraded to version 19.09.00.00.00
DBMS_RCVMAN package upgraded to version 19.09.00.00
DBMS_RCVCAT package upgraded to version 19.09.00.00.

The version upgrade could be verified querying the rcver. In the below output it could be seen that recovery catalog reside in a database which is 19.8. However, the recovery catalog version is 19.09.

sqlplus /@recotns

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Jan 5 21:25:17 2021
Version 19.9.0.0.0

Copyright (c) 1982, 2020, Oracle.  All rights reserved.

Last Successful login time: Tue Jan 05 2021 21:15:03 +00:00

Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.8.0.0.0

SQL>  select * from rcver;

VERSION
---------------
19.09.00.00.00

Related Posts
Recovery Catalog
Recovery Catalog and Data Guard

Update on 2021-02-26
Strange behaviour was observed with recovery catalog where backups were failing with following error.

Oracle error from recovery catalog database: ORA-04063: package body "RECOCAT.DBMS_RCVMAN" has errors
ORA-06508: PL/SQL: could not find program unit being called: "RECOCAT.DBMS_RCVMAN"

recovery catalog is partially upgraded to 19.09.00.00
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of report command at 02/26/2021 00:05:04
RMAN-06429: RCVCAT database is not compatible with this version of RMAN

Both the client and the recovery catalog had the same version.

SQL> select * from rcver;

VERSION
---------------
19.09.00.00.00

rman catalog /@recotns

Recovery Manager: Release 19.0.0.0.0 - Production on Fri Feb 26 16:49:30 2021
Version 19.9.0.0.0

It's not sure why this happened. Ppossibly update catalog was run only once not twice. This cause is suspected because of "recovery catalog is partially upgraded" shown during the subsequent upgrade. MOS note 2022782.1 matched the error and list cauase as compatibility mismatch, which isn't the case. Neverthless running upgrade catalog twice (though first run gave out an error) resolved the issue.

rman catalog /@recotns

Recovery Manager: Release 19.0.0.0.0 - Production on Fri Feb 26 16:49:30 2021
Version 19.9.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

connected to recovery catalog database
recovery catalog is partially upgraded to 19.09.00.00

RMAN> UPGRADE CATALOG;

Oracle error from recovery catalog database: ORA-04063: package body "RECOCAT.DBMS_RCVMAN" has errors
ORA-06508: PL/SQL: could not find program unit being called: "RECOCAT.DBMS_RCVMAN"

recovery catalog owner is RECOCAT
enter UPGRADE CATALOG command again to confirm catalog upgrade

RMAN> UPGRADE CATALOG;

recovery catalog is partially upgraded to 19.09.00.00
recovery catalog upgraded to version 19.09.00.00.00
DBMS_RCVMAN package upgraded to version 19.09.00.00
DBMS_RCVCAT package upgraded to version 19.09.00.00.

Backups continued with recovery catalog afterwards and no issues observed.

Update on 2021-03-02
Further investigation revealed that above error was a result of running catalog upgrade command (upgrade catalog) before Datapatch (datapatch -verbose). PSU readme file clearly state that catalog upgrade should be run after datapatch.

High Disk file operations I/O Waits When Querying Unified Audit Trail

DB monitoring showed high waits for Disk file operations I/O event.

The select query originated from the EM console.

The database is running pure unified auditing (not mix mode) as such the dba_common_audit_trail part was of no concern. A simple select query on the unified audit trail also showed the same high wait times for Disk file operations I/O.

The issue was happening only on the CDB$root unified audit trail. The PDB audit trail had no issue.
Gathering statistics on audsys didn't help either.

exec dbms_STATS.GATHER_TABLE_STATS(OWNNAME=>'AUDSYS',TABNAME=>'AUD$UNIFIED',degree=>4);

Finally ran a 10046 trace and it showed the following for the Disk file operations I/O wait.

WAIT #140628544496888: nam='Disk file operations I/O' ela= 2352 FileOperation=8 fileno=1 filetype=36 obj#=-1 tim=5526698301528

It was starge objection id is -1 but stranger was there was no filetype 36 listed.

select file_no,filetype_id,FILETYPE_NAME from v$iostat_file where file_no=1 and filetype_id=36;

no rows selected 

At this stage looked at the historical data for the disk file operation I/O wait event on the AWR. It showed the first high waits occured soon after the swtichover to standby (circled in black). Even after switching back to original primary the wait events continued (circled in blue). Prior the switchover there was very low wait events and wait times on the primary.

When unified auditing is enabled on a standby it creates audit files on the local disk in the $ORACLE_BASE/audit/$ORACLE_SID directory. Based on above pattern a hypothesis was devised that unified audit trail could be getting populated from records in the audit files on the local disk that were craeted when it was a standby.
This hypothesis was tested out by archiving and removing the audit records created in the $ORACLE_BASE/audit/$ORACLE_SID. Afterwards querying the unified audit trail did not result in high disk file operation I/O.
Comparing the audit record count before the audit files on the local disks were removed

select count(*) from unified_audit_trail;

COUNT(*)
----------
761793 

and after

select count(*) from unified_audit_trail;

COUNT(*)
----------
516385

shows that some records from audit files on the local disk were used to populat the unified audit trail view.