[SNMP4J] Question regarding request id when doing getnext

[Mátyás Kuti]

Hello,

We are doing the following:

List<VariableBinding> snmpTable = new ArrayList<VariableBinding>();
        for (TreeEvent event : events) {
            if (event != null) {
                if (event.isError()) {
                    logger.info
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2flogger.info>("oid
[" + oid + "] " + event.getErrorMessage());
                }
                VariableBinding[] varBindings = event.getVariableBindings();
                if (varBindings == null || varBindings.length == 0) {
                    continue;
                }
                for (VariableBinding varBinding : varBindings) {
                    snmpTable.add(varBinding);
                }
            }
        }
...

And we have enforced the GETNEXT behavior by setting:
mTarget.setVersion(SnmpConstants.version1);

We experience, that the request IDs increase by 2 instead of the expected 1:

Java-log output:

2014-09-30 15:05:05,888 [DEBUG] Received message from /192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 58:
30:38:02:01:00:04:05:74:72:61:70:73:a2:2c:02:04:1b:b0:d2:2d:02:01:00:02:01:00:30:1e:30:1c:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:30:04:08:07:de:09:1e:0d:02:27:1e
2014-09-30 15:05:05,888 [DEBUG] Looking up pending request with handle
PduHandle[464572973]
2014-09-30 15:05:05,888 [DEBUG] Cancelling pending request with handle
PduHandle[464572973]
2014-09-30 15:05:05,888 [DEBUG] Running pending async request with handle
PduHandle[464572975] and retry count left 1
2014-09-30 15:05:05,888 [DEBUG] Sending message to 192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 50:
30:30:02:01:00:04:05:74:72:61:70:73:a1:24:02:04:1b:b0:d2:2f:02:01:00:02:01:00:30:16:30:14:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:30:05:00
2014-09-30 15:05:05,941 [DEBUG] Received message from /192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 58:
30:38:02:01:00:04:05:74:72:61:70:73:a2:2c:02:04:1b:b0:d2:2f:02:01:00:02:01:00:30:1e:30:1c:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:31:04:08:07:de:09:1e:0d:02:27:50
2014-09-30 15:05:05,941 [DEBUG] Looking up pending request with handle
PduHandle[464572975]
2014-09-30 15:05:05,941 [DEBUG] Cancelling pending request with handle
PduHandle[464572975]
2014-09-30 15:05:05,941 [DEBUG] Running pending async request with handle
PduHandle[464572977] and retry count left 1
2014-09-30 15:05:05,941 [DEBUG] Sending message to 192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 50:
30:30:02:01:00:04:05:74:72:61:70:73:a1:24:02:04:1b:b0:d2:31:02:01:00:02:01:00:30:16:30:14:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:31:05:00
2014-09-30 15:05:05,978 [DEBUG] Received message from /192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 58:
30:38:02:01:00:04:05:74:72:61:70:73:a2:2c:02:04:1b:b0:d2:31:02:01:00:02:01:00:30:1e:30:1c:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:32:04:08:07:de:09:1e:0d:02:28:1a
2014-09-30 15:05:05,978 [DEBUG] Looking up pending request with handle
PduHandle[464572977]
2014-09-30 15:05:05,978 [DEBUG] Cancelling pending request with handle
PduHandle[464572977]
2014-09-30 15:05:05,978 [DEBUG] Running pending async request with handle
PduHandle[464572979] and retry count left 1
2014-09-30 15:05:05,978 [DEBUG] Sending message to 192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 50:
30:30:02:01:00:04:05:74:72:61:70:73:a1:24:02:04:1b:b0:d2:33:02:01:00:02:01:00:30:16:30:14:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:32:05:00
2014-09-30 15:05:06,026 [DEBUG] Received message from /192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 58:
30:38:02:01:00:04:05:74:72:61:70:73:a2:2c:02:04:1b:b0:d2:33:02:01:00:02:01:00:30:1e:30:1c:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:33:04:08:07:de:09:1e:0d:02:28:3d
2014-09-30 15:05:06,026 [DEBUG] Looking up pending request with handle
PduHandle[464572979]
2014-09-30 15:05:06,026 [DEBUG] Cancelling pending request with handle
PduHandle[464572979]
2014-09-30 15:05:06,027 [DEBUG] Running pending async request with handle
PduHandle[464572981] and retry count left 1
2014-09-30 15:05:06,027 [DEBUG] Sending message to 192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 50:
30:30:02:01:00:04:05:74:72:61:70:73:a1:24:02:04:1b:b0:d2:35:02:01:00:02:01:00:30:16:30:14:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:33:05:00
2014-09-30 15:05:06,077 [DEBUG] Received message from /192.168.210.1/30165
<https://mail.internal.ericsson.com/owa/redir.aspx?C=2ipCqKJBBEyRoKqLqlcn5EPTOE5putEI6g7WPUCTE6ZOVwcy2_JaQ_aA843rf0UcX-2b_mw8x5E.&URL=http%3a%2f%2f192.168.210.1%2f30165>
with length 50:
30:30:02:01:00:04:05:74:72:61:70:73:a2:24:02:04:1b:b0:d2:35:02:01:05:02:01:00:30:16:30:14:06:10:2b:06:01:04:01:81:41:81:37:04:01:03:05:01:08:33:05:00
2014-09-30 15:05:06,077 [DEBUG] Looking up pending request with handle
PduHandle[464572981]
2014-09-30 15:05:06,077 [DEBUG] Cancelling pending request with handle
PduHandle[464572981]

We expect on the agent side that the request IDs increase by 1 just as with
netsnmp's snmpwalk. This behaviour (the request ID increasing by 2) was
verified with a TCP dump also.
What could cause this behaviour? Any idea how to fix it?

Thanks a lot,
Matyas