LMS 3.2 - DFM Notification Services issue

[frankzehrer]

My customer installed an LMS 3.2 on Windows 2008 Server with SP1.

Now the DFM Notification Services causing Problems.
We configured for a test the Event Set A and setup a Notification group with the following boxes ticked:
Alert Severity  
Critical   Informational

Alert Status  
Active

Event Selection  
Event Set: A

Event Severity  
Critical   Informational

Event Status  
Active

And all Devices marked in the device selector.

At least the E-Mail configuration was set.

Now none of the Alerts or Events generate an automated e-mail, while the manual mailing from the AAD is working.

I restarted the LMS dmgtd and founf the following lines in the DFMLogServer.log:
05/May/2010 10:39:46:473 ERROR  ? ?  - Exception in registry server java.net.BindException: Address already in use: JVM_Bind
05/May/2010 10:40:16:220 ERROR  ? ?  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:40:16:222 ERROR  ? ?  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:40:16:223 ERROR  ? ?  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:40:26:262 ERROR  ? ?  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:40:26:263 ERROR  ? ?  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!

In the nos.log is see the following:
05-May-2010|10:55:16.370|ERROR|NOS|Process EPM Data Thread:Pooled Thread:1|EpmDataQueueItem|processEPMData()|.|Caught Exception in processEPMData(): java.util.NoSuchElementException

While the NOSServer.log is showing the following:
05/May/2010 10:41:05:973 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:41:05:981 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:41:05:983 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:41:35:995 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:41:35:997 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:41:35:998 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:42:06:008 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:42:06:009 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:42:06:009 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:42:36:018 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:42:36:019 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:42:36:021 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:43:06:028 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:43:06:029 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:43:06:030 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:43:36:038 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:43:36:039 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:43:36:040 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:44:06:050 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:44:06:051 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:44:06:053 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:44:36:064 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:44:36:065 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:44:36:066 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
05/May/2010 10:45:06:075 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:45:06:076 ERROR main com.cisco.nm.xms.ctm.client.CTMCall establishIPC  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
05/May/2010 10:45:06:077 ERROR main com.cisco.nm.xms.ctm.client.CTMClientProxy getProxy  - URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
com.cisco.nm.xms.ctm.common.CTMException: URN_NOT_FOUND : urn "ogs_server_urn" : Not found !!
    at com.cisco.nm.xms.ctm.client.CTMCall.establishIPC(CTMCall.java:238)
    at com.cisco.nm.xms.ctm.client.CTMCall.<init>(CTMCall.java:218)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.<init>(CTMClientProxy.java:64)
    at com.cisco.nm.xms.ctm.client.CTMClientProxy.getProxy(CTMClientProxy.java:180)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:179)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.init(OGSServerProxy.java:98)
    at com.cisco.nm.xms.ogs.client.OGSServerProxy.<init>(OGSServerProxy.java:85)
    at com.cisco.nm.trx.nos.server.EPMPoller.ogsVerifyService(EPMPoller.java:212)
    at com.cisco.nm.trx.nos.server.EPMPoller.<init>(EPMPoller.java:144)
    at com.cisco.nm.trx.nos.server.NOSServer.initializeEPMPoller(NOSServer.java:244)
    at com.cisco.nm.trx.nos.server.NOSServer.<init>(NOSServer.java:107)
    at com.cisco.nm.trx.nos.server.NOSServer.main(NOSServer.java:259)
java.util.NoSuchElementException
    at java.util.StringTokenizer.nextToken(StringTokenizer.java:332)
    at com.cisco.nm.trx.nos.server.ProcessEPMDataManager$EpmDataQueueItem.formatAlertDataOnly(ProcessEPMDataManager.java:789)
    at com.cisco.nm.trx.nos.server.ProcessEPMDataManager$EpmDataQueueItem.processAlertData(ProcessEPMDataManager.java:951)
    at com.cisco.nm.trx.nos.server.ProcessEPMDataManager$EpmDataQueueItem.processEPMData(ProcessEPMDataManager.java:1319)
    at com.cisco.nm.trx.nos.server.ProcessEPMDataManager$EpmDataQueueItem.run(ProcessEPMDataManager.java:206)
    at com.cisco.nm.trx.nos.server.ThreadPool$1.run(ThreadPool.java:37)
java.util.NoSuchElementException

And in the dcrclient.log i noticed this:

