Should you gather system statistics on Exadata ?

I got a questions from one user of Exadata: 

1.Do we need to gather system statistics on Exadata ?
2. How to gather system statistics on Exadata ?
3. If I run the command exec dbms_stats.gather_system_stats ('EXADATA') - how to point the start time and end time?

1.Do we need to gather system statistics on Exadata ?

The optimizer cost formula is 

cost =  (#srds * sreadtm + #mrds * mreadtm + #cpucycles / cpuspeed) / sreadtm
 
   #srds                 number of single block reads
   sreadtm               single block read time
   #mrds                 number of multi block reads
   mreadtm               multi block read time
   #cpucycles            number of cpu cycles
   cpuspeed              cpu cycles per second
 

As documentation say: "The cost is an internal numeric measure that represents the estimated resource usage for a plan. The cost is specific to a query in an optimizer environment. To estimate cost, the optimizer considers factors such as the following:

• System resources, which includes estimated I/O, CPU, and memory .... "
  

 So, in order to generate an optimal plan, the optimizer must know the characteristics of the equipment.

 10.2.4 System Statistic: "  The system statistics describe hardware characteristics such as I/O and CPU performance and utilization.
System statistics enable the query optimizer to more accurately estimate I/O and CPU costs when choosing execution plans. The database does not invalidate previously parsed SQL statements when updating system statistics. The database parses all new SQL statements using new statistics. "

Table 15-2  Optimizer System Statistics in the DBMS_STAT Package

Parameter Name	Description	Initialization	Options for Gathering or Setting Statistics
cpuspeed	CPU speed is the average number of CPU cycles per second.	At system startup	Set gathering_mode = NOWORKLOAD, INTERVAL, or START|STOP, or set statistics manually.
ioseektim	I/O seek time equals seek time + latency time + OS overhead time.	At system startup	Set gathering_mode = NOWORKLOAD or set statistics manually.
iotfrspeed	I/O transfer speed is the rate at which an Oracle database can read data in the single read request.	At system startup	Set gathering_mode = NOWORKLOAD or set statistics manually.
maxthr	Maximum I/O throughput is the maximum throughput that the I/O subsystem can deliver.	None	Set gathering_mode = NOWORKLOAD, INTERVAL, or START|STOP, or set statistics manually.
slavethr	Slave I/O throughput is the average parallel slave I/O throughput.	None	Set gathering_mode = INTERVAL or START|STOP, or set statistics manually.
sreadtim	Single block read time is the average time to read a single block randomly.	None	Set gathering_mode = INTERVAL or START|STOP, or set statistics manually.
mreadtim	Multiblock read is the average time to read a multiblock sequentially.	None	Set gathering_mode = INTERVAL or START|STOP, or set statistics manually.
mbrc	Multiblock count is the average multiblock read count sequentially.	None	Set gathering_mode = INTERVAL or START|STOP, or set statistics manually.

Unlike table, index, or column statistics, Oracle does not invalidate already parsed SQL statements when system statistics get updated. All new SQL statements are parsed using new statistics.
https://docs.oracle.com/cd/B14117_01/server.101/b10752/stats.htm#40899

 

But there is another view on this question: https://blogs.oracle.com/optimizer/should-you-gather-system-statistics

 

2. How to gather system statistics on Exadata ?

 13.4 Gathering System Statistics Manually

 166.7.53 GATHER_SYSTEM_STATS Procedure 

Rules:

• Capture system statistics when the database has the most typical workload 
• Capture system statistics during not less than 1-2 hours

Also you can set YOUR OWN VALUES:

1.      begin
dbms_stats.set_system_stats('sreadtim',2); -- define single blocks reads to 2 ms
dbms_stats.set_system_stats('mreadtim',5); -- define multiblock reads to 5 ms
end;

 3. About  dbms_stats.gather_system_stats ('EXADATA')

 The dbms_stats.gather_system_stats('EXADATA') - does not gather statistics, it simply SET SOME CONSTANTS:

For example, on my notebook i have defaul values before dbms_stats.gather_system_stats('EXADATA'):

SQL> select * from aux_stats$;

SNAME                  PNAME              PVAL1    PVAL2
------------- ----------------------- ---------- ---------------------
SYSSTATS_INFO          STATUS                     COMPLETED
SYSSTATS_INFO          DSTART                     07-29-2020 07:53
SYSSTATS_INFO          DSTOP                      07-29-2020 07:53
SYSSTATS_INFO          FLAGS                 1
SYSSTATS_MAIN          CPUSPEEDNW     897.990726
SYSSTATS_MAIN          IOSEEKTIM             10
SYSSTATS_MAIN          IOTFRSPEED          4096
SYSSTATS_MAIN          SREADTIM
SYSSTATS_MAIN          MREADTIM
SYSSTATS_MAIN          CPUSPEED
SYSSTATS_MAIN          MBRC
SYSSTATS_MAIN          MAXTHR
SYSSTATS_MAIN          SLAVETHR

After :

SQL> delete * from aux_stats$;
SQL> commit;
Commit complete.

SQL> exec dbms_stats.gather_system_stats('EXADATA');
PL/SQL procedure successfully completed.

SQL> select * from aux_stats$;

SNAME                  PNAME             PVAL1    PVAL2
------------- ------------------------ ---------- ---------------------
SYSSTATS_INFO          STATUS                         COMPLETED
SYSSTATS_INFO          DSTART                         12-16-2020 11:34
SYSSTATS_INFO          DSTOP                          12-16-2020 11:34
SYSSTATS_INFO          FLAGS                   1
SYSSTATS_MAIN          CPUSPEEDNW           2928
SYSSTATS_MAIN          IOSEEKTIM               10
SYSSTATS_MAIN          IOTFRSPEED         204800
SYSSTATS_MAIN          SREADTIM
SYSSTATS_MAIN          MREADTIM
SYSSTATS_MAIN          CPUSPEED
SYSSTATS_MAIN          MBRC                   83
SYSSTATS_MAIN          MAXTHR
SYSSTATS_MAIN          SLAVETHR

13 rows selected.

As you can see dbms_stats.gather_system_stats('EXADATA')simply set

CPUSPEEDNW     2987
IOSEEKTIM        10
IOTFRSPEED   204800
MBRC            83

Or dbms_stats.gather_system_stats('EXADATA') calculated these values ? 

Let trace dbms_stats.gather_system_stats('EXADATA') :

SQL> alter session set events '10046 trace name context forever, level 4';

SQL> exec dbms_stats.gather_system_stats('EXADATA');

SQL> alter session set events '10046 trace name context forever, level 0';

 

What we see in the trace:

=====================
PARSING IN CURSOR #140565938845448 len=77 dep=1 uid=0 oct=2 lid=0 tim=1832183071 hv=928404322 ad='6a0f3e88' sqlid='67ncvpsvpcnv2'

INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'CPUSPEEDNW', :B1 , NULL)

END OF STMT
BINDS #140565938845448:

Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1460  bln=22  avl=03  flg=09
  value=2928

EXEC #140565938845448:c=45,e=45,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183111
CLOSE #140565938845448:c=1,e=1,dep=1,type=3,tim=1832183122
=====================
PARSING IN CURSOR #140565938842944 len=76 dep=1 uid=0 oct=2 lid=0 tim=1832183132 hv=543581576 ad='6a0f3b58' sqlid='auvf07wh6ctc8'

INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'IOSEEKTIM', :B1 , NULL)

END OF STMT
BINDS #140565938842944:

Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1478  bln=22  avl=02  flg=09
  value=10

EXEC #140565938842944:c=37,e=37,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183165
CLOSE #140565938842944:c=0,e=0,dep=1,type=3,tim=1832183174
=====================
PARSING IN CURSOR #140565938837432 len=77 dep=1 uid=0 oct=2 lid=0 tim=1832183184 hv=3127723828 ad='6a0f3828' sqlid='38gjx7kx6ujtn'

INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'IOTFRSPEED', :B1 , NULL)

END OF STMT
BINDS #140565938837432:

Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1490  bln=22  avl=03  flg=09
  value=204800

EXEC #140565938837432:c=36,e=36,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183216
CLOSE #140565938837432:c=0,e=0,dep=1,type=3,tim=1832183226
=====================

The full listing of trace file:

===========================================================

Trace file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_10584.trc
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.9.0.0.0
Build label:    RDBMS_19.9.0.0.0DBRU_LINUX.X64_200930
ORACLE_HOME:    /u01/app/oracle/dbhome_1
System name:    Linux
Node name:    oem.test.edu
Release:    5.4.17-2011.4.4.el8uek.x86_64
Version:    #2 SMP Sat Jun 27 11:14:55 PDT 2020
Machine:    x86_64
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 7
Unix process pid: 10584, image: oracle@oem.test.edu


*** 2020-12-16T11:41:38.329894+03:00 (PDB1(3))
*** SESSION ID:(240.2244) 2020-12-16T11:41:38.329923+03:00
*** CLIENT ID:() 2020-12-16T11:41:38.329926+03:00
*** SERVICE NAME:(pdb1) 2020-12-16T11:41:38.329929+03:00
*** MODULE NAME:(sqlplus@oem.test.edu (TNS V1-V3)) 2020-12-16T11:41:38.329932+03:00
*** ACTION NAME:() 2020-12-16T11:41:38.329934+03:00
*** CLIENT DRIVER:(SQL*PLUS) 2020-12-16T11:41:38.329936+03:00
*** CONTAINER ID:(3) 2020-12-16T11:41:38.329939+03:00
 
CLOSE #140565941051688:c=23,e=23,dep=0,type=1,tim=1832062095
=====================
PARSING IN CURSOR #140565942129688 len=54 dep=0 uid=0 oct=47 lid=0 tim=1832062521 hv=1060689565 ad='6bccd980' sqlid='95vr6z4zmjpnx'
BEGIN dbms_stats.gather_system_stats('EXADATA'); END;

END OF STMT
PARSE #140565942129688:c=44,e=44,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1832062520
=====================
PARSING IN CURSOR #140565941838896 len=73 dep=1 uid=0 oct=3 lid=0 tim=1832062775 hv=2059840778 ad='67bf7358' sqlid='2f002z1xcdb8a'
SELECT VALUE FROM SYS.NLS_SESSION_PARAMETERS WHERE PARAMETER = 'NLS_SORT'
END OF STMT
EXEC #140565941838896:c=21,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1805486652,tim=1832062774
FETCH #140565941838896:c=20,e=20,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1805486652,tim=1832062842
CLOSE #140565941838896:c=0,e=0,dep=1,type=3,tim=1832062855
=====================
PARSING IN CURSOR #140565940524088 len=73 dep=1 uid=0 oct=3 lid=0 tim=1832062872 hv=1472012665 ad='67bf7028' sqlid='5w5npw9bvu8bt'
SELECT VALUE FROM SYS.NLS_SESSION_PARAMETERS WHERE PARAMETER = 'NLS_COMP'
END OF STMT
EXEC #140565940524088:c=8,e=8,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1805486652,tim=1832062872
FETCH #140565940524088:c=12,e=12,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1805486652,tim=1832062901
CLOSE #140565940524088:c=0,e=0,dep=1,type=3,tim=1832062909
=====================
PARSING IN CURSOR #140565942378136 len=94 dep=1 uid=0 oct=3 lid=0 tim=1832062929 hv=3821161089 ad='67964348' sqlid='5mgx3qrjw4kn1'
SELECT /*+ OPT_PARAM('_parallel_syspls_obey_force' 'false') */ ST_OPR_ID_SEQ.NEXTVAL FROM DUAL
END OF STMT
EXEC #140565942378136:c=4,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=2973543806,tim=1832062929
FETCH #140565942378136:c=6,e=6,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=2973543806,tim=1832062952
CLOSE #140565942378136:c=1,e=1,dep=1,type=3,tim=1832062960
=====================
PARSING IN CURSOR #140565941832296 len=183 dep=1 uid=0 oct=3 lid=0 tim=1832062980 hv=3205126760 ad='67963188' sqlid='b4fqsa2zhnqm8'
SELECT /*+ OPT_PARAM('_parallel_syspls_obey_force' 'false') */ O.NAME FROM OBJ$ O, USER$ U WHERE O.OWNER# = U.USER# AND O.OBJ# = (SELECT SYS_CONTEXT('USERENV', 'BG_JOB_ID') FROM DUAL)
END OF STMT
EXEC #140565941832296:c=14,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=750105498,tim=1832062980
FETCH #140565941832296:c=1,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=750105498,tim=1832063001
CLOSE #140565941832296:c=1,e=0,dep=1,type=3,tim=1832063023
=====================
PARSING IN CURSOR #140565938848144 len=172 dep=1 uid=0 oct=2 lid=0 tim=1832063387 hv=872460390 ad='6952de30' sqlid='ddsukg4u01c36'
insert /* QOSH:REC_STS */ into sys.wri$_optstat_opr  (id, operation, target, start_time, end_time, status, job_name, session_id, notes) values  (:1,:2,:3,:4,:5,:6,:7,:8,:9)
END OF STMT
PARSE #140565938848144:c=169,e=293,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=1832063387
BINDS #140565938848144:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd814c25f30  bln=22  avl=03  flg=05
  value=583
 Bind#1
  oacdty=01 mxl=32(19) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=7fd814c32a7c  bln=32  avl=19  flg=09
  value="gather_system_stats"
 Bind#2
  oacdty=01 mxl=32(00) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=00000000  bln=32  avl=00  flg=09
 Bind#3
  oacdty=181 mxl=13(13) mxlc=00 mal=00 scl=09 pre=00
  oacflg=00 fl2=9000001 frm=00 csi=00 siz=56 off=0
  kxsbbbfp=7fd814c25ee0  bln=13  avl=13  flg=05
  value=16-DEC-20 11.41.38.330251000 AM +03:00
 Bind#4
  oacdty=181 mxl=13(13) mxlc=00 mal=00 scl=09 pre=00
  oacflg=00 fl2=9000001 frm=00 csi=00 siz=0 off=16
  kxsbbbfp=7fd814c25ef0  bln=13  avl=13  flg=01
  value=16-DEC-20 11.41.38.330251000 AM +03:00
 Bind#5
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=32
  kxsbbbfp=7fd814c25f00  bln=22  avl=02  flg=01
  value=1
 Bind#6
  oacdty=01 mxl=32(00) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=00000000  bln=32  avl=00  flg=09
 Bind#7
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd814c25eb0  bln=22  avl=03  flg=05
  value=240
 Bind#8
  oacdty=01 mxl=2000(183) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=2000 off=0
  kxsbbbfp=7fd814c3293c  bln=2000  avl=183  flg=09
  value="<params><param name="gathering_mode" val="EXADATA"/><param name="interval" val="60"/><param name="statid" val=""/><param name="statown" val=""/><param name="stattab" val=""/></params>"
