A problem of 'snmpwalk' result

SNMP4J
1

Hi Frank,

We have below problem and appreciate if you could provide some comments.

For the 1st command, we expect the response should include ‘1.3.6.1.4.1.9.9.395.1.1.2.1.8.1.2’, but it didn’t.
While from the 2nd command, we’re sure that object ‘1.3.6.1.4.1.9.9.395.1.1.2.1.8.1.2’ did exist.

[vcapuser@localhost ~]$ snmpwalk -v 3 -u gsli -l authPriv -a MD5 -A 12345678 -x DES -X 12345678 169.254.63.251:161 1.3.6.1.4.1.9.9.395.1.1.2
SNMPv2-SMI::enterprises.9.9.395.1.1.2.1.1.1.2 = Hex-STRING: 20 00 
SNMPv2-SMI::enterprises.9.9.395.1.1.2.1.4.1.2 = Hex-STRING: 00 0A 94 00 1F 72 

[vcapuser@localhost ~]$ snmpwalk -v 3 -u gsli -l authPriv -a MD5 -A 12345678 -x DES -X 12345678 169.254.63.251:161 1.3.6.1.4.1.9.9.395.1.1.2.1.8
SNMPv2-SMI::enterprises.9.9.395.1.1.2.1.8.1.2 = INTEGER: 1

I captured some logs, and found for the 1st command, snmp4j-agent finds ‘1.3.6.1.4.1.9.9.395.1.1.2.2’ after ‘1.3.6.1.4.1.9.9.395.1.1.2.1.4.1.2’, and skipped ‘1.3.6.1.4.1.9.9.395.1.1.2.1.8.1.2’.
Do you have any idea or suggestion how to debug it?
Thanks a lot.