[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:2
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - backed up registry = {47001=[dmserver-RMELogLevelChange, EssentialsDM]}
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - RegistryHandler.addCTMPort returning port = 47002
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:4
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Added urn inventory.ics.server-RMELogLevelChangeat port 47002
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - backed up registry = {47002=[], 47001=[dmserver-RMELogLevelChange, EssentialsDM]}
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:2
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - backed up registry = {47002=[inventory.ics.server-RMELogLevelChange], 47001=[dmserver-RMELogLevelChange, EssentialsDM]}
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - RegistryHandler.addCTMPort returning port = 47003
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:4
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Added urn archive.service-RMELogLevelChangeat port 47003
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - backed up registry = {47003=[], 47002=[inventory.ics.server-RMELogLevelChange], 47001=[dmserver-RMELogLevelChange, EssentialsDM]}
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] INFO com.cisco.nm.dcr.DCRContext - Settings File: E:/LMS\lib\classpath\com\cisco\nm\dcr/dcr.ini
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG com.cisco.nm.dcr.DCRSystem - In Instantiating DCR Subsystems...
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:1
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG com.cisco.nm.dcr.DCRDatabaseAccess -  Query is UPDATE JRM set command= '$JP -cw:jre lib\jre -cp MDC\tomcat\common\lib\activation.jar;objects\db\java\smtp.jar;MDC\tomcat\common\lib\mail.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\dcrimpexp.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-client.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-util.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-server.jar;MDC\tomcat\webapps\cwhp\WEB-INF\classes;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ctm.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\struts.jar;MDC\tomcat\shared\lib\MICE.jar;MDC\tomcat\shared\lib\NATIVE.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\log4j.jar;MDC\tomcat\shared\lib\xerces.jar;MDC\tomcat\common\lib\servlet.jar;MDC\jre\lib\ext\trust.jar;MDC\jre\lib\ext\jcert.jar;MDC\jre\lib\ext\jnet.jar;MDC\jre\lib\ext\trust.jar;MDC\jre\lib\ext\jsse.jar;MDC\jre\lib\ext\store.jar;lib\classpath;www\classpath $JJ com.cisco.nm.dcr.impexp.DCRJobInvoker $JI' WHERE type_id = 'DCR Import Export';
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG com.cisco.nm.dcr.DCRDataManagement - Attribute type details feteched from database
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG com.cisco.nm.dcr.DCRSystem - DCR Subsystems intialized sucessfully
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - Urn:"DCRCAM" Host:EGEER00AS64 Encoding style:1URL:443/cwhp/CTMServlet
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] INFO CTM.client - Establishing RPC
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - Secure Connection is set to TRUE in CTMClientProperties
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - Port specified in CTMClientProperties is 80
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - The newly formed URL is https://EGEER00AS64:443/cwhp/CTMServlet
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - Urn:"LocalDCR" Host:EGEER00AS64 Encoding style:1URL:443/cwhp/CTMServlet
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] INFO CTM.client - Establishing RPC
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - Secure Connection is set to TRUE in CTMClientProperties
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - Port specified in CTMClientProperties is 80
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - The newly formed URL is https://EGEER00AS64:443/cwhp/CTMServlet
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-16] DEBUG CTM.client - RPC, EncodingStyle = CTMConstants.CTM_BINARY
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-21] DEBUG CTM.Registry - Server Start Check Passed For 47002
[ Wed May 05 10:40:15 CEST 2010 ] [Thread-21] DEBUG CTM.Registry -  server running at 47002
[ Wed May 05 10:40:16 CEST 2010 ] [Thread-22] DEBUG CTM.Registry - Server Start Check Passed For 47003
[ Wed May 05 10:40:16 CEST 2010 ] [Thread-22] DEBUG CTM.Registry -  server running at 47003
[ Wed May 05 10:40:17 CEST 2010 ] [main] INFO com.cisco.nm.dcr.DCRContext - Settings File: E:/LMS\lib\classpath\com\cisco\nm\dcr/dcr.ini
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG com.cisco.nm.dcr.DCRSystem - In Instantiating DCR Subsystems...
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG com.cisco.nm.dcr.DCRDatabaseAccess -  Query is UPDATE JRM set command= '$JP -cw:jre lib\jre -cp MDC\tomcat\common\lib\activation.jar;objects\db\java\smtp.jar;MDC\tomcat\common\lib\mail.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\dcrimpexp.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-client.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-util.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-server.jar;MDC\tomcat\webapps\cwhp\WEB-INF\classes;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ctm.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\struts.jar;MDC\tomcat\shared\lib\MICE.jar;MDC\tomcat\shared\lib\NATIVE.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\log4j.jar;MDC\tomcat\shared\lib\xerces.jar;MDC\tomcat\common\lib\servlet.jar;MDC\jre\lib\ext\trust.jar;MDC\jre\lib\ext\jcert.jar;MDC\jre\lib\ext\jnet.jar;MDC\jre\lib\ext\trust.jar;MDC\jre\lib\ext\jsse.jar;MDC\jre\lib\ext\store.jar;lib\classpath;www\classpath $JJ com.cisco.nm.dcr.impexp.DCRJobInvoker $JI' WHERE type_id = 'DCR Import Export';
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG com.cisco.nm.dcr.DCRDataManagement - Attribute type details feteched from database
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG com.cisco.nm.dcr.DCRSystem - DCR Subsystems intialized sucessfully
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG CTM.client - Urn:"DCRCAM" Host:EGEER00AS64 Encoding style:1URL:443/cwhp/CTMServlet
[ Wed May 05 10:40:17 CEST 2010 ] [main] INFO CTM.client - Establishing RPC
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG CTM.client - Secure Connection is set to TRUE in CTMClientProperties
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG CTM.client - Port specified in CTMClientProperties is 80
[ Wed May 05 10:40:17 CEST 2010 ] [main] DEBUG CTM.client - The newly formed URL is https://EGEER00AS64:443/cwhp/CTMServlet
[ Wed May 05 10:40:17 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:1
[ Wed May 05 10:40:19 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:1
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - Invoked method   class com.cisco.nm.trx.tis.server.TISServiceImpl::getAllDeviceStatusSuccessfully
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - After executecall now
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - method executed
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - response sent
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - came in handleRequest
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - Header read
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - Got a closeconnection from client
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] INFO CTM.server - ClientEntry requestID:1273048820494 is deleted. hashtable size:0
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-8] DEBUG CTM.server - Will now close the TCPChannel
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-7] INFO com.cisco.nm.dcr.DCRContext - Settings File: E:/LMS\lib\classpath\com\cisco\nm\dcr/dcr.ini
[ Wed May 05 10:40:20 CEST 2010 ] [Thread-7] DEBUG com.cisco.nm.dcr.DCRSystem - In Instantiating DCR Subsystems...
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG com.cisco.nm.dcr.DCRDatabaseAccess -  Query is UPDATE JRM set command= '$JP -cw:jre lib\jre -cp MDC\tomcat\common\lib\activation.jar;objects\db\java\smtp.jar;MDC\tomcat\common\lib\mail.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\dcrimpexp.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-client.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-util.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ogs-server.jar;MDC\tomcat\webapps\cwhp\WEB-INF\classes;MDC\tomcat\webapps\cwhp\WEB-INF\lib\ctm.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\struts.jar;MDC\tomcat\shared\lib\MICE.jar;MDC\tomcat\shared\lib\NATIVE.jar;MDC\tomcat\webapps\cwhp\WEB-INF\lib\log4j.jar;MDC\tomcat\shared\lib\xerces.jar;MDC\tomcat\common\lib\servlet.jar;MDC\jre\lib\ext\trust.jar;MDC\jre\lib\ext\jcert.jar;MDC\jre\lib\ext\jnet.jar;MDC\jre\lib\ext\trust.jar;MDC\jre\lib\ext\jsse.jar;MDC\jre\lib\ext\store.jar;lib\classpath;www\classpath $JJ com.cisco.nm.dcr.impexp.DCRJobInvoker $JI' WHERE type_id = 'DCR Import Export';
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG com.cisco.nm.dcr.DCRDataManagement - Attribute type details feteched from database
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG com.cisco.nm.dcr.DCRSystem - DCR Subsystems intialized sucessfully
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG CTM.client - Urn:"DCRCAM" Host:EGEER00AS64 Encoding style:1URL:443/cwhp/CTMServlet
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] INFO CTM.client - Establishing RPC
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG CTM.client - Secure Connection is set to TRUE in CTMClientProperties
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG CTM.client - Port specified in CTMClientProperties is 80
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG CTM.client - The newly formed URL is https://EGEER00AS64:443/cwhp/CTMServlet
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.common - classLocation is: jar:file:/E:/LMS/MDC/tomcat/webapps/rme/WEB-INF/lib/ctm.jar!/com/cisco/nm/xms/ctm/common/CTMConfig.class
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - LocalUrnPort recd = 40053
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Optimization =  true
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-7] DEBUG CTM.client - RPC, EncodingStyle = CTMConstants.CTM_BINARY
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Returning result of invoke
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Urn:"LocalDCR" Host:EGEER00AS64 Encoding style:1URL:443/cwhp/CTMServlet
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] INFO CTM.client - Establishing RPC
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Secure Connection is set to TRUE in CTMClientProperties
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Port specified in CTMClientProperties is 80
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - The newly formed URL is https://EGEER00AS64:443/cwhp/CTMServlet
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - RPC, EncodingStyle = CTMConstants.CTM_BINARY
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.common - classLocation is: jar:file:/E:/LMS/MDC/tomcat/webapps/rme/WEB-INF/lib/ctm.jar!/com/cisco/nm/xms/ctm/common/CTMConfig.class
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - LocalUrnPort recd = 40053
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Optimization =  true
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-16] DEBUG CTM.client - Returning result of invoke
[ Wed May 05 10:40:21 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:1
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] DEBUG CTM.common - classLocation is: jar:file:/E:/LMS/MDC/tomcat/webapps/rme/WEB-INF/lib/ctm.jar!/com/cisco/nm/xms/ctm/common/CTMConfig.class
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] INFO CTM.server - Publishing with urn:"inventory.ics.server-RMELogLevelChange"
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] DEBUG CTM.Registry - port:47001 urn:"inventory.ics.server-RMELogLevelChange"
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] INFO CTM.Registry -  Waiting to read the data ...
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:4
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Sever is Alive ! Socket[addr=localhost/127.0.0.1,port=47002,localport=32440]
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-0] ERROR CTM.Registry - DUPLICATE_URN,CTMRegistry::addNewURNEntry(): URN already in use
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-0] ERROR CTM.Registry - CTMRegistryResponse FAILED
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] ERROR CTM.Registry - CTMRegistryClient::addNewURNEntry  URN : inventory.ics.server-RMELogLevelChange ErrMsg : URN already in use
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] DEBUG CTM.server - Duplicate urn inventory.ics.server-RMELogLevelChange
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-16] ERROR CTM.server - CTMRegistryClient::addNewURNEntry  URN : inventory.ics.server-RMELogLevelChange ErrMsg : URN already in use
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - Incoming request type is:2
[ Wed May 05 10:40:22 CEST 2010 ] [Thread-0] DEBUG CTM.Registry - backed up registry = {47003=[archive.service-RMELogLevelChange], 47002=[inventory.ics.server-RMELogLevelChange], 47001=[dmserver-RMELogLevelChange, EssentialsDM]}