EXEC #140565938848144:c=615,e=615,p=0,cr=1,cu=9,mis=1,r=1,dep=1,og=1,plh=0,tim=1832064028
STAT #140565938848144 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL  WRI$_OPTSTAT_OPR (cr=1 pr=0 pw=0 str=1 time=98 us)'
CLOSE #140565938848144:c=2,e=2,dep=1,type=0,tim=1832064069
=====================
PARSING IN CURSOR #140565940797768 len=129 dep=1 uid=0 oct=3 lid=0 tim=1832064274 hv=1326288355 ad='67a6e7f0' sqlid='0dcdtrt7hv3g3'
SELECT /*+ rule OPT_PARAM('_parallel_syspls_obey_force' 'false') */ VALUE FROM V$PARAMETER WHERE UPPER(NAME) = 'STATISTICS_LEVEL'
END OF STMT
EXEC #140565940797768:c=28,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1023639799,tim=1832064274
FETCH #140565940797768:c=6953,e=7546,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=3,plh=1023639799,tim=1832071850
CLOSE #140565940797768:c=23,e=23,dep=1,type=3,tim=1832071910
=====================
PARSING IN CURSOR #140565942739648 len=97 dep=2 uid=0 oct=3 lid=0 tim=1832074081 hv=791757000 ad='70d11f58' sqlid='87gaftwrm2h68'
select o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname from obj$ o where o.obj#=:1
END OF STMT
PARSE #140565942739648:c=180,e=181,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,plh=0,tim=1832074081
BINDS #140565942739648:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80f145880  bln=22  avl=06  flg=05
  value=4294953262
EXEC #140565942739648:c=574,e=614,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,plh=1072382624,tim=1832074734
FETCH #140565942739648:c=6,e=7,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832074747
STAT #140565942739648 id=1 cnt=0 pid=0 pos=1 obj=18 op='TABLE ACCESS BY INDEX ROWID BATCHED OBJ$ (cr=2 pr=0 pw=0 str=1 time=8 us cost=3 size=113 card=1)'
STAT #140565942739648 id=2 cnt=0 pid=1 pos=1 obj=36 op='INDEX RANGE SCAN I_OBJ1 (cr=2 pr=0 pw=0 str=1 time=7 us cost=2 size=0 card=1)'
CLOSE #140565942739648:c=0,e=0,dep=2,type=3,tim=1832074789
BINDS #140565942739648:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80f145880  bln=22  avl=06  flg=05
  value=4294951319
EXEC #140565942739648:c=22,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832074825
FETCH #140565942739648:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832074832
CLOSE #140565942739648:c=0,e=0,dep=2,type=3,tim=1832074840
BINDS #140565942739648:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80f145880  bln=22  avl=06  flg=05
  value=4294951050
EXEC #140565942739648:c=26,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832074876
FETCH #140565942739648:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832074883
CLOSE #140565942739648:c=0,e=0,dep=2,type=3,tim=1832074890
=====================
PARSING IN CURSOR #140565938848144 len=72 dep=1 uid=0 oct=3 lid=0 tim=1832074935 hv=3235042752 ad='695b2f58' sqlid='0kuzyw30d5pf0'
select count(*) cnt from v$datafile where status in ('SYSTEM', 'ONLINE')
END OF STMT
PARSE #140565938848144:c=2344,e=2974,p=0,cr=7,cu=0,mis=1,r=0,dep=1,og=1,plh=1332938801,tim=1832074935
EXEC #140565938848144:c=20,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1332938801,tim=1832074983
FETCH #140565938848144:c=151,e=151,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1332938801,tim=1832075142
STAT #140565938848144 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=0 pr=0 pw=0 str=1 time=164 us)'
STAT #140565938848144 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KCVDF (cr=0 pr=0 pw=0 str=1 time=146 us cost=0 size=65 card=1)'
CLOSE #140565938848144:c=30,e=31,dep=1,type=0,tim=1832075206
BINDS #140565942739648:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80f145880  bln=22  avl=06  flg=05
  value=4294953262
EXEC #140565942739648:c=34,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832076828
FETCH #140565942739648:c=3,e=3,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832076838
CLOSE #140565942739648:c=1,e=1,dep=2,type=3,tim=1832076849
BINDS #140565942739648:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80f145880  bln=22  avl=06  flg=05
  value=4294951319
EXEC #140565942739648:c=21,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832076881
FETCH #140565942739648:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832076888
CLOSE #140565942739648:c=0,e=0,dep=2,type=3,tim=1832076895
BINDS #140565942739648:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80f145880  bln=22  avl=06  flg=05
  value=4294951050
EXEC #140565942739648:c=20,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832076924
FETCH #140565942739648:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=4,plh=1072382624,tim=1832076930
CLOSE #140565942739648:c=0,e=0,dep=2,type=3,tim=1832076937
=====================
PARSING IN CURSOR #140565938848144 len=86 dep=1 uid=0 oct=3 lid=0 tim=1832076967 hv=2806229348 ad='69563690' sqlid='5tpvatamn7ab4'
select file#,  blocks, block_size from v$datafile where status in ('SYSTEM', 'ONLINE')
END OF STMT
PARSE #140565938848144:c=2267,e=1718,p=0,cr=7,cu=0,mis=1,r=0,dep=1,og=1,plh=3398306107,tim=1832076967
EXEC #140565938848144:c=10,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3398306107,tim=1832077007
FETCH #140565938848144:c=61,e=61,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=3398306107,tim=1832077077
FETCH #140565938848144:c=10,e=10,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=3398306107,tim=1832077095
FETCH #140565938848144:c=8,e=8,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=3398306107,tim=1832077109
FETCH #140565938848144:c=7,e=7,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=3398306107,tim=1832077123
FETCH #140565938848144:c=18,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3398306107,tim=1832077147
STAT #140565938848144 id=1 cnt=4 pid=0 pos=1 obj=0 op='FIXED TABLE FULL X$KCVDF (cr=0 pr=0 pw=0 str=1 time=66 us cost=0 size=104 card=1)'
CLOSE #140565938848144:c=2,e=2,dep=1,type=0,tim=1832077172
=====================
PARSING IN CURSOR #140565942165984 len=170 dep=1 uid=0 oct=3 lid=0 tim=1832179784 hv=1931359042 ad='67965a68' sqlid='5rurx5xtjwcu2'
SELECT /*+ OPT_PARAM('_parallel_syspls_obey_force' 'false') */ KSPPCV.KSPPSTVL FROM X$KSPPCV KSPPCV, X$KSPPI KSPPI WHERE KSPPI.INDX = KSPPCV.INDX AND KSPPI.KSPPINM = :B1
END OF STMT
BINDS #140565942165984:

 Bind#0
  oacdty=01 mxl=2000(116) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1206001 frm=01 csi=873 siz=2000 off=0
  kxsbbbfp=7fd80edac850  bln=2000  avl=29  flg=05
  value="db_file_multiblock_read_count"
EXEC #140565942165984:c=110,e=110,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=185276389,tim=1832179874
FETCH #140565942165984:c=106,e=106,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=185276389,tim=1832179996
CLOSE #140565942165984:c=1,e=1,dep=1,type=3,tim=1832180023
EXEC #140565941838896:c=11,e=11,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1805486652,tim=1832180060
FETCH #140565941838896:c=20,e=20,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1805486652,tim=1832180095
CLOSE #140565941838896:c=1,e=1,dep=1,type=3,tim=1832180107
EXEC #140565940524088:c=7,e=7,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1805486652,tim=1832180122
FETCH #140565940524088:c=12,e=12,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1805486652,tim=1832180142
CLOSE #140565940524088:c=0,e=0,dep=1,type=3,tim=1832180151
=====================
PARSING IN CURSOR #140565942168488 len=119 dep=1 uid=0 oct=3 lid=0 tim=1832180190 hv=4203535333 ad='679925e8' sqlid='b9nbhsbx8tqz5'
SELECT /*+ OPT_PARAM('_parallel_syspls_obey_force' 'false') */ SPARE4 FROM SYS.OPTSTAT_HIST_CONTROL$ WHERE SNAME = :B1
END OF STMT
BINDS #140565942168488:

 Bind#0
  oacdty=01 mxl=128(30) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1206001 frm=01 csi=873 siz=128 off=0
  kxsbbbfp=7fd80edacfa0  bln=128  avl=07  flg=05
  value="PUBLISH"
