Mining Autoupgrade Results

Posted in: Technical Track

We wanted to define a consistent process for upgrading databases using an autoupgrade method for single instance databases:

Create directory for autoupgrade/log: $ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log, where $ORACLE_UNQNAME=db_unique_name

Create upgrade.config as shown: $ORACLE_BASE/admin/$ORACLE_UNQNAME/${ORACLE_UNQNAME}_upgrade.config


global.autoupg_log_dir=$ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log
upg1.log_dir=$ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log
upg1.dbname=$ORACLE_UNQNAME
upg1.sid=$ORACLE_SID
upg1.start_time=NOW
upg1.source_home=/oracle/app/product/11.2/dbhome_1
upg1.target_home=/oracle/app/product/12.2/dbhome_1
upg1.upgrade_node=localhost
upg1.target_version=12.2
upg1.timezone_upg=no
upg1.restoration=yes

Let’s take a took at summary for autograde job process 102.

Find autoupgrade directories:

$ export JOBNO=102
$ ls -l $ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log/*/*/*
-rwx------    1 oracle   dba           73349 Nov 04 12:46 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/100/autoupgrade_20191104.log
-rwx------    1 oracle   dba             233 Nov 04 12:46 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/100/autoupgrade_20191104_user.log
-rwx------    1 oracle   dba               0 Nov 04 12:46 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/100/autoupgrade_err.log
-rwx------    1 oracle   dba           71390 Nov 04 13:07 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/101/autoupgrade_20191104.log
-rwx------    1 oracle   dba             233 Nov 04 13:06 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/101/autoupgrade_20191104_user.log
-rwx------    1 oracle   dba               0 Nov 04 13:06 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/101/autoupgrade_err.log
-rwx------    1 oracle   dba          891207 Nov 04 16:01 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/autoupgrade_20191104.log
-rwx------    1 oracle   dba           12371 Nov 04 16:01 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/autoupgrade_20191104_user.log
-rwx------    1 oracle   dba             245 Nov 04 15:50 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/autoupgrade_err.log
-rwx------    1 oracle   dba            1118 Nov 04 12:46 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/after_upgrade_pfile_ORACLE_SID.ora
-rwx------    1 oracle   dba               0 Nov 04 14:05 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID.restart
-rwx------    1 oracle   dba            2236 Nov 04 15:48 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID_autocompile.sql
-rwx------    1 oracle   dba           16805 Nov 04 13:52 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID_catnoamd.sql
-rwx------    1 oracle   dba            3685 Nov 04 13:56 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID_catnoexf.sql
-rwx------    1 oracle   dba           19753 Nov 04 13:56 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID_catnorul.sql
-rwx------    1 oracle   dba           20740 Nov 04 13:54 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID_emremove.sql
-rwx------    1 oracle   dba             883 Nov 04 15:48 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/ORACLE_SID_objcompare.sql
-rwx------    1 oracle   dba            1118 Nov 04 12:46 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/before_upgrade_pfile_ORACLE_SID.ora
-rwx------    1 oracle   dba            1168 Nov 04 14:00 ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/temp/during_upgrade_pfile_ORACLE_SID.ora

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/100/prechecks:
total 376
-rwx------    1 oracle   dba            2781 Nov 04 12:46 ORACLE_SID_checklist.cfg
-rwx------    1 oracle   dba            9328 Nov 04 12:46 ORACLE_SID_checklist.json
-rwx------    1 oracle   dba            9962 Nov 04 12:46 ORACLE_SID_checklist.xml
-rwx------    1 oracle   dba           25980 Nov 04 12:46 ORACLE_SID_preupgrade.html
-rwx------    1 oracle   dba           10018 Nov 04 12:46 ORACLE_SID_preupgrade.log
-rwx------    1 oracle   dba          121687 Nov 04 12:46 prechecks_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/101/prechecks:
total 376
-rwx------    1 oracle   dba            2781 Nov 04 13:07 ORACLE_SID_checklist.cfg
-rwx------    1 oracle   dba            9328 Nov 04 13:07 ORACLE_SID_checklist.json
-rwx------    1 oracle   dba            9962 Nov 04 13:07 ORACLE_SID_checklist.xml
-rwx------    1 oracle   dba           25980 Nov 04 13:07 ORACLE_SID_preupgrade.html
-rwx------    1 oracle   dba           10018 Nov 04 13:07 ORACLE_SID_preupgrade.log
-rwx------    1 oracle   dba          121687 Nov 04 13:07 prechecks_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/dbupgrade:
total 446064
-rwx------    1 oracle   dba           13059 Nov 04 15:48 autoupgrade20191104135121ORACLE_SID.log
-rwx------    1 oracle   dba           12042 Nov 04 15:48 ORACLE_SID_autocompile20191104135121ORACLE_SID0.log
-rwx------    1 oracle   dba             551 Nov 04 15:48 ORACLE_SID_autocompile20191104135121ORACLE_SID_catcon_10617264.lst
-rwx------    1 oracle   dba       208215073 Nov 04 15:48 catupgrd20191104135121ORACLE_SID0.log
-rwx------    1 oracle   dba         7481470 Nov 04 15:46 catupgrd20191104135121ORACLE_SID1.log
-rwx------    1 oracle   dba         5527017 Nov 04 15:46 catupgrd20191104135121ORACLE_SID2.log
-rwx------    1 oracle   dba         7040784 Nov 04 15:46 catupgrd20191104135121ORACLE_SID3.log
-rwx------    1 oracle   dba             527 Nov 04 14:01 catupgrd20191104135121ORACLE_SID_catcon_17039806.lst
-rwx------    1 oracle   dba               0 Nov 04 15:23 catupgrd20191104135121ORACLE_SID_datapatch_normal.err
-rwx------    1 oracle   dba            1050 Nov 04 15:46 catupgrd20191104135121ORACLE_SID_datapatch_normal.log
-rwx------    1 oracle   dba               0 Nov 04 15:17 catupgrd20191104135121ORACLE_SID_datapatch_upgrade.err
-rwx------    1 oracle   dba             702 Nov 04 15:18 catupgrd20191104135121ORACLE_SID_datapatch_upgrade.log
-rwx------    1 oracle   dba            9877 Nov 04 15:18 during_upgrade_pfile_catctl.ora
-rwx------    1 oracle   dba           32649 Nov 04 14:01 phase.log
-rwx------    1 oracle   dba            1489 Nov 04 15:48 upg_summary.log
-rwx------    1 oracle   dba              46 Nov 04 15:48 upg_summary_report.log
-rwx------    1 oracle   dba             408 Nov 04 15:48 upg_summary_report.pl

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/drain:
total 16
-rwx------    1 oracle   dba            4952 Nov 04 14:01 drain_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/postchecks:
total 104
-rwx------    1 oracle   dba             969 Nov 04 15:50 ORACLE_SID_checklist.cfg
-rwx------    1 oracle   dba            3202 Nov 04 15:50 ORACLE_SID_checklist.json
-rwx------    1 oracle   dba            3395 Nov 04 15:50 ORACLE_SID_checklist.xml
-rwx------    1 oracle   dba           16916 Nov 04 15:50 ORACLE_SID_postupgrade.html
-rwx------    1 oracle   dba            3383 Nov 04 15:50 ORACLE_SID_postupgrade.log
-rwx------    1 oracle   dba           14861 Nov 04 15:50 postchecks_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/postfixups:
total 40
-rwx------    1 oracle   dba           14864 Nov 04 16:00 postchecks_ORACLE_SID.log
-rwx------    1 oracle   dba            3262 Nov 04 15:59 postfixups_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/postupgrade:
total 24
-rwx------    1 oracle   dba           10177 Nov 04 16:01 postupgrade.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/prechecks:
total 376
-rwx------    1 oracle   dba            2781 Nov 04 13:52 ORACLE_SID_checklist.cfg
-rwx------    1 oracle   dba            9328 Nov 04 13:52 ORACLE_SID_checklist.json
-rwx------    1 oracle   dba            9962 Nov 04 13:52 ORACLE_SID_checklist.xml
-rwx------    1 oracle   dba           25980 Nov 04 13:52 ORACLE_SID_preupgrade.html
-rwx------    1 oracle   dba           10018 Nov 04 13:52 ORACLE_SID_preupgrade.log
-rwx------    1 oracle   dba          121687 Nov 04 13:51 prechecks_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/prefixups:
total 304
-rwx------    1 oracle   dba          121708 Nov 04 14:00 prechecks_ORACLE_SID.log
-rwx------    1 oracle   dba           32727 Nov 04 14:00 prefixups_ORACLE_SID.log

