So I am using the latest appliance in a vmware environment and I am new to NAV as of two weeks ago. Things started well and I am in love the potential of NAV. I had 20 devices added and those were working well; however I have run into an issue that I cannot seem to wrap my head around. It stated last week when I added a device and it failed to locate the typeoid string after performing an inventory. As I added additional devices I kept getting the same results. Thinking it might be a resource issue I purged all devices, restarted NAV and just added the device where the typeoid string first failed to load. No change. I then started searching the web for other with like errors. Not much except for a singe bridge plugin error which does not match this issue. I then bumped up the logging for ipdevpol plugings and found this warning:
[WARNING plugins.typeoid.typeoid] [inventory DA13_SW07.xxxx.xxx] Netbox has changed type from unknown to unknown (sysObjectID 1.3.6.1.4.1.9.1.367)
Each device for where the typeoid failed to load has this warning. So I figure the typeoid just failed to populate the table correctly. So I matched the reporting sysObjectID with the correct Cisco name and created a database seed with this type. I then rescanned and bingo the type field populated. Thinking I was out of the woods I check after the next inventory poll and found the device failed to access the devices inventory. Huh. Logs report this issue:
[ERROR jobs.jobhandler] [inventory DA13_SW07.xxxx.xxx] Job 'inventory' for DA13_SW07.xxxx.xxx aborted: Plugin ciscovlan reported a timeout
I have verified the system snmp and switch configurations and they are identical. I am using snmp 2c and the same RO community for all switches. There are layer 2 and layer 3 switches with produce this issue. There multiple models and port configurations. These are single function LANS connected with high speed MPLS, broadband, and direct fiber connections.
I am guessing this is all stemming from a condition where the device cannot be polled or cannot be polled in a allotted time. There are no network error to these site and I have some sites were devices work well and others do not.
All other aspects of the device can be polled and reported on just fine it’s just the inventory which fails.
Here is the snmp stats from a L3 device which is subject to this issue.
DA53_SW01#sh snmp Chassis: CAT1114NJ57 Contact: DAIT Support Center 1-877-815-4357 924035 SNMP packets input 0 Bad SNMP version errors 0 Unknown community name 0 Illegal operation for community name supplied 0 Encoding errors 419240 Number of requested variables 0 Number of altered variables 405503 Get-request PDUs 13737 Get-next PDUs 0 Set-request PDUs 0 Input queue packet drops (Maximum queue size 1000) 924035 SNMP packets output 0 Too big errors (Maximum packet size 1500) 0 No such name errors 0 Bad values errors 0 General errors 169251 Response PDUs 0 Trap PDUs SNMP global trap: enabled
Here is a trace from a device which is subject to this issue
2015-09-27 09:43:33,837 [DEBUG plugins.cam.cam] [topo da53_sw01.xxxx.xxx] Q- BRIDGE-MIB: 0 MAC addresses found on 0 ports 2015-09-27 09:43:35,553 [DEBUG plugins.entity.entity] [statuscheck da53_sw01.xxxx.xxx] Collecting physical entity data 2015-09-27 09:43:36,608 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.447021. next run in 0:00:59.553002. 2015-09-27 09:43:36,608 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.447021. next run in 0:00:59.553002. 2015-09-27 09:43:37,272 [DEBUG plugins.cam.cam] [topo da53_sw01.xxxx.xxx] BRIDGE-MIB: 47 MAC addresses found on 6 ports 2015-09-27 09:43:37,350 [DEBUG plugins.cam.cam] [topo da53_sw01.xxxx.xxx] up/ downlinks: [10102] 2015-09-27 09:43:37,350 [DEBUG plugins.cam.cam] [topo da53_sw01.xxxx.xxx] access ports: [10005, 10007, 10008, 10011, 10101] 2015-09-27 09:43:37,350 [DEBUG plugins.cam.cam] [topo da53_sw01.xxxx.xxx] 10102 sees the following monitored mac addresses: set(['50:87:89:b9:5a:81']) 2015-09-27 09:43:38,994 [DEBUG plugins.lldp.lldp] [topo da53_sw01.xxxx.xxx] collecting LLDP remote table 2015-09-27 09:43:40,759 [DEBUG plugins.statports.statports] [5minstats da53_sw01.xxxx.xxx] High Capacity counters used 2015-09-27 09:43:40,759 [DEBUG plugins.statports.statports] [5minstats da53_sw01.xxxx.xxx] Counters collected 2015-09-27 09:43:40,846 [INFO schedule.netboxjobscheduler] [5minstats da53_sw01.xxxx.xxx] 5minstats for da53_sw01.xxxx.xxx completed in 0:00:06.269234. next run in 0:04:53.730793. 2015-09-27 09:43:40,846 [INFO schedule.netboxjobscheduler] [5minstats da53_sw01.xxxx.xxx] 5minstats for da53_sw01.xxxx.xxx completed in 0:00:06.269234. next run in 0:04:53.730793. 2015-09-27 09:43:41,231 [DEBUG plugins.cdp.cdp] [topo da53_sw01.xxxx.xxx] collecting CDP cache table 2015-09-27 09:43:41,585 [DEBUG plugins.cdp.cdp] [topo da53_sw01.xxxx.xxx] found CDP cache data: [CDPNeighbor(ifindex=10102, ip=IP('xxx.xxx19.4'), deviceid='DA53_SW02.xxxx.xxx', deviceport='GigabitEthernet0/2'), CDPNeighbor(ifindex=10003, ip=IP('1xxx.xxx.42.98'), deviceid='jch.win.xxx.xxx', deviceport='FastEthernet0/2/0')] 2015-09-27 09:43:41,605 [DEBUG plugins.cdp.cdp] [topo da53_sw01.xxxx.xxx] identified neighbor (Netbox(id=33, sysname=u'da53_sw02.xxxx.xxx'), None) from CDPNeighbor(ifindex=10102, ip=IP('xxx.xxx19.4'), deviceid='DA53_SW02.xxxx.xxx', deviceport='GigabitEthernet0/2') 2015-09-27 09:43:41,663 [INFO schedule.netboxjobscheduler] [topo da53_sw01.xxxx.xxx] topo for da53_sw01.xxxx.xxx completed in 0:00:09.384465. next run in 0:14:50.615562. 2015-09-27 09:43:41,663 [INFO schedule.netboxjobscheduler] [topo da53_sw01.xxxx.xxx] topo for da53_sw01.xxxx.xxx completed in 0:00:09.384465. next run in 0:14:50.615562. 2015-09-27 09:43:41,780 [DEBUG plugins.cdp.cdp] [topo da53_sw02.xxxx.xxx] found CDP cache data: [CDPNeighbor(ifindex=10102, ip=IP('xxx.xxx19.3'), deviceid='DA53_SW01.xxxx.xxx', deviceport='GigabitEthernet0/2'), CDPNeighbor(ifindex=10101, ip=IP('xxx.xxx19.2'), deviceid='DA53_DMVPN01.xxxx.xxx', deviceport='GigabitEthernet0/1')] 2015-09-27 09:43:41,812 [DEBUG plugins.cdp.cdp] [topo da53_sw02.xxxx.xxx] identified neighbor (Netbox(id=32, sysname=u'da53_sw01.xxxx.xxx'), None) from CDPNeighbor(ifindex=10102, ip=IP('xxx.xxx19.3'), deviceid='DA53_SW01.xxxx.xxx', deviceport='GigabitEthernet0/2') 2015-09-27 09:43:41,812 [DEBUG plugins.cdp.cdp] [topo da53_sw02.xxxx.xxx] identified neighbor (Netbox(id=32, sysname=u'da53_sw01.xxxx.xxx'), None) from CDPNeighbor(ifindex=10102, ip=IP('xxx.xxx19.3'), deviceid='DA53_SW01.xxxx.xxx', deviceport='GigabitEthernet0/2') 2015-09-27 09:43:44,136 [DEBUG plugins.entity.entity] [statuscheck da53_sw01.xxxx.xxx] found 32 entities 2015-09-27 09:43:44,142 [DEBUG plugins.modules.modules] [statuscheck da53_sw01.xxxx.xxx] Collecting ENTITY-MIB module data 2015-09-27 09:43:44,446 [INFO schedule.netboxjobscheduler] [statuscheck da53_sw01.xxxx.xxx] statuscheck for da53_sw01.xxxx.xxx completed in 0:00:11.139991. next run in 0:04:48.860036. 2015-09-27 09:43:44,446 [INFO schedule.netboxjobscheduler] [statuscheck da53_sw01.xxxx.xxx] statuscheck for da53_sw01.xxxx.xxx completed in 0:00:11.139991. next run in 0:04:48.860036. 2015-09-27 09:44:36,235 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.066100. next run in 0:00:59.933920. 2015-09-27 09:44:36,235 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.066100. next run in 0:00:59.933920. 2015-09-27 09:44:59,131 [DEBUG plugins.typeoid.typeoid] [inventory da53_sw01.xxxx.xxx] Collecting sysObjectId 2015-09-27 09:44:59,170 [DEBUG plugins.typeoid.typeoid] [inventory da53_sw01.xxxx.xxx] sysObjectID is 1.3.6.1.4.1.9.1.633 2015-09-27 09:44:59,173 [WARNING plugins.typeoid.typeoid] [inventory da53_sw01.xxxx.xxx] Netbox has changed type from unknown to unknown (sysObjectID 1.3.6.1.4.1.9.1.633) 2015-09-27 09:44:59,173 [DEBUG plugins.typeoid.typeoid] [inventory da53_sw01.xxxx.xxx] old=None new=None 2015-09-27 09:44:59,215 [DEBUG plugins.typeoid.typeoid] [inventory da53_sw01.xxxx.xxx] Creating new type with descr='Cisco IOS Software, C3560 Software (C3560-IPSERVICESK9-M), Version 12.2(55)SE, RELEASE SOFTWARE (fc2)\r \nTechnical Support: http://www.cisco.com/techsupport%5Cr%5CnCopyright (c) 1986-2010 by Cisco Systems, Inc.\r\nCompiled Sat 07-Aug-10 22:26 by prod_rel_team' 2015-09-27 09:44:59,266 [DEBUG plugins.uptime.uptime] [inventory da53_sw01.xxxx.xxx] uptime data (changed=None): ((1443365099.0, 221406078L),) 2015-09-27 09:44:59,266 [DEBUG plugins.uptime.uptime] [inventory da53_sw01.xxxx.xxx] last sysuptime reset/rollover reported by device: 2015-09-01 18:43:59 2015-09-27 09:44:59,267 [DEBUG plugins.entity.entity] [inventory da53_sw01.xxxx.xxx] Collecting physical entity data 2015-09-27 09:45:01,427 [DEBUG plugins.entity.entity] [inventory da53_sw01.xxxx.xxx] found 32 entities 2015-09-27 09:45:01,431 [DEBUG plugins.modules.modules] [inventory da53_sw01.xxxx.xxx] Collecting ENTITY-MIB module data 2015-09-27 09:45:02,057 [DEBUG plugins.bridge.bridge] [inventory da53_sw01.xxxx.xxx] Found 25 base (switch) ports: {1: 10101, 2: 10102, 3: 10001, 4: 10002, 6: 10004, 7: 10005, 8: 10006, 9: 10007, 10: 10008, 11: 10009, 12: 10010, 13: 10011, 14: 10012, 15: 10013, 16: 10014, 17: 10015, 18: 10016, 19: 10017, 20: 10018, 21: 10019, 22: 10020, 23: 10021, 24: 10022, 25: 10023, 26: 10024} 2015-09-27 09:45:02,058 [DEBUG plugins.interfaces.interfaces] [inventory da53_sw01.xxxx.xxx] Collecting interface data 2015-09-27 09:45:03,569 [DEBUG plugins.interfaces.interfaces] [inventory da53_sw01.xxxx.xxx] Got duplex information: {10001: 'unknown', 10002: 'fullDuplex', 10003: 'fullDuplex', 10004: 'unknown', 10005: 'fullDuplex', 10006: 'unknown', 10007: 'fullDuplex', 10008: 'fullDuplex', 10009: 'unknown', 10010: 'unknown', 10011: 'fullDuplex', 10012: 'unknown', 10013: 'unknown', 10014: 'unknown', 10015: 'unknown', 10016: 'unknown', 10017: 'unknown', 10018: 'unknown', 10019: 'unknown', 10020: 'unknown', 10021: 'unknown', 10022: 'unknown', 10023: 'unknown', 10024: 'unknown', 10101: 'fullDuplex', 10102: 'fullDuplex'} 2015-09-27 09:45:03,570 [DEBUG plugins.interfaces.interfaces] [inventory da53_sw01.xxxx.xxx] Found 28 interfaces 2015-09-27 09:45:03,860 [DEBUG plugins.dot1q.dot1q] [inventory da53_sw01.xxxx.xxx] Collecting 802.1q VLAN information 2015-09-27 09:45:08,053 [ERROR jobs.jobhandler] [inventory da53_sw01.xxxx.xxx] Job 'inventory' for da53_sw01.xxxx.xxx aborted: Plugin ciscovlan reported a timeout 2015-09-27 09:45:08,053 [ERROR jobs.jobhandler] [inventory da53_sw01.xxxx.xxx] Job 'inventory' for da53_sw01.xxxx.xxx aborted: Plugin ciscovlan reported a timeout 2015-09-27 09:45:08,054 [INFO schedule.netboxjobscheduler] [inventory da53_sw01.xxxx.xxx] inventory for da53_sw01.xxxx.xxx failed in 0:00:08.927518. next run in 0:07:50.999975. 2015-09-27 09:45:08,054 [INFO schedule.netboxjobscheduler] [inventory da53_sw01.xxxx.xxx] inventory for da53_sw01.xxxx.xxx failed in 0:00:08.927518. next run in 0:07:50.999975. 2015-09-27 09:45:36,230 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.060605. next run in 0:00:59.939420. 2015-09-27 09:45:36,230 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.060605. next run in 0:00:59.939420. 2015-09-27 09:46:36,237 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.065369. next run in 0:00:59.934652. 2015-09-27 09:46:36,237 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.065369. next run in 0:00:59.934652. 2015-09-27 09:47:36,336 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.164168. next run in 0:00:59.836076. 2015-09-27 09:47:36,336 [INFO schedule.netboxjobscheduler] [1minstats da53_sw01.xxxx.xxx] 1minstats for da53_sw01.xxxx.xxx completed in 0:00:00.164168. next run in 0:00:59.836076.
Any help would be greatly appreciated.
Ken…
On Sun, 27 Sep 2015 17:33:35 +0200 ken.livesey@gmail.com wrote:
[WARNING plugins.typeoid.typeoid] [inventory DA13_SW07.xxxx.xxx] Netbox has changed type from unknown to unknown (sysObjectID 1.3.6.1.4.1.9.1.367)
This warning message may be badly worded (and should, IMHO, be an INFO level message, rather than a WARNING).
What this means is that the device had no type entry, but that ipdevpoll has now created a new type entry based on the collected sysObjectID, .1.3.6.1.4.1.9.1.367. However, the new type entry still represents an unknown entity, so it should later be edited in SeedDB by an admin to make sense (This may be why the WARNING level was chosen for this message)..
The newly created type entry will be attached to the "unknown" vendor, using the sysObjectID itself as the type name, while the type description will be whatever ipdevpoll got from the device's sysDescr value.
[ERROR jobs.jobhandler] [inventory DA13_SW07.xxxx.xxx] Job 'inventory' for DA13_SW07.xxxx.xxx aborted: Plugin ciscovlan reported a timeout
This plugin uses the proprietary mibs CISCO-VTP-MIB, CISCO-VLAN-MEMBERSHIP-MIB and CISCO-VLAN-IFTABLE-RELATIONSHIP-MIB to retrieve VLAN configuration information. The plugin will only attempt to use the MIBs on a device with Cisco's enterprise number (9) in its sysObjectID.
A timeout here usually just means that this device is a bit on the slow side when building responses to queries in one of these MIBs. Some of the queried values are large octet strings representing lists of ports or vlans, which could be the cause of this.
You will likely fix your problem by tweaking the SNMP settings in `ipdevpoll.conf`. Either decrease the max-repetitions option, increase the timeout option, or both.
You can manually run an inventory job against your device to verify whether it helped:
/usr/lib/nav/ipdevpolld -J inventory -n da13_sw07
Morten,
Thanks for the prompt reply and the info regarding the ipdevpoll.
I played around with the max-repetitions and timeout options but to no avail.
I did get the inventory to function to complete by commenting out the ciscovlan plugin. Once I did this, the OID populated for all unknown devices and I started to get inventory information.
Just for clarity the "warning" event concerning the typeoid unknown to unknown should be kept as a warning or error as this process did not populate any netbox information. I had to glean the typeoid from the logfile, then lookup the typename, and manually create a type entry. Maybe that is not the case in most instances but was the case with this issue.
[WARNING plugins.typeoid.typeoid] [inventory DA13_SW07.xxxx.xxx] Netbox has changed type from unknown to unknown (sysObjectID 1.3.6.1.4.1.9.1.367)
Anyway I will continue to look into the ciscovlan plugin timeout error. Is there anyway to get additional info from this process?
Again thanks for your help.
Ken...
On Mon, 28 Sep 2015 20:09:52 +0200 ken.livesey@gmail.com wrote:
I played around with the max-repetitions and timeout options but to no avail.
What combinations did you try? Some devices will have a problem with anything but really small values for max-repetitions. They're just completely unable to build a response that large within the allotted time.
Some devices are just plain slow and cannot be helped.
I did get the inventory to function to complete by commenting out the ciscovlan plugin. Once I did this, the OID populated for all unknown devices and I started to get inventory information.
Just for clarity the "warning" event concerning the typeoid unknown to unknown should be kept as a warning or error as this process did not populate any netbox information.
I assure you that this message has nothing to do with your problem, whatsoever.
Nothing was populated in the database because the job only updates the database when its collection phase finishes successfully - but yours timed out in the ciscovlan plugin.
Anyway I will continue to look into the ciscovlan plugin timeout error. Is there anyway to get additional info from this process?
The relevant MIB implementations don't have much in the way of debug logging, so you would have to get that from the SNMP protocol layer.
You could try running a manual inventory collection for a device, with a log level setting of "root = DEBUG" - if you dare. This will produce huge amounts of log lines, not just from NAV, but from third party libraries. I would recommend sending a copy of stderr to file for later review, and to rememeber resetting the log levels afterwards.
(A slightly more defensive approach is just using "nav = DEBUG" in your `logging.conf`, leaving third party code out of it)
-
ken.livesey＠gmail.com -
Morten Brekkevold