EXEC #140565942168488:c=38,e=38,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1097271556,tim=1832180223
FETCH #140565942168488:c=34,e=34,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=1097271556,tim=1832180264
CLOSE #140565942168488:c=1,e=1,dep=1,type=3,tim=1832180275
=====================
PARSING IN CURSOR #140565940787984 len=163 dep=1 uid=0 oct=3 lid=0 tim=1832180308 hv=3937375941 ad='67a734f0' sqlid='8ndfc0zpaz5q5'
SELECT /*+ OPT_PARAM('_parallel_syspls_obey_force' 'false') */ S.SNAME, S.PNAME, S.PVAL1, S.PVAL2 FROM AUX_STATS$ S WHERE S.SNAME LIKE 'SYSSTATS%' ORDER BY S.SNAME
END OF STMT
EXEC #140565940787984:c=10,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=302179760,tim=1832180308
FETCH #140565940787984:c=10,e=10,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180344
FETCH #140565940787984:c=3,e=3,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180358
FETCH #140565940787984:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180368
FETCH #140565940787984:c=1,e=1,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180376
FETCH #140565940787984:c=1,e=1,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180385
FETCH #140565940787984:c=1,e=1,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180394
FETCH #140565940787984:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180403
FETCH #140565940787984:c=1,e=1,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180411
FETCH #140565940787984:c=1,e=1,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180419
FETCH #140565940787984:c=1,e=2,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180428
FETCH #140565940787984:c=1,e=1,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180436
FETCH #140565940787984:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180445
FETCH #140565940787984:c=2,e=2,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=302179760,tim=1832180454
FETCH #140565940787984:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=302179760,tim=1832180461
CLOSE #140565940787984:c=1,e=1,dep=1,type=3,tim=1832180541
=====================
PARSING IN CURSOR #140565941320288 len=61 dep=1 uid=0 oct=6 lid=0 tim=1832180573 hv=2318223170 ad='67bf7ce8' sqlid='8fmhq7a52uju2'
UPDATE SYS.WRI$_OPTSTAT_AUX_HISTORY SET PVAL1 = 0 WHERE 1 = 0
END OF STMT
EXEC #140565941320288:c=20,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=2156868965,tim=1832180573
CLOSE #140565941320288:c=0,e=0,dep=1,type=3,tim=1832180595
=====================
PARSING IN CURSOR #140565941317784 len=47 dep=1 uid=0 oct=6 lid=0 tim=1832180608 hv=108181487 ad='67bf79b8' sqlid='cvszzn4375dzg'
UPDATE SYS.AUX_STATS$ SET PVAL1 = 0 WHERE 1 = 0
END OF STMT
EXEC #140565941317784:c=6,e=6,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=4206089498,tim=1832180608
CLOSE #140565941317784:c=0,e=0,dep=1,type=3,tim=1832180633
=====================
PARSING IN CURSOR #140565938870544 len=56 dep=1 uid=0 oct=7 lid=0 tim=1832180745 hv=311428414 ad='6a0f51a8' sqlid='f4zw6vs99019y'
DELETE FROM SYS.AUX_STATS$ WHERE SNAME = 'SYSSTATS_INFO'
END OF STMT
EXEC #140565938870544:c=102,e=102,p=0,cr=1,cu=8,mis=0,r=4,dep=1,og=1,plh=1692104539,tim=1832180745
CLOSE #140565938870544:c=0,e=0,dep=1,type=3,tim=1832180772
=====================
PARSING IN CURSOR #140565938867696 len=73 dep=1 uid=0 oct=2 lid=0 tim=1832180791 hv=454001916 ad='6a0f4e78' sqlid='d93t6tndhz17w'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_INFO', 'STATUS', NULL, :B1 )
END OF STMT
BINDS #140565938867696:

 Bind#0
  oacdty=01 mxl=32(30) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=7fd80eec1300  bln=32  avl=09  flg=09
  value="COMPLETED"
EXEC #140565938867696:c=0,e=51,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832180837
CLOSE #140565938867696:c=0,e=1,dep=1,type=3,tim=1832180848
=====================
PARSING IN CURSOR #140565938863400 len=73 dep=1 uid=0 oct=2 lid=0 tim=1832180858 hv=3821777836 ad='6a0f4b48' sqlid='2rtww83jwrcxc'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_INFO', 'DSTART', NULL, :B1 )
END OF STMT
BINDS #140565938863400:

 Bind#0
  oacdty=01 mxl=32(30) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=7fd80eec1320  bln=32  avl=16  flg=09
  value="12-16-2020 11:41"
EXEC #140565938863400:c=0,e=38,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832180892
CLOSE #140565938863400:c=0,e=1,dep=1,type=3,tim=1832180902
=====================
PARSING IN CURSOR #140565938858232 len=72 dep=1 uid=0 oct=2 lid=0 tim=1832180912 hv=912777027 ad='6a0f4818' sqlid='b1z10j0v6gru3'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_INFO', 'DSTOP', NULL, :B1 )
END OF STMT
BINDS #140565938858232:

 Bind#0
  oacdty=01 mxl=32(30) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=7fd80eec1340  bln=32  avl=16  flg=09
  value="12-16-2020 11:41"
EXEC #140565938858232:c=0,e=58,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832180966
CLOSE #140565938858232:c=0,e=0,dep=1,type=3,tim=1832180977
=====================
PARSING IN CURSOR #140565938855384 len=72 dep=1 uid=0 oct=2 lid=0 tim=1832180987 hv=994138424 ad='6a0f44e8' sqlid='2tj5x5hxn2q9s'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_INFO', 'FLAGS', :B1 , NULL)
END OF STMT
BINDS #140565938855384:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1360  bln=22  avl=02  flg=09
  value=1
EXEC #140565938855384:c=0,e=37,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832181020
CLOSE #140565938855384:c=0,e=0,dep=1,type=3,tim=1832181029
=====================
PARSING IN CURSOR #140565938848144 len=289 dep=1 uid=0 oct=2 lid=0 tim=1832181239 hv=383811924 ad='695e1c28' sqlid='33xdmccbf10an'
insert /* QOSH:SAV_SYS_STS */ into sys.wri$_optstat_aux_history (savtime, sname, pname, pval1, pval2) select :1, sname, pname, pval1, pval2  from sys.aux_stats$ where sname = 'SYSSTATS_MAIN' and not exists  (select /*+index(h) */ 1 from sys.wri$_optstat_aux_history h   where savtime = :2)
END OF STMT
PARSE #140565938848144:c=0,e=182,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=1832181239
BINDS #140565938848144:

 Bind#0
  oacdty=181 mxl=13(13) mxlc=00 mal=00 scl=09 pre=00
  oacflg=00 fl2=9000001 frm=00 csi=00 siz=32 off=0
  kxsbbbfp=7fd80f18fa78  bln=13  avl=13  flg=05
  value=16-DEC-20 11.41.38.448560000 AM +03:00
 Bind#1
  oacdty=181 mxl=13(13) mxlc=00 mal=00 scl=09 pre=00
  oacflg=00 fl2=9000001 frm=00 csi=00 siz=0 off=16
  kxsbbbfp=7fd80f18fa88  bln=13  avl=13  flg=01
  value=16-DEC-20 11.41.38.448560000 AM +03:00
