Hi Frank,
I have been creating an application used to host multiple agents each on their own dedicated thread. I got everything to work with V1 and V2 configurations, but things seemed to break down when introducing a V3 configuration.
When the threads are running and entering in the command:
snmpget -v3 -n public -l AuthPriv -u TEST -a SHA -A "maplesyrup" -x DES -X "maplesyrup" 127.0.0.2:16100 1.3.6.1.4.1.73.17.1.5.1.17.6
Sometimes I will get the desired string output, other times it will give me an error stating that it cannot find the username. This seems to only happen when I host a V3 agent on a thread while running other V1 agents on other threads. I never seem to have the issue when running it alone on the main thread. Is there anyway that there is are non thread-safe methods being executed? It almost seems like there’s some buffer getting junked or some kind of shared resource causing issues?
Failing state debug output of when I poll a v1 agent with snmpget snmpget -v1 -c public 127.0.0.3:28000
followed by snmpget -v3 -n public -l AuthPriv -u TEST -a SHA -A "maplesyrup" -x DES -X "maplesyrup" 127.0.0.2:16100 1.3.6.1.4.1.73.17.1.5.1.17.6
Status issues:
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.4.0 = 1, status=1410
USM_UNKNOWN_ENGINEID
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.3.0 = 1, status=1404
USM_UNKNOWN_SECURITY_NAME
5654 [DefaultUDPTransportMapping_127.0.0.3/28545] DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.3/34175 with length 54: 30:34:02:01:00:04:06:70:75:62:6c:69:63:a0:27:02:04:1c:48:36:f6:02:01:00:02:01:00:30:19:30:17:06:13:2b:06:01:04:01:49:11:01:08:06:01:03:01:04:74:69:01:ba:37:05:00
DEBUG org.snmp4j.Snmp - Fire process PDU event: CommandResponderEvent[securityModel=1, securityLevel=1, maxSizeResponsePDU=65535, pduHandle=PduHandle[474494710], stateReference=StateReference[msgID=0,pduHandle=PduHandle[474494710],securityEngineID=null,securityModel=null,securityName=public,securityLevel=1,contextEngineID=null,contextName=null,retryMsgIDs=null], pdu=GET[requestID=474494710, errorStatus=Success(0), errorIndex=0, VBS[1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105.1.7479 = Null]], messageProcessingModel=0, securityName=public, processed=false, peerAddress=127.0.0.3/34175, transportMapping=org.snmp4j.transport.DefaultUdpTransportMapping@64c9e273, tmStateReference=null]
DEBUG org.snmp4j.agent.mo.snmp.SnmpCommunityMIB - Looking up coexistence info for 'public'
DEBUG org.snmp4j.agent.mo.snmp.SnmpCommunityMIB - Found coexistence info for 'public'=CoexistenceInfo[securityName=cpublic,contextEngineID=80:00:13:70:01:c0:a8:fc:64:10:a1:eb:cc,contextName=public,transportTag=]
DEBUG org.snmp4j.agent.mo.snmp.SnmpCommunityMIB - Address 127.0.0.3/34175 passes filter, because source address filtering is disabled
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Found group name 'v1v2group' for secName 'cpublic' and secModel 1
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Got views [DefaultMOMutableRow2PC[index=9.118.49.118.50.103.114.111.117.112.6.112.117.98.108.105.99.0.1,values=[1, fullReadView, fullWriteView, fullNotifyView, 3, 1]] for group name 'v1v2group'
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Matching against access entry DefaultMOMutableRow2PC[index=9.118.49.118.50.103.114.111.117.112.6.112.117.98.108.105.99.0.1,values=[1, fullReadView, fullWriteView, fullNotifyView, 3, 1] with exactContextMatch=true, prefixMatch=false, matchSecModel=true and matchSecLevel=true
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Matching view found for group name 'v1v2group' is 'fullReadView'
DEBUG org.snmp4j.agent.request.SnmpRequest - Created subrequest 0 with scope org.snmp4j.agent.DefaultMOContextScope[context=public,lowerBound=1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105.1.7479,lowerIncluded=true,upperBound=1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105,upperIncluded=true] from 1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105 = Null
DEBUG org.snmp4j.agent.request.SnmpRequest - SnmpSubRequests initialized: [org.snmp4j.agent.request.SnmpRequest$SnmpSubRequest[scope=org.snmp4j.agent.DefaultMOContextScope[context=public,lowerBound=1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105,lowerIncluded=true,upperBound=1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105,upperIncluded=true],vb=1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105 = Null,status=org.snmp4j.agent.request.RequestStatus@69ae1105,query=null,index=0,targetMO=null]]
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Access allowed for view 'fullReadView' by subtree 1.3 for OID 1.3.6.1.4.1.73.17.1.8.6.1.3.1.4.116.105
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Sending message to 127.0.0.3/34175 with length 71: 30:45:02:01:00:04:06:70:75:62:6c:69:63:a2:38:02:04:1c:48:36:f6:02:01:00:02:01:00:30:2a:30:28:06:13:2b:06:01:04:01:49:11:01:08:06:01:03:01:04:74:69:01:ba:37:04:11:54:68:69:73:20:69:73:20:61:20:73:74:72:69:6e:67:32
10313 [DefaultUDPTransportMapping_127.0.0.4/16101]DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/59238 with length 70: 30:44:02:01:03:30:11:02:04:5f:1b:34:50:02:03:00:ff:e3: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:1a:04:00:04:06:70:75:62:6c:69:63:a0:0e:02:04:39:8d:60:01:02:01:00:02:01:00:30:00
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/59238 with length 70: 30:44:02:01:03:30:11:02:04:5f:1b:34:50:02:03:00:ff:e3: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:1a:04:00:04:06:70:75:62:6c:69:63:a0:0e:02:04:39:8d:60:01:02:01:00:02:01:00:30:00
DEBUG org.snmp4j.security.USM - RFC3414 §3.2.3 Unknown engine ID:
DEBUG org.snmp4j.security.USM - RFC3414 §3.1.4.b Outgoing message is not encrypted
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Sending message to 127.0.0.4/59238 with length 104: 30:66:02:01:03:30:11:02:04:5f:1b:34:50:02:03:00:ff:ff:04:01:00:02:01:03:04:1d:30:1b:04:0d:80:00:13:70:01:c0:a8:fc:64:ad:fa:6d:87:02:01:00:02:01:00:04:00:04:00:04:00:30:2f:04:0d:80:00:13:70:01:c0:a8:fc:64:ad:fa:6d:87: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:01
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.4.0 = 1, status=1410
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/59238 with length 146: 30:81:8f:02:01:03:30:11:02:04:5f:1b:34:4f:02:03:00:ff:e3:04:01:07:02:01:03:04:35:30:33:04:0d:80:00:13:70:01:c0:a8:fc:64:ad:fa:6d:87:02:01:00:02:01:00:04:04:54:45:53:54:04:0c:9d:98:bb:16:0a:8e:eb:1d:26:5c:cc:3e:04:08:00:00:00:01:b1:b4:29:4d:04:40:2a:1b:0c:e1:e7:97:a2:74:56:24:b2:ba:e3:4b:32:eb:7b:1c:94:00:ca:92:73:f5:05:b4:84:c2:b3:b5:bf:15:49:5b:34:8e:39:c9:ba:a6:42:cd:5d:4a:b8:bf:4b:14:94:8a:d6:b1:3a:7b:4a:4d:49:03:1a:f6:4c:50:4f:5a
DEBUG org.snmp4j.security.USM - RFC3414 §3.2.4 Unknown security name: 54:45:53:54 (TEST)
DEBUG org.snmp4j.security.USM - RFC3414 §3.1.4.b Outgoing message is not encrypted
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Sending message to 127.0.0.4/59238 with length 108: 30:6a:02:01:03:30:11:02:04:5f:1b:34:4f:02:03:00:ff:ff:04:01:00:02:01:03:04:21:30:1f:04:0d:80:00:13:70:01:c0:a8:fc:64:ad:fa:6d:87:02:01:00:02:01:00:04:04:54:45:53:54:04:00:04:00:30:2f:04:0d:80:00:13:70:01:c0:a8:fc:64:ad:fa:6d:87: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:03:00:41:01:01
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.3.0 = 1, status=1404
``
Debug output when the Agent responds correctly, notice I am still getting some warnings returned:
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.2.0 = 8, status=1411
USM_NOT_IN_TH_TIME_WINDOW
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.4.0 = 8, status=1410
USM_UNKNOWN_ENGINEID
624649 [DefaultUDPTransportMapping_127.0.0.4/16101] DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/60483 with length 70: 30:44:02:01:03:30:11:02:04:16:0f:e4:76:02:03:00:ff:e3: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:1a:04:00:04:06:70:75:62:6c:69:63:a0:0e:02:04:14:f1:5d:2e:02:01:00:02:01:00:30:00
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/60483 with length 70: 30:44:02:01:03:30:11:02:04:16:0f:e4:76:02:03:00:ff:e3: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:1a:04:00:04:06:70:75:62:6c:69:63:a0:0e:02:04:14:f1:5d:2e:02:01:00:02:01:00:30:00
DEBUG org.snmp4j.security.USM - RFC3414 §3.2.3 Unknown engine ID:
EBUG org.snmp4j.security.USM - RFC3414 §3.1.4.b Outgoing message is not encrypted
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Sending message to 127.0.0.4/60483 with length 104: 30:66:02:01:03:30:11:02:04:16:0f:e4:76:02:03:00:ff:ff:04:01:00:02:01:03:04:1d:30:1b:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee:02:01:00:02:01:00:04:00:04:00:04:00:30:2f:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee: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:08
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.4.0 = 8, status=1410
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/60483 with length 146: 30:81:8f:02:01:03:30:11:02:04:16:0f:e4:75:02:03:00:ff:e3:04:01:07:02:01:03:04:35:30:33:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee:02:01:00:02:01:00:04:04:54:45:53:54:04:0c:96:c4:82:4b:89:d1:7c:f2:7b:51:79:cd:04:08:00:00:00:01:8b:75:b4:0a:04:40:4c:db:eb:f1:7b:03:fa:c4:92:c9:aa:22:45:ef:40:79:77:45:67:6b:46:12:e7:47:49:86:a8:02:01:5f:03:a9:4d:0d:4d:9c:46:f1:0c:a0:fe:79:cc:f6:60:aa:b2:ce:3e:39:66:e6:be:a4:54:a8:23:b2:1c:22:ea:a6:98:fb
DEBUG org.snmp4j.security.USM - getUser(engineID=80:00:13:70:01:c0:a8:fc:64:30:43:17:ee, securityName=TEST)
DEBUG org.snmp4j.security.UsmTimeTable - CheckTime: received message outside time window (authoritative):engineBoots differ 80!=0
DEBUG org.snmp4j.security.USM - RFC3414 §3.2.7.a Not in time window; engineID='80:00:13:70:01:c0:a8:fc:64:30:43:17:ee', engineBoots=0, engineTime=0
DEBUG org.snmp4j.security.USM - RFC3414 §3.1.4.b Outgoing message is not encrypted
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Sending message to 127.0.0.4/60483 with length 121: 30:77:02:01:03:30:11:02:04:16:0f:e4:75:02:03:00:ff:ff:04:01:01:02:01:03:04:2e:30:2c:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee:02:01:50:02:02:02:70:04:04:54:45:53:54:04:0c:31:4d:a8:d3:55:fe:fe:af:69:f1:5e:41:04:00:30:2f:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee: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:02:00:41:01:08
WARN org.snmp4j.MessageDispatcherImpl - statusInfo=1.3.6.1.6.3.15.1.1.2.0 = 8, status=1411
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Received message from /127.0.0.4/60483 with length 147: 30:81:90:02:01:03:30:11:02:04:16:0f:e4:77:02:03:00:ff:e3:04:01:07:02:01:03:04:36:30:34:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee:02:01:50:02:02:02:70:04:04:54:45:53:54:04:0c:c5:07:f0:8b:07:6c:7b:8b:2d:25:ce:ee:04:08:00:00:00:01:8b:75:b4:0b:04:40:9a:ff:72:c7:ec:07:3d:6a:c4:8f:dd:d7:b9:e7:aa:6f:90:53:c8:59:22:5f:ad:88:86:78:15:bc:42:1a:c0:3f:8e:89:98:dd:d9:f4:6f:9c:10:21:dc:8e:cf:0e:79:17:ce:e3:79:78:e5:3d:09:20:57:33:02:ee:96:0c:5d:bb
DEBUG org.snmp4j.security.USM - getUser(engineID=80:00:13:70:01:c0:a8:fc:64:30:43:17:ee, securityName=TEST)
DEBUG org.snmp4j.security.UsmTimeTable - CheckTime: time ok (authoritative)
DEBUG org.snmp4j.Snmp - Fire process PDU event: CommandResponderEvent[securityModel=3, securityLevel=3, maxSizeResponsePDU=65325, pduHandle=PduHandle[351362349], stateReference=StateReference[msgID=370140279,pduHandle=null,securityEngineID=80:00:13:70:01:c0:a8:fc:64:30:43:17:ee,securityModel=org.snmp4j.security.USM@2b2eba30,securityName=TEST,securityLevel=3,contextEngineID=80:00:13:70:01:c0:a8:fc:64:30:43:17:ee,contextName=public,retryMsgIDs=null], pdu=GET[{contextEngineID=80:00:13:70:01:c0:a8:fc:64:30:43:17:ee, contextName=public}, requestID=351362349, errorStatus=0, errorIndex=0, VBS[1.3.6.1.4.1.73.17.1.5.1.17.6 = Null]], messageProcessingModel=3, securityName=TEST, processed=false, peerAddress=127.0.0.4/60483, transportMapping=org.snmp4j.transport.DefaultUdpTransportMapping@33ab30a5, tmStateReference=null]
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Found group name 'v3test' for secName 'TEST' and secModel 3
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Got views [DefaultMOMutableRow2PC[index=6.118.51.116.101.115.116.6.112.117.98.108.105.99.3.3,values=[1, testReadView, testWriteView, testNotifyView, 3, 1]] for group name 'v3test'
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Matching against access entry DefaultMOMutableRow2PC[index=6.118.51.116.101.115.116.6.112.117.98.108.105.99.3.3,values=[1, testReadView, testWriteView, testNotifyView, 3, 1] with exactContextMatch=true, prefixMatch=false, matchSecModel=true and matchSecLevel=true
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Matching view found for group name 'v3test' is 'testReadView'
DEBUG org.snmp4j.agent.request.SnmpRequest - Created subrequest 0 with scope org.snmp4j.agent.DefaultMOContextScope[context=public,lowerBound=1.3.6.1.4.1.73.17.1.5.1.17.6,lowerIncluded=true,upperBound=1.3.6.1.4.1.73.17.1.5.1.17.6,upperIncluded=true] from 1.3.6.1.4.1.73.17.1.5.1.17.6 = Null
DEBUG org.snmp4j.agent.request.SnmpRequest - SnmpSubRequests initialized: [org.snmp4j.agent.request.SnmpRequest$SnmpSubRequest[scope=org.snmp4j.agent.DefaultMOContextScope[context=public,lowerBound=1.3.6.1.4.1.73.17.1.5.1.17.6,lowerIncluded=true,upperBound=1.3.6.1.4.1.73.17.1.5.1.17.6,upperIncluded=true],vb=1.3.6.1.4.1.73.17.1.5.1.17.6 = Null,status=org.snmp4j.agent.request.RequestStatus@12bffbd6,query=null,index=0,targetMO=null]]
DEBUG org.snmp4j.agent.mo.snmp.VacmMIB - Access allowed for view 'testReadView' by subtree 1.3 for OID 1.3.6.1.4.1.73.17.1.5.1.17.6
DEBUG org.snmp4j.security.USM - RFC3414 §3.1.4.a Outgoing message needs to be encrypted
DEBUG org.snmp4j.security.PrivDES - Preparing decrypt_params.
DEBUG org.snmp4j.security.PrivDES - Preparing iv for encryption.
EBUG org.snmp4j.security.PrivacyGeneric - Using padding.
DEBUG org.snmp4j.security.PrivDES - Encryption finished.
DEBUG org.snmp4j.transport.DefaultUdpTransportMapping - Sending message to 127.0.0.4/60483 with length 163: 30:81:a0:02:01:03:30:11:02:04:16:0f:e4:77:02:03:00:ff:ff:04:01:03:02:01:03:04:36:30:34:04:0d:80:00:13:70:01:c0:a8:fc:64:30:43:17:ee:02:01:50:02:02:02:70:04:04:54:45:53:54:04:0c:1e:39:a8:1a:57:33:c1:c8:85:b0:2b:76:04:08:00:00:00:50:0e:5b:1b:55:04:50:d4:22:0c:8c:37:95:ea:1f:3a:dd:95:15:ca:21:4e:82:9b:d3:0a:48:55:d0:8f:ee:e8:60:90:1c:49:09:cb:1b:00:25:dc:41:d5:2f:06:ef:06:6b:86:9a:b3:a6:ae:49:b4:cb:02:50:43:ce:f9:28:34:97:b1:09:43:3a:0d:8a:bc:97:b0:c1:81:0e:30:5f:83:c4:fe:f9:00:a3:d6:b1
Agent code can be founder here:Converting an Agent from SNMPv2 to SNMPV3 Its pretty much the same except that I fixed the context definition of my MOs being null