[SNMP4J] What I missing about engineTime in SNMPv3?

Tue May 1 00:40:39 CEST 2007

Sorry for the messy email. Obviously hotmail web client is not a WYSIWYG editor.

Tony

> From: tonywillett at hotmail.com> To: snmp4j at agentpp.org> Date: Mon, 30 Apr 2007 15:35:58 -0700> Subject: [SNMP4J] What I missing about engineTime in SNMPv3?> > To Frank or anyone,> > I am having an issue with an agent and manager in regards to v3. I have built both the agent and manager using SNMP4J and SNMP4J Agentpackages. The manager sends confirmed requests to the agent so my understanding is that the agent contains the authoritative engineID. I have confirmed that there is a VACM set up for the USM users that I add to both the agent and manager. I then start the agent applicationand if I start the manager within 150 seconds then all is good in v3 world between the agent and manager. The problem is that if a manager is started more than 150 seconds after the agent startup then I get the "Not in time window" response. I figure I am missing something real simple, but I have been unable to figure it out.> > The Agent is based heavily on org.snmp4j.agent.BaseAgent. Here are what I guess would be interesting Agent snippets:> > public void init() throws IOException { initTransportMappings(); initMessageDispatcher(); agent = new CommandProcessor(localEngineID); server = new DefaultMOServer(); server.addContext(new OctetString()); snmpv2MIB = new SNMPv2MIB(new OctetString("Agent"), new OID("1.3.6.1.4.1.100"), new Integer32(10));> // register Snmp counters for updates dispatcher.addCounterListener(snmpv2MIB); snmpFrameworkMIB = new SnmpFrameworkMIB((USM) mpv3.getSecurityModel(SecurityModel.SECURITY_MODEL_USM), dispatcher.getTransportMappings()); UsmMIB usmMIB = new UsmMIB(usm, SecurityProtocols.getInstance()); usm.addUsmUserListener(usmMIB);> VacmMIB vacmMIB = new VacmMIB(server); /*SnmpTargetMIB*/ targetMIB = new SnmpTargetMIB(session); SnmpNotificationMIB notificationMIB = new SnmpNotificationMIB(); notificationOriginator = new NotificationOriginatorImpl(session, vacmMIB, snmpv2MIB.getSysUpTime(), targetMIB, notificationMIB);> // add USM users addUsmUser(usm); try { targetMIB.registerMOs(server, null); notificationMIB.registerMOs(server, null); vacmMIB.registerMOs(server, null); usmMIB.registerMOs(server, null); snmpv2MIB.registerMOs(server, null); snmpFrameworkMIB.registerMOs(server, null); registerManagedObjects(); } catch(DuplicateRegistrationException ex) { ex.printStackTrace(); } finishInit(vacmMIB, targetMIB, notificationMIB, notificationOriginator); }> protected void initMessageDispatcher() { dispatcher = new MessageDispatcherImpl(); dispatcher.addMessageProcessingModel(new MPv1()); dispatcher.addMessageProcessingModel(new MPv2c()); dispatcher.addMessageProcessingModel(new MPv3());> session = new Snmp(dispatcher); mpv3 = (MPv3)session.getMessageProcessingModel(MessageProcessingModel.MPv3); usm = new USM(SecurityProtocols.getInstance(), new OctetString(localEngineID), 0); //Check the "new" USM with existing USM in the security model and see it //one exists with the same ID already. If so then use it as the instance usm. //If the ID is not the same then add the new USM. SecurityModel existingUSM = SecurityModels.getInstance().getSecurityModel(new Integer32(usm.getID())); if(existingUSM != null && existingUSM instanceof USM) usm = (USM)existingUSM; else SecurityModels.getInstance().addSecurityModel(usm);> SecurityProtocols.getInstance().addDefaultProtocols(); for(int i = 0; i < transportMappings.length; i++) { session.addTransportMapping(transportMappings[i]); } }> > protected void addUsmUser(USM usm) { UsmUser user = new UsmUser(_secName, AuthMD5.ID, _authPass, PrivDES.ID, _privPass); usm.addUser(_secName, new OctetString(localEngineID), user); }> > protected void addViews(VacmMIB vacm) { vacm.addGroup(SecurityModel.SECURITY_MODEL_USM, _secName, _v3Group, StorageType.nonVolatile);> vacm.addAccess(_v3Group, new OctetString(), SecurityModel.SECURITY_MODEL_USM, SecurityLevel.AUTH_PRIV, MutableVACM.VACM_MATCH_EXACT, new OctetString("fullReadWriteView"), new OctetString("fullReadWriteView"), new OctetString("fullReadWriteView"), StorageType.nonVolatile);> vacm.addViewTreeFamily(new OctetString("fullReadWriteView"), new OID(SnmpUtils.LinkMonitorRootOID), new OctetString(), VacmMIB.vacmViewIncluded, StorageType.nonVolatile); } > Corresponding Manager code snippets:> public SnmpManager(String agentAdd, String agentPort, int linkID, IComConCommand callback, int pingTime, boolean useV3) { String METHOD = "CCSnmpClient()"; _logger.writeInfo(METHOD, "linkId = " + linkID + " - "+ getVersion()); try { _linkId = linkID; _commandCallback = callback; _pingMillis = pingTime; _useSNMPv3 = useV3;> _targetAddress = GenericAddress.parse("udp:" + agentAdd + "/" + agentPort); TransportMapping transport = new DefaultUdpTransportMapping(); _snmp = new Snmp(transport); USM usm = new USM(SecurityProtocols.getInstance(), new OctetString(MPv3.createLocalEngineID()), 0); SecurityModels.getInstance().addSecurityModel(usm); transport.listen(); byte[] _authEngineID = _snmp.discoverAuthoritativeEngineID(_targetAddress, 1500); OctetString engOctStr = new OctetString(_authEngineID);> UsmUser user = new UsmUser(_secName, AuthMD5.ID, _authPass, PrivDES.ID, _privPass); usm.addUser(_secName, engOctStr, user); _snmp.getUSM().addUser(_secName, engOctStr, user);> UserTarget _userTarget = new UserTarget(); _userTarget.setAddress(_targetAddress); _userTarget.setRetries(2); _userTarget.setTimeout(2500); _userTarget.setVersion(SnmpConstants.version3); _userTarget.setSecurityLevel(SecurityLevel.AUTH_PRIV); _userTarget.setSecurityName(_secName);> _target = _userTarget; } catch(Exception e) { e.printStackTrace(); } }> > public int GetNumberOfLinks() throws Exception { // creating PDU based on SNMPv3 use or not PDU pdu = (_useSNMPv3?new ScopedPDU():new PDU()); String numLinksOID = SnmpUtils.LinkMonitorRootOID + SnmpUtils.LinkMonitorCountOIDExt; pdu.add(new VariableBinding(new OID(numLinksOID))); VariableBinding b = new VariableBinding(); try { ResponseEvent evt = _snmp.get(pdu, _target); b = evt.getResponse().get(0); Integer32 value = (Integer32)b.getVariable(); return value.getValue(); } catch(ClassCastException cce) { _logger.writeError(_CLASS + ".GetNumberOfLinks()", "Error response: " + b.getOid() + " - " + b.getVariable().toString()); throw cce; } catch(Exception getEx) { _logger.writeWarn(_CLASS + ".GetNumberOfLinks()", "No Number of links response from Agent - " + _targetAddress.toString()); throw getEx; } }> > Agent log snippet:> 04/30 14:13:57.242 0.0.0/1161 DEBUG Received message from /127.0.0.1/3017 with length 61: 30:3b:02:01:03:30:11:02:04:11:0e:23:1a: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:a0:0b:02:01:00:02:01:00:02:01:00:30:0004/30 14:13:57.258 0.0.0/1161 DEBUG SNMPv3 header decoded: msgId=286139162, msgMaxSize=65535, msgFlags=04, secModel=304/30 14:13:57.258 0.0.0/1161 DEBUG RFC3414 §3.2.3 Unknown engine ID: 04/30 14:13:57.258 0.0.0/1161 DEBUG Adding cache entry: StateReference[msgID=286139162,pduHandle=PduHandle[264289321],securityEngineID=,securityModel=org.snmp4j.security.USM at 35c467,securityName=,securityLevel=1,contextEngineID=,contextName=]04/30 14:13:57.258 0.0.0/1161 DEBUG Removed cache entry: StateReference[msgID=286139162,pduHandle=PduHandle[264289321],securityEngineID=,securityModel=org.snmp4j.security.USM at 35c467,securityName=,securityLevel=1,contextEngineID=,contextName=]04/30 14:13:57.258 0.0.0/1161 DEBUG RFC3414 §3.1.4.b Outgoing message is not encrypted04/30 14:13:57.258 0.0.0/1161 DEBUG Sending message to 127.0.0.1/3017 with length 87: 30:55:02:01:03:30:11:02:04:11:0e:23:1a:02:03:00:ff:ff:04:01:00:02:01:03:04:19:30:17:04:09:80:00:13:70:01:c0:a8:01:07:02:01:00:02:01:00:04:00:04:00:04:00:30:22:04:00: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:0104/30 14:13:57.273 0.0.0/1161 WARN 1.3.6.1.6.3.15.1.1.4.0 = 104/30 14:13:57.289 0.0.0/1161 DEBUG Received message from /127.0.0.1/3017 with length 82: 30:50:02:01:03:30:11:02:04:11:0e:23:1b:02:03:00:ff:ff:04:01:04:02:01:03:04:19:30:17:04:09:80:00:13:70:01:c0:a8:01:07:02:01:00:02:01:00:04:00:04:00:04:00:30:1d:04:09:80:00:13:70:01:c0:a8:01:07:04:00:a0:0e:02:04:47:fe:5a:7d:02:01:00:02:01:00:30:0004/30 14:13:57.289 0.0.0/1161 DEBUG SNMPv3 header decoded: msgId=286139163, msgMaxSize=65535, msgFlags=04, secModel=304/30 14:13:57.289 0.0.0/1161 DEBUG Accepting zero length security name04/30 14:13:57.289 0.0.0/1161 DEBUG RFC3412 §7.2.10 - Received PDU is NOT a response or internal class message -> unchanged PduHandle = PduHandle[1207851645]04/30 14:13:57.289 0.0.0/1161 DEBUG Adding cache entry: StateReference[msgID=286139163,pduHandle=PduHandle[1207851645],securityEngineID=80:00:13:70:01:c0:a8:01:07,securityModel=org.snmp4j.security.USM at 35c467,securityName=,securityLevel=1,contextEngineID=80:00:13:70:01:c0:a8:01:07,contextName=]04/30 14:13:57.289 0.0.0/1161 DEBUG Fire process PDU event: CommandResponderEvent[transportMapping=org.snmp4j.transport.DefaultUdpTransportMapping at 197c965peerAddress=127.0.0.1/3017, processed=false, pdu=[GET[reqestID=1207851645, errorStatus=0, errorIndex=0, VBS[]]], securityName=, securityModel=3, securityLevel=1]04/30 14:13:59.523 0.0.0/1161 DEBUG Received message from /127.0.0.1/3017 with length 129: 30:7f:02:01:03:30:11:02:04:11:0e:23:1c:02:03:00:ff:ff:04:01:07:02:01:03:04:35:30:33:04:09:80:00:13:70:01:c0:a8:01:07:02:01:00:02:01:01:04:08:6f:70:74:65:63:68:53:4e:04:0c:62:06:d9:8c:6c:57:33:be:55:12:d5:22:04:08:00:00:00:00:f2:e1:6f:70:04:30:bb:2b:97:ae:69:b0:b0:ff:71:61:13:15:93:39:e6:2b:6c:4f:91:20:60:3b:f8:64:f2:c8:4c:bf:75:29:9b:e6:0b:2a:c2:9a:86:bf:76:a7:26:49:38:30:71:34:49:0004/30 14:13:59.523 0.0.0/1161 DEBUG SNMPv3 header decoded: msgId=286139164, msgMaxSize=65535, msgFlags=07, secModel=304/30 14:13:59.523 0.0.0/1161 DEBUG getUser(engineID=80:00:13:70:01:c0:a8:01:07, securityName=theSecName)> **04/30 14:13:59.523 0.0.0/1161 DEBUG CheckTime: received message outside time window (authorative):1287 > 150**04/30 14:13:59.523 0.0.0/1161 DEBUG RFC3414 §3.2.7.a Not in time window; engineID='80:00:13:70:01:c0:a8:01:07', engineBoots=0, engineTime=1> 04/30 14:13:59.523 0.0.0/1161 DEBUG Adding cache entry: StateReference[msgID=286139164,pduHandle=PduHandle[264289323],securityEngineID=80:00:13:70:01:c0:a8:01:07,securityModel=org.snmp4j.security.USM at 35c467,securityName=theSecName,securityLevel=3,contextEngineID=,contextName=]04/30 14:13:59.523 0.0.0/1161 DEBUG Removed cache entry: StateReference[msgID=286139164,pduHandle=PduHandle[264289323],securityEngineID=80:00:13:70:01:c0:a8:01:07,securityModel=org.snmp4j.security.USM at 35c467,securityName=theSecName,securityLevel=3,contextEngineID=,contextName=]04/30 14:13:59.523 0.0.0/1161 DEBUG RFC3414 §3.1.4.b Outgoing message is not encrypted04/30 14:13:59.523 0.0.0/1161 DEBUG Sending message to 127.0.0.1/3017 with length 108: 30:6a:02:01:03:30:11:02:04:11:0e:23:1c:02:03:00:ff:ff:04:01:01:02:01:03:04:2e:30:2c:04:09:80:00:13:70:01:c0:a8:01:07:02:01:00:02:02:05:08:04:08:6f:70:74:65:63:68:53:4e:04:0c:40:7f:b2:30:c7:9a:b7:f5:29:ae:a6:2b:04:00:30:22:04:00: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:0104/30 14:13:59.523 0.0.0/1161 WARN 1.3.6.1.6.3.15.1.1.2.0 = 1> > Manager log Snippet:> 04/30 14:13:59.070 main DEBUG Context engine ID of scoped PDU is empty! Setting it to authoritative engine ID: 80:00:13:70:01:c0:a8:01:0704/30 14:13:59.070 main DEBUG getUser(engineID=80:00:13:70:01:c0:a8:01:07, securityName=theSecName)04/30 14:13:59.070 main DEBUG RFC3414 §3.1.4.a Outgoing message needs to be encrypted04/30 14:13:59.070 main DEBUG Preparing decrypt_params.04/30 14:13:59.070 main DEBUG Preparing iv for encryption.04/30 14:13:59.086 Thread-3 DEBUG CCProcPingThread.run() -> Setting Process health flag for link 47.04/30 14:13:59.086 Thread-2 DEBUG CCSnmpClient.run() -> Checking Command Flags for link 47.04/30 14:13:59.523 main DEBUG Encryption finished.04/30 14:13:59.523 main DEBUG Adding cache entry: StateReference[msgID=286139164,pduHandle=PduHandle[1207851647],securityEngineID=80:00:13:70:01:c0:a8:01:07,securityModel=org.snmp4j.security.USM at 1e6e305,securityName=theSecName,securityLevel=3,contextEngineID=80:00:13:70:01:c0:a8:01:07,contextName=]04/30 14:13:59.523 main DEBUG Sending message to 127.0.0.1/1161 with length 129: 30:7f:02:01:03:30:11:02:04:11:0e:23:1c:02:03:00:ff:ff:04:01:07:02:01:03:04:35:30:33:04:09:80:00:13:70:01:c0:a8:01:07:02:01:00:02:01:01:04:08:6f:70:74:65:63:68:53:4e:04:0c:62:06:d9:8c:6c:57:33:be:55:12:d5:22:04:08:00:00:00:00:f2:e1:6f:70:04:30:bb:2b:97:ae:69:b0:b0:ff:71:61:13:15:93:39:e6:2b:6c:4f:91:20:60:3b:f8:64:f2:c8:4c:bf:75:29:9b:e6:0b:2a:c2:9a:86:bf:76:a7:26:49:38:30:71:34:49:0004/30 14:13:59.523 .168.1.7/0 DEBUG Received message from /127.0.0.1/1161 with length 108: 30:6a:02:01:03:30:11:02:04:11:0e:23:1c:02:03:00:ff:ff:04:01:01:02:01:03:04:2e:30:2c:04:09:80:00:13:70:01:c0:a8:01:07:02:01:00:02:02:05:08:04:08:6f:70:74:65:63:68:53:4e:04:0c:40:7f:b2:30:c7:9a:b7:f5:29:ae:a6:2b:04:00:30:22:04:00: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:0104/30 14:13:59.523 .168.1.7/0 DEBUG SNMPv3 header decoded: msgId=286139164, msgMaxSize=65535, msgFlags=01, secModel=304/30 14:13:59.523 .168.1.7/0 DEBUG getUser(engineID=80:00:13:70:01:c0:a8:01:07, securityName=theSecName)> **04/30 14:13:59.523 .168.1.7/0 DEBUG CheckTime: received message outside time window (authorative):1286 > 150**04/30 14:13:59.523 .168.1.7/0 DEBUG RFC3414 §3.2.7.a Not in time window; engineID='80:00:13:70:01:c0:a8:01:07', engineBoots=0, engineTime=1288> 04/30 14:13:59.523 .168.1.7/0 WARN 1.3.6.1.6.3.15.1.1.2.0 = 0> The above log snippets are from a run where the agent was started and then the manager was started at a period of time longer than 150 seconds after. The lines marked with ** arethe interesting lines. They show that the engine times were not in sync when the manager was started.How do I synchronize these times? I would have expected the the following line in the manager would do this for me.> > byte[] _authEngineID = _snmp.discoverAuthoritativeEngineID(_targetAddress, 1500);> > Can anyone tell me what I am missing here?> > Thanks > > Tony> _________________________________________________________________> Invite your mail contacts to join your friends list with Windows Live Spaces. It's easy!> http://spaces.live.com/spacesapi.aspx?wx_action=create&wx_url=/friends.aspx&mkt=en-us_______________________________________________> SNMP4J mailing list> SNMP4J at agentpp.org> http://lists.agentpp.org/mailman/listinfo/snmp4j
_________________________________________________________________
Explore the seven wonders of the world
http://search.msn.com/results.aspx?q=7+wonders+world&mkt=en-US&form=QBRE