EXEC #140565938848144:c=1737,e=1557,p=0,cr=5,cu=6,mis=1,r=9,dep=1,og=1,plh=333016110,tim=1832182819
STAT #140565938848144 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL  WRI$_OPTSTAT_AUX_HISTORY (cr=5 pr=0 pw=0 str=1 time=152 us)'
STAT #140565938848144 id=2 cnt=9 pid=1 pos=1 obj=0 op='FILTER  (cr=4 pr=0 pw=0 str=1 time=69 us)'
STAT #140565938848144 id=3 cnt=9 pid=2 pos=1 obj=644 op='TABLE ACCESS FULL AUX_STATS$ (cr=3 pr=0 pw=0 str=1 time=60 us cost=2 size=252 card=9)'
STAT #140565938848144 id=4 cnt=0 pid=2 pos=2 obj=684 op='INDEX RANGE SCAN I_WRI$_OPTSTAT_AUX_ST (cr=1 pr=0 pw=0 str=1 time=6 us cost=1 size=11 card=1)'
CLOSE #140565938848144:c=2,e=2,dep=1,type=0,tim=1832182915
=====================
PARSING IN CURSOR #140565938850216 len=56 dep=1 uid=0 oct=7 lid=0 tim=1832183028 hv=2821397124 ad='6a0f41b8' sqlid='a535pb2n2q6n4'
DELETE FROM SYS.AUX_STATS$ WHERE SNAME = 'SYSSTATS_MAIN'
END OF STMT
EXEC #140565938850216:c=74,e=74,p=0,cr=1,cu=13,mis=0,r=9,dep=1,og=1,plh=1692104539,tim=1832183028
CLOSE #140565938850216:c=1,e=1,dep=1,type=3,tim=1832183057
=====================
PARSING IN CURSOR #140565938845448 len=77 dep=1 uid=0 oct=2 lid=0 tim=1832183071 hv=928404322 ad='6a0f3e88' sqlid='67ncvpsvpcnv2'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'CPUSPEEDNW', :B1 , NULL)
END OF STMT
BINDS #140565938845448:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1460  bln=22  avl=03  flg=09
  value=2928
EXEC #140565938845448:c=45,e=45,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183111
CLOSE #140565938845448:c=1,e=1,dep=1,type=3,tim=1832183122
=====================
PARSING IN CURSOR #140565938842944 len=76 dep=1 uid=0 oct=2 lid=0 tim=1832183132 hv=543581576 ad='6a0f3b58' sqlid='auvf07wh6ctc8'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'IOSEEKTIM', :B1 , NULL)
END OF STMT
BINDS #140565938842944:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1478  bln=22  avl=02  flg=09
  value=10
EXEC #140565938842944:c=37,e=37,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183165
CLOSE #140565938842944:c=0,e=0,dep=1,type=3,tim=1832183174
=====================
PARSING IN CURSOR #140565938837432 len=77 dep=1 uid=0 oct=2 lid=0 tim=1832183184 hv=3127723828 ad='6a0f3828' sqlid='38gjx7kx6ujtn'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'IOTFRSPEED', :B1 , NULL)
END OF STMT
BINDS #140565938837432:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1490  bln=22  avl=03  flg=09
  value=204800
EXEC #140565938837432:c=36,e=36,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183216
CLOSE #140565938837432:c=0,e=0,dep=1,type=3,tim=1832183226
=====================
PARSING IN CURSOR #140565938834928 len=75 dep=1 uid=0 oct=2 lid=0 tim=1832183238 hv=1547970203 ad='6a0f34f8' sqlid='5ca6vx5f489nv'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'SREADTIM', :B1 , NULL)
END OF STMT
BINDS #140565938834928:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec14c0  bln=22  avl=00  flg=09
EXEC #140565938834928:c=33,e=33,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183268
CLOSE #140565938834928:c=1,e=1,dep=1,type=3,tim=1832183277
=====================
PARSING IN CURSOR #140565942665592 len=75 dep=1 uid=0 oct=2 lid=0 tim=1832183285 hv=2108722292 ad='6a0f21c8' sqlid='fm39amjyv133n'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'MREADTIM', :B1 , NULL)
END OF STMT
BINDS #140565942665592:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec14d8  bln=22  avl=00  flg=09
EXEC #140565942665592:c=44,e=44,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183326
CLOSE #140565942665592:c=0,e=0,dep=1,type=3,tim=1832183353
=====================
PARSING IN CURSOR #140565942663352 len=75 dep=1 uid=0 oct=2 lid=0 tim=1832183362 hv=4129833197 ad='6a0f1e98' sqlid='1rh50c7v2hh7d'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'CPUSPEED', :B1 , NULL)
END OF STMT
BINDS #140565942663352:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec14a8  bln=22  avl=00  flg=09
EXEC #140565942663352:c=37,e=37,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183396
CLOSE #140565942663352:c=0,e=0,dep=1,type=3,tim=1832183404
=====================
PARSING IN CURSOR #140565941835392 len=71 dep=1 uid=0 oct=2 lid=0 tim=1832183415 hv=4016519028 ad='6a0f1b68' sqlid='32kbjpmrqfdvn'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'MBRC', :B1 , NULL)
END OF STMT
BINDS #140565941835392:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec14f0  bln=22  avl=02  flg=09
  value=83
EXEC #140565941835392:c=72,e=73,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183483
CLOSE #140565941835392:c=0,e=0,dep=1,type=3,tim=1832183494
=====================
PARSING IN CURSOR #140565942331992 len=73 dep=1 uid=0 oct=2 lid=0 tim=1832183505 hv=941172397 ad='6a0f1838' sqlid='5nv8b5cw1k9pd'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'MAXTHR', :B1 , NULL)
END OF STMT
BINDS #140565942331992:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1508  bln=22  avl=00  flg=09
EXEC #140565942331992:c=34,e=35,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183536
CLOSE #140565942331992:c=0,e=0,dep=1,type=3,tim=1832183544
=====================
PARSING IN CURSOR #140565942329488 len=75 dep=1 uid=0 oct=2 lid=0 tim=1832183554 hv=3800693767 ad='6a0f1508' sqlid='b11g5kvj8mz07'
INSERT INTO SYS.AUX_STATS$ VALUES ('SYSSTATS_MAIN', 'SLAVETHR', :B1 , NULL)
END OF STMT
BINDS #140565942329488:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1520  bln=22  avl=00  flg=09
EXEC #140565942329488:c=39,e=39,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=1,plh=0,tim=1832183590
CLOSE #140565942329488:c=0,e=0,dep=1,type=3,tim=1832183598
=====================
PARSING IN CURSOR #140565938847952 len=6 dep=1 uid=0 oct=44 lid=0 tim=1832183612 hv=255718823 ad='0' sqlid='8ggw94h7mvxd7'
COMMIT
END OF STMT
PARSE #140565938847952:c=4,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832183612
XCTEND rlbk=0, rd_only=0, tim=1832183632
EXEC #140565938847952:c=68,e=68,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=0,plh=0,tim=1832183697
CLOSE #140565938847952:c=1,e=1,dep=1,type=3,tim=1832183708
=====================
PARSING IN CURSOR #140565942376648 len=56 dep=1 uid=0 oct=7 lid=0 tim=1832184015 hv=885923863 ad='6a0f11d8' sqlid='0v4vphwucw80r'
DELETE FROM SYS.AUX_STATS$ WHERE SNAME = 'SYSSTATS_TEMP'
END OF STMT
EXEC #140565942376648:c=26,e=26,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=1,plh=1692104539,tim=1832184015
CLOSE #140565942376648:c=0,e=0,dep=1,type=3,tim=1832184057
PARSE #140565938847952:c=1,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184067
XCTEND rlbk=0, rd_only=1, tim=1832184075
EXEC #140565938847952:c=10,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184082
CLOSE #140565938847952:c=0,e=0,dep=1,type=3,tim=1832184088
PARSE #140565938847952:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184095
XCTEND rlbk=0, rd_only=1, tim=1832184101
EXEC #140565938847952:c=5,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184105
CLOSE #140565938847952:c=0,e=0,dep=1,type=3,tim=1832184109
PARSE #140565938847952:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184114
XCTEND rlbk=0, rd_only=1, tim=1832184119
EXEC #140565938847952:c=4,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184123
CLOSE #140565938847952:c=0,e=0,dep=1,type=3,tim=1832184127
=====================
PARSING IN CURSOR #140565941082320 len=138 dep=1 uid=0 oct=6 lid=0 tim=1832184143 hv=113741489 ad='67962b28' sqlid='0kygk503cg3pj'
UPDATE /*+ OPT_PARAM('_parallel_syspls_obey_force' 'false') */ WRI$_OPTSTAT_OPR SET STATUS = :B2 , END_TIME = SYSTIMESTAMP WHERE ID = :B1
END OF STMT
BINDS #140565941082320:

 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=646f5560  bln=22  avl=02  flg=09
  value=2
 Bind#1
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7fd80eec1fa8  bln=22  avl=03  flg=09
  value=583