[DEBUG] 04-Jun-2020::05:43:22,097  Log4j2LogAdapter SnmpApp.0: - Created subrequest 0 with scope org.snmp4j.agent.DefaultMOContextScope[context=,lowerBound=1.3.6.1.4.1.9.9.395.1.1.2.1.4.1.2,lowerIncluded=false,upperBound=null,upperIncluded=false] from 1.3.6.1.4.1.9.9.395.1.1.2.1.4.1.2 = Null
[DEBUG] 04-Jun-2020::05:43:22,097  Log4j2LogAdapter SnmpApp.0: - SnmpSubRequests initialized: [org.snmp4j.agent.request.SnmpRequest$SnmpSubRequest[scope=org.snmp4j.agent.DefaultMOContextScope[context=,lowerBound=1.3.6.1.4.1.9.9.395.1.1.2.1.4.1.2,lowerIncluded=false,upperBound=null,upperIncluded=false],vb=1.3.6.1.4.1.9.9.395.1.1.2.1.4.1.2 = Null,status=RequestStatus{processed=false, phaseComplete=false, errorStatus=0},query=null,index=0,targetMO=null]]
[DEBUG] 04-Jun-2020::05:43:22,097  Log4j2LogAdapter SnmpApp.0: - Access allowed for view 'LIMIB' by subtree 1.3.6.1.4.1.9.9.395 for OID 1.3.6.1.4.1.9.9.395.1.1.2.1.5.1.2
[DEBUG] 04-Jun-2020::05:43:22,097  SnmpAppUtils SnmpApp.0: - Access allowed by view LIMIB subtree 1.3.6.1.4.1.9.9.395 for OID 1.3.6.1.4.1.9.9.395.1.1.2.1.5.1.2
[DEBUG] 04-Jun-2020::05:43:22,098  Log4j2LogAdapter SnmpApp.0: - Processing NEXT query org.snmp4j.agent.CommandProcessor$VACMQuery[]=1.3.6.1.4.1.9.9.395.1.1.2.1.4.1.2< x <null[viewName=LIMIB] with DefaultMOTable[id=1.3.6.1.4.1.9.9.395.1.1.2.1,index=org.snmp4j.agent.mo.MOTableIndex@59883b70,columns=[org.snmp4j.agent.mo.MOMutableColumn[columnID=1,syntax=4,default=null,mutableInService=true,mandatory=true], org.snmp4j.agent.mo.MOMutableColumn[columnID=2,syntax=2,default=null,mutableInService=true,mandatory=true], org.snmp4j.agent.mo.MOMutableColumn[columnID=3,syntax=4,default=null,mutableInService=true,mandatory=true], org.snmp4j.agent.mo.MOMutableColumn[columnID=4,syntax=4,default=null,mutableInService=true,mandatory=true], org.snmp4j.agent.mo.MOMutableColumn[columnID=5,syntax=66,default=null,mutableInService=true,mandatory=true], org.snmp4j.agent.mo.MOMutableColumn[columnID=7,syntax=66,default=null,mutableInService=true,mandatory=true], org.snmp4j.agent.mo.MOMutableColumn[columnID=6,syntax=66,default=null,mutableInService=true,mandatory=true], com.nokia.snmpapp.mo.snmp.GsRowStatus[columnID=8,syntax=2,default=null,mutableInService=true,mandatory=true]]] sub-request with index 0
[DEBUG] 04-Jun-2020::05:43:22,098  Log4j2LogAdapter SnmpApp.0: - Access allowed for view 'LIMIB' by subtree 1.3.6.1.4.1.9.9.395 for OID 1.3.6.1.4.1.9.9.395.1.1.2.2
[DEBUG] 04-Jun-2020::05:43:22,098  SnmpAppUtils SnmpApp.0: - Access allowed by view LIMIB subtree 1.3.6.1.4.1.9.9.395 for OID 1.3.6.1.4.1.9.9.395.1.1.2.2
[DEBUG] 04-Jun-2020::05:43:22,099  Log4j2LogAdapter SnmpApp.0: - Processing NEXT query org.snmp4j.agent.CommandProcessor$VACMQuery[]=1.3.6.1.4.1.9.9.395.1.1.2.2<= x <null[viewName=LIMIB] with com.nokia.snmpapp.mo.GsMdNewIdxScalar[oid=1.3.6.1.4.1.9.9.399.1.1.1.0,access=MOAccessImpl{read|notify},value=0,volatile=false] sub-request with index 0
[DEBUG] 04-Jun-2020::05:43:22,099  Log4j2LogAdapter SnmpApp.0: - Processed GETNEXT/BULK request 'org.snmp4j.agent.request.SnmpRequest$SnmpSubRequest[scope=org.snmp4j.agent.DefaultMOContextScope[context=,lowerBound=1.3.6.1.4.1.9.9.395.1.1.2.2,lowerIncluded=true,upperBound=null,upperIncluded=false],vb=1.3.6.1.4.1.9.9.399.1.1.1.0 = 0,status=RequestStatus{processed=true, phaseComplete=true, errorStatus=0},query=org.snmp4j.agent.CommandProcessor$VACMQuery[]=1.3.6.1.4.1.9.9.395.1.1.2.2<= x <null[viewName=LIMIB],index=0,targetMO=null]' by '1.3.6.1.4.1.9.9.399.1.1.1.0
[DEBUG] 04-Jun-2020::05:43:22,099  SnmpAgent$2$1 SnmpApp.0: - event.MaxSizeResponsePDU was changed from 65325 to 65325 before super.sendResponse
[DEBUG] 04-Jun-2020::05:43:22,103  Log4j2LogAdapter SnmpApp.0: - Removed cache entry: StateReference[msgID=628686757,pduHandle=null,securityEngineID=32473,securityModel=org.snmp4j.security.USM@513f722c,securityName=gsli,securityLevel=3,contextEngineID=32473,contextName=,retryMsgIDs=null]
[DEBUG] 04-Jun-2020::05:43:22,103  Log4j2LogAdapter SnmpApp.0: - RFC3414 搂3.1.4.a Outgoing message needs to be encrypted
[DEBUG] 04-Jun-2020::05:43:22,103  Log4j2LogAdapter SnmpApp.0: - Preparing decrypt_params.
[DEBUG] 04-Jun-2020::05:43:22,103  Log4j2LogAdapter SnmpApp.0: - Preparing iv for encryption.
[DEBUG] 04-Jun-2020::05:43:22,104  Log4j2LogAdapter SnmpApp.0: - Using padding.
[DEBUG] 04-Jun-2020::05:43:22,104  Log4j2LogAdapter SnmpApp.0: - Encryption finished.
[DEBUG] 04-Jun-2020::05:43:22,104  Log4j2LogAdapter SnmpApp.0: - Sending message to 169.254.63.251/55428 with length 123: 30:79:02:01:03:30:11:02:04:25:78:ff:a5:02:03:00:ff:ff:04:01:03:02:01:03:04:2f:30:2d:04:05:33:32:34:37:33:02:02:00:f4:02:02:18:ee:04:04:67:73:6c:69:04:0c:c6:b6:45:af:fa:53:2b:67:31:bd:96:62:04:08:00:00:00:f4:2e:05:2c:3c:04:30:f2:60:cb:42:de:6a:7a:e9:25:b1:c2:f0:14:80:44:a8:1f:b0:47:f1:9f:24:83:14:d9:cb:43:38:d5:4f:64:8d:94:92:a9:1e:6f:7e:c0:44:d7:04:bf:b9:4b:43:dd:53
2