ORACLE_BASE/admin/ORACLE_UNQNAME/autoupgrade/102/preupgrade:
total 8
-rwx------    1 oracle   dba              98 Nov 04 13:51 preupgrade.log

/orahome/oracle/app/admin/ORACLE_SID/autoupgrade/log/cfgtoollogs/upgrade/auto:
total 880
-rwx------    1 oracle   dba          414589 Nov 04 16:01 autoupgrade.log
-rwx------    1 oracle   dba             780 Nov 04 13:00 autoupgrade_err.log
-rwx------    1 oracle   dba            3113 Nov 04 16:01 autoupgrade_user.log
drwx------    2 oracle   dba            4096 Nov 04 14:01 config_files
drwx------    2 oracle   dba             256 Nov 04 16:01 lock
-rwx------    1 oracle   dba           12381 Nov 04 16:01 state.html
drwx------    2 oracle   dba            4096 Nov 04 16:01 status
$

Find timing for autoupgrade process:

$ tail -12 `ls $ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log/$ORACLE_UNQNAME/$JOBNO/autoupgrade*.log|egrep -v 'user|err'`
2019-11-04 16:01:21.082 INFO ----------------------Stages  Summary------------------------ - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.082 INFO     SETUP             <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.083 INFO     PREUPGRADE        <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.083 INFO     PRECHECKS         <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.083 INFO     GRP               <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.084 INFO     PREFIXUPS         8 min                                   - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.084 INFO     DRAIN             <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.084 INFO     DBUPGRADE         108 min                                 - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.085 INFO     POSTCHECKS        <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.085 INFO     POSTFIXUPS        9 min                                   - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.086 INFO     POSTUPGRADE       <1 min                                  - DispatcherOSHelper.writeStageSummary
2019-11-04 16:01:21.086 INFO End of dispatcher instance for ORACLE_SID - AutoUpgDispatcher.run