I attached the output of pdshow command.

What is causing these Problem? A corrupt database or some invalid setting??
Does anybody has an idea?

Thanks in advance
Frank

[Joe Clarke]

Looks like you are seeing CSCtg43956.  If you contact TAC, you can get a patch which will correct this problem.

[frankzehrer]

Hi Joe,

this did not solve the problem.

I did some further crawling through the logs and saw the follwoing in the EPMServer.log after the serverstartup:

... loads of urn_not_found messages to be ignored during LMS startup

... init of the DFM groups

Groupname retreived at startup is:/RME@egeer00as64
Groupname retreived at startup is:/RME@egeer00as64/All Devices
Groupname retreived at startup is:/RME@egeer00as64/Normal Devices
Groupname retreived at startup is:/RME@egeer00as64/Pre-deployed
Groupname retreived at startup is:/RME@egeer00as64/User Defined Groups

java.lang.NullPointerException
    at com.cisco.nm.trx.epm.providers.alarm.AlarmUpdateListener.processUpdatedAlarm(Unknown Source)
    at com.cisco.nm.trx.epm.providers.alarm.AlarmUpdateListener.run(Unknown Source)
    at java.lang.Thread.run(Thread.java:595)
java.lang.NullPointerException
    at com.cisco.nm.trx.epm.providers.alarm.AlarmUpdateListener.processUpdatedAlarm(Unknown Source)
    at com.cisco.nm.trx.epm.providers.alarm.AlarmUpdateListener.run(Unknown Source)
    at java.lang.Thread.run(Thread.java:595)
