OEM 13.4 AgentPull.sh failed with '0403-011 The specified substitution is not valid for this command'

When using Oracle Enterprise Manager 13.4 AgentPull.sh to deploy Agent 13.4 on AIX server, got following error,

./AgentPull.sh[270]: platform=${platform/\)/%29}: 0403-011 The specified substitution is not valid for this command.

Line 270 in AgentPull.sh is

platform=${platform/\)/%29}

It is a bash statement which tries to replace right parenthesis with code '%29', it works for bash but not Bourne shell (sh). The problem is that the script has directive to have Unix/Linux to run the script under bourne shell

$ head AgentPull.sh
#!/bin/sh
#
# $Header: emcore/install/unix/AgentPull.sh.template /main/30 2019/12/19 21:29:10 vbhaagav Exp $
#
# AgentPull.sh
#
# Copyright (c) 2011, 2019, Oracle and/or its affiliates. All rights reserved.
#
#    NAME
#      AgentPull.sh - <one-line expansion of the name>

The script works on most Linux servers because the /bin/sh is a symbolic link file linked to /bin/bash on these servers. Unfortunately, AIX is honest :), sh is sh and bash is bash, they are different.

As workaround, replace first line of AgentPull.sh '#!/bin/sh' with '#!/bin/bash'.

OEM 13.4 New Imported RuleSet False Evaluation of Lifecycle Status

If Rule Set is defined for targets based on Lifecycle Status, and the Rule Set is exported and imported into Enterprise Manager 13.4, the Rule Set will be always activated regardless of Lifecycle Status.

For example, two Rule Sets are created in source Enterprise Manager,

   Rule Set A for targets which Lifecycle Status is Production
   Rule Set B for targets which Lifecycle Status is Development

Both A and B are exported from source EM and imported into EM 13.4, and one target (no matter what value of Lifecycle Status) is brought down, both A and B will send out notification.

It can be fixed by manually editing the Rule Set. You do not need really to change anything of the Rule Set, just select the Rule Set and click Edit, then click Save.

OEM 13.2 Exported Ruleset Failed with 'Error in parsing properties for RuleSet from the XML' when Importing into EM 13.x

When importing ruleset in Enterprise Manager 13.x (confirmed in 13.2 and 13.4) from xml file exported from Enterprise Manager 13.2, got following error,

  Error in parsing properties for RuleSet from the XML

If the destination EM version is 13.2, following message will be found from trace file emoms.trc under directory <OMS_INSTANCE_BASE>/em/EMGC_OMS1/sysman/log

2021-03-29 22:49:12,394 [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] ERROR exportimport.ImportHelper logp.251 - Error in parsing properties for RuleSet from the XML
oracle.sysman.emSDK.app.exception.EMSystemException
     at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesModelUtil.throwEMSystemException(RulesModelUtil.java:1486)
     at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesFwkEntityImpl.postChanges(RulesFwkEntityImpl.java:116)
     ...
    ... 100 more
Caused by: oracle.jbo.JboException: JBO-29000: Unexpected exception caught: oracle.jbo.DMLConstraintException, msg=JBO-26048: Constraint "EM_RULE_EXPRESSIONS_UK1" is violated during post operation "Insert" using SQL statement "INSERT INTO EM_RULE_EXPRESSIONS(SELECTION_OBJECT_ID,EXPRESSION_ID,EXPRESSION_GROUP_ID,ATTR_ID,OPERATOR_CODE,ATTR_VALUE,SEL_OBJ_TYPE,EXPRESSION_TYPE,UI_GROUP_ID,EXCLUSION_GROUP_ID) VALUES (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10)".
    at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesFwkEntityImpl.doDML(RulesFwkEntityImpl.java:201)
    at oracle.jbo.server.EntityImpl.postChanges(EntityImpl.java:7271)
    at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesFwkEntityImpl.postChanges(RulesFwkEntityImpl.java:97)
    ... 104 more
Caused by: oracle.jbo.DMLConstraintException: JBO-26048: Constraint "EM_RULE_EXPRESSIONS_UK1" is violated during post operation "Insert" using SQL statement "INSERT INTO EM_RULE_EXPRESSIONS(SELECTION_OBJECT_ID,EXPRESSION_ID,EXPRESSION_GROUP_ID,ATTR_ID,OPERATOR_CODE,ATTR_VALUE,SEL_OBJ_TYPE,EXPRESSION_TYPE,UI_GROUP_ID,EXCLUSION_GROUP_ID) VALUES (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10)".
    at oracle.jbo.server.OracleSQLBuilderImpl.doEntityDML(OracleSQLBuilderImpl.java:565)
    at oracle.jbo.server.EntityImpl.doDML(EntityImpl.java:9098)
    at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesFwkEntityImpl.doDML(RulesFwkEntityImpl.java:196)
    ... 106 more
Caused by: java.sql.SQLIntegrityConstraintViolationException: ORA-00001: unique constraint (SYSMAN.EM_RULE_EXPRESSIONS_UK1) violated

If the destination EM version is 13.4 (or 13.3), following message will be found from trace file emoms.trc

2021-03-29 22:04:29,284 [[ACTIVE] ExecuteThread: '70' for queue: 'weblogic.kernel.Default (self-tuning)'] ERROR exportimport.ImportHelper logp.251 - Error in parsing properties for RuleSet from the XML
oracle.sysman.emSDK.app.exception.EMSystemException
    at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesModelUtil.throwEMSystemException(RulesModelUtil.java:1509)
    at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesFwkEntityImpl.postChanges(RulesFwkEntityImpl.java:106)
    ...
    at weblogic.work.ExecuteThread.execute(ExecuteThread.java:420)
    at weblogic.work.ExecuteThread.run(ExecuteThread.java:360)
Caused by: oracle.jbo.RowAlreadyDeletedException: JBO-25019: Entity row with key oracle.jbo.Key[BEB7FD94E2112377E053DA570F89CC8F ] is not found in EmRuleSetsEO.
    at oracle.jbo.server.OracleSQLBuilderImpl.doEntitySelectForAltKey(OracleSQLBuilderImpl.java:811)
    at oracle.jbo.server.BaseSQLBuilderImpl.doEntitySelect(BaseSQLBuilderImpl.java:554)
    at oracle.jbo.server.EntityImpl.doSelect(EntityImpl.java:9133)
    at oracle.jbo.server.EntityImpl.lock(EntityImpl.java:6612)
    at oracle.jbo.server.EntityImpl.beforePost(EntityImpl.java:7150)
    at oracle.jbo.server.EntityImpl.postChanges(EntityImpl.java:7384)
    at oracle.sysman.core.event.rules.uimodel.rulesfwk.RulesFwkEntityImpl.postChanges(RulesFwkEntityImpl.java:97)
    ... 95 more

It is a bug of EM 13.2, it can be fixed by apply OMS one-off patch 25986453 on source EM 13.2. The patch is also needed for destination EM if the version is 13.2.

OEM 13.4: Oracle Coherence Cache Targets Showing Down after WLS PSU 12.2.1.3.201217 applied

 After WebLogic Server (WLS) Patch Set Update 12.2.1.3.201217 is applied on Oracle Enterprise Manager (OEM) 13.4.0.9 home, two of Oracle Coherence Cache objects in WebLogic Domain '/EMGC_GCDomain/GCDomain' show Down in EM console.

It can be fixed by removing and re-adding the targets as following,

1.  Remove the Oracle Coherence Cache Targets showing Down from OEM

    * In the OEM Console,  navigate to 'Targets' > 'Middleware'
    * On left panel expand 'Target Type', then expand 'Coherence', Select Oracle Coherence Cache. All Oracle Coherence Cache targets will be listed on the right window.
    * Right click on the name of the targets showing Down, click pop-up menu 'Target Setup' > 'Remove Target'
   
    The Down targets are deleted from OEM console.
   
2.  Refresh the domain '/EMGC_GCDomain/GCDomain' to add removed/missing Oracle Coherence Cache objects

    * In the OEM Console,  navigate to 'Targets' > 'Middleware'
    * On left panel, clear the selection you did while removing the targets. The Oracle WebLogic Domain '/EMGC_GCDomain/GCDomain' will be listed in right window
    * Click the domain name '/EMGC_GCDomain/GCDomain'
    * Navigate to the  'Refresh Weblogic Domain' in the Drop-Down menu on the home page of target '/EMGC_GCDomain/GCDomain'
    * New Screen will appear, click on "Add and Update Targets..."
    * Following the prompt to add new found targets
 
The removed targets will be added with new target names.

DBCA does not list ASM diskgroup for storage option

Oracle 19c DBCA does not list ASM disk groups in "Select Database Storage Option" window.

Messages in dbca trace file $ORACLE_BASE/cfgtoollogs/dbca/trace.log_<TIMESTAMP>

[DBStorageOption.flowWorker] [ 2021-03-08 13:24:45.969 EST ] [KfodUtil.kfodOutput:375]  /u01/app/19.0.0/grid/bin/kfod
[DBStorageOption.flowWorker] [ 2021-03-08 13:24:45.969 EST ] [KfodUtil.kfodOutput:375]  nohdr=TRUE
[DBStorageOption.flowWorker] [ 2021-03-08 13:24:45.969 EST ] [KfodUtil.kfodOutput:375]  OP=GROUPS
[DBStorageOption.flowWorker] [ 2021-03-08 13:24:45.969 EST ] [KfodUtil.kfodOutput:375]  status=true
[DBStorageOption.flowWorker] [ 2021-03-08 13:24:45.969 EST ] [KfodUtil.kfodOutput:375]  asmcompatibility=true dbcompatibility=true
[DBStorageOption.flowWorker] [ 2021-03-08 13:24:46.045 EST ] [KfodUtil.kfodOutput:386]  Kfod result
Error 49802 initializing ADR
ERROR!!! could not initialize the diag context
[DBStorageOption.flowWorker] [ 2021-03-08 13:24:46.046 EST ] [ASMUtils.loadDiskGroups:1221]  Loading  the diskgroups. exception using kfodError retrieving diskgroup using kfod utility, null
INFO: Mar 08, 2021 1:24:46 PM oracle.assistants.common.lib.FileSystemInfo getSharedStoragePaths
INFO: Getting default shared storage path.