There can be several reasons:

  1. The object’s Variable null (it will then be skipped by a GETNEXT/GETBULK operation)
  2. Column access is (temporarily) notAccessible
  3. Row in the table has been removed while request has been processed.
  4. VACM config (vie ‘LIMIB’) has been changed while request has been processed.
  5. Some special DefaultMOServer registration issue by bypassing registration security checks (duplicate registration, etc.)
  6. Bug in SNMP4J-Agent

Although 6. is not impossible, it is rather unlikely because otherwise this would have been reported in the past 10 years. BTW, What SNMP4J-Agent version are you using?

3

Thanks Frank for the brain stroming.
I’ve found the root cause after a double check.
It’s due to a fault in MIB spec: sequence of c802tapStreamSourceLlcSap and c802tapStreamDestinationLlcSap in ‘SEQUENCE’ and below definition is not alligned.

C802tapStreamEntry ::= SEQUENCE {
    c802tapStreamFields OCTET STRING,
    c802tapStreamInterface INTEGER,
    c802tapStreamDestinationAddress MacAddress,
    c802tapStreamSourceAddress MacAddress,
    c802tapStreamEthernetPid Gauge,
    c802tapStreamSourceLlcSap Gauge,
    c802tapStreamDestinationLlcSap Gauge,
    c802tapStreamStatus RowStatus
    }

c802tapStreamDestinationLlcSap OBJECT-TYPE
    SYNTAX Gauge
    ACCESS read-write
    STATUS mandatory
    DESCRIPTION
        "The value of the IEEE 802.2 Destination SAP."
    ::= { c802tapStreamEntry 6 }

c802tapStreamSourceLlcSap OBJECT-TYPE
    SYNTAX Gauge
    ACCESS read-write
    STATUS mandatory
    DESCRIPTION
        "The value of the IEEE 802.2 Source SAP."
    ::= { c802tapStreamEntry 7 }

So we got below auto-generated code:
public static final int colC802tapStreamSourceLlcSap = 7;
public static final int colC802tapStreamDestinationLlcSap = 6;
public static final int colC802tapStreamStatus = 8;

    public static final int idxC802tapStreamSourceLlcSap = 5;
    public static final int idxC802tapStreamDestinationLlcSap = 6;
    public static final int idxC802tapStreamStatus = 7;

This caused C802tapStreamDestinationLlcSap could not be created, and the result of ‘snmpwalk C802tapStreamTable’ not including C802tapStreamStatus.

I changed below code manually and fixed the issue.

    public static final int idxC802tapStreamSourceLlcSap = 6;
    public static final int idxC802tapStreamDestinationLlcSap = 5;

But I’m still not sure which part of code in snmp4j-agent was impacted by the error sequence and caused the issue.
Could you please help me to understand the whole page of this issue?
BTW, we use snmp4j-agnet 2.7.3.