snmpset timeout, but did work, help with debug traces

Hi all,

I have an object which takes time to set, around 10 seconds, and the
command snmpset returns a timeout, even though the Set action actually
worked.

The set request is done this way:
snmpset -v 3 -u  Admin -t 30 -r 0  -a MD5 -A "Admin-00"  -l authNoPriv
172.27.42.191  MPBC-MIB::mpbcIPaddress.0 a 172.27.42.191
snmpset: Timeout

And it is doing the same thing (timeout) with another program, MIBBrowser.

But the set did work.

I have compared the debug traces of this set operation (Set with
MIBBrowser) with another similar object that takes less time to do the set
action.  I show you the difference between the two debug traces, omitting
traces that are identical or alike.  Assuming it could give a hint.


TRACES FOR TIMEOUT SET
dumpx_recv:      02 01 04
dumpv_recv:        Integer:4 (0x04)
trace: snmpv3_parse(): snmp_api.c, 3604:
dumph_recv:     msgMaxSize
dumpx_recv:      02 02 05 DC
dumpv_recv:        Integer:1500 (0x5DC)
trace: snmpv3_parse(): snmp_api.c, 3642:
snmpv3_parse: msgMaxSize 1500 received
trace: snmpv3_parse(): snmp_api.c, 3650:
dumph_recv:     msgFlags
dumpx_recv:      04 01 05
dumpv_recv:        String:.
trace: snmpv3_parse(): snmp_api.c, 3668:
dumph_recv:     msgSecurityModel

(...)