DBCA failed with command "/u01/app/19.0.0/grid/bin/kfod", manually run the command

[oracle@host01]$ /u01/app/19.0.0/grid/bin/kfod nohdr=TRUE OP=GROUPS status=true asmcompatibility=true dbcompatibility=true
Error 49802 initializing ADR
ERROR!!! could not initialize the diag context

Debug the command with truss or strace as following

  On Linux:  strace -o /tmp/kfod.out /u01/app/19.9.0/grid/bin/kfod nohdr=TRUE OP=GROUPS status=true asmcompatibility=true dbcompatibility=true
  On Solaris/AIX: truss -o /tmp/kfod.out /u01/app/19.0.0/grid/bin/kfod nohdr=TRUE OP=GROUPS status=true asmcompatibility=true dbcompatibility=true

Example on Solaris

[oracle@host01]$ truss -o /tmp/kfod.out /u01/app/19.0.0/grid/bin/kfod nohdr=TRUE OP=GROUPS status=true asmcompatibility=true dbcompatibility=true
Error 49802 initializing ADR
ERROR!!! could not initialize the diag context
[oracle@host01]$
[oracle@host01]$ tail /tmp/kfod.out
stat("/u01/app/19.0.0/grid/log/diag/kfod/host01/kfod/log", 0xFFFFFFFF7FFFBF80) Err#2 ENOENT
stat("/u01/app/19.0.0/grid/log/diag/kfod/host01/kfod", 0xFFFFFFFF7FFFBF80) Err#2 ENOENT
stat("/u01/app/19.0.0/grid/log/diag/kfod/host01", 0xFFFFFFFF7FFFBF80) Err#2 ENOENT
stat("/u01/app/19.0.0/grid/log/diag/kfod", 0xFFFFFFFF7FFFBF80) Err#2 ENOENT
stat("/u01/app/19.0.0/grid/log/diag", 0xFFFFFFFF7FFFBF80) = 0
getuid()     = 104 [104]
getgid()     = 112 [112]
getuid()     = 104 [104]
getuid()     = 104 [104]
mmap(0x00010000, 65536, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFFFFFFFF73900000
getuid()     = 104 [104]
getuid()     = 104 [104]
open("/system/volatile/name_service_door", O_RDONLY) = 6
fcntl(6, F_SETFD, 0x00000001)   = 0
door_info(6, 0xFFFFFFFF75D8B5B0)  = 0
door_call(6, 0xFFFFFFFF7FFFBBB8)  = 0
ioctl(1, TCGETA, 0xFFFFFFFF7FFF8F7C)  = 0
fstat(1, 0xFFFFFFFF7FFF8F10)   = 0
write(1, " E r r o r   4 9 8 0 2  ".., 29) = 29
write(1, " E R R O R ! ! !   c o u".., 47) = 47
close(5)     = 0
_exit(1)

From the trace file /tmp/kfod.out, kfod failed with accessing following directories

    /u01/app/19.0.0/grid/log/diag/kfod/host01/kfod/log
    /u01/app/19.0.0/grid/log/diag/kfod/host01/kfod
    /u01/app/19.0.0/grid/log/diag/kfod/host01
    /u01/app/19.0.0/grid/log/diag/kfod
    /u01/app/19.0.0/grid/log/diag

Check the permission of the directory

[oracle@host01]$ ls -ld /u01/app/19.0.0/grid/log/diag
drwxr-x---   4 grid     oinstall       5 Dec 12 23:17 /u01/app/19.0.0/grid/log/diag
[oracle@host01]$ id
uid=104(oracle) gid=112(oinstall)

oracle, who is running kfod, is member of group oinstall, but group oinstall does not have write permission on directory. Trying to grant write permission as root or grid (owner of GI home)

[grid@host01]$ chmod g+w /u01/app/19.0.0/grid/log/diag
[grid@host01]$ ls -ld /u01/app/19.0.0/grid/log/diag
drwxrwx---   4 grid     oinstall       5 Dec 13 02:45 /u01/app/19.0.0/grid/log/diag

Re-try kfod as oracle

[oracle@host01]$ /u01/app/19.0.0/grid/bin/kfod nohdr=TRUE OP=GROUPS status=true asmcompatibility=true dbcompatibility=true
    204528     188110 EXTERN REDO 10.1.0.0.0 12.1.0.0.0
    613584     388124 EXTERN FRA  10.1.0.0.0 12.1.0.0.0
   4091624     470712 EXTERN DATA 10.1.0.0.0 12.1.0.0.0

Now, dbca can list ASM disk groups.

19c runcluvfy.sh faile with PRVF-7596 PRVG-2002

When upgrading Oracle Infrastructure 12.2 to 19c, runcluvfy.sh failed with following messages

Verifying OCR Integrity ...FAILED
host02: PRVF-7596 : CSS is probably working with a non-clustered, local-only
          configuration on node "host02"

Verifying resolv.conf Integrity ...FAILED
host02: PRVG-2002 : Encountered error in copying file "/etc/resolv.conf" from
          node "host02" to node "host01"
          protocol error: filename does not match request

Verifying DNS/NIS name service ...FAILED
host02: PRVG-2002 : Encountered error in copying file "/etc/netsvc.conf" from
          node "host02" to node "host01"
          protocol error: filename does not match request

Set log location and re-run runcluvfy.sh

# runcluvfy.sh will write log files to directory /u01/tmp
export CV_TRACELOC=/u01/tmp

# re-run runcluvfy.sh
./runcluvfy.sh stage -pre crsinst -upgrade -rolling -src_crshome /u01/app/12.2.0/grid_1 -dest_crshome /u01/app/19.0.0/grid_1 -dest_version 19.0.0.0.0 -fixup -verbose

# Log files created
cd /u01/tmp
ls -l
total 15200
-rw-r--r--    1 grid     oinstall     952467 Feb 24 16:52 cvuhelper.log.0
-rw-r--r--    1 grid     oinstall          0 Feb 24 16:48 cvuhelper.log.0.lck
-rw-r--r--    1 grid     oinstall    6824223 Feb 24 16:52 cvutrace.log.0

The log file cvutrace.log.0 shows messsage

[Worker 0] [ 2021-02-24 16:47:49.784 EST ] [UnixSystem.remoteCopyFile:848]  UnixSystem: /usr/bin/scp -p host02:'/tmp/CVU_19.0.0.0.0_grid/scratch/getFileInfo3605304.out' /tmp/host02.getFileInfo3605304.out
[Worker 0] [ 2021-02-24 16:47:49.798 EST ] [RuntimeExec.runCommand:294]  runCommand: Waiting for the process
[Thread-83] [ 2021-02-24 16:47:49.798 EST ] [StreamReader.run:62]  In StreamReader.run
[Thread-82] [ 2021-02-24 16:47:49.798 EST ] [StreamReader.run:62]  In StreamReader.run
[Thread-83] [ 2021-02-24 16:47:50.201 EST ] [StreamReader.run:66]  ERROR>protocol error: filename does not match request
...
[main] [ 2021-02-24 16:51:46.747 EST ] [UnixSystem.remoteCopyFile:848]  UnixSystem: /usr/bin/scp -p host02:'/etc/resolv.conf' /tmp/CVU_19.0.0.0.0_grid/scratch/resolv.conf_host02
[main] [ 2021-02-24 16:51:46.760 EST ] [RuntimeExec.runCommand:294]  runCommand: Waiting for the process
[Thread-1060] [ 2021-02-24 16:51:46.760 EST ] [StreamReader.run:62]  In StreamReader.run
[Thread-1059] [ 2021-02-24 16:51:46.760 EST ] [StreamReader.run:62]  In StreamReader.run
[main] [ 2021-02-24 16:51:47.148 EST ] [RuntimeExec.runCommand:296]  runCommand: process returns 1
[Thread-1060] [ 2021-02-24 16:51:47.149 EST ] [StreamReader.run:66]  ERROR>protocol error: filename does not match request
...
[main] [ 2021-02-24 16:51:47.548 EST ] [UnixSystem.remoteCopyFile:848]  UnixSystem: /usr/bin/scp -p host02:'/etc/netsvc.conf' /tmp/CVU_19.0.0.0.0_grid/scratch/nssw_conf_host02
[Thread-1066] [ 2021-02-24 16:51:47.559 EST ] [StreamReader.run:62]  In StreamReader.run
[main] [ 2021-02-24 16:51:47.559 EST ] [RuntimeExec.runCommand:294]  runCommand: Waiting for the process
[Thread-1065] [ 2021-02-24 16:51:47.560 EST ] [StreamReader.run:62]  In StreamReader.run
[main] [ 2021-02-24 16:51:47.965 EST ] [RuntimeExec.runCommand:296]  runCommand: process returns 1
[Thread-1066] [ 2021-02-24 16:51:47.973 EST ] [StreamReader.run:66]  ERROR>protocol error: filename does not match request

All three errors occurred when scp is executed to copy file from remote node host02 to local node.

Interesting thing is that all three commands are using single quotation marks to enclose remote file name, I guess Oracle programmer left them there by accident because there is no reason to use them. Let's verify if it is the culprit by manually running scp

[grid@host01]$ scp -p host02:"'/etc/resolv.conf'" /tmp/CVU_19.0.0.0.0_grid/scratch/resolv.conf_host02
protocol error: filename does not match request
[grid@host01]$
[grid@host01]$ scp -T -p host02:"'/etc/resolv.conf'" /tmp/CVU_19.0.0.0.0_grid/scratch/resolv.conf_host02
resolv.conf                                             96    51.3KB/s   00:00
[grid@host01]$

The scp fails with same error "protocol error: filename does not match request", but succeeds if extra option -T is used.

The -T option was introduced by OpenSSH 8.0 released in April 2019. In earlier version of OpenSSH, when copying files from a remote system to a local directory, scp did not verify that the file names that the server sent matched those requested by the client. This could allow a hostile server to create or clobber unexpected local files with attacker-controlled content. OpenSSH 8.0 fixed this security issue and scp, by default, verifies the file name on client side, and also introduced -T option to provide capacity to disable the verification.

Although OpenSSH officially claims that the fix is introduced in 8.0, runcluvfy.sh shipped with Grid Infrastructure 19.3 also fails with same reason on AIX with OpenSSH 7.5p1 and it is where the errors used in this article happened.

This version of runcluvfy.sh sends remote file name with single quotation marks, but remote server returns file name without quotation. Technically, they are same thing, but they are visually different. Therefore, old version scp worked because it did not verify them, but current scp fails it with "filename does not match".

It can be resolved by downloading new standalone version Cluster Verification Utility from My Oracle Support(Patch 30839369). Note: the executable is cluvfy instead of runcluvfy.sh. If download is not the option. As a temporary workaround, we can rename scp and create a new scp

# Rename the original scp
mv /usr/bin/scp /usr/bin/scp.bak

# Create a new file scp
echo "/usr/bin/scp.orig -T $*" > /usr/bin/scp

# Make the file executable
chmod a+rx /usr/bin/scp

Now, the errors are gone. After successfully installing GI, remember to restore original scp

# Delete interim scp
rm /usr/bin/scp

# Restore the original scp.
mv /usr/bin/scp.bak /usr/bin/scp

19c gridSetup.sh failed with [INS-06006] Passwordless SSH connectivity not set up between the following nodes

When running 19.3 gridSetup.sh to configure Grid Infrastructure, following error occurs at configuring passwordless SSH connectivity between cluster nodes

[INS-06006] Passwordless SSH connectivity not set up between the following node(s): [host02].

Cause - Either passwordless SSH connectivity is not setup between specified node(s) or they are not reachable. Refer to the logs for more details.

Action - Refer to the logs for more details or contact Oracle Support Services.

More Details

PRVF-5311 : File "/tmp/GridSetupActions2021-02-24_05-29-41PM/host02.getFileInfo1638946.out" either does not exist or is not accessible on node "host02". 

Manually test passwordless SSH connectivity between nodes

[grid@host01]$ ssh host02       <=  Connect to second node host02 from first node host01

[grid@host02]$                  <=  Connected to host02 successfully without password

[grid@host02]$ ssh host02       <=  Connect to first node host01 from second node host02

[grid@host01]$                  <=  Connected to host01 successfully without password

Apparently, the passwordless SSH connectivity has been configured properly. Re-run gridSetup.sh in debug mode to figure out what happened,

grid@host01]$ /u01/app/19.0.0/grid _1/gridSetup.sh -debug

