Fixed
Details
Assignee
David SmithDavid SmithReporter
Jesse WhiteJesse WhiteComponents
Sprint
NoneFix versions
Affects versions
Priority
Major
Details
Details
Assignee
David Smith
David SmithReporter
Jesse White
Jesse WhiteComponents
Sprint
None
Fix versions
Affects versions
Priority
MajorPagerDuty
PagerDuty
PagerDuty
Created November 26, 2018 at 2:39 PM
Updated December 7, 2018 at 8:38 PM
Resolved December 7, 2018 at 8:38 PM
Here's an excerpt from the log showing the alarm being created, and the duplicate key except that follows:
2018-11-23 18:00:18,881 DEBUG [alarmd-Thread-4-of-4] o.o.n.e.EventIpcManagerDefaultImpl: run: calling onEvent on alarmd for event {"uei":"uei.opennms.org/vendor/cisco/syslog/ifUp","time":"2018-11-23 17:54:51,000-0600","dbid":19431251,"source":"syslogd","nodeid":1673,"parms":[{"hostname":"7.192.16.6"}, {"syslogmessage":"%ETHPORT-5-IF_UP: Interface Ethernet111/1/41 is up in mode access"}, {"severity":"Notice"}, {"timestamp":"Nov 23 23:54:51"}, {"service":"local7"}, {"group1":"Ethernet111/1/41"}, {"ifDescr":"Ethernet111/1/41"}]} 2018-11-23 18:00:18,881 DEBUG [alarmd-Thread-4-of-4] o.o.n.a.AlarmPersisterImpl: process: uei.opennms.org/vendor/cisco/syslog/ifUp; nodeid: 1673; ipaddr: 7.192.16.6; serviceid: null 2018-11-23 18:00:18,881 DEBUG [alarmd-Thread-4-of-4] o.o.n.a.AlarmPersisterImpl: addOrReduceEventAsAlarm: looking for existing reduction key: uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41 2018-11-23 18:00:18,882 DEBUG [alarmd-Thread-4-of-4] o.o.n.a.AlarmPersisterImpl: addOrReduceEventAsAlarm: reductionKey:uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41 not found, instantiating new alarm 2018-11-23 18:00:18,889 DEBUG [alarmd-Thread-3-of-4] o.o.n.e.EventIpcManagerDefaultImpl: run: calling onEvent on alarmd for event {"uei":"uei.opennms.org/generic/traps/SNMP_Link_Up","time":"2018-11-23 17:59:03,554-0600","dbid":19431252,"source":"trapd","nodeid":1673,"parms":[{".1.3.6.1.2.1.2.2.1.1.527305216":"527305216"}, {".1.3.6.1.2.1.2.2.1.7.527305216":"1"}, {".1.3.6.1.2.1.2.2.1.8.527305216":"1"}, {".1.3.6.1.2.1.2.2.1.2.527305216":"Ethernet111/1/41"}, {".1.3.6.1.2.1.31.1.1.1.18.527305216":"LS2E31-AZ1-1017"}, {".1.3.6.1.6.3.1.1.4.3.0":".1.3.6.1.6.3.1.1.5.4"}, {"ifIndex":"527305216"}]} 2018-11-23 18:00:18,889 DEBUG [alarmd-Thread-3-of-4] o.o.n.a.AlarmPersisterImpl: process: uei.opennms.org/generic/traps/SNMP_Link_Up; nodeid: 1673; ipaddr: 7.192.16.6; serviceid: null 2018-11-23 18:00:18,891 DEBUG [alarmd-Thread-3-of-4] o.o.n.a.AlarmPersisterImpl: addOrReduceEventAsAlarm: looking for existing reduction key: uei.opennms.org/generic/traps/SNMP_Link_Up:00000000-0000-0000-0000-000000000000:1673:527305216 2018-11-23 18:00:18,895 DEBUG [alarmd-Thread-3-of-4] o.o.n.a.AlarmPersisterImpl: addOrReduceEventAsAlarm: reductionKey:uei.opennms.org/generic/traps/SNMP_Link_Up:00000000-0000-0000-0000-000000000000:1673:527305216 found, reducing event to existing alarm: /7.192.16.6 2018-11-23 18:00:18,907 DEBUG [alarmd-Thread-4-of-4] o.o.n.a.d.DroolsAlarmContext: Inserting alarm into session: OnmsAlarm{alarmid=1470370, distPoller=OnmsDistPoller{id=00000000-0000-0000-0000-000000000000, label=localhost, location=Default, type=OpenNMS}, uei=uei.opennms.org/vendor/cisco/syslog/ifUp, severity=CLEARED, lastEventTime=2018-11-23 17:54:51.0} 2018-11-23 18:00:18,908 DEBUG [alarmd-Thread-4-of-4] o.o.n.d.h.AbstractDaoHibernate: criteria = Criteria [class=class org.opennms.netmgt.model.OnmsAcknowledgment,orders=[Order [attribute=ackTime, ascending=false], Order [attribute=id, ascending=false]],restrictions=[EqRestriction [attribute=refId, value=1470370]],distinct=false,limit=1] 2018-11-23 18:00:18,914 DEBUG [alarmd-Thread-4-of-4] o.o.n.a.d.DroolsAlarmContext: Inserting first alarm acknowledgement into session: Acknowledgment ID:0 User:admin Time:2018-11-23 17:54:51.0 AckType:Alarm AckAction:Unacknowledge Acknowledable ID:1470370 2018-11-23 18:00:18,914 DEBUG [alarmd-Thread-4-of-4] o.o.n.b.d.Bsmd: Handling alarm with id: 1470370, reduction key: uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41 and severity: CLEARED and status: Indeterminate 2018-11-23 18:00:18,924 DEBUG [alarmd-Thread-3-of-4] o.o.n.d.h.AbstractDaoHibernate: criteria = Criteria [class=class org.opennms.netmgt.model.OnmsAcknowledgment,orders=[Order [attribute=ackTime, ascending=false], Order [attribute=id, ascending=false]],restrictions=[EqRestriction [attribute=refId, value=1470337]],distinct=false,limit=1] 2018-11-23 18:00:18,931 DEBUG [alarmd-Thread-3-of-4] o.o.n.b.d.Bsmd: Handling alarm with id: 1470337, reduction key: uei.opennms.org/generic/traps/SNMP_Link_Down:00000000-0000-0000-0000-000000000000:1673:527305216 and severity: CLEARED and status: Indeterminate 2018-11-23 18:00:18,942 DEBUG [alarmd-Thread-1-of-4] o.o.n.e.EventIpcManagerDefaultImpl: run: calling onEvent on alarmd for event {"uei":"uei.opennms.org/vendor/cisco/syslog/ifUp","time":"2018-11-23 17:54:51,000-0600","dbid":19431253,"source":"syslogd","nodeid":1673,"parms":[{"hostname":"7.192.16.6"}, {"syslogmessage":"%ETHPORT-5-IF_UP: Interface Ethernet111/1/41 is up in mode access"}, {"severity":"Notice"}, {"timestamp":"Nov 23 23:54:51"}, {"service":"local7"}, {"group1":"Ethernet111/1/41"}, {"ifDescr":"Ethernet111/1/41"}]} 2018-11-23 18:00:18,942 DEBUG [alarmd-Thread-1-of-4] o.o.n.a.AlarmPersisterImpl: process: uei.opennms.org/vendor/cisco/syslog/ifUp; nodeid: 1673; ipaddr: 7.192.16.6; serviceid: null 2018-11-23 18:00:18,943 DEBUG [alarmd-Thread-1-of-4] o.o.n.a.AlarmPersisterImpl: addOrReduceEventAsAlarm: looking for existing reduction key: uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41 2018-11-23 18:00:18,943 DEBUG [alarmd-Thread-1-of-4] o.o.n.a.AlarmPersisterImpl: addOrReduceEventAsAlarm: reductionKey:uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41 not found, instantiating new alarm 2018-11-23 18:00:18,966 DEBUG [alarmd-Thread-1-of-4] o.o.n.a.d.DroolsAlarmContext: Inserting alarm into session: OnmsAlarm{alarmid=1470371, distPoller=OnmsDistPoller{id=00000000-0000-0000-0000-000000000000, label=localhost, location=Default, type=OpenNMS}, uei=uei.opennms.org/vendor/cisco/syslog/ifUp, severity=CLEARED, lastEventTime=2018-11-23 17:54:51.0} 2018-11-23 18:00:18,966 DEBUG [alarmd-Thread-1-of-4] o.o.n.d.h.AbstractDaoHibernate: criteria = Criteria [class=class org.opennms.netmgt.model.OnmsAcknowledgment,orders=[Order [attribute=ackTime, ascending=false], Order [attribute=id, ascending=false]],restrictions=[EqRestriction [attribute=refId, value=1470371]],distinct=false,limit=1] 2018-11-23 18:00:18,971 DEBUG [alarmd-Thread-1-of-4] o.o.n.a.d.DroolsAlarmContext: Inserting first alarm acknowledgement into session: Acknowledgment ID:0 User:admin Time:2018-11-23 17:54:51.0 AckType:Alarm AckAction:Unacknowledge Acknowledable ID:1470371 2018-11-23 18:00:18,971 DEBUG [alarmd-Thread-1-of-4] o.o.n.b.d.Bsmd: Handling alarm with id: 1470371, reduction key: uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41 and severity: CLEARED and status: Indeterminate 2018-11-23 18:00:18,984 WARN [alarmd-Thread-1-of-4] o.h.u.JDBCExceptionReporter: SQL Error: 0, SQLState: 23505 2018-11-23 18:00:18,984 ERROR [alarmd-Thread-1-of-4] o.h.u.JDBCExceptionReporter: ERROR: duplicate key value violates unique constraint "alarm_reductionkey_idx" Detail: Key (reductionkey)=(uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41) already exists. 2018-11-23 18:00:18,987 DEBUG [alarmd-Thread-1-of-4] o.o.n.e.a.AnnotationBasedEventListenerAdapter: Caught an unhandled exception while processing event uei.opennms.org/vendor/cisco/syslog/ifUp, for listener org.opennms.netmgt.alarmd.Alarmd@3f250786. Add EventExceptionHandler annotation to the listener org.springframework.dao.DataIntegrityViolationException: could not insert: [org.opennms.netmgt.model.OnmsAlarm]; SQL [insert into alarms (tticketId, tticketState, alarmAckTime, alarmAckUser, alarmType, applicationDN, clearKey, counter, description, systemId, firstAutomationTime, firstEventTime, ifIndex, ipAddr, lastAutomationTime, lastEventId, lastEventTime, logmsg, managedObjectInstance, managedObjectType, mouseOverText, nodeId, operinstruct, ossPrimaryKey, qosAlarmState, reductionKey, serviceid, severity, stickymemo, suppressedTime, suppressedUntil, suppressedUser, eventUEI, x733AlarmType, x733ProbableCause, alarmId) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]; constraint [alarm_reductionkey_idx]; nested exception is org.hibernate.exception.ConstraintViolationException: could not insert: [org.opennms.netmgt.model.OnmsAlarm] at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:659) ~[org.apache.servicemix.bundles.spring-orm-4.2.9.RELEASE_1.jar:?] at org.springframework.orm.hibernate3.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:800) ~[org.apache.servicemix.bundles.spring-orm-4.2.9.RELEASE_1.jar:?] at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:670) ~[org.apache.servicemix.bundles.spring-orm-4.2.9.RELEASE_1.jar:?] at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761) ~[org.apache.servicemix.bundles.spring-tx-4.2.9.RELEASE_1.jar:?] at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730) ~[org.apache.servicemix.bundles.spring-tx-4.2.9.RELEASE_1.jar:?] at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:150) ~[org.apache.servicemix.bundles.spring-tx-4.2.9.RELEASE_1.jar:?] at org.opennms.netmgt.alarmd.AlarmPersisterImpl.persist(AlarmPersisterImpl.java:120) ~[opennms-alarmd-24.0.0-SNAPSHOT.jar:?] at org.opennms.netmgt.alarmd.Alarmd.onEvent(Alarmd.java:85) ~[opennms-alarmd-24.0.0-SNAPSHOT.jar:?] at sun.reflect.GeneratedMethodAccessor496.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_112] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_112] at org.opennms.netmgt.events.api.AnnotationBasedEventListenerAdapter.processEvent(AnnotationBasedEventListenerAdapter.java:221) [org.opennms.features.events.api-24.0.0-SNAPSHOT.jar:?] at org.opennms.netmgt.events.api.AnnotationBasedEventListenerAdapter$1.run(AnnotationBasedEventListenerAdapter.java:182) [org.opennms.features.events.api-24.0.0-SNAPSHOT.jar:?] at org.opennms.core.logging.Logging.withPrefix(Logging.java:71) [org.opennms.core.logging-24.0.0-SNAPSHOT.jar:?] at org.opennms.netmgt.events.api.AnnotationBasedEventListenerAdapter.onEvent(AnnotationBasedEventListenerAdapter.java:175) [org.opennms.features.events.api-24.0.0-SNAPSHOT.jar:?] at org.opennms.netmgt.eventd.EventIpcManagerDefaultImpl$EventListenerExecutor$2.run(EventIpcManagerDefaultImpl.java:189) [org.opennms.features.events.daemon-24.0.0-SNAPSHOT.jar:?] at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1626) [?:1.8.0_112] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112] at org.opennms.core.concurrent.LogPreservingThreadFactory$3.run(LogPreservingThreadFactory.java:124) [opennms-util-24.0.0-SNAPSHOT.jar:?] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112] Caused by: org.hibernate.exception.ConstraintViolationException: could not insert: [org.opennms.netmgt.model.OnmsAlarm] at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:96) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2455) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2875) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:79) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:273) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:265) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:184) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:383) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:133) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:662) ~[org.apache.servicemix.bundles.spring-orm-4.2.9.RELEASE_1.jar:?] ... 18 more Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "alarm_reductionkey_idx" Detail: Key (reductionkey)=(uei.opennms.org/vendor/cisco/syslog/ifUp:00000000-0000-0000-0000-000000000000:1673:Ethernet111/1/41) already exists. at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2458) ~[postgresql-9.4.1211.jar:9.4.1211] at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2158) ~[postgresql-9.4.1211.jar:9.4.1211] at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:291) ~[postgresql-9.4.1211.jar:9.4.1211] at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:432) ~[postgresql-9.4.1211.jar:9.4.1211] at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:358) ~[postgresql-9.4.1211.jar:9.4.1211] at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:171) ~[postgresql-9.4.1211.jar:9.4.1211] at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:138) ~[postgresql-9.4.1211.jar:9.4.1211] at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-2.5.1.jar:?] at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-2.5.1.jar:?] at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2435) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2875) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:79) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:273) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:265) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:184) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:383) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:133) ~[hibernate-core-3.6.10.Final.jar:3.6.10.Final] at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:662) ~[org.apache.servicemix.bundles.spring-orm-4.2.9.RELEASE_1.jar:?] ... 18 more 2018-11-23 18:00:19,793 DEBUG [Timer-1] o.o.n.a.d.DroolsAlarmContext: Firing rules.