trace: snmpv3_parse(): snmp_api.c, 3742:
dumph_recv:   SM msgSecurityParameters
trace: usm_process_in_msg(): snmpusm.c, 2361:
usm: USM processing begun...
trace: usm_parse_security_parameters(): snmpusm.c, 1934:
dumph_recv:     msgAuthoritativeEngineID
dumpx_recv:      04 0D 80 00 1F 88 80 05 08 15 0E 52 AF EC D0
dumpv_recv:        String:.........R...
trace: usm_parse_security_parameters(): snmpusm.c, 1957:
dumph_recv:     msgAuthoritativeEngineBoots
dumpx_recv:      02 01 4B
dumpv_recv:        Integer:75 (0x4B)
trace: usm_parse_security_parameters(): snmpusm.c, 1981:
dumph_recv:     msgAuthoritativeEngineTime
dumpx_recv:      02 02 03 11
dumpv_recv:        Integer:785 (0x311)
trace: usm_parse_security_parameters(): snmpusm.c, 2009:
dumph_recv:     msgUserName
dumpx_recv:      04 05 41 64 6D 69 6E
dumpv_recv:        String:Admin
trace: usm_parse_security_parameters(): snmpusm.c, 2052:
dumph_recv:     msgAuthenticationParameters
dumpx_recv:      04 0C D5 43 BE EF 20 1D 0E 79 34 BC 3C D9
dumpv_recv:        String:.C.. ..y4.<.
trace: usm_parse_security_parameters(): snmpusm.c, 2081:
dumph_recv:     msgPrivacyParameters
dumpx_recv:      04 00
dumpv_recv:        String:
trace: sc_hash(): scapi.c, 463:
trace: sc_get_properlength(): scapi.c, 138:
trace: get_enginetime(): lcd_time.c, 156:
lcd_get_enginetime: engineID 80 00 1F 88 80 05 08 15 0E 52 AF EC D0 :
boots=76, time=139
trace: usm_get_user_from_list(): snmpusm.c, 3525:
usm: match on user Admin
trace: usm_check_secLevel(): snmpusm.c, 3402:
comparex: Comparing: 1 3 SNMP-USER-BASED-SM-MIB::usmNoPrivProtocol
trace: sc_check_keyed_hash(): scapi.c, 615:
trace: sc_generate_keyed_hash(): scapi.c, 303:
trace: sc_get_properlength(): scapi.c, 138:
trace: usm_process_in_msg(): snmpusm.c, 2518:
usm: Verification succeeded.
trace: usm_check_and_update_timeliness(): snmpusm.c, 2181:
usm: boot_uint 75 myBoots 76 time_diff 646 => not in time window
trace: snmpv3_parse(): snmp_api.c, 3773:
dumph_recv:     ScopedPDU
trace: snmpv3_scopedPDU_parse(): snmp_api.c, 4647:
dumph_recv:       contextEngineID
dumpx_recv:        04 0D 80 00 1F 88 80 05 08 15 0E 52 AF EC D0
dumpv_recv:          String:.........R...
trace: snmpv3_scopedPDU_parse(): snmp_api.c, 4660:
dumph_recv:       contextName
dumpx_recv:        04 00
dumpv_recv:          String:
trace: snmpv3_parse(): snmp_api.c, 3781:
dumph_recv:       SET
trace: snmp_pdu_parse(): snmp_api.c, 4354:
dumpv_recv:     Command SET
trace: snmp_pdu_parse(): snmp_api.c, 4439:
dumph_recv:         request_id
dumpx_recv:          02 01 04
dumpv_recv:            Integer:4 (0x04)
trace: snmp_pdu_parse(): snmp_api.c, 4450:
dumph_recv:         error status
dumpx_recv:          02 01 00
dumpv_recv:            Integer:0 (0x00)
trace: snmp_pdu_parse(): snmp_api.c, 4461:
dumph_recv:         error index
dumpx_recv:          02 01 00
dumpv_recv:            Integer:0 (0x00)
trace: snmp_pdu_parse(): snmp_api.c, 4479:
dumph_recv:         VarBindList
trace: snmp_pdu_parse(): snmp_api.c, 4509:
dumph_recv:           VarBind
trace: snmp_parse_var_op(): snmp.c, 164:
dumph_recv:             Name
dumpx_recv:              06 0D 2B 06 01 04 01 A2 70 02 02 0C 01 05 00
dumpv_recv:                ObjID: SNMPv2-SMI::enterprises.4464.2.2.12.1.5.0
trace: snmp_pdu_parse(): snmp_api.c, 4518:
dumph_recv:             Value
dumpx_recv:              40 04 AC 1B 2A BF
dumpv_recv:                String:..*.
trace: _snmp_parse(): snmp_api.c, 4151:
snmp_parse: Parsed SNMPv3 message (secName:Admin, secLevel:authNoPriv): USM
not in time window
trace: snmpv3_build(): snmp_api.c, 2153:
snmp_build: Building SNMPv3 message (secName:"Admin",
secLevel:authNoPriv)...
trace: snmpv3_build(): snmp_api.c, 2155:
dumph_send:   SNMPv3 Message
trace: snmpv3_packet_realloc_rbuild(): snmp_api.c, 2498:
dumph_send:     REPORT
trace: snmp_pdu_realloc_rbuild(): snmp_api.c, 3266:
snmp_pdu_realloc_rbuild: starting
trace: snmp_pdu_realloc_rbuild(): snmp_api.c, 3281:
dumph_send:       VarBind
trace: snmp_realloc_rbuild_var_op(): snmp.c, 339:
dumph_send:         Value
dumpx_send:          41 01 01
dumpv_send:            UInteger:1 (0x01)
trace: snmp_realloc_rbuild_var_op(): snmp.c, 440:
dumph_send:         Name
dumpx_send:          06 0A 2B 06 01 06 03 0F 01 01 02 00
dumpv_send:            ObjID:
SNMP-USER-BASED-SM-MIB::usmStatsNotInTimeWindows.0
trace: snmp_pdu_realloc_rbuild(): snmp_api.c, 3349:
dumph_send:     error index
dumpx_send:      02 01 00
dumpv_send:        Integer:0 (0x00)
trace: snmp_pdu_realloc_rbuild(): snmp_api.c, 3362:
dumph_send:     error status
dumpx_send:      02 01 00
dumpv_send:        Integer:0 (0x00)
trace: snmp_pdu_realloc_rbuild(): snmp_api.c, 3375:
dumph_send:     request_id
dumpx_send:      02 01 04
dumpv_send:        Integer:4 (0x04)
trace: snmpv3_packet_realloc_rbuild(): snmp_api.c, 2516:
dumph_send:     ScopedPdu
trace: snmpv3_scopedPDU_header_realloc_rbuild(): snmp_api.c, 2444:
dumph_send:       contextName
dumpx_send:        04 00
dumpv_send:          String: [NULL]
trace: snmpv3_scopedPDU_header_realloc_rbuild(): snmp_api.c, 2458:
dumph_send:       contextEngineID
dumpx_send:        04 0D 80 00 1F 88 80 05 08 15 0E 52 AF EC D0
dumpv_send:          String:.........R...
trace: snmpv3_header_realloc_rbuild(): snmp_api.c, 2319:
dumph_send:   msgSecurityModel
dumpx_send:    02 01 03
dumpv_send:      Integer:3 (0x03)
trace: snmpv3_header_realloc_rbuild(): snmp_api.c, 2333:
dumph_send:   msgFlags
dumpx_send:    04 01 01
dumpv_send:      String:.
trace: snmpv3_header_realloc_rbuild(): snmp_api.c, 2347:
dumph_send:   msgMaxSize
dumpx_send:    02 03 00 FF E3
dumpv_send:      Integer:65507 (0xFFE3)
trace: snmpv3_header_realloc_rbuild(): snmp_api.c, 2360:
dumph_send:   msgID
dumpx_send:    02 01 04
dumpv_send:      Integer:4 (0x04)
trace: snmpv3_header_realloc_rbuild(): snmp_api.c, 2384:
dumph_send:   SNMP Version Number
dumpx_send:    02 01 03
dumpv_send:      Integer:3 (0x03)
trace: snmpv3_packet_realloc_rbuild(): snmp_api.c, 2544:
dumph_send:   SM msgSecurityParameters
trace: usm_rgenerate_out_msg(): snmpusm.c, 1418:
usm: USM processing has begun (offset 49)
trace: usm_get_user(): snmpusm.c, 3509:
usm: getting user Admin
trace: usm_get_user_from_list(): snmpusm.c, 3525:
usm: match on user Admin
trace: sc_hash(): scapi.c, 463:
trace: sc_get_properlength(): scapi.c, 138:
trace: get_enginetime(): lcd_time.c, 156:
lcd_get_enginetime: engineID 80 00 1F 88 80 05 08 15 0E 52 AF EC D0 :
boots=76, time=139
trace: usm_rgenerate_out_msg(): snmpusm.c, 1645:
dumph_send:     msgPrivacyParameters
dumpx_send:      04 00
dumpv_send:        String: [NULL]
trace: usm_rgenerate_out_msg(): snmpusm.c, 1661:
dumph_send:     msgAuthenticationParameters
dumpx_send:      04 0C 00 00 00 00 00 00 00 00 00 00 00 00
dumpv_send:        String:............
trace: usm_rgenerate_out_msg(): snmpusm.c, 1693:
dumph_send:     msgUserName
dumpx_send:      04 05 41 64 6D 69 6E
dumpv_send:        String:Admin
trace: usm_rgenerate_out_msg(): snmpusm.c, 1708:
dumph_send:     msgAuthoritativeEngineTime
dumpx_send:      02 02 00 8B
dumpv_send:        Integer:139 (0x8B)
trace: usm_rgenerate_out_msg(): snmpusm.c, 1724:
dumph_send:     msgAuthoritativeEngineBoots
dumpx_send:      02 01 4C
dumpv_send:        Integer:76 (0x4C)
trace: usm_rgenerate_out_msg(): snmpusm.c, 1737:
dumph_send:     msgAuthoritativeEngineID
dumpx_send:      04 0D 80 00 1F 88 80 05 08 15 0E 52 AF EC D0
dumpv_send:        String:.........R...
trace: sc_generate_keyed_hash(): scapi.c, 303:
trace: sc_get_properlength(): scapi.c, 138:
trace: usm_rgenerate_out_msg(): snmpusm.c, 1846:
usm: USM processing completed.
trace: _sess_async_send(): snmp_api.c, 4930:
sess_process_packet: sending message id#4 reqid#4 len 119
transport:send: 119 bytes to UDP: [172.27.37.29]:4375->[172.27.42.191]:161
trace: netsnmp_udpbase_send(): transports/snmpUDPBaseDomain.c, 173:
netsnmp_udp: send 119 bytes from 0x800713b9 to UDP:
[172.27.37.29]:4375->[172.27.42.191]:161 on fd 5
trace: netsnmp_udpbase_sendto(): transports/snmpUDPBaseDomain.c, 297:
udpbase:sendto: sending from 172.27.42.191 iface 4
trace: _sess_process_packet(): snmp_api.c, 5212:
sess_process_packet: received message id#4 reqid#4 len 132
trace: _sess_process_packet(): snmp_api.c, 5215:
sess_process_packet: parse fail
trace: _sess_process_packet(): snmp_api.c, 5220:
sess_process_packet: post-parse fail
trace: _sess_read(): snmp_api.c, 5501:
sess_read: not reading 3 (fdset 0xbfc4fbd0 set 0)
trace: snmp_sess_select_info2_flags(): snmp_api.c, 5995:
sess_select: for all sessions: 5 3
sess_select: next alarm 1610665048.-2147480086 sec
sess_select: blocking:no session requests or alarms.
trace: receive(): snmpd.c, 1379:
snmpd/select: select( numfds=6, ..., tvp=(nil))
trace: receive(): snmpd.c, 1384:
snmpd/select: returned, count = 1
trace: netsnmp_udpbase_recvfrom(): transports/snmpUDPBaseDomain.c, 241:
udpbase:recv: got source addr: 172.27.37.29
trace: netsnmp_udpbase_recvfrom(): transports/snmpUDPBaseDomain.c, 253:
udpbase:recv: got destination (local) addr 172.27.42.191, iface 4
trace: netsnmp_udpbase_recv(): transports/snmpUDPBaseDomain.c, 136:
netsnmp_udp: recvfrom fd 5 got 132 bytes (from UDP:
[172.27.37.29]:4375->[172.27.42.191]:161)
transport:recv: 132 bytes from UDP: [172.27.37.29]:4375->[172.27.42.191]:161
trace: _sess_process_packet(): snmp_api.c, 5165:
sess_process_packet: session 0x800509d8 fd 5 pkt 0x80060680 length 132
trace: snmp_parse_version(): snmp_api.c, 3483:
dumph_recv: SNMP Version
dumpx_recv:  02 01 03
dumpv_recv:    Integer:3 (0x03)
trace: snmpv3_parse(): snmp_api.c, 3524:
dumph_recv: SNMPv3 Message
trace: snmpv3_parse(): snmp_api.c, 3539:
dumph_recv:   SNMP Version Number
dumpx_recv:    02 01 03
dumpv_recv:      Integer:3 (0x03)
trace: snmpv3_parse(): snmp_api.c, 3555:
dumph_recv:   msgGlobalData
trace: snmpv3_parse(): snmp_api.c, 3572:
dumph_recv:     msgID
dumpx_recv:      02 01 05
dumpv_recv:        Integer:5 (0x05)


(........)


Any help on why the Agent does not respond ?

Thanks,

Francois

------------------------------------------------------------------------------
Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server
from Actuate! Instantly Supercharge Your Business Reports and Dashboards
with Interactivity, Sharing, Native Excel Exports, App Integration & more
Get technology previously reserved for billion-dollar corporations, FREE
http://pubads.g.doubleclick.net/gampad/clk?id=164703151&iu=/4140/ostg.clktrk

_______________________________________________
Net-snmp-users mailing list
[email protected]
Please see the following page to unsubscribe or change other options:
https://lists.sourceforge.net/lists/listinfo/net-snmp-users