Launching Oracle Grid Infrastructure Setup Wizard...

[main] [ 2021-02-24 17:29:53.105 EST ] [Version.isPre:757]  version to be checked 19.0.0.0.0 major version to check against 10

[main] [ 2021-02-24 17:29:53.106 EST ] [Version.isPre:768]  isPre.java: Returning FALSE

  <<Message truncated>>

[Worker 2] [ 2021-02-24 17:31:26.521 EST ] [Utils.getLocalHost:487]  Hostname retrieved: host01, returned: host01

[Worker 2] [ 2021-02-24 17:31:26.521 EST ] [Utils.getLocalHost:487]  Hostname retrieved: host01, returned: host01

[Worker 2] [ 2021-02-24 17:31:26.521 EST ] [UnixSystem.remoteCopyFile:848]  UnixSystem: /usr/bin/scp -p host02:'/tmp/GridSetupActions2021-02-24_05-29-41PM/CVU_19.0.0.0.0_grid/scratch/getFileInfo1638946.out' /tmp/GridSetupActions2021-02-24_05-29-41PM/host02.getFileInfo1638946.out

[Worker 2] [ 2021-02-24 17:31:26.534 EST ] [RuntimeExec.runCommand:294]  runCommand: Waiting for the process

[Thread-442] [ 2021-02-24 17:31:26.534 EST ] [StreamReader.run:62]  In StreamReader.run 

[Thread-443] [ 2021-02-24 17:31:26.534 EST ] [StreamReader.run:62]  In StreamReader.run 

[Thread-443] [ 2021-02-24 17:31:26.855 EST ] [StreamReader.run:66]  ERROR>protocol error: filename does not match request

[Worker 2] [ 2021-02-24 17:31:26.855 EST ] [RuntimeExec.runCommand:296]  runCommand: process returns 1

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.runCommand:323]  RunTimeExec: error>

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.runCommand:326]  protocol error: filename does not match request

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.traceCmdEnv:516]  Calling Runtime.exec() with the command 

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.traceCmdEnv:518]  /usr/bin/scp 

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.traceCmdEnv:518]  -p 

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.traceCmdEnv:518]  host02:'/tmp/GridSetupActions2021-02-24_05-29-41PM/CVU_19.0.0.0.0_grid/scratch/getFileInfo1638946.out' 

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.traceCmdEnv:518]  /tmp/GridSetupActions2021-02-24_05-29-41PM/host02.getFileInfo1638946.out 

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [RuntimeExec.runCommand:349]  Returning from RunTimeExec.runCommand

[Worker 2] [ 2021-02-24 17:31:26.856 EST ] [NativeSystem.rununixcmd:1345]  NativeSystem.rununixcmd: RetString 0|protocol error: filename does not match request :failed

[Worker 2] [ 2021-02-24 17:31:26.859 EST ] [ClusterConfig$ExecuteCommand.returnCommandToClient:3324]  returnCommandToClient; fillCount=1 is full=false

[Worker 2] [ 2021-02-24 17:31:26.859 EST ] [Semaphore.release:88]  SyncBufferFull:Release called by thread Worker 2 m_count=2

When validating/configuring passwordless SSH connectivity, it has to copy SSH key information between nodes using scp. From the trace we can find that, it uses scp with -p option to copy the files, and destination file on local server (host01) is sent to scp with file name:

  /tmp/GridSetupActions2021-02-24_05-29-41PM/host02.getFileInfo1638946.out

  

And source file on remote server(host02) is sent to scp with file name:

  host02:'/tmp/GridSetupActions2021-02-24_05-29-41PM/CVU_19.0.0.0.0_grid/scratch/getFileInfo1638946.out'

Interesting thing is that the whole file path includes single quotation marks, I guess Oracle programmer left them there by accident because there is no reason to use them. Let's verify if it is the culprit by manually running scp

[grid@host01]$ scp -p host02:"'/tmp/GridSetupActions2021-02-24_05-29-41PM/CVU_19.0.0.0.0_grid/scratch/getFileInfo1638946.out'" /tmp/GridSetupActions2021-02-24_05-29-41PM/host02.getFileInfo1638946.out

protocol error: filename does not match request

[grid@host01]$

[grid@host01]$ scp -T -p host02:"'/tmp/GridSetupActions2021-02-24_05-29-41PM/CVU_19.0.0.0.0_grid/scratch/getFileInfo1638946.out'" /tmp/GridSetupActions2021-02-24_05-29-41PM/host02.getFileInfo1638946.out

getFileInfo1638946.out                                             98    56.5KB/s   00:00

[grid@host01]$

The scp fails with same error "protocol error: filename does not match request", but succeeds if extra option -T is used.

The -T option was introduced by OpenSSH 8.0 released in April 2019. In earlier version of OpenSSH, when copying files from a remote system to a local directory, scp did not verify that the file names that the server sent matched those requested by the client. This could allow a hostile server to create or clobber unexpected local files with attacker-controlled content. OpenSSH 8.0 fixed this security issue and scp, by default, verifies the file name on client side, and also introduced -T option to provide capacity to disable the verification.

Although OpenSSH officially claims that the fix is introduced in 8.0, gridSetup.sh 19.3 also fails with same reason on AIX with OpenSSH 7.5p1 and it is where the errors used in this article happened.

Oracle gridSetup.sh 19.3 (base pubic release of 19c) sends remote file name with single quotation marks, but remote server returns file name without quotation. Techinally, they are same thing, but they are visually different. Therefore, old version scp worked because it did not verify them, but current scp fails it with "filename does not match".

Oracle Release Update 19.6 fixed this problem by removing the single quotation marks. Therefore, gridSetup.sh can be run successfully with -applyRU option to apply 19.6 or higher Realease Update before installing/configuring GI

[grid@r6-dart]$ ./gridSetup.sh -applyRU /u01/stage/30501910

Preparing the home to patch...

Applying the patch /u01/stage/grid/30501910...

Successfully applied the patch.

The log can be found at: /u01/app/oraInventory/logs/GridSetupActions2021-02-24_03-25-57PM/installerPatchActions_2021-02-24_03-25-57PM.log

...

Here, Oracle Grid Infrastructure Release Update 19.6 (Patch 30501910) is unzipped under directory /u01/stage/30501910.

If 19.3 is really needed for some reason, as a temporary workaround, we can rename scp and create a new scp

# Rename the original scp

mv /usr/bin/scp /usr/bin/scp.bak

# Create a new file scp

echo "/usr/bin/scp.orig -T $*" > /usr/bin/scp

