Ode to a Dead Bug




Then you have a service you can play with. Kill it and watch the events, set up notifications, etc.

However, it was real embarrassing when students would stop httpd, and see a node down event instead of the node lost service event.

It finally happened in an environment I could capture, and I found the issue. Service polls on a node usually occur at about the same time. So OpenNMS would poll ICMP, DNS, HTTP, etc. at close to the same moment. Well, when a service poll fails, the poller checks the critical service, by default ICMP.

As of 1.1, part of the new poller is the storage of the response time in an RRD file. A second ICMP poll on the heels of the first can result in a second RRD update command with the same time stamp.
This throws a java RuntimeException, which is effectively a failed poll.

So the scenario is as follows:

  • OpenNMS polls ICMP on a node, and updates an RRD.
  • OpenNMS polls HTTP on a node, which fails.
  • ICMP, as the critical service, is immediately polled again.
  • This results in another update to the RRD. If it is quick enough, the second update fails and throws a RuntimeException.
  • The critical service poll is seen to fail, and thus the node is marked down.

This is now fixed in CVS by catching the exception and simply throwing a log when this happens. It is tracked as Bug 748.