EXEC #140565941082320:c=146,e=146,p=0,cr=1,cu=3,mis=0,r=1,dep=1,og=1,plh=2375226716,tim=1832184282
CLOSE #140565941082320:c=1,e=1,dep=1,type=3,tim=1832184303
PARSE #140565938847952:c=1,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184311
XCTEND rlbk=0, rd_only=0, tim=1832184334
EXEC #140565938847952:c=116,e=116,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=0,plh=0,tim=1832184448
CLOSE #140565938847952:c=0,e=0,dep=1,type=3,tim=1832184458
EXEC #140565942129688:c=45819,e=121939,p=0,cr=52,cu=82,mis=0,r=1,dep=0,og=1,plh=0,tim=1832184484

*** 2020-12-16T11:42:17.944697+03:00 (PDB1(3))
CLOSE #140565942129688:c=15,e=15,dep=0,type=1,tim=1871677173
=====================
PARSING IN CURSOR #140565941051688 len=68 dep=0 uid=0 oct=42 lid=0 tim=1871677421 hv=222310797 ad='0' sqlid='bb055g46n0ccd'
alter session set events '10046 trace name context forever, level 0'
END OF STMT
PARSE #140565941051688:c=186,e=186,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1871677420
EXEC #140565941051688:c=199,e=199,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1871677646

*** 2020-12-16T11:42:54.340753+03:00 (PDB1(3))
CLOSE #140565941051688:c=15,e=15,dep=0,type=1,tim=1908073209

*** 2020-12-16T11:42:54.341135+03:00 (PDB1(3))
Processing Oradebug command 'help'

*** 2020-12-16T11:42:54.341299+03:00 (PDB1(3))

The number of Exadata storage indexes raised to 24 per table

" ... the limit of 8 has been lifted in recent versions of the Exadata software up to 24."

 https://connor-mcdonald.com/2019/11/19/exadata-storage-indexes/

USE_LARGE_PAGES=AUTO_ONLY

 Interesting new feature:

USE_LARGE_PAGES=AUTO_ONLY - database calculates how many HugePages are needed
to create the SGA and RECONFIGURES(!) the total number of HugePages in the operating system.
If there are no pre-provisioned HugePages on the system, then the database automatically
requests the amount of HugePages it needs from the operating system.
If the request is successful, then the database start up proceeds.
If the operating system cannot find enough HugePages to satisfy the request for the database,
then the database start up fails.

Soon we will live on Linux as well as on large Unixes :))))

Also it would be good idea to do the correctly working TransparentHuge Pages in Linux.

Slow DataPump impdp, wait event is "wait for unread message on broadcast channel"

The customer complains about slow import. 

The import was going about 40h at METADATA ONLY mode. The CPU consumption is about 0. Database alert log shows no errors, but simetime 

*************************
NI cryptographic checksum mismatch error: 12599.

  VERSION INFORMATION:
        TNS for Linux: Version 19.0.0.0.0 - Production
        Oracle Bequeath NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
        TCP/IP NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
  Version 19.3.0.0.0
  Time: 06-OCT-2020 17:05:00
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12599

TNS-12599: TNS:cryptographic checksum mismatch
    ns secondary err code: 12656
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
2020-10-06T17:10:00.113924+03:00
*************************

Is the import actually running? Check DBA_DATAPUMP_JOBS to find out:

select owner_name, job_name, operation, job_mode
from dba_datapump_jobs
where state='EXECUTING' ;

Which gives something like:

OWNER_NAME JOB_NAME           OPERATION JOB_MODE
---------- ------------------ --------- --------
   ...     SYS_IMPORT_FULL_01 IMPORT    FULL

Yes, at least one full import job is running. Good news. 

Do we have any sessions running though?

select owner_name, job_name, session_type
from dba_datapump_sessions;

And we see this:

OWNER_NAME JOB_NAME           SESSION_TYPE
---------- ------------------ -------------
   ...     SYS_IMPORT_FULL_01 DBMS_DATAPUMP
   ...     SYS_IMPORT_FULL_01 MASTER
   ...     SYS_IMPORT_FULL_01 WORKER
   ...     SYS_IMPORT_FULL_01 WORKER
   ...     SYS_IMPORT_FULL_01 WORKER
   ...     SYS_IMPORT_FULL_01 WORKER

What import's sessions are doing? Let check the wait event:

select v.status,v.inst_id,v.sid,v.serial#,io.block_changes,event
from gv$sess_io io, gv$session v
where io.sid = v.sid
and v.saddr in (
    select saddr
    from dba_datapump_sessions
) order by inst_id,sid;


STATUS      SID     SERIAL#    BLOCK_CHANGES    EVENT                                      
--------    ----    -------    -------------    --------------------------------------------
ACTIVE      82      31744      90864            wait for unread message on broadcast channel
INACTIVE    102     44694      722              SQL*Net message from client
ACTIVE      2396    7781       169755           wait for unread message on broadcast channel
ACTIVE      2410    11021      241385           wait for unread message on broadcast channel


select s.inst_id,s.sid,s.module,s.state,
       substr(s.event, 1, 21) as event,
       s.seconds_in_wait as secs,
       substr(sql.sql_text, 1, 30) as sql_text
from gv$session s
join gv$sql sql on sql.sql_id = s.sql_id
where s.module like 'Data Pump%'
order by s.inst_id, s.module, s.sid;

INST_ID    SID     MODULE              STATE      EVENT                    SECS    SQL_TEXT                     
-------    ----    ----------------    -------    ---------------------    ----    ------------------------------
1          82      Data Pump Worker    WAITING    wait for unread messa    1       BEGIN :1 := sys.kupc$que_int.t
1          82      Data Pump Worker    WAITING    wait for unread messa    1       BEGIN :1 := sys.kupc$que_int.t
1          82      Data Pump Worker    WAITING    wait for unread messa    1       BEGIN :1 := sys.kupc$que_int.t
1          2396    Data Pump Worker    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.t
1          2396    Data Pump Worker    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.t
1          2396    Data Pump Worker    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.t
1          2410    Data Pump Worker    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.t
1          2410    Data Pump Worker    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.t
1          2410    Data Pump Worker    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.t
2          54      Data Pump Master    WAITING    wait for unread messa    0       BEGIN :1 := sys.kupc$que_int.r
2          34      Data Pump Worker    WAITING    wait for unread messa    4       BEGIN :1 := sys.kupc$que_int.t
2          34      Data Pump Worker    WAITING    wait for unread messa    4       BEGIN :1 := sys.kupc$que_int.t
2          34      Data Pump Worker    WAITING    wait for unread messa    4       BEGIN :1 := sys.kupc$que_int.t
2          61      Data Pump Worker    WAITING    wait for unread messa    4       BEGIN :1 := sys.kupc$que_int.t
2          61      Data Pump Worker    WAITING    wait for unread messa    4       BEGIN :1 := sys.kupc$que_int.t
2          61      Data Pump Worker    WAITING    wait for unread messa    4       BEGIN :1 := sys.kupc$que_int.t
2          2358    Data Pump Worker    WAITING    wait for unread messa    5       BEGIN :1 := sys.kupc$que_int.t
2          2358    Data Pump Worker    WAITING    wait for unread messa    5       BEGIN :1 := sys.kupc$que_int.t
2          2358    Data Pump Worker    WAITING    wait for unread messa    5       BEGIN :1 := sys.kupc$que_int.t
2          2394    Data Pump Worker    WAITING    wait for unread messa    3       BEGIN :1 := sys.kupc$que_int.t
2          2394    Data Pump Worker    WAITING    wait for unread messa    3       BEGIN :1 := sys.kupc$que_int.t
2          2394    Data Pump Worker    WAITING    wait for unread messa    3       BEGIN :1 := sys.kupc$que_int.t