# Make the file executable

chmod a+rx /usr/bin/scp

After successfully installing GI 19.3, remember restore original scp

# Delete interim scp

rm /usr/bin/scp

# Restore the original scp.

mv /usr/bin/scp.bak /usr/bin/scp

19c Upgrade - Fail with ORA-07445: exception encountered: core dump [joevm_invokevirtual()+1260]

When 12.2 pluggable database is upgraded to 19c, dbupgrade fails with message

**********   Upgrading Java and non-Java   *********

Serial   Phase #:53   [PDB1] Files:2 

Unexpected error encountered in catctlMain; Error Stack Below; exiting

Died at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 9188.

 at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 9188.

main::catctlDie("\x{a}Unexpected error encountered in catconExec; exiting\x{a} No such"...) called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 5650

main::catctlExecutePhaseFiles(53, 2, "PDB1", "", undef) called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 2035

main::catctlRunPhase(53, 2, "PDB1", "", undef) called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 2197

main::catctlRunPhases(0, 108, 108, "PDB1", "", undef) called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 2816

main::catctlRunMainPhases() called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 1463

main::catctlMain() called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 1370

eval {...} called at /u01/app/oracle/product/19.0.0/dbhome_1/rdbms/admin/catctl.pl line 1368

------------------------------------------------------

CATCTL FATAL ERROR

------------------------------------------------------

 LOG FILES: (/u01/app/oracle/product/19.0.0/dbhome_1/cfgtoollogs/DB01/upgrade20210222125535/catupgrdPDB1*.log)

TRACE FILE: (/u01/app/oracle/product/19.0.0/dbhome_1/cfgtoollogs/DB01/upgrade20210222125535/catupgrdPDB1_trace.log)

In log file catupgrdPDB1*.log

13:09:24 SQL> -- Load all the Java classes

13:09:24 SQL> begin if initjvmaux.startstep('CREATE_JAVA_SYSTEM') then

13:09:24   2  initjvmaux.rollbacksetup;

13:09:24   3  commit;

13:09:24   4  initjvmaux.rollbackset;

13:09:24   5  initjvmaux.exec('create or replace java system');

13:09:24   6  commit;

13:09:24   7  initjvmaux.rollbackcleanup;

13:09:24   8  initjvmaux.endstep;

13:09:24   9  dbms_registry.update_schema_list('JAVAVM',

13:09:24  10        dbms_registry.schema_list_t('OJVMSYS'));

13:09:24  11  end if; end;

13:09:24  12  /

begin if initjvmaux.startstep('CREATE_JAVA_SYSTEM') then

*

ERROR at line 1:

ORA-03113: end-of-file on communication channel

ERROR:

ORA-03114: not connected to ORACLE

In database alert log file

2021-02-22T13:09:41.671656-05:00

PDB1(4):Exception [type: SIGSEGV, Address not mapped to object] [ADDR:0x4] [PC:0x118CE298C, joevm_invokevirtual()+1260] [flags: 0x0, count: 1]

Errors in file /u01/app/oracle/diag/rdbms/db01/DB01/trace/DB01_2_ora_4739.trc  (incident=28841) (PDBNAME=PDB1):

ORA-07445: exception encountered: core dump [joevm_invokevirtual()+1260] [SIGSEGV] [ADDR:0x4] [PC:0x118CE298C] [Address not mapped to object] []

PDB1(4):Incident details in: /u01/app/oracle/diag/rdbms/db01/DB01/incident/incdir_28841/DB01_ora_4739_i28841.trc

PDB1(4):Use ADRCI or Support Workbench to package the incident.

The culprit is that the PDB (PDB1) was plugged from NONCDB which was followed by running noncdb_to_pdb.sql.  It can be fixed as following,

1. Connect to the database as SYS and run following sql commands in root container CDB$ROOT

alter session set container=CDB$ROOT;

alter session set "_ORACLE_SCRIPT"=true;

create or replace view rootobj sharing=object as

   select obj#,o.name,u.name uname,o.type#,o.flags

     from obj$ o,user$ u where owner#=user#;

2. Connect to the database as SYS and run following sql commands in PDB container PDB1 (your PDB name may be different)

alter session set container=PDB1;

create or replace view rootobj sharing=object as

   select obj#,o.name,u.name uname,o.type#,o.flags

     from obj$ o,user$ u where owner#=user#;

update obj$ set flags=flags+65536

 where type# in (28,29,30,56)

       and bitand(flags,65536)=0

       and obj# in (select o.obj# from obj$ o,user$ u,rootobj r

                     where o.name=r.name and o.type#=r.type# and o.owner#=u.user# and u.name=r.uname and bitand(r.flags,65536)!=0

                    union

                    select obj# from obj$ where bitand(flags,4259840)=4194304);

delete from sys.idl_ub1$

 where obj# in (select obj# from sys.obj$ where bitand(flags, 65536)=65536 and type# in (28,29,30,56));

commit;

