Invalid asset field name in requisition causes node to lose interfaces, services
Description
Acceptance / Success Criteria
is duplicated by
Lucidchart Diagrams
Activity
Benjamin Reed May 9, 2011 at 12:07 PM
This was already fixed in master by seth, I cherry-picked the fix back to 1.8.
Jeff Gehlbach April 28, 2011 at 1:57 PM
Even with a fresh 1.8.11 system I still can't get the affected node to drop its interfaces and services, but I was able to cause the node to fail to re-import by changing the requisition from the one pasted above to the following:
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<model-import last-import="2011-04-28T13:50:02.268-04:00" foreign-source="test" date-stamp="2011-04-28T13:50:02.126-04:00" xmlns="http://xmlns.opennms.org/xsd/config/model-import">
<node node-label="foo" foreign-id="node-foo" building="test">
<interface status="1" snmp-primary="N" ip-addr="127.0.0.1" descr="">
<monitored-service service-name="ICMP"/>
</interface>
<asset value="90210" name="zip"/>
<asset value="bar" name="pollerCategory"/>
<asset value="12345" name="assetNumber"/>
<asset value="54321" name="maintcontract"/>
</node>
</model-import>
Note the addition of the valid "pollerCategory" asset field besides the invalid "maintcontract" one; the pollerCategory asset field is not set after the import, providing further evidence of the failure.
During that failed import, I get the folowing in provisiond.log (after turning up Provisiond logging from the default WARN to DEBUG):
2011-04-28 13:50:02,221 INFO [importExecutor-5] CoreImportActivities: Loading requisition from resource URL [file:/opt/opennms/etc/imports/pending/test.xml]
2011-04-28 13:50:02,279 DEBUG [importExecutor-5] CoreImportActivities: Finished loading requisition.
2011-04-28 13:50:02,283 INFO [importExecutor-1] CoreImportActivities: Auditing nodes for requisition org.opennms.netmgt.provision.persist.requisition.Requisition@34342fd2[foreign-source=test,date-stamp=2011-04-28T13:50:02.126-04:00,last-import=2011-04-28T13:50:02.268-04:00,nodes=[org.opennms.netmgt.provision.persist.requisition.RequisitionNode@4e2f9ec4[interfaces=[org.opennms.netmgt.provision.persist.requisition.RequisitionInterface@18607df6[monitored-services=[org.opennms.netmgt.provision.persist.requisition.RequisitionMonitoredService@66edadfa],categories=[],description=,ip-address=127.0.0.1,is-managed=<null>,snmp-primary=N,status=1]],categories=[],assets=[org.opennms.netmgt.provision.persist.requisition.RequisitionAsset@7e392ce0[name=zip,value=90210], org.opennms.netmgt.provision.persist.requisition.RequisitionAsset@5bb166dd[name=pollerCategory,value=bar], org.opennms.netmgt.provision.persist.requisition.RequisitionAsset@5bd86632[name=assetNumber,value=12345], org.opennms.netmgt.provision.persist.requisition.RequisitionAsset@5c1d8bb9[name=maintcontract,value=54321]],building=test,city=<null>,foreign-id=node-foo,node-label=foo,parent-foreign-id=<null>,parent-node-label=<null>]]]
2011-04-28 13:50:02,286 INFO [importExecutor-1] Phase$PhaseMethod$1: failed to invoke lifecycle instance
java.lang.reflect.InvocationTargetException
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.opennms.netmgt.provision.service.lifecycle.Phase$PhaseMethod.doInvoke(Phase.java:194)
at org.opennms.netmgt.provision.service.lifecycle.Phase$PhaseMethod.access$100(Phase.java:160)
at org.opennms.netmgt.provision.service.lifecycle.Phase$PhaseMethod$1.run(Phase.java:177)
at org.opennms.core.tasks.SyncTask.run(SyncTask.java:92)
at org.opennms.core.tasks.SyncTask$1.run(SyncTask.java:103)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: org.springframework.beans.NotWritablePropertyException: Invalid property 'maintcontract' of bean class [org.opennms.netmgt.model.OnmsAssetRecord]: Bean property 'maintcontract' is not writable or has an invalid setter method. Does the parameter type of the setter match the return type of the getter?
at org.springframework.beans.BeanWrapperImpl.setPropertyValue(BeanWrapperImpl.java:1022)
at org.springframework.beans.BeanWrapperImpl.setPropertyValue(BeanWrapperImpl.java:847)
at org.opennms.netmgt.provision.service.operations.SaveOrUpdateOperation.foundAsset(SaveOrUpdateOperation.java:208)
at org.opennms.netmgt.provision.service.RequisitionAccountant.visitAsset(RequisitionAccountant.java:99)
at org.opennms.netmgt.provision.persist.OnmsAssetRequisition.visit(OnmsAssetRequisition.java:65)
at org.opennms.netmgt.provision.persist.OnmsNodeRequisition.visit(OnmsNodeRequisition.java:128)
at org.opennms.netmgt.provision.persist.requisition.Requisition.visit(Requisition.java:306)
at org.opennms.netmgt.provision.service.operations.ImportOperationsManager.auditNodes(ImportOperationsManager.java:295)
at org.opennms.netmgt.provision.service.CoreImportActivities.auditNodes(CoreImportActivities.java:130)
... 23 more
2011-04-28 13:50:02,287 INFO [importExecutor-6] CoreImportActivities: Scheduling nodes for phase Phase scan of lifecycle import
2011-04-28 13:50:02,287 INFO [importExecutor-6] Phase$PhaseMethod$1: failed to invoke lifecycle instance
java.lang.reflect.InvocationTargetException
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.opennms.netmgt.provision.service.lifecycle.Phase$PhaseMethod.doInvoke(Phase.java:194)
at org.opennms.netmgt.provision.service.lifecycle.Phase$PhaseMethod.access$100(Phase.java:160)
at org.opennms.netmgt.provision.service.lifecycle.Phase$PhaseMethod$1.run(Phase.java:177)
at org.opennms.core.tasks.SyncTask.run(SyncTask.java:92)
at org.opennms.core.tasks.SyncTask$1.run(SyncTask.java:103)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.NullPointerException
at org.opennms.netmgt.provision.service.CoreImportActivities.scanNodes(CoreImportActivities.java:148)
... 23 more
2011-04-28 13:50:02,287 INFO [importExecutor-7] CoreImportActivities: Running relate phase
2011-04-28 13:50:02,288 DEBUG [importExecutor-7] CoreImportActivities$1: Scheduling relate of node org.opennms.netmgt.provision.persist.OnmsNodeRequisition@841a0b4
2011-04-28 13:50:02,288 INFO [importExecutor-7] CoreImportActivities: Finished Running relate phase
2011-04-28 13:50:02,290 INFO [scanExecutor-8] DefaultProvisionService: Setting parent of node: [OnmsNode@62ee6618 id = 2, label = 'foo'] to: null
2011-04-28 13:50:02,290 INFO [scanExecutor-8] DefaultProvisionService: Setting criticalInterface of node: [OnmsNode@62ee6618 id = 2, label = 'foo'] to: null
2011-04-28 13:50:02,291 INFO [Provisiond:EventListener] Provisioner: Finished Importing: Deletes: 0 Updates: 0 Inserts: 0
Importing: has not begun Loading: has not begun Auditing: has not begun
Scanning: has not begun Processing: has not begun Relating: has not begun Total Scan Effort: 0.0 thread-seconds Total Write Effort: 0.0 thread-seconds Total Event Sending Effort: 0.0 thread-seconds
Presumably some factor about the customer's system configuration or the requisition used is making the difference in whether the interfaces and services are deleted.
Steps to reproduce (cannot reproduce on my own 1.8.10 system, but observed on customer's 1.8.11 production system with much larger requisitions under MyNMS ticket #258):
1. Create a wholly valid requisition in OPENNMS_HOME/etc/imports/pending/test.xml with the following contents:
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<model-import last-import="2011-04-27T18:10:04.027-04:00" foreign-source="test" date-stamp="2011-04-27T18:10:03.905-04:00" xmlns="http://xmlns.opennms.org/xsd/config/model-import">
<node node-label="foo" foreign-id="node-foo" building="test">
<interface status="1" snmp-primary="N" ip-addr="127.0.0.1" descr="">
<monitored-service service-name="ICMP"/>
</interface>
<asset value="12345" name="assetNumber"/>
</node>
</model-import>
2. Import the requisition, see that the node is created with all specified interfaces, services, and asset field.
3. Move the requisition into imports/pending and hand-edit it, adding the following invalid asset information after the existing "assetNumber" element:
<asset value="98765" name="bogusassetfield"/>
4. Synchronize the requisition again
Expected result: node remains unchanged, maybe we see a burp in the logs or even an event indicating that there was a problem with the asset information in the requisition
Actual result: all interfaces and services disappear from the node. Very bad.