What the wait event "wait for unread message on broadcast channel" is?  I've found no useful information in the MOS or in the internet.

What is system doing?

select * from (
select event,p1,p2,p3,count(*)
from V$ACTIVE_SESSION_HISTORY
where sample_time> (sysdate-1/24)
group by event,p1,p2,p3
order by count(*) desc)
where rownum <10;

EVENT                           P1              P2              P3              COUNT(*)
----------------------------    ------------    ------------    ------------    --------
                                1213661190      7               7552            4
                                0               0               0               2
Sync ASM rebalance              0               0               0               2
                                102400588528    60691899808     0               2
                                100             0               0               1
control file sequential read    0               56              1               1
                                3456712662      425201762304    21474836480     1
                                268566527       1               100263033448    1
                                268632063       1               101462207064    1

It looks like the system is doing nothing !

Datapump Worker DW00:

select inst_id,session_id,  session_state,count(*)
from GV$ACTIVE_SESSION_HISTORY
where sample_time> (sysdate-1/24)
and session_id = 2396 and   inst_id=1
group by inst_id,session_id,  session_state;

INST_ID    SESSION_ID    SESSION_STATE    COUNT(*)
-------    ----------    -------------    --------
1          2396          ON CPU           1

Datapump Master:

select inst_id,session_id,  session_state,count(*)
 from GV$ACTIVE_SESSION_HISTORY
where sample_time> (sysdate-1/24)
and session_id = 54  and   inst_id=2
group by inst_id,session_id,  session_state;

INST_ID    SESSION_ID    SESSION_STATE    COUNT(*)
-------    ----------    -------------    --------
2          54            WAITING          3

Which objects are createing now? We see the VIEW is last:

select * from dba_objects
order by created desc

OBJECT_NAME                       OBJECT_TYPE    CREATED           
------------------------------    -----------    -------------------
items_MYSQL_MATRIX_rv             VIEW           06.10.2020 17:10:29
replenishments_MYSQL_MATRIX_rv    VIEW           06.10.2020 16:52:45
bb_PROCUREMENT                    VIEW           06.10.2020 16:35:08
XXWH_ONHAND_QUANTITIES_INC        VIEW           06.10.2020 16:35:07
bb_xxwh_repairs_v                 VIEW           06.10.2020 16:35:07
xxwh_repairs_v                    VIEW           06.10.2020 16:35:07

 

New messages in alert log are:

*************************
NI cryptographic checksum mismatch error: 12599.

  VERSION INFORMATION:
        TNS for Linux: Version 19.0.0.0.0 - Production
        Oracle Bequeath NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
        TCP/IP NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
  Version 19.3.0.0.0
  Time: 06-OCT-2020 17:05:00
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12599

TNS-12599: TNS:cryptographic checksum mismatch
    ns secondary err code: 12656
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
2020-10-06T17:10:00.113924+03:00
*************************

The reason is: during the creation of a view, a remote object is accessed via database link.
If remote database is unavailable, then TCP timeout = 600 seconds occurs.
After the timeout expires, an error is written to the alert log.
And the import moves to the next view.


After DBA has configured the access to the remote database the import completed in 5 minutes.

gridSetup.sh -applyRU ERROR: The home is not clean. This home cannot be used since there was a failed OPatch execution in this home. Use a different home to proceed.

I plan to install RAC VM on my notebook. I created new VM from Oracle Linux 7.7 and unzipped 19.3 Grid home and need to apply 19.7 RU.

During the gridSetup.sh -applyRU procedure we sometime may obtain a failing message:

$ ./gridSetup.sh -silent -applyRU /stage/30899722

ERROR: The home is not clean. This home cannot be used since there was a failed OPatch execution in this home. Use a different home to proceed.

And some bloggers may give you the advice: "When the command gridSetup.sh fails,  it makes the NEW_HOME unusable. The only way to get around this issue currently is to clean the contents out of that HOME , and unzip the gold image again. "

There is another solution: add the Grid home to oraInventory and use the opatch apply.

I have fresh Oracle Linux 7.7. VM and Grid 19.3 base image and 19.7 patch.

 

[grid@node1 grid]$ opatch lspatches
Argument(s) Error... Oracle Home's central inventory is not found.
Please check the arguments and try again.
OPatch failed with error code 135

This error because there is no Grid home in fresh VM.

So we need to register Grid home in  Central Inventory.

[grid@node1 grid]$ mkdir /u01/app/oraInventory
 

[grid@node1 grid]$ $OH/oui/bin/runInstaller -silent -attachHome ORACLE_HOME="/u01/app/19.0.0/grid" ORACLE_HOME_NAME="OraGI197Home1" CRS="true"
 

Starting Oracle Universal Installer...

Checking swap space: must be greater than 500 MB.   Actual 5118 MB    Passed
The inventory pointer is located at /etc/oraInst.loc
You can find the log of this install session at:
 /u01/app/oraInventory/logs/AttachHome2020-09-09_10-13-14PM.log
Please execute the '/u01/app/oraInventory/orainstRoot.sh' script at the end of the session.
'AttachHome' was successful.
 

 [grid@node1 30899722]$ pwd
/stage/30899722

[grid@node1 30899722]$ ll
total 132
drwxr-x--- 5 grid oinstall     81 Apr 11 01:16 30869156
drwxr-x--- 5 grid oinstall     62 Apr 11 01:18 30869304
drwxr-x--- 5 grid oinstall     62 Apr 11 01:19 30894985
drwxr-x--- 4 grid oinstall     48 Apr 11 01:18 30898856
drwxr-x--- 2 grid oinstall   4096 Apr 11 01:20 automation
-rw-rw-r-- 1 grid oinstall   5054 Apr 11 04:37 bundle.xml
-rw-r--r-- 1 grid oinstall 122266 Apr 11 04:25 README.html
-rw-r--r-- 1 grid oinstall      0 Apr 11 01:20 README.txt

[grid@node1 30898856]$ opatch apply
Oracle Interim Patch Installer version 12.2.0.1.21
Copyright (c) 2020, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/19.0.0/grid
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/19.0.0/grid/oraInst.loc
OPatch version    : 12.2.0.1.21
OUI version       : 12.2.0.7.0
Log file location : /u01/app/19.0.0/grid/cfgtoollogs/opatch/opatch2020-09-12_15-42-19PM_1.log

Verifying environment and performing prerequisite checks...
OPatch continues with these patches:   30898856

Do you want to proceed? [y|n]
y
User Responded with: Y
All checks passed.

Please shutdown Oracle instances running out of this ORACLE_HOME on the local system.
(Oracle Home = '/u01/app/19.0.0/grid')


Is the local system ready for patching? [y|n]
y
User Responded with: Y
Backing up files...
Applying interim patch '30898856' to OH '/u01/app/19.0.0/grid'

Patching component oracle.tomcat.crs, 19.0.0.0.0...
Patch 30898856 successfully applied.
Sub-set patch [29401763] has become inactive due to the application of a super-set patch [30898856].
Please refer to Doc ID 2161861.1 for any possible further required actions.
Log file location: /u01/app/19.0.0/grid/cfgtoollogs/opatch/opatch2020-09-12_15-42-19PM_1.log

OPatch succeeded.

Next patch 30898856:

