DG Switchover, EMON Termination and kponpst: ORA-1033, during ksrpublish0

As part of my company's policy, we regularly perform DR-related activities, which includes switchover tests of databases configured to use Data Guard (physical standby).  During one of the tests in a lower environment the switchover command (run in "dgmgrl") hung.  Normally this process takes a few minutes but after waiting longer than usual, we checked the database for wait events and saw that the switchover was waiting on "EMON Termination".  We also checked the primary's alert log and saw the following:

Started @ 11:11:40
2018-10-22 11:11:56.745000 -04:00
minact-scn: Master considers inst:4 dead
kponpst: ORA-1033, during ksrpublish0
kponpst: ORA-1033, during ksrpublish0
kponpst: ORA-1033, during ksrpublish0
2018-10-22 11:11:58.862000 -04:00
Archived Log entry 438383 added for thread 1 sequence 31328 ID 0xe8c2ea16 dest 1:
ARC4: Archive log rejected (thread 2 sequence 31330) at host '****'
FAL[server, ARC4]: FAL archive failed, see trace file.
ARCH: FAL archive failed. Archiver continuing
ORACLE Instance **** - Archival Error. Archiver continuing.
2018-10-22 11:12:48.377000 -04:00
kponpst: ORA-1033, during ksrpublish0
2018-10-22 11:12:55.734000 -04:00
kponpst: ORA-1033, during ksrpublish0

In ARC[4] tracefile:
*** 2018-10-22 11:11:58.429 4645 krsu.c
Logged on to standby successfully
Client logon and security negotiation successful!
Error 16401 creating standby archive log file at host '****'
kcrrwkx: unknown error:16401

MOS document "Database Shutdown Hangs on "EMON termination" / " Waiting for Job queue slaves to complete" (Doc ID 1915888.1)" describes this event as caused by "a few orphan subscribers for the ALERT QUEUE which caused emon to spin during shutdown.".  This implies that one or more EMON background process could be hung.  Checking the view V$EMON I found:

SID LAST_UPDATE_TIME
------- -----------------------------
    336 04-OCT-18 23.42.02.881 -04:00
    396 22-OCT-18 11.11.51.986 -04:00
    427 22-OCT-18 11.11.51.986 -04:00
    456 22-OCT-18 11.11.51.986 -04:00
      7 22-OCT-18 11.11.51.986 -04:00

 
From the above it looks as though EMON SID 336 (highlighted) doesn't belong or at least is having issues.  I killed this database session, but unfortunately it couldn't be killed (marked for killed).  Fortunately, experience has told me to always grab the SPID associated with an Oracle session, just in case it can't be killed.  After killing the OS process the switchover picked up immediately and completed without issue.

Normally it's not a good idea to kill Oracle background sessions but from a bit of searching BEFORE anything was killed, I determined that EMON does have several bugs associated with it across releases of Oracle and that killing EMON is sometimes advised, in emergency situations.

KEY_MISMATCH as Last AgentURL is null in "emoms.trc"

Every once-in-a-while I'll be reviewing a logfile or trace file in search of one thing and I'll come across something else which doesn't look quite right.  As the title of this blog suggests, I found a frequently repeating error in our development OEM's "emoms.trc" file, specifically:

[2018-08-23T17:26:18.819-04:00] [EMGC_OMS1] [ERROR:32] [] 
[oracle.sysman.core.pbs.receiver.AbstractOMSHandshake] [tid: [ACTIVE].ExecuteThread: '15' for queue: 
'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 
0000MJPAUGO1JfV0U3J7Fs1RMaUD00000B,0:7540:1] [APP: empbs] [URI: /empbs/upload] OMSHandshake 
failed.(AGENT URL = https://<agent host>:3872/emd/main/)(ERROR = KEY_MISMATCH as Last AgentURL is 
null and the Agent Key doesn't exist in repos)

A few things caught my attention with this message.  First, the error was from an agent on a server that I know has been decommissioned, or at least removed from OEM.  Second, the error was coming in every minute, which to me seemed like a real waste since the agent shouldn't exist.

It turns out that not only did the server still exist but the management agent was up.  Apparently in-between our team shutting down all Oracle processes plus removing targets from OEM and the final step of decommissioning the hardware, the server itself suffered a reboot which caused all processes to start automatically.  From then on, the management agent tried every minute to upload information to the repository yet the repository couldn't find a match for the agent.

Shutting down the management agent stopped the flow of error messages to "emoms.trc" (this would be the domain server's file under "/user_projects/domains/GCDomain/…/sysman/log") but the quickest way to avoid any repeats of this in the future was to also rename the top-level directory for the agent.