notificationOriginator.notify() slow

When I send my Alarm clear trap, it is taking over 5 seconds for each alarm to clear. The function that seems to be taking the longest is notificationOriginator.notify(). Any idea what might be going on?

I assume that you are using SNMPv3 to send notifications and that you are using authNoPriv or authPriv security level:

  • When you send a notification to a target, the SNMPv3 USM user that is used is being localised with the local engine ID - if this has not been done yet. This localisation requires a lot of CPU power, because security algorithms are used for that. Depending on the CPU power of the system, this may take some time.

  • Besides the hashing/encryption of passphrase to keys (see above), on some systems, generating a random number could also take a lot of time.

  • For TLS targets, the TLS handshake can take some time too. In such cases, UDP with decent SHA-2/AES SNMPv3 auth/priv protocols could provide much better performance regarding delay (but not necessarily regarding throughput for the same target).

BTW, which version of SNMP4J/SNMP4J-Agent are you using?

I tracked it down to a specific “sendNotification()” call inside NotificationOrginator.notify(). It is the first call to sendNotification() and it takes about 5 seconds. The log I have captured is below:

Jul 15, 2019 8:55:35 PM org.snmp4j.log.JavaLogAdapter log
INFO: Sent notification with ID 2 INFORM[requestID=1943531406, errorStatus=Success(0), errorIndex=0, VBS[1.3.6.1.2.1.1.3.0 = 0:00:10.66; 1.3.6.1.6.3.1.1.4.1.0 = 1.3.6.1.4.1.5351.1.50.0.101; 1.3.6.1.4.1.5351.1.50.99.0 = 2]] to CommunityTarget[address=127.0.0.1/162,version=1,timeout=2500,retries=1,securityLevel=1,securityModel=1,securityName=public,preferredTransports=null]
DefaultMOMutableRow2PC[index=110.111.116.105.102.121.50,values=[1.3.6.1.2.1.100.1.1, 7f:00:00:01:00:a2, 250, 1, notify notifySecure, SNMPv2c, 4, 1] took 5009ms

I would like to remove this target from the target MIB, but I don’t know how to find the “name” to pass to targetMIB.removeTargetAddress(OctetString name).

I removed this address in a very hackish way by not executing sendNotification() on the first iteration, and the problem went away, but there must be a better way and an underlying explanation.

Thanks for the quick response,

I am using SNMP4J version 2.7.0, and SNMP4J-Agent-2.6.3. I had trouble getting newer versions to run on my system because they require later versions of Java than Version 8. I am using a raspberry pi compute module.

I’m not sure if I am using SNMPv3 yet, I have attached the code where I add the target to the target MIB. It looks like I specify V2C here.

You are actually sending an INFORM request with timeout 2500ms and one retry. That is why it takes 5 seconds to send the next notification. The notification (inform) sending is not multi-threaded by default in SNMP4J-Agent 2.x. Thus an INFORM request that times out (because the receiver does not send a response) will block any following notifications.

To fix that, remove the INFORM target from the snmpTargetAddrEntry by defining your own SnmpAgentConfig.properties file where this row is not added. In the default properties file, this row is defined by

snmp4j.agent.cfg.index.1.3.6.1.6.3.12.1.2.1.1={o}'notify2'
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.0={o}1.3.6.1.2.1.100.1.1
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.1={x}7F:00:00:01:00:A2
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.2={i}250
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.3={i}1
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.4={s}notify notifySecure
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.5={s}SNMPv2c
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.6={i}3
snmp4j.agent.cfg.value.1.3.6.1.6.3.12.1.2.1.1.7={i}1

To delete it programmatically, call

removeTargetAddress(new OctetString("notify2"));

Thank you, that fixed it.