[grid@node1 30899722]$ ll
drwxr-x--- 5 grid oinstall     81 Apr 11 01:16 30869156
drwxr-x--- 5 grid oinstall     62 Apr 11 01:18 30869304
drwxr-x--- 5 grid oinstall     62 Apr 11 01:19 30894985
drwxr-x--- 4 grid oinstall     48 Apr 11 01:18 30898856
drwxr-x--- 2 grid oinstall   4096 Apr 11 01:20 automation
-rw-rw-r-- 1 grid oinstall   5054 Apr 11 04:37 bundle.xml
-rw-r--r-- 1 grid oinstall 122266 Apr 11 04:25 README.html
-rw-r--r-- 1 grid oinstall      0 Apr 11 01:20 README.txt
 

[grid@node1 30899722]$ pwd
/stage/30899722

[grid@node1 30899722]$ opatch lspatches
30898856;TOMCAT RELEASE UPDATE 19.0.0.0.0 (30898856)
29585399;OCW RELEASE UPDATE 19.3.0.0.0 (29585399)
29517247;ACFS RELEASE UPDATE 19.3.0.0.0 (29517247)
29517242;Database Release Update : 19.3.0.0.190416 (29517242)

OPatch succeeded.
 

[grid@node1 30899722]$ cd 30869304
[grid@node1 30869304]$ opatch apply
Oracle Interim Patch Installer version 12.2.0.1.21
Copyright (c) 2020, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/19.0.0/grid
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/19.0.0/grid/oraInst.loc
OPatch version    : 12.2.0.1.21
OUI version       : 12.2.0.7.0
Log file location : /u01/app/19.0.0/grid/cfgtoollogs/opatch/opatch2020-09-12_16-17-11PM_1.log

Verifying environment and performing prerequisite checks...
OPatch continues with these patches:   30869304

Do you want to proceed? [y|n]
y
User Responded with: Y
All checks passed.

Please shutdown Oracle instances running out of this ORACLE_HOME on the local system.
(Oracle Home = '/u01/app/19.0.0/grid')


Is the local system ready for patching? [y|n]
y
User Responded with: Y
Backing up files...
Applying interim patch '30869304' to OH '/u01/app/19.0.0/grid'

Patching component oracle.usm, 19.0.0.0.0...
Patch 30869304 successfully applied.
Sub-set patch [29517247] has become inactive due to the application of a super-set patch [30869304].
Please refer to Doc ID 2161861.1 for any possible further required actions.
Log file location: /u01/app/19.0.0/grid/cfgtoollogs/opatch/opatch2020-09-12_16-17-11PM_1.log

OPatch succeeded.

[grid@node1 30869304]$ opatch lspatches
30869304;ACFS RELEASE UPDATE 19.7.0.0.0 (30869304)
30898856;TOMCAT RELEASE UPDATE 19.0.0.0.0 (30898856)
29585399;OCW RELEASE UPDATE 19.3.0.0.0 (29585399)
29517242;Database Release Update : 19.3.0.0.190416 (29517242)

OPatch succeeded.

...

And after apply all 4 patches:

[grid@node1 30869156]$ opatch lspatches
30869156;Database Release Update : 19.7.0.0.200414 (30869156)
30894985;OCW RELEASE UPDATE 19.7.0.0.0 (30894985)
30869304;ACFS RELEASE UPDATE 19.7.0.0.0 (30869304)
30898856;TOMCAT RELEASE UPDATE 19.0.0.0.0 (30898856)

And the last step - Detach Grid home from Central Inventory:

[grid@node1 30869156]$ $OH/oui/bin/runInstaller -silent -detachHome ORACLE_HOME="/u01/app/19.0.0/grid" ORACLE_HOME_NAME="OraGI197Home1"
Starting Oracle Universal Installer...

Checking swap space: must be greater than 500 MB.   Actual 5118 MB    Passed
The inventory pointer is located at /etc/oraInst.loc
You can find the log of this install session at:
 /u01/app/oraInventory/logs/DetachHome2020-09-12_04-33-16PM.log
'DetachHome' was successful.

$ opatch lspatches
Inventory load failed... LsPatchesSession::loadAndPrintInstalledPatch()
LsPatchesSession failed: OPatch failed to locate Central Inventory.
Possible causes are:
    The Central Inventory is corrupted
    The oraInst.loc file specified is not valid.

OPatch failed with error code 2

I'm not sure the way described above is suppported solution.

The solution give us the Note Executing "gridSetup.sh" Fails with "ERROR: The home is not clean" (Doc ID 2279633.1)

ORA-12152: TNS: Unable to send break message

 The new Exadata customer came with a problem "ORA-12152: TNS: Unable to send break message".  (What is the in-band breaking and out-of-band breaking we know from Tanel Poder's post:
https://tanelpoder.com/2008/02/05/oracle-hidden-costs-revealed-part-1/ ).

The customer say: 

"  We're testing upgrade to Oracle 19c from 11.2.0.4. And on 19c we got a problem with interrupting the connection between the application (pl/sql developer, sqlplus) on the client machine and the Oracle database: ORA-12152: TNS: Unable to send break message.

This problem is show stopper to upgrade to 19c!

The connection between the application (pl / sql developer, sqlplus) on the client machine and the process on the Oracle server is interrupted if the client application does not generate traffic for 60 minutes. The application is waiting for a response from the long procedure. After the procedure on the server is actually finished, the application is still waiting for the procedure to complete. When trying to interrupt the connection from the application side, we get ORA-12152: TNS: Unable to send break message (Cause: Unable to send break message).

Network engineers don't see any problems.

Simple test case show this problem:

begin
 dbms_lock.sleep(3590);
end;
/
Finished successully.
 

But

begin
 dbms_lock.sleep(3610);
end;
/
is finished unsuccessfully. 

 "

Thanks to the detailed description, the customer's problem became clear. It is not a In-Band or OOB breaking. It is actually Dead Connection Detection : DCD was enchanced in 12c to reduce detection time.

DCD is mechanism which allow the RDBMS server to check if the client is alive.

This feature is configured on server side using sqlnet.expire_time in sqlnet.ora. The probe packet is sent to the client side every sqlnet.expire_time minutes. If database server have got an error then client is dead and server can close this connection. In pre-12c releases this work was done by NS layer in SQL*Net . 

The 12c mechanism is intended to reduce the detection time and minimize load from RDBMS. This new mechanism is based on the TCP-keepalive property of the socket. With this approach TCP-keepalive probes are sent by OS after the connection has been idle for some time. Because these probes are implemented on the OS level then RDBMS rely on socket state (don't need send its own probes).

But in 12c we still able to use the sqlnet.expire_time.
After the customer have set sqlnet.expire_time=10 the error "ORA-12152: TNS: Unable to send break message" disappeared.

  

inmemory_force = CELLMEMORY_LEVEL

The Oracle Database InMemory feature requires the amount of physical memory from the database server to place IM Cache and some amount CPU resources.

The Exadata has the ability to use InMemory database feature on the cells. To use InMemory feature on cells you should enable the INMEMORY_SIZE at the Database nodes. So, Exadata owners still need to spend the amount of physical memory on the Database servers and memory on the cells.

The 19.8 PSU have brought the new great feature: inmemory_force = CELLMEMORY_LEVEL which offload 100% IM load to the cell level that significantly improve offloading for IM operations.

Starting with PSU 19.8, you can use the CellMemory feature without enabling the IM column store on the DB level. Starting with PSU 19.8 you can use combination of parameters

INMEMORY_FORCE=CELLMEMORY_LEVEL +  INMEMORY_SIZE=0

to enable IM column store at cell level and minimize IM Cache memory consumption at DB level.

From my point of view this feature will greatly improve the scalability of Exadata database machine for IM operations, because the more cells the more physical memory, IM-cache and CPU cores. This feature bring the more value to the Exadata cells.

 

Optimal Redo Log Size