java.lang.NullPointerException

i do not have any clue what causes these NullPointerExceptions.

Maybe you can give ma a hint??

Thanks a lot for your help so fra.

Best regards,

Frank

[Joe Clarke]

What patch files did you apply, and what process did you perform to apply them?  I still think your problem is related to the aforementioned bug.

[frankzehrer]

Hi Joe,

thanks for your fast reply.

The corresponding SR is 614309645.

These are the TAC provided files and sizes.

05/06/2010 10:46 AM 1,731  ProcessEPMDataManager$EpmDataQueueItem$epmAlarmHistory.class

05/06/2010 10:46 AM 1,391  ProcessEPMDataManager$EpmDataQueueItem$epmConditionHistory.class

05/06/2010 10:46 AM 889  ProcessEPMDataManager$EpmDataQueueItem$epmEventProperties.class

05/06/2010 10:46 AM 33,774  ProcessEPMDataManager$EpmDataQueueItem.class

05/06/2010 10:46 AM 7,112  ProcessEPMDataManager.class

The setup instruction from TAC:

1- Stop the  daemon manager:

             net stop crmdmgtd

2- Go  to:

$NMSROOT/MDC/tomcat/webapps/triveni/WEB-INF/classes/com/cisco/nm/trx/nos/server

and backup  the original files (either copy them to another safe directory or rename them to  something like . Please don't retain the  original extension when renaming the files.

3- Make  sure that the patch files have the following MD5s:

MD5  (ProcessEPMDataManager$EpmDataQueueItem$epmAlarmHistory.class) =  08851732b0b3aac5bb0636cc3e8e3c10

MD5  (ProcessEPMDataManager$EpmDataQueueItem$epmConditionHistory.class) =  7933e55abb6ad604aa6ca8d3126ff189

MD5  (ProcessEPMDataManager$EpmDataQueueItem$epmEventProperties.class) =  af3b72952ec59d59e30b0309af80a9d2

MD5  (ProcessEPMDataManager$EpmDataQueueItem.class) =  a70f49f8eab6bdea007b4ddd79e3809f

MD5  (ProcessEPMDataManager.class) =  a6ec024955bb638d8fec47694816a82a3-

4- Replace  the originals in the above mentioned directory with these  versions.

5 Start the  Daemon manager:

             net start crmdmgtd

I followed these instructions and still facing the problem.

I also searched for the libeay32.dll and ssleay32.dll, i found them, but in a path not included in the Windows PATH variable. Therefore these files should not influence LMS.

In the NOS Log i still see these messages:

10-May-2010|15:01:10.027|ERROR|NOS|Process EPM Data Thread:Pooled  Thread:1|EpmDataQueueItem|processEPMData()|.|Caught Exception in  processEPMData():  java.util.NoSuchElementException
10-May-2010|15:01:39.747|DEBUG|NOS|Thread-5|EPMPoller|pollEPM_Wash|.|Inside  pollEPM_Wash
10-May-2010|15:01:39.747|DEBUG|NOS|Thread-5|EPMPoller|pollEPM_Wash()|.|!!  _pollStarted =  true
10-May-2010|15:01:39.747|DEBUG|NOS|Thread-5|NOSUtil|sendNotifOnStart|.|0
10-May-2010|15:01:39.747|DEBUG|NOS|Thread-5|EPMPoller|pollEPM_Wash()|.|No  DB Exception in  polling

Since these Messages depends on EPM Data i had a look into the EPMServer.log and EPM.log

The EPMServer.log is shortened and showing all entries from the last dmgtd start. After the usual urn_not_found messages and the init of the Groups the following entry is generated:

java.lang.NullPointerException
    at com.cisco.nm.trx.epm.providers.alarm.AlarmUpdateListener.processUpdatedAlarm(Unknown Source)
    at com.cisco.nm.trx.epm.providers.alarm.AlarmUpdateListener.run(Unknown Source)
    at java.lang.Thread.run(Thread.java:595)

After that i changerd the logging of EPM to debug and attached the file as EPM_Debug.zip to this post.

Thanks a lot for your valuable support so far.

Cheers Frank

[Joe Clarke · Accepted solution]

They left out the most important file, nos.jar.  Have your engineer send you this file, and the instructions to install it.  Restart Daemon Manager, and you should be set.

[frankzehrer]

Hi Joe,

the missing jar file did the trick.

Many thanks for your support and have a great day.

Cheers Frank