Hi,
I’ve taken the example from SNMPv3 GETNEXT Example and tried this w/SNMP4J v2.8.5. This seems to fundamentally work, however, for some reason, I am seeing duplicate requests/responses and this is resulting in an eventual exception. The log is below and I’ve confirmed with Wireshark that two get-next-requests/get-responses occur. I’m guessing that this why the notify()
is throwing, but I’m not sure why the duplication is happening.
Any thoughts on this? I am a new user to SNMP4J so it’s likely that I’ve just overlooked something obvious here ;)…
Thanks!
Initialized Salt to e767a2fae215bbae. UDP receive buffer size for socket 0.0.0.0/0 is set to: 65536 Adding user admin = UsmUser[secName=admin,authProtocol=1.3.6.1.6.3.10.1.1.3,authPassphrase=initauth,privProtocol=1.3.6.1.6.3.10.1.2.4,privPassphrase=initpriv,localizationEngineID=null] RFC3414 §3.1.4.b Outgoing message is not encrypted Adding cache entry: StateReference[msgID=1030587082,pduHandle=PduHandle[1853501735],securityEngineID=,securityModel=org.snmp4j.security.USM@ae45eb6,securityName=admin,securityLevel=1,contextEngineID=,contextName=,retryMsgIDs=null] Running pending async request with handle PduHandle[1853501735] and retry count left 1 Sending message to 205.159.216.220/161 with length 61: 30:3b:02:01:03:30:11:02:04:3d:6d:82:ca:02:03:00:ff:ff:04:01:04:02:01:03:04:10:30:0e:04:00:02:01:00:02:01:00:04:00:04:00:04:00:30:11:04:00:04:00:a1:0b:02:01:00:02:01:00:02:01:00:30:00 Received message from /205.159.216.220/161 with length 107: 30:69:02:01:03:30:11:02:04:3d:6d:82:ca:02:03:00:ff:e3:04:01:00:02:01:03:04:20:30:1e:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:02:02:01:18:02:03:05:3b:ff:04:00:04:00:04:00:30:2f:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:04:00:a8:1c:02:01:00:02:01:00:02:01:00:30:11:30:0f:06:0a:2b:06:01:06:03:0f:01:01:04:00:41:01:17 SNMPv3 header decoded: msgId=1030587082, msgMaxSize=65507, msgFlags=00, secModel=3 Accepting zero length security name Removed cache entry: StateReference[msgID=1030587082,pduHandle=null,securityEngineID=,securityModel=org.snmp4j.security.USM@ae45eb6,securityName=admin,securityLevel=1,contextEngineID=,contextName=,retryMsgIDs=null] RFC3412 §7.2.10 - Received PDU (msgID=1030587082) is a response or an internal class message. PduHandle.transactionID = 1853501735 MPv3 finished CommandResponderEvent[securityModel=3, securityLevel=1, maxSizeResponsePDU=65400, pduHandle=PduHandle[1853501735], stateReference=null, pdu=REPORT[{contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, contextName=}, requestID=0, errorStatus=0, errorIndex=0, VBS[1.3.6.1.6.3.15.1.1.4.0 = 23]], messageProcessingModel=3, securityName=, processed=false, peerAddress=205.159.216.220/161, transportMapping=org.snmp4j.transport.DefaultUdpTransportMapping@16aed750, tmStateReference=null] Searching pending request with handlePduHandle[1853501735] Send new request after report. Context engine ID of scoped PDU is empty! Setting it to authoritative engine ID: 80:00:1f:88:80:16:89:14:3c:65:66:51:5d getUser(engineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, securityName=admin) SHA-1First digest: d0:b5:b2:e7:31:aa:ae:e7:ee:86:75:29:0c:34:1e:78:51:68:99:4d SHA-1localized key: 21:f4:c1:5c:cd:02:d8:c6:ad:79:94:49:fc:c2:a1:ca:11:28:5e:6f SHA-1First digest: 21:9f:31:da:0f:fd:c6:a8:ef:10:7c:95:cf:4e:90:6e:22:32:f6:76 SHA-1localized key: 6e:6b:7e:c5:5a:d3:14:0a:42:3a:0c:16:6a:30:b6:18:4d:24:39:7f Adding user admin = UsmUser[secName=admin,authProtocol=1.3.6.1.6.3.10.1.1.3,authPassphrase=21:f4:c1:5c:cd:02:d8:c6:ad:79:94:49:fc:c2:a1:ca:11:28:5e:6f,privProtocol=1.3.6.1.6.3.10.1.2.4,privPassphrase=6e:6b:7e:c5:5a:d3:14:0a:42:3a:0c:16:6a:30:b6:18,localizationEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d] RFC3414 §3.1.4.a Outgoing message needs to be encrypted initVect is 00:00:01:18:00:05:3c:00:e7:67:a2:fa:e2:15:bb:ae getUser(engineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, securityName=admin) RFC3414 §3.1.4.a Outgoing message needs to be encrypted initVect is 00:00:01:18:00:05:3c:00:e7:67:a2:fa:e2:15:bb:af aes encrypt: Data to encrypt 30:2b:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:04:00:a1:18:02:04:6e:7a:31:27:02:01:00:02:01:00:30:0a:30:08:06:04:29:03:06:01:05:00 aes encrypt: Data to encrypt 30:2b:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:04:00:a1:18:02:04:6e:7a:31:27:02:01:00:02:01:00:30:0a:30:08:06:04:29:03:06:01:05:00 aes encrypt: used key 6e:6b:7e:c5:5a:d3:14:0a:42:3a:0c:16:6a:30:b6:18 aes encrypt: used key 6e:6b:7e:c5:5a:d3:14:0a:42:3a:0c:16:6a:30:b6:18 aes encrypt: created privacy_params e7:67:a2:fa:e2:15:bb:af aes encrypt: created privacy_params e7:67:a2:fa:e2:15:bb:ae aes encrypt: encrypted Data 8f:35:c3:62:de:b7:b6:be:df:b3:32:96:7b:86:08:c1:1b:3a:a8:5f:35:af:3d:be:27:63:e0:79:c5:8c:16:7e:88:d8:db:88:99:cd:34:9e:ea:8a:f5:2c:be aes encrypt: encrypted Data 6f:6a:88:77:db:19:e2:9c:b0:40:dd:77:af:77:9a:ae:8c:8d:ae:91:bf:79:43:8b:52:d7:8a:aa:1c:c5:28:c7:fb:46:db:bf:86:0f:c1:7f:d7:5d:9f:9b:66 Adding cache entry: StateReference[msgID=1030587083,pduHandle=PduHandle[1853501735],securityEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,securityModel=org.snmp4j.security.USM@ae45eb6,securityName=admin,securityLevel=3,contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,contextName=,retryMsgIDs=null] Adding cache entry: StateReference[msgID=1030587084,pduHandle=PduHandle[1853501735],securityEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,securityModel=org.snmp4j.security.USM@ae45eb6,securityName=admin,securityLevel=3,contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,contextName=,retryMsgIDs=null] Sending message to 205.159.216.220/161 with length 131: 30:81:80:02:01:03:30:11:02:04:3d:6d:82:cb:02:03:00:ff:ff:04:01:07:02:01:03:04:39:30:37:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:02:02:01:18:02:03:05:3c:00:04:05:61:64:6d:69:6e:04:0c:a5:ae:2d:25:62:a6:e8:bb:bd:61:a9:97:04:08:e7:67:a2:fa:e2:15:bb:ae:04:2d:6f:6a:88:77:db:19:e2:9c:b0:40:dd:77:af:77:9a:ae:8c:8d:ae:91:bf:79:43:8b:52:d7:8a:aa:1c:c5:28:c7:fb:46:db:bf:86:0f:c1:7f:d7:5d:9f:9b:66 Adding previous message IDs [1030587083] to new entry StateReference[msgID=1030587084,pduHandle=PduHandle[1853501735],securityEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,securityModel=org.snmp4j.security.USM@ae45eb6,securityName=admin,securityLevel=3,contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,contextName=,retryMsgIDs=null] Running pending async request with handle PduHandle[1853501735] and retry count left 0 Sending message to 205.159.216.220/161 with length 131: 30:81:80:02:01:03:30:11:02:04:3d:6d:82:cc:02:03:00:ff:ff:04:01:07:02:01:03:04:39:30:37:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:02:02:01:18:02:03:05:3c:00:04:05:61:64:6d:69:6e:04:0c:56:0d:f9:ea:e9:5b:a7:a7:f9:ca:db:c6:04:08:e7:67:a2:fa:e2:15:bb:af:04:2d:8f:35:c3:62:de:b7:b6:be:df:b3:32:96:7b:86:08:c1:1b:3a:a8:5f:35:af:3d:be:27:63:e0:79:c5:8c:16:7e:88:d8:db:88:99:cd:34:9e:ea:8a:f5:2c:be Received message from /205.159.216.220/161 with length 178: 30:81:af:02:01:03:30:11:02:04:3d:6d:82:cb:02:03:00:ff:e3:04:01:03:02:01:03:04:39:30:37:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:02:02:01:18:02:03:05:3c:00:04:05:61:64:6d:69:6e:04:0c:9e:03:15:11:23:ee:3c:88:15:ad:75:f2:04:08:61:db:61:d8:11:89:26:f5:04:5c:32:01:7a:2c:61:6f:af:69:80:01:5f:d3:68:0f:ca:ac:9f:57:a2:8c:0b:00:b6:17:18:44:2e:a5:a6:39:ed:12:9b:54:2d:76:d4:d3:ca:d4:e1:fa:0d:3a:32:56:a9:d8:f0:78:77:f2:60:70:9a:62:09:cf:f1:a2:76:61:0b:38:27:74:8c:15:0d:21:0a:7f:dd:65:58:2b:6a:17:23:ed:4a:a4:82:57:2d:2a:cf:ed:6e:a0:79:de SNMPv3 header decoded: msgId=1030587083, msgMaxSize=65507, msgFlags=03, secModel=3 getUser(engineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, securityName=admin) CheckTime: time ok (non authoritative) initVect is 00:00:01:18:00:05:3c:00:61:db:61:d8:11:89:26:f5 java.lang.IllegalMonitorStateException Removed cache entry: StateReference[msgID=1030587084,pduHandle=null,securityEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,securityModel=org.snmp4j.security.USM@ae45eb6,securityName=admin,securityLevel=3,contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d,contextName=,retryMsgIDs=[1030587083]] java.lang.IllegalMonitorStateException RFC3412 §7.2.10 - Received PDU (msgID=1030587083) is a response or an internal class message. PduHandle.transactionID = 1853501735 MPv3 finished at java.lang.Object.notify(Native Method) CommandResponderEvent[securityModel=3, securityLevel=3, maxSizeResponsePDU=65325, pduHandle=PduHandle[1853501735], stateReference=null, pdu=RESPONSE[{contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, contextName=}, requestID=1853501735, errorStatus=0, errorIndex=0, VBS[1.3.6.1.2.1.1.1.0 = <xxxxxxxx>]], messageProcessingModel=3, securityName=admin, processed=false, peerAddress=205.159.216.220/161, transportMapping=org.snmp4j.transport.DefaultUdpTransportMapping@16aed750, tmStateReference=null] Looking up pending request with handle PduHandle[1853501735] Cancelling pending request with handle PduHandle[1853501735] Received: RESPONSE[{contextEngineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, contextName=}, requestID=1853501735, errorStatus=0, errorIndex=0, VBS[1.3.6.1.2.1.1.1.0 = <xxxxxxxx>]] Received message from /205.159.216.220/161 with length 178: 30:81:af:02:01:03:30:11:02:04:3d:6d:82:cc:02:03:00:ff:e3:04:01:03:02:01:03:04:39:30:37:04:0d:80:00:1f:88:80:16:89:14:3c:65:66:51:5d:02:02:01:18:02:03:05:3c:00:04:05:61:64:6d:69:6e:04:0c:74:84:e1:ea:e5:8c:00:0e:d2:22:cc:c7:04:08:61:db:61:d8:11:89:26:f6:04:5c:32:34:5e:61:78:e2:ac:70:8d:a7:f5:80:6c:b1:ef:ef:7a:d2:4d:5b:98:9a:d1:95:b9:02:e2:33:38:04:e0:8b:e7:b9:bc:cd:bf:f7:67:f5:78:18:6b:34:4c:aa:1d:45:63:c0:d4:22:b9:7d:79:dc:6f:51:9c:5d:1f:8f:47:cc:27:3c:0d:67:84:40:d7:d2:ac:0a:4c:c7:65:a9:a1:9c:88:87:06:13:e9:f0:bd:be:a2:73:69:6d SNMPv3 header decoded: msgId=1030587084, msgMaxSize=65507, msgFlags=03, secModel=3 getUser(engineID=80:00:1f:88:80:16:89:14:3c:65:66:51:5d, securityName=admin) CheckTime: time ok (non authoritative) initVect is 00:00:01:18:00:05:3c:00:61:db:61:d8:11:89:26:f6 RFC3412 §7.2.10 - Received PDU (msgID=1030587084) is a response or internal class message, but cached information for the msgID could not be found Message from 205.159.216.220/161 not dispatched, reason: statusInfo=noError, status=-1409 at wctest.SNMP4jTest$2.onResponse(SNMP4jTest.java:136) at org.snmp4j.Snmp.processPdu(Snmp.java:1300) at org.snmp4j.MessageDispatcherImpl.fireProcessPdu(MessageDispatcherImpl.java:694) at org.snmp4j.MessageDispatcherImpl.dispatchMessage(MessageDispatcherImpl.java:310) at org.snmp4j.MessageDispatcherImpl.processMessage(MessageDispatcherImpl.java:390) at org.snmp4j.MessageDispatcherImpl.processMessage(MessageDispatcherImpl.java:350) at org.snmp4j.transport.AbstractTransportMapping.fireProcessMessage(AbstractTransportMapping.java:76) at org.snmp4j.transport.DefaultUdpTransportMapping$ListenThread.run(DefaultUdpTransportMapping.java:430) at java.lang.Thread.run(Thread.java:748)