Find timing for database upgrade:

$ tail -35 $ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log/$ORACLE_UNQNAME/102/dbupgrade/catupgrd*${ORACLE_UNQNAME}0.log
========== PROCESS ENDED ==========
SQL> Disconnected from Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

Start of Summary Report
------------------------------------------------------

Oracle Database 12.2 Post-Upgrade Status Tool           11-04-2019 15:46:14

Component                               Current         Version  Elapsed Time
Name                                    Status          Number   HH:MM:SS

Oracle Server                          UPGRADED      12.2.0.1.0  00:19:53
JServer JAVA Virtual Machine           UPGRADED      12.2.0.1.0  00:07:34
Oracle Workspace Manager               UPGRADED      12.2.0.1.0  00:02:16
OLAP Analytic Workspace                UPGRADED      12.2.0.1.0  00:00:23
Oracle OLAP API                        UPGRADED      12.2.0.1.0  00:00:23
Oracle XDK                             UPGRADED      12.2.0.1.0  00:01:15
Oracle Text                            UPGRADED      12.2.0.1.0  00:01:24
Oracle XML Database                    UPGRADED      12.2.0.1.0  00:05:28
Oracle Database Java Packages          UPGRADED      12.2.0.1.0  00:00:25
Oracle Multimedia                      UPGRADED      12.2.0.1.0  00:03:25
Spatial                                UPGRADED      12.2.0.1.0  00:09:03
Oracle Application Express             UPGRADED     5.0.4.00.12  00:23:17
Final Actions                                                    00:04:44
Post Upgrade                                                     00:00:09

Total Upgrade Time: 01:20:32

Database time zone version is 14. It is older than current release time
zone version 26. Time zone upgrade is needed using the DBMS_DST package.

Grand Total Upgrade Time:    [0d:1h:47m:34s]

End of Summary Report
------------------------------------------------------
$

Find timing for datapatch:

$ cat $ORACLE_BASE/admin/$ORACLE_UNQNAME/autoupgrade/log/$ORACLE_UNQNAME/$JOBNO/dbupgrade/catupgrd*datapatch_normal.log
SQL Patching tool version 12.2.0.1.0 Production on Mon Nov 4 15:23:22 2019
Copyright (c) 2012, 2019, Oracle. All rights reserved.

Log file for this invocation: /orahome/oracle/app/cfgtoollogs/sqlpatch/sqlpatch_14221746_2019_11_04_15_23_22/sqlpatch_invocation.log

Connecting to database...OK
Bootstrapping registry and package to current versions...done
Determining current state...done

Current state of SQL patches:
Bundle series DBRU:
ID 190716 in the binary registry and not installed in the SQL registry

Adding patches to installation queue and performing prereq checks...
Installation queue:
Nothing to roll back
The following patches will be applied:
29757449 (DATABASE JUL 2019 RELEASE UPDATE 12.2.0.1.190716)

Installing patches...
Patch installation complete. Total patches installed: 1

Validating logfiles...
Patch 29757449 apply: SUCCESS
logfile: /orahome/oracle/app/cfgtoollogs/sqlpatch/29757449/23013437/29757449_apply_ORACLE_SID_2019Nov04_15_24_11.log (no errors)
SQL Patching tool complete on Mon Nov 4 15:46:00 2019
$

Hopefully, this will be useful as a starting point to determine autoupgrade process timing.

email

Interested in working with Michael? Schedule a tech call.

No comments

Leave a Reply

Your email address will not be published. Required fields are marked *