3. Re-start upgrade from failed step (Phase #:53 in my case)

$ORACLE_HOME/bin/dbupgrade -p 53 -c 'PDB1'

Use UTL_FILE to Write BLOBs Stored Inside the Database Out to Files

Create a precedure as following

create or replace procedure  save_blob_to_file (a_directory varchar2, a_filename varchar2, a_data blob)
is
  p_blob_length  integer;
  p_file         utl_file.file_type;
  p_offset       integer := 1;
  p_chunksize    pls_integer := 32767;
  p_buffer       raw(32767);
begin
  /* Determine size of BLOB */
  p_blob_length := dbms_lob.getlength(a_data);
  /* open a file handle */
  p_file := utl_file.fopen(a_directory, a_filename, 'wb', p_chunksize);
  begin
    /* write BLOB to file in chunks */
    while p_offset <= p_blob_length loop
      if p_offset + p_chunksize - 1 > p_blob_length then
         p_chunksize := p_blob_length - p_offset + 1;
      end if;
      dbms_lob.read(a_data, p_chunksize, p_offset, p_buffer);
      utl_file.put_raw(p_file, p_buffer, true);
      p_offset := p_offset + p_chunksize;
    end loop;
  exception
    when others then
      /* Close the file handle in case of any exceptions*/
      utl_file.fclose(p_file);
      raise;
  end;
  /* Close the file handle after all data is written out*/
  utl_file.fclose(p_file);
end;
/

Sample code to save BLOB to file with procedure 'save_blob_to_file'

declare
  p_blob       blob;
  p_directory  varchar2(30) := 'BLOB_DIR';
  p_filename   varchar2(255):= 'first_blob_file.tst';
begin
  select blob_data into p_blob from tb_blob_file where rownum=1;
  save_blob_to_file(p_directory,p_filename,p_blob);
end;
/

Here, directory 'BLOB_DIR' has to be created before calling the procedure. Example for creating directory,

system@db01> create directory BLOB_DIR as '/u01/blob_files';

Directory created.

Make sure OS directory '/u01/blob_files' exists and Oracle home owner (normally oracle) has read/write under this directory

[oracle@host01]$ ls -ld /u01/blob_files
drwxr-xr-x    2 oracle   oinstall       8192 Feb 20 20:33 /u01/blob_files

Oracle Data Pump Export Failing with ORA-39244

Oracle database 19.9 Data Pump export job fails with ORA-39244: Event to disable dropping null bit image header during relational select, as following,

Connected to: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
ORA-31626: job does not exist
ORA-31637: cannot create job SYS_EXPORT_SCHEMA_01 for user SYSTEM
ORA-06512: at "SYS.KUPV$FT", line 1142
ORA-06512: at "SYS.KUPV$FT", line 1744
ORA-06512: at "SYS.DBMS_SYS_ERROR", line 95
ORA-06512: at "SYS.KUPV$FT_INT", line 1099
ORA-39244: Event to disable dropping null bit image header during relational select
ORA-06512: at "SYS.DBMS_SYS_ERROR", line 86
ORA-06512: at "SYS.KUPC$QUE_INT", line 2002
ORA-24145: evaluation context SYS.AQ$_KUPC$DATAPUMP_QUETAB_1_V already exists

The evaluation context SYS.AQ$_KUPC$DATAPUMP_QUETAB_1_V was left by corrupted/failed Data Pump job. Manually dropping the context will fix the issue

sys@DB> exec DBMS_RULE_ADM.DROP_EVALUATION_CONTEXT(EVALUATION_CONTEXT_NAME=>'AQ$_KUPC$DATAPUMP_QUETAB_1_V',FORCE=>true);

PL/SQL procedure successfully completed.

Create Oracle ASM disks using multipath devices and udev rules on Oracle Linux / Red Hat Enterprise Linux

 Since Oracle Automatic Storage Management Filter Driver (ASMFD) was released with Oracle Database 12c, DBA has very few chance to work with udev rules when creating ASM disks. 

Fortunately, Oracle Database 19.6 introduced a new feature, Zero-Downtime Grid Infrastructure patching which brings the requirement of udev rules back to DBA. When Oracle ASMFD is used for ASM disks, Oracle patching has to update the operating system driver for ASMFD, which cannot be done in zero-downtime mode. Therefore, in order to patch Grid Infrastructure in zero-downtime mode instead of rolling mode, udev rules becomes a perfect option.

Rename / Change the Multipath Device Names on Linux

 Each multipath device has a World Wide Identifier (WWID), which is guaranteed to be globally unique and unchanging. By default, the name of a multipath device is set to its WWID. Alternately, you can set the user_friendly_names option in the multipath configuration file, which sets the alias to a node-unique name of the form mpathn.

Zero-Downtime patching Oracle Grid Infrastructure 19c on Linux

 In the past, when we were patching Grid Infrastructure (GI) in rolling mode, the database instances had to be shut down on the node which we were patching on. 

Starting with Oracle Database 19c Release Update (RU) 19.8, Oracle announced that Oracle RAC database instances can keep running and accessible to the database users during Oracle Grid Infrastructure patching. My patching practice is done in following environment

   * Two nodes Grid Infrastructure 19.8 running on Oracle Linux 7 update 8

   * Host name of nodes are rac01.lab.dbaplus.ca and rac02.lab.dbaplus.ca

   * GI RU 19.9.0.0.201020 and OJVM RU 19.9.0.0.201020 are applied in out-of-place(OOP) mode

   * ACFS and AFD are being used

Zero-Downtime Grid Infrastructure Patching root.sh failed with CLSRSC-675: Cluster-wide Grid Plug and Play profile not found

 When running root.sh with zero-downtime GI patching option -transparent and -nodriverupdate, got following errors

2020/11/05 11:55:01 CLSRSC-675: Cluster-wide Grid Plug and Play profile not found on this node.

Died at /u01/app/19.9.0/grid/crs/install/crsgpnp.pm line 3436.

The command '/u01/app/19.9.0/grid/perl/bin/perl -I/u01/app/19.9.0/grid/perl/lib -I/u01/app/19.9.0/grid/crs/install /u01/app/19.9.0/grid/srvm/admin/rhpmovegi.pl /u01/app/19.0.0/grid /u01/app/19.9.0/grid true' execution failed

Using configuration parameter file: /u01/app/19.9.0/grid/crs/install/crsconfig_params

The log of current session can be found at:

  /u01/app/grid/crsdata/rac02/crsconfig/crs_prepatch_apply_oop_rac02_2020-11-05_11-55-01AM.log

Using configuration parameter file: /u01/app/19.9.0/grid/crs/install/crsconfig_params

The log of current session can be found at:

  /u01/app/grid/crsdata/rac02/crsconfig/crs_prepatch_apply_oop_rac02_2020-11-05_11-55-01AM.log

2020/11/05 11:55:01 CLSRSC-675: Cluster-wide Grid Plug and Play profile not found on this node.

Died at /u01/app/19.9.0/grid/crs/install/crsgpnp.pm line 3436.

The command '/u01/app/19.9.0/grid/perl/bin/perl -I/u01/app/19.9.0/grid/perl/lib -I/u01/app/19.9.0/grid/crs/install /u01/app/19.9.0/grid/crs/install/rootcrs.pl  -transparent -nodriverupdate -dstcrshome /u01/app/19.9.0/grid -prepatch' execution failed

Oracle AHF installation failed with "AHF-00074: Perl Modules not found: Data::Dumper"

Oracle combined Trace File Analyzer (TFA) & ORAchk/EXAchk into single installer called Oracle Autonomous Health Framework (AHF).

When installing AHF on Linux platform (Red Hat Enterprise Linux / Oracle Linux), got error "AHF-00074: Perl Modules not found :  Data::Dumper"

[root@host01]# ./ahf_setup

AHF Installer for Platform Linux Architecture x86_64

AHF Installation Log : /tmp/ahf_install_202300_4904_2020_11_05-18_04_25.log

PERL : /u01/app/19.9.0/grid/perl/bin/perl

[ERROR] : AHF-00074: Perl Modules not found :  Data::Dumper

Configure ASM audit with syslog on Solaris

This article shows how to use syslog to manage ASM audit files on Solaris 10/11.

If you are looking for the information for Linux or AIX, please check out following posts

  Reduce number of privileged access audit files for ASM with syslog on AIX.
  Reduce number of privileged access audit files for ASM with rsyslog on Linux.

Pluggable database opened with RESTRICTED SESSION due to Sync PDB failed with ORA-65177 during 'alter user'

 When open pluggable database, got following error

SQL> alter pluggable database ORCL open;

Warning: PDB altered with errors.

SQL> 

SQL> show pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED

---------- ------------------------------ ---------- ----------

         2 PDB$SEED                       READ ONLY  NO

         3 ORCL                           READ WRITE YES

The pluggable databse ORCL is opened with RESTRICTED SESSION. Check the view pdb_plug_in_violations for error details,

SQL> show con_name

CON_NAME

------------------------------

CDB$ROOT

SQL> col name for a10

SQL> col time for a18

SQL> col cause for a15

SQL> col message for a75

SQL> set linesize 255

SQL> alter session set nls_timestamp_format='dd-mon-yy hh24:mi:ss';

Session altered.

SQL> select time,name,type,cause,status,message from pdb_plug_in_violations where status <>'RESOLVED';

TIME               NAME       TYPE      CAUSE           STATUS    MESSAGE

------------------ ---------- --------- --------------- --------- ---------------------------------------------------------------------------

30-oct-20 12:00:52 ORCL       ERROR     Sync Failure    PENDING   Sync PDB failed with ORA-65177 during 'alter user ABCDE_APP account unlock'

When the pdb ORCL is being opened, it tries to synchronize the sql "alter user ABCDE_APP account unlock" between pdb and cdb$root, because the sql was run in cdb$root but not in pdb. Check the status of user ABCDE_APP

SQL> col username for a10

SQL> select con_id,username,account_status,created,common from cdb_users where username='ABCDE_APP';

    CON_ID USERNAME   ACCOUNT_STATUS     CREATED   COM

---------- ---------- ------------------ --------- ---

         1 ABCDE_APP  OPEN               11-JUN-19 YES

SQL> alter session set container=ORCL;

Session altered.

SQL>

SQL> select con_id,username,account_status,created,common from cdb_users where username='ABCDE_APP';

    CON_ID USERNAME   ACCOUNT_STATUS    CREATED   COM

---------- ---------- ----------------- --------- ---

         3 ABCDE_APP  OPEN              04-AUG-20 NO

The user ABCDE_APP was created as common user in root container, but in pdb user ABCDE_APP was created as local user. Both user are using same user name, but are totally different user account in the database. When DBA run sql 'alter user ABCDE_APP account unlock' in root container, the database tries to sync the sql with all pdbs, but the common user cannot be synced in pdb ORCL because the user ABCDE_APP is not the same user.

AS a workaround, the issue can be temporarily solved by deleting the sync-pending statement (alter user ABCDE_APP account unlock) from PDB_SYNC$ in both CDB and PDB 

In CDB root container,

SQL> show con_name

CON_NAME

------------------------------

CDB$ROOT

SQL> 

SQL> col name for a10

SQL> col sqlstmt for a40

SQL> 

SQL> alter session set nls_date_format='dd-mon-yy hh24:mi:ss';

Session altered.

SQL> 

SQL> select ctime,sqlstmt,name,flags,opcode,replay# from pdb_sync$ where sqlstmt like 'alter user ABCDE_APP account unlock%';

CTIME              SQLSTMT                                  NAME            FLAGS      OPCODE     REPLAY#

------------------ ---------------------------------------- ---------- ---------- ---------- ----------

30-oct-20 10:24:42 alter user ABCDE_APP account unlock      ABCDE_APP           0          5          21

SQL> delete from PDB_SYNC$ where sqlstmt like ('alter user ABCDE_APP account unlock%');

1 row deleted.

SQL> commit;

Commit complete.

In pdb ORCL

SQL> alter session set container=ORCL;

Session altered.

SQL> select ctime,sqlstmt,name,flags,opcode,replay# from pdb_sync$ where sqlstmt like 'alter user ABCDE_APP account unlock%';

CTIME              SQLSTMT                                  NAME         FLAGS      OPCOD      EREPLAY#

------------------ ---------------------------------------- ---------- ------- ---------- ----------

30-oct-20 10:24:42 alter user ABCDE_APP account unlock      ABCDE_APP        0          5          21

SQL> delete from PDB_SYNC$ where sqlstmt like 'alter user ABCDE_APP account unlock%';

1 row deleted.

SQL> commit;

Commit complete.

Re-open the pdb

SQL> alter pluggable database ORCL close;

Pluggable database altered.

SQL> alter pluggable database ORCL open;

Pluggable database altered.

SQL> show pdbs

    CON_ID CON_NAME                       OPEN MODE  RESTRICTED

---------- ------------------------------ ---------- ----------

         2 PDB$SEED                       READ ONLY  NO

         3 ORCL                           READ WRITE NO

The pdb is open without RESTRICT SESSION. However, the issue may happen again when you run 'alter user ABCDE_APP' statement in root container. The permanent solution is that drop local user from pdb and grant common user access to the pdb.

Reduce number of privileged access audit files for ASM with rsyslog on Linux

This post shows how to configure rsyslog on Linux (Red Hat Enterprise Linux 7/8) to redirect ASM audit message to OS log files.

If you are looking for the information for Solaris or AIX, please check out following posts

  Configure ASM audit with syslog on Solaris.
  Reduce number of privileged access audit files for ASM with syslog on AIX.

Install and Configure Kerberos Authentication on Red Hat Enterprise Linux 8

The demonstration includes three installation/configuration parts,

  Part 1. Install and configure Kerberos Key Distribution Center (KDC) Server

  

     Server name: xdc01.lab.dbaplus.ca

     OS version:  Red Hat Enterprise Linux (RHEL) 8

  Part 2. Install and configure Kerberos client on application (SSH) server

  

     Server 1: host01.lab.dbaplus.ca

     Server 2: host02.lab.dbaplus.ca

     OS version:  Red Hat Enterprise Linux (RHEL) 8

  

  Part 3. Install and configure Kerberos client on workstation to test single-sign-on (SSO) for SSH authentication with Kerberos

GI 19c opatchauto out-of-place patching failed with file permission issues

Environment,

   Grid Infrastructure Home version : 19.7.0.0.200414

   OPatch version: 12.2.0.1.21

   Patch version: P31305339 - GI Release Update 19.8.0.0.200714

On fist node of the cluster, when runng opatchauto with option -outofplace or -prepare-clone, got errors

[root@rac01]# /u01/app/19.7.0/grid _1/OPatch/opatchauto apply -phBaseDir /u01/stage/grid -outofplace -logLevel FINEST

     ... ...

Creating clone for oracle home /u01/app/19.7.0/grid_1.

Failed to perform clone operation for oracle home /u01/app/19.7.0/grid_1. 

Execution of [CloneOracleHomeAction] patch action failed, check log for more details. Failures:

Patch Target : rac01->/u01/app/19.7.0/grid_1 Type[crs]

Details: [

---------------------------Patching Failed---------------------------------

Command execution failed during patching in home: /u01/app/19.7.0/grid_1, host: rac01.

Command failed:  /u01/app/19.8.0/grid_1/perl/bin/perl /u01/app/19.8.0/grid_1/clone/bin/clone.pl ORACLE_BASE=/u01/app/grid ORACLE_HOME=/u01/app/19.8.0/grid_1 INVENTORY_LOCATION=/u01/app/oraInventory -defaultHomeName 'CLUSTER_NODES={rac01,rac02}' "LOCAL_NODE=rac01" CRS=false SHOW_ROOTSH_CONFIRMATION=false oracle.install.skipRootPre=true -silent

Command failure output: 

[INFO] [INS-32183] Use of clone.pl is deprecated in this release. Clone operation is equivalent to performing a Software Only installation from the image. 

You must use /u01/app/19.8.0/grid_1/gridSetup.sh script available to perform the Software Only install. For more details on image based installation, refer to help documentation.

Starting Oracle Universal Installer...

[FATAL] [INS-32012] Unable to create directory: /u01/app/19.8.0/grid_1, on this server.

   CAUSE: Either proper permissions were not granted to create the directory or there was no space left in the volume.

   ACTION: Check your permission on the selected directory or choose another directory.

[WARNING] [INS-32029] The Installer has detected that the Oracle Base location is not empty.

   ACTION: Oracle recommends that the Oracle Base location is empty. 

After fixing the cause of failure Run opatchauto resume

]

The process failed with error "Unable to create directory: /u01/app/19.8.0/grid_1", the directory is cloned (new) home and the process is trying to apply RU 19.8.0.0.200714 onto the home.

Check the directory permission

[root@rac01]# ls -ld /u01/app/19.8.0/grid_1       

drwxr-xr-x   94 root     oinstall       4096 Sep 20 18:27 /u01/app/19.8.0/grid_1

Chang the directory owner from root to Grid Home owner grid

[root@rac01]$ chown grid /u01/app/19.8.0/grid_1       

Resume the patch process

[root@rac01]# /u01/app/19.7.0/grid_1/OPatch/opatchauto resume

Different errors occur

Patch Target : rac01->/u01/app/19.7.0/grid_1 Type[crs]

Details: [

---------------------------Patching Failed---------------------------------

Command execution failed during patching in home: /u01/app/19.7.0/grid_1, host: rac01.

Command failed:  /u01/app/19.8.0/grid_1/perl/bin/perl /u01/app/19.8.0/grid_1/clone/bin/clone.pl ORACLE_BASE=/u01/app/grid ORACLE_HOME=/u01/app/19.8.0/grid_1 INVENTORY_LOCATION=/u01/app/oraInventory -defaultHomeName 'CLUSTER_NODES={rac01,rac02}' "LOCAL_NODE=rac01" CRS=false SHOW_ROOTSH_CONFIRMATION=false oracle.install.skipRootPre=true -silent

Command failure output: 

[INFO] [INS-32183] Use of clone.pl is deprecated in this release. Clone operation is equivalent to performing a Software Only installation from the image. 

You must use /u01/app/19.8.0/grid_1/gridSetup.sh script available to perform the Software Only install. For more details on image based installation, refer to help documentation.

Starting Oracle Universal Installer...

[WARNING] [INS-32029] The Installer has detected that the Oracle Base location is not empty.

   ACTION: Oracle recommends that the Oracle Base location is empty.

You can find the log of this install session at:

 /u01/app/oraInventory/logs/cloneActions2020-09-20_06-38-13PM.log

..................................................   5% Done.

..................................................   10% Done.

..................................................   15% Done.

..................................................   20% Done.

..................................................   25% Done.

..................................................   30% Done.

..................................................   35% Done.

..................................................   40% Done.

..................................................   45% Done.

..................................................   50% Done.

..................................................   55% Done.

..................................................   60% Done.

..................................................   65% Done.

..................................................   70% Done.

..................................................   75% Done.

..................................................   80% Done.

..................................................   85% Done.

..........[FATAL] Failed to restore the saved templates to the Oracle home being cloned. Aborting the clone operation. 

After fixing the cause of failure Run opatchauto resume

]

The root cause is that the opatchauto did not successfully unlock the new cloned home before applying patches on it. Lots of files/directories under new home are still owned by root

[root@rac01]# find /u01/app/19.8.0/grid_1 -user root

/u01/app/19.8.0/grid_1/acfs

/u01/app/19.8.0/grid_1/acfs/tunables

/u01/app/19.8.0/grid_1/auth

/u01/app/19.8.0/grid_1/auth/crs

/u01/app/19.8.0/grid_1/auth/crs/r10-sohei

   ... ...

/u01/app/19.8.0/grid_1/bin/cloudcli

/u01/app/19.8.0/grid_1/bin/clscfg

/u01/app/19.8.0/grid_1/bin/clscfg.bin

/u01/app/19.8.0/grid_1/bin/clsdiaglsnr

   ... ...

/u01/app/19.8.0/grid_1/suptools/tfa/release/tfa_home/tfa.jks

/u01/app/19.8.0/grid_1/suptools/tfa/release/tfa_home/tfa_directories.txt

/u01/app/19.8.0/grid_1/suptools/tfa/release/tfa_home/tfa_setup.txt

/u01/app/19.8.0/grid_1/xag/mesg/xagus.le

Change the owner of these file/directories to grid

[root@rac01]# find /u01/app/19.8.0/grid_1 -user root -exec chown grid {} \;

Continue opatchauto with resume option,

[root@rac01]# /u01/app/19.7.0/grid _1/OPatch/opatchauto resume

The home will be out-of-place patched, and new home is /u01/app/19.8.0/grid_1.

HTTP 404 when enabling Friendly URLs or referencing Static Application Files using substitution string #APP_IMAGES#

As it is known, Oracle is trying to deprecate two web listeners Oracle HTTP Server (mod_plsql) and Embedded PL/SQL Gateway, and Oracle REST Data Services (ORDS) will be the only supported web listener for APEX.

Oracle database 19c "srvctl status service" fails with Java.lang.NullPointerException

The following errors occur while running "srvctl status service -db <db_name>" command from 19.7 database home on AIX and Linux x86_64,

$ srvctl status service -db orcl

Exception in thread "main" java.lang.NullPointerException

        at oracle.ops.opsctl.StatusAction.internalExecuteService(StatusAction.java:2077)

        at oracle.ops.opsctl.StatusAction.executeSIHAService(StatusAction.java:1692)

        at oracle.ops.opsctl.Action.executeSIHA(Action.java:445)

        at oracle.ops.opsctl.OPSCTLDriver.execute(OPSCTLDriver.java:537)

        at oracle.ops.opsctl.OPSCTLDriver.main(OPSCTLDriver.java:252)

Configure SSL on WebLogic 12c with CA Issued Certificate

Weblogic 12c has demo identity keystore shipped with installation, it makes it very easy to implement SSL communication for WebLogic managed servers in non-production environment. However,  if you are deploying your application in production, especially public accessible, a certificate issued by Certificate Authority (CA) is absolutely necessary. To request and install CA issued certificate on WebLogic 12c, follow these steps,

Install APEX with deploying ORDS in WebLogic as Web listener

The installation is completed on Oracle Linux 7.5, and following components/ applications are installed,

    JDK 1.8.0_241

    Weblogic 12.2.1.4.0

    Oracle Application Express (APEX) 19.2

    Oracle REST Data Services (ORDS) 19.4

Agent status shows 'Diagnose for Agent Blocked (Bounce Counter Mismatch)' in OEM 13c

Agent 13.2 home was restored from a backup after failed OS patching maintenance. On the Enterprise Manager 13.2 console, the agent status shows 'Diagnose for Agent Blocked (Bounce Counter Mismatch)', and targets monitored by the agent show 'Diagnose for Status Pending (Post Blackout)'.

Database 12.2 crashed with ORA-04031 ("shared pool","unknown object","init_heap_kfsg","ASM extent pointer array")

Database 12.2 instance crashed with following messages in alert log,

2020-05-20T22:28:52.724801-04:00

Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_asmb_15204374.trc  (incident=320299):

ORA-04031: unable to allocate 4120 bytes of shared memory ("shared pool","unknown object","init_heap_kfsg","ASM extent pointer array")

Incident details in: /u01/app/oracle/diag/rdbms/orcl/orcl/incident/incdir_320299/orcl_asmb_15204374_i320299.trc

Use ADRCI or Support Workbench to package the incident.

See Note 411.1 at My Oracle Support for error and packaging details.

2020-05-20T22:29:30.066864-04:00

NOTE: ASMB0 terminating

2020-05-20T22:29:30.067840-04:00

Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_asmb_15204374.trc:

ORA-04031: unable to allocate 4120 bytes of shared memory ("shared pool","unknown object","init_heap_kfsg","ASM extent pointer array")

2020-05-20T22:29:30.070882-04:00

Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_asmb_15204374.trc:

ORA-04031: unable to allocate 4120 bytes of shared memory ("shared pool","unknown object","init_heap_kfsg","ASM extent pointer array")

Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_asmb_15204374.trc  (incident=320300):

ORA-4031 [] [] [] [] [] [] [] [] [] [] [] []

Incident details in: /u01/app/oracle/diag/rdbms/orcl/orcl/incident/incdir_320300/orcl_asmb_15204374_i320300.trc

2020-05-20T22:29:31.376055-04:00

USER (ospid: 15204374): terminating the instance due to error 4031

From the alert log, we can find that asmb process (ospid: 15204374) wrote following errors into trace file orcl_asmb_15204374.trc

ORA-04031: unable to allocate 4120 bytes of shared memory ("shared pool","unknown object","init_heap_kfsg","ASM extent pointer array")

Then, the asmb process terminated the instance.

This issue happened after the database home was applied Oracle database Release Update April 2020 (12.2.0.1.200414).

It is a bug introduce by Release Update 12.2.0.1.200414, and can be fixed by apply patch 31341859.

12.2.0.1 init.ohasd does not start clusterware stack after April 2020 RU applied

The init.ohasd process does not start clusterware stack after the 12.2.0.1 Grid Infrastructure home is applied April 2020 Release Update. The scenario is not a typical Grid Infrastructure startup issue. It is a human error and happened when DBA, by accident, ran roothas.sh instead of rootcrs.sh while patching GI cluster home. Before knowing it is human error, the diagnose process is done as following.

impdp failed at dbms_logrep_imp.instantiate_schema with ORA-01031: insufficient privileges

When execute impdp to import 12.2 database, ORA-01031 occured as following,

[oracle@host01]$ impdp system@pdb01 dumpfile=appdata.dmp schemas=appdata

Import: Release 12.2.0.1.0 - Production on Tue May 12 17:58:56 2020

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

Password:

Connected to: Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

Starting "SYSTEM"."SYS_IMPORT_SCHEMA_03":  system/********@pdb01 dumpfile=appdata.dmp schemas=appdata

Processing object type SCHEMA_EXPORT/USER

Processing object type SCHEMA_EXPORT/SYSTEM_GRANT

Processing object type SCHEMA_EXPORT/DEFAULT_ROLE

Processing object type SCHEMA_EXPORT/TABLESPACE_QUOTA

Processing object type SCHEMA_EXPORT/PRE_SCHEMA/PROCACT_SCHEMA

ORA-39083: Object type PROCACT_SCHEMA failed to create with error:

ORA-31625: Schema APPDATA is needed to import this object, but is unaccessible

ORA-01031: insufficient privileges

Failing sql is:

BEGIN

sys.dbms_logrep_imp.instantiate_schema(schema_name=>SYS_CONTEXT('USERENV','CURRENT_SCHEMA'), export_db_name=>'DB02', inst_scn=>'386040157882');COMMIT; END;

Processing object type SCHEMA_EXPORT/SEQUENCE/SEQUENCE

Processing object type SCHEMA_EXPORT/SEQUENCE/GRANT/OWNER_GRANT/OBJECT_GRANT

ORA-39083: Object type OBJECT_GRANT failed to create with error:

ORA-31625: Schema APPDATA is needed to import this object, but is unaccessible

ORA-01031: insufficient privileges

Failing sql is:

GRANT SELECT ON "APPDATA"."WORKLOAD_SEQ" TO "USER01"

ORA-39083: Object type OBJECT_GRANT failed to create with error:

ORA-31625: Schema APPDATA is needed to import this object, but is unaccessible

ORA-01031: insufficient privileges

Failing sql is:

GRANT SELECT ON "APPDATA"."LOG_SEQ" TO "USER02"

The user SYSTEM, which is used by impdp to connect to database, does not have BECOME USER privilege, 

system@PDB01> select * from dba_sys_privs where privilege='BECOME USER';

GRANTEE    PRIVILEGE       ADMIN_OPTION COMMON INHERITED

---------- --------------- ------------ ------ ---

SYS        BECOME USER     NO           YES    YES

The healthy database privilege grant looks like,

system@PDB01> select * from dba_sys_privs where privilege='BECOME USER';

GRANTEE              PRIVILEGE    ADMIN_OPTION COMMON INHERITED

-------------------- ------------ ------------ ------ ---

DBA                  BECOME USER  NO           YES    YES

IMP_FULL_DATABASE    BECOME USER  NO           YES    YES

SYS                  BECOME USER  NO           YES    YES

It can be fixed by running grand command

grant BECOME USER to DBA,IMP_FULL_DATABASE;

This privilege is normally granted to roles DBA and IMP_FULL_DATABASE. For some reason, it could be revoked. One of the scenario is that DBUA run script dvu121.sql to revoke BECOME USER privileges from DBA and IMP_FULL_DATABASE roles when upgrading database to 12.2 and Database Vault component is VALID.

opatchauto out-of-place patching Oracle Restart and Database home

Out of place (OOP) patching is a new feature introduced by Oracle 12.2 with the latest version of opatchauto. It is a patching method where patching is performed by following operations,

  * Creating a copy of current oracle home

  * Applying patches to the copied home

  * Switching services to the copied home

This patching method helps on moving Oracle home and/or reducing the downtime of patching Oracle home and database. OPatchauto supports OOP patching for the following configurations,

  * Grid Infrastructure (GI) and Real Application Cluster (RAC)

  * Oracle Restart (Standalone Grid Infrastructure) (SIHA) and single instance database (SIDB)

DBA_REGISTRY_SQLPATCH shows END status after datapatch ran against database

During postinstallation of a database patching, datapatch utility shows following message while loading modified SQL files into the database,

[oracle@host01]$ $ORACLE_HOME/OPatch/datapatch -verbose
SQL Patching tool version 12.2.0.1.0 Production on Sun Dec 22 14:32:47 2019
Copyright (c) 2012, 2019, Oracle.  All rights reserved.

Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_18481316_2019_12_22_14_32_47/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 191015 in the binary registry and ID 190416 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:
    30138470 (DATABASE OCT 2019 RELEASE UPDATE 12.2.0.1.191015)

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

Validating logfiles...
Patch 30138470 apply: SUCCESS
  logfile:  (no errors)
SQL Patching tool complete on Sun Dec 22 14:33:32 2019

It shows 'Patch 30138470 apply: SUCCESS', but the log file name is missing and patch status shows END in view DBA_REGISTRY_SQLPATCH,

SQL> select patch_id,version,action,status,description
  2   from dba_registry_sqlpatch
  3  order by action_time;

  PATCH_ID VERSION     ACTION   STATUS     DESCRIPTION
---------- ----------- -------- ---------- -------------------------------------------------
  29314339 12.2.0.1    APPLY    SUCCESS    DATABASE APR 2019 RELEASE UPDATE 12.2.0.1.190416
  30138470 12.2.0.1    APPLY    END

SQL>

Check the sql execution log,

[oracle@host01]$ cd /u01/app/oracle/cfgtoollogs/sqlpatch/
[oracle@host01]$ ls -l
total 104
drwxr-xr-x    3 oracle   oracle          256 Jul 21 16:28 29314339
drwxr-xr-x    3 oracle   oracle          256 Dec 22 14:33 30138470
drwxr-xr-x    2 oracle   oracle         4096 Jul 21 16:24 sqlpatch_10879194_2019_07_21_16_24_15
drwxr-xr-x    2 oracle   oracle         4096 Dec 22 14:33 sqlpatch_18481316_2019_12_22_14_32_47
-rw-r--r--    1 oracle   oracle         1373 Dec 22 14:31 sqlpatch_history.txt

[oracle@host01]$ cd 30138470
[oracle@host01]$ ls -l
total 0
drwxr-xr-x    2 oracle   oracle          256 Dec 22 15:10 23136421
[oracle@host01]$ cd 23136421
[oracle@host01]$ ls -l
total 440
-rw-r--r--    1 oracle   oracle       184086 Dec 22 14:33 30138470_apply_DB01_2019Dec22_14_33_31.log
[oracle@host01]$ pwd
/u01/app/oracle/cfgtoollogs/sqlpatch/30138470/23136421
[oracle@host01]$
[oracle@host01]$ grep -n 'ORA-' 30138470_apply_DB01_2019Dec22_14_33_31.log
32:ORA-01693: max # extents (505) reached in lob segment
34:ORA-06512: at "SYS.DBMS_SQLPATCH", line 639
35:ORA-06512: at "SYS.DBMS_SQLPATCH", line 605
36:ORA-06512: at line 2
65:ORA-20004: Uninitialized state in install_file
66:ORA-06512: at "SYS.DBMS_SQLPATCH", line 738
159:ORA-20004: Uninitialized state in install_file
       ...
7305:SQL> PROMPT IGNORABLE ERRORS: ORA-04043
7306:IGNORABLE ERRORS: ORA-04043
7313:ORA-20004: Uninitialized state in install_file
7314:ORA-06512: at "SYS.DBMS_SQLPATCH", line 738
7407:ORA-20004: Uninitialized state in install_file
7408:ORA-06512: at "SYS.DBMS_SQLPATCH", line 738

ORA-01693 is found in line 32 of the log file. List the details of the errors,

[oracle@host01]$ head -37 30138470_apply _DB01_2019Dec22_14_33_31.log
SQL>
SQL> SET PAGESIZE 0
SQL> SELECT 'Starting apply for patch 30138470/23136421 on ' ||
  2         SYSTIMESTAMP FROM dual;
Starting apply for patch 30138470/23136421 on 22-DEC-19 02.33.31.103477 PM -05:0
0


SQL> SET PAGESIZE 10
SQL>
SQL> BEGIN
  2      dbms_sqlpatch.patch_initialize(p_patch_id      => 30138470,
  3                                     p_patch_uid     => 23136421,
  4                                     p_flags         => '&flags',
  5                                     p_description   => '&description',
  6                                     p_action        => 'APPLY',
  7                                     p_logfile       => '&full_logfile',
  8                                     p_bundle_series => '&bundle_series');
  9  END;
 10  /
old   4:                                    p_flags         => '&flags',
new   4:                                    p_flags         => 'NB',
old   5:                                    p_description   => '&description',
new   5:                                    p_description   => 'DATABASE OCT 2019 RELEASE UPDATE 12.2.0.1.191015',
old   7:                                    p_logfile       => '&full_logfile',
new   7:                                    p_logfile       => '/u01/app/oracle/cfgtoollogs/sqlpatch/30138470/23136421/30138470_apply_DB01_2019Dec22_14_33_31.log',
old   8:                                    p_bundle_series => '&bundle_series');
new   8:                                    p_bundle_series => 'DBRU');
BEGIN
*
ERROR at line 1:
ORA-01693: max # extents (505) reached in lob segment
SYS.SYS_LOB0000190607C00013$$
ORA-06512: at "SYS.DBMS_SQLPATCH", line 639
ORA-06512: at "SYS.DBMS_SQLPATCH", line 605
ORA-06512: at line 2

[oracle@host01]$

The segment 'SYS.SYS_LOB0000190607C00013$$' reaches the extent maximum limitation (505), and it caused the SQL failure, find out what the segment is

SQL> select owner,object_name,object_type
  2    from dba_objects
  3   where object_name='SYS_LOB0000190607C00013$$';

OWNER                OBJECT_NAME                    OBJECT_TYPE
-------------------- ------------------------------ -----------------------
SYS                  SYS_LOB0000190607C00013$$      LOB

SQL> select owner,table_name,column_name,segment_name
  2    from dba_lobs
  3   where segment_name='SYS_LOB0000190607C00013$$';

OWNER      TABLE_NAME                     COLUMN_NAME          SEGMENT_NAME
---------- ------------------------------ -------------------- -------------------------
SYS        REGISTRY$SQLPATCH              PATCH_DIRECTORY      SYS_LOB0000190607C00013$$

SQL>
SQL> desc sys.registry$sqlpatch
 Name                          Null?    Type
 ----------------------------- -------- -------------------------
 PATCH_ID                      NOT NULL NUMBER                  
 ACTION                        NOT NULL VARCHAR2(15)            
 ACTION_TIME                   NOT NULL TIMESTAMP(6)            
 DESCRIPTION                            VARCHAR2(100)           
 LOGFILE                                VARCHAR2(500)           
 STATUS                                 VARCHAR2(25)            
 VERSION                       NOT NULL VARCHAR2(20)            
 PATCH_UID                     NOT NULL NUMBER                  
 FLAGS                                  VARCHAR2(10)            
 BUNDLE_SERIES                          VARCHAR2(30)            
 BUNDLE_ID                              NUMBER                  
 INSTALL_ID                             NUMBER                  
 PATCH_DIRECTORY                        BLOB                    
 BUNDLE_DATA                            XMLTYPE                 
 PATCH_DESCRIPTOR                       XMLTYPE                 
 POST_LOGFILE                           VARCHAR2(500)           
SQL>
SQL> select owner,segment_name,max_extents
  2    from dba_segments
  3   where segment_name in ('REGISTRY$SQLPATCH','SYS_LOB0000190607C00013$$');

OWNER      SEGMENT_NAME                   MAX_EXTENTS
---------- ------------------------------ -----------
SYS        REGISTRY$SQLPATCH                      505
SYS        SYS_LOB0000190607C00013$$              505

The segment is BLOB column PATCH_DIRECTORY of table SYS.REGISTRY$SQLPATCH, both the BLOB segment and its table have extent maximum limitation 505. To remove the limitation,

SQL> alter table sys.registry$sqlpatch storage (maxextents unlimited);

Table altered.

SQL> alter table sys.registry$sqlpatch
  2  modify lob (patch_directory) (storage (maxextents unlimited));

Table altered.

SQL> select owner,segment_name,max_extents
  2    from dba_segments
  3   where segment_name in ('REGISTRY$SQLPATCH','SYS_LOB0000190607C00013$$');

OWNER      SEGMENT_NAME                   MAX_EXTENTS
---------- ------------------------------ -----------
SYS        REGISTRY$SQLPATCH               2147483645
SYS        SYS_LOB0000190607C00013$$       2147483645

Then re-run the datapatch utility,

[oracle@host01]$ $ORACLE _HOME/OPatch/datapatch -verbose
SQL Patching tool version 12.2.0.1.0 Production on Sun Dec 22 16:43:43 2019
Copyright (c) 2012, 2019, Oracle.  All rights reserved.

Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_35782878_2019_12_22_16_43_43/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 191015 in the binary registry and ID 190416 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:
    30138470 (DATABASE OCT 2019 RELEASE UPDATE 12.2.0.1.191015)

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

Validating logfiles...
Patch 30138470 apply: SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/30138470/23136421/30138470_apply_DB01_2019Dec22_16_44_33.log (no errors)
SQL Patching tool complete on Sun Dec 22 16:45:22 2019

Now, it gives the log file name. Validate the status,

SQL> select patch_id,version,action,status,description
  2    from dba_registry_sqlpatch order by action_time;

  PATCH_ID VERSION     ACTION   STATUS     DESCRIPTION
---------- ----------- -------- ---------- -------------------------------------------------
  29314339 12.2.0.1    APPLY    SUCCESS    DATABASE APR 2019 RELEASE UPDATE 12.2.0.1.190416
  30138470 12.2.0.1    APPLY    END
  30138470 12.2.0.1    APPLY    SUCCESS    DATABASE OCT 2019 RELEASE UPDATE 12.2.0.1.191015

The patch is installed successfully.

DBUA 12.2 Failed while PDBS Recompile Invalid Objects

When upgrading 12.1 database to 12.2 with DBUA, got following error,

Server errors encountered during the execution of "PDBS Recompile Invalid Objects".

Following information is found in DBUA log file,

SQL> EXECUTE dbms_registry_sys.validate_components;
...(20:04:27) Starting validate_apex for APEX_180200
ORA-20001: MISSING GRANT: grant execute on "MDSYS"."SDO_DIM_ARRAY" to APEX_180200
ORA-20001: MISSING GRANT: grant execute on "MDSYS"."SDO_DIM_ELEMENT" to APEX_180200
ORA-20001: MISSING GRANT: grant execute on "MDSYS"."SDO_ELEM_INFO_ARRAY" to APEX_180200
ORA-20001: MISSING GRANT: grant execute on "MDSYS"."SDO_GEOMETRY" to APEX_180200
ORA-20001: MISSING GRANT: grant execute on "MDSYS"."SDO_ORDINATE_ARRAY" to APEX_180200
ORA-20001: MISSING GRANT: grant execute on "MDSYS"."SDO_POINT_TYPE" to APEX_180200

These privileges were granted by SYS (SYS is grantor) in original database, and missing during upgrading.

Object privileges in original database,

SQL> select GRANTEE,GRANTOR,OWNER,TABLE_NAME,PRIVILEGE from dba_tab_privs
  2   where owner='MDSYS' and grantee='APEX_180200'
  3   order by grantor,table_name;

GRANTEE        GRANTOR    OWNER     TABLE_NAME                     PRIVILEGE
-------------- ---------- --------- ------------------------------ ----------------------
APEX_180200    MDSYS      MDSYS     MDERR                          EXECUTE
APEX_180200    MDSYS      MDSYS     SDO_GEOM_METADATA_TABLE        DELETE
APEX_180200    MDSYS      MDSYS     SDO_GEOM_METADATA_TABLE        SELECT
APEX_180200    MDSYS      MDSYS     SDO_GEOM_METADATA_TABLE        INSERT
APEX_180200    MDSYS      MDSYS     SDO_META                       EXECUTE
APEX_180200    MDSYS      MDSYS     SDO_UTIL                       EXECUTE
APEX_180200    MDSYS      MDSYS     USER_SDO_INDEX_INFO            SELECT
APEX_180200    SYS        MDSYS     SDO_DIM_ARRAY                  EXECUTE
APEX_180200    SYS        MDSYS     SDO_DIM_ELEMENT                EXECUTE
APEX_180200    SYS        MDSYS     SDO_ELEM_INFO_ARRAY            EXECUTE
APEX_180200    SYS        MDSYS     SDO_GEOMETRY                   EXECUTE
APEX_180200    SYS        MDSYS     SDO_ORDINATE_ARRAY             EXECUTE
APEX_180200    SYS        MDSYS     SDO_POINT_TYPE                 EXECUTE

Object privileges in current (partly upgraded) database,

SQL> select GRANTEE,GRANTOR,OWNER,TABLE_NAME,PRIVILEGE from dba_tab_privs
  2   where owner='MDSYS' and grantee='APEX_180200'
  3   order by grantor,table_name;

GRANTEE        GRANTOR    OWNER      TABLE_NAME                     PRIVILEGE
-------------- ---------- ---------- ------------------------------ --------------------
APEX_180200    MDSYS      MDSYS      MDERR                          EXECUTE
APEX_180200    MDSYS      MDSYS      SDO_GEOM_METADATA_TABLE        DELETE
APEX_180200    MDSYS      MDSYS      SDO_GEOM_METADATA_TABLE        INSERT
APEX_180200    MDSYS      MDSYS      SDO_GEOM_METADATA_TABLE        SELECT
APEX_180200    MDSYS      MDSYS      SDO_META                       EXECUTE
APEX_180200    MDSYS      MDSYS      SDO_UTIL                       EXECUTE
APEX_180200    MDSYS      MDSYS      USER_SDO_INDEX_INFO            SELECT

Workaround

Manually grant the missing privileges and click retry in DBUA.