Problem with SNMP

Started by Nikk, October 29, 2014, 04:53:53 PM

Previous topic - Next topic

Nikk

Hi,

I recently placed a new Netxms server at remote site, and added a few core switches (Enterasys S3, S4) to the monitoring. I haven't set up yet any parameters to monitor (there are just the default ones). So there shouldn't be much load.
The problem is, these switches  get load of SNMP coming to them -> their processor jumps up to 90%. I tried unmanaging the nodes, disabling all pollings and even deleted the node at the end, but this SNMP kept going (as seen in Wireshark).
The SNMP mib was 1.3.6.1.2.1.17.7.1.4.2.1.4.X.X

It stops only, when I restart agent or server. In server log file, i didn't notice anything odd.

Is NetXMS generating this, or something else, as i haven't noticed this behavior on other servers.

Regards,
Nikk

Nikk

Upgraded from 1.2.16 to 1.2.17, but the problem still persists. The most annoying thing is, i can't stop the 'snmp get' from NetXMS.

Victor Kirhenshtein

Hi,

sounds really weird. OID you mentioned used only during topology polls to get VLAN information. Unmanaging node or disabling topology polling on it should stop it. Can you check if there is an active topology poll for this switch at time you get those SNMP requests?

Best regards,
Victor

Nikk

Yes, there is topology poll, and it just keeps requesting this  oid: 1.3.6.1.2.1.17.7.1.4.2.1.4. even if I disable topology polling.

Victor Kirhenshtein

Could you please turn on debug level 6 and filter out all records in server log containing name or IP address of this switch?

Best regards,
Victor

Nikk

So. here is the log:
Quote[19-Nov-2014 11:30:27.142] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:30:27.142] [DEBUG] [CLSN-0] Sending message CMD_OBJECT_UPDATE
[19-Nov-2014 11:30:27.142] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931335 from SNMP
[19-Nov-2014 11:30:27.142] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:30:27.142] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:30:28.392] [DEBUG] Node 1338 "172.22.2.11" queued for routing table poll
[19-Nov-2014 11:30:28.392] [DEBUG] Routing table updated for node 172.22.2.11 [1338]
[19-Nov-2014 11:31:28.408] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:31:28.408] [DEBUG] Starting status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:31:28.408] [DEBUG] StatusPoll(172.22.2.11): check SNMP
[19-Nov-2014 11:31:28.408] [DEBUG] StatusPoll(172.22.2.11): SNMP check finished
[19-Nov-2014 11:31:28.916] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:31:28.918] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931334 from SNMP
[19-Nov-2014 11:31:28.918] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:31:28.918] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:32:33.491] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:32:33.491] [DEBUG] Starting status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:32:33.491] [DEBUG] StatusPoll(172.22.2.11): check SNMP
[19-Nov-2014 11:32:33.491] [DEBUG] StatusPoll(172.22.2.11): SNMP check finished
[19-Nov-2014 11:32:33.979] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:32:33.979] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931334 from SNMP
[19-Nov-2014 11:32:33.979] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:32:33.979] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:33:38.495] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:33:38.495] [DEBUG] Starting status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:33:38.495] [DEBUG] StatusPoll(172.22.2.11): check SNMP
[19-Nov-2014 11:33:38.495] [DEBUG] StatusPoll(172.22.2.11): SNMP check finished
[19-Nov-2014 11:33:39.026] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:33:39.026] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931335 from SNMP
[19-Nov-2014 11:33:39.026] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:33:39.026] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:34:43.496] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:34:43.496] [DEBUG] Starting status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:34:43.496] [DEBUG] StatusPoll(172.22.2.11): check SNMP
[19-Nov-2014 11:34:43.496] [DEBUG] StatusPoll(172.22.2.11): SNMP check finished
[19-Nov-2014 11:34:44.012] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:34:44.012] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931335 from SNMP
[19-Nov-2014 11:34:44.012] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:34:44.012] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:35:33.497] [DEBUG] Node 1338 "172.22.2.11" queued for routing table poll
[19-Nov-2014 11:35:33.497] [DEBUG] Routing table updated for node 172.22.2.11 [1338]
[19-Nov-2014 11:35:48.497] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:35:48.497] [DEBUG] Starting status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:35:48.497] [DEBUG] StatusPoll(172.22.2.11): check SNMP
[19-Nov-2014 11:35:48.497] [DEBUG] StatusPoll(172.22.2.11): SNMP check finished
[19-Nov-2014 11:35:48.981] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:35:48.981] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931334 from SNMP
[19-Nov-2014 11:35:48.981] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:35:48.981] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:36:53.497] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:36:53.497] [DEBUG] Starting status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:36:53.497] [DEBUG] StatusPoll(172.22.2.11): check SNMP
[19-Nov-2014 11:36:53.497] [DEBUG] StatusPoll(172.22.2.11): SNMP check finished
[19-Nov-2014 11:36:53.903] [DEBUG] StatusPoll(172.22.2.11): bAllDown=false, dynFlags=0x00001001
[19-Nov-2014 11:36:53.919] [DEBUG] StatusPoll(172.22.2.11 [1338]): boot time set to 1402931334 from SNMP
[19-Nov-2014 11:36:53.919] [DEBUG] StatusPoll(172.22.2.11 [1338]): unable to get agent uptime
[19-Nov-2014 11:36:53.919] [DEBUG] Finished status poll for node 172.22.2.11 (ID: 1338)
[19-Nov-2014 11:37:18.498] [DEBUG] Node 1338 "172.22.2.11" queued for topology poll
[19-Nov-2014 11:37:18.498] [DEBUG] Started topology poll for node 172.22.2.11 [1338]
[19-Nov-2014 11:37:58.512] [DEBUG] Node 1338 "172.22.2.11" queued for status poll
[19-Nov-2014 11:40:38.589] [DEBUG] Node 1338 "172.22.2.11" queued for routing table poll
[19-Nov-2014 11:40:38.589] [DEBUG] Routing table updated for node 172.22.2.11 [1338]
[19-Nov-2014 11:45:43.607] [DEBUG] Node 1338 "172.22.2.11" queued for routing table poll
[19-Nov-2014 11:45:43.607] [DEBUG] Routing table updated for node 172.22.2.11 [1338]
[19-Nov-2014 11:50:24.953] [DEBUG] CorrelateEvent: event SYS_NODE_UNMANAGED id 4676 source 172.22.2.11 [1338]
[19-Nov-2014 11:50:24.953] [DEBUG] CorrelateEvent: finished, rootId=0
[19-Nov-2014 11:50:24.953] [DEBUG] [CLSN-0] Sending message CMD_OBJECT_UPDATE
[19-Nov-2014 11:50:24.953] [DEBUG] EVENT 12 (ID:4676 F:0x0001 S:0 TAG:"") FROM 172.22.2.11: Node status changed to UNMANAGED

At the end I changed status to unmanaged, but as I saw in Wireshark:
Quote4078950   3192.569851000   172.22.5.95   172.22.2.11   SNMP   93 get-next-request 1.3.6.1.2.1.17.7.1.4.2.1.4.56088.140
4078952   3192.571206000   172.22.2.11   172.22.5.95   SNMP   141   get-response 1.3.6.1.2.1.17.7.1.4.2.1.4.56088.153

It still keeps spamming this oid, but in server log nothing appears from that node (after unmanaging it).

Victor Kirhenshtein

Hi,

interesting is that I don't see "Finished topology poll" message for that node. This may indicate that server is stuck within topology poller for some reason. Can you please run snmp walk from command line on this node on OID .1.3.6.1.2.1.17.7.1.4.2.1.4? I suspect that walk may cycle for some reason thus forming infinite loop.

Best regards,
Victor

Nikk

Yes, that walk is forming infinite loop, and is not stoping.

Regards,
Nikk

Victor Kirhenshtein

So it's a bug in SNMP agent on switch then. The only workaround so far is to disable topology poll on that node and restart NetXMS server.

Best regards,
Victor

Nikk

Hi,

Here I got response from switch manufacturer:
QuoteCause
These OIDs are time-filtered, so per the RFCs (e.g. RFC3512, RFC4502) must return entries for all valid timeMarks.

The SNMP browser should understand the behavior of a timeFiltered MIB and move on after seeing the timeFilter index increment. However, not all browsers behave in this manner.

Solution/Workaround
Ensure you are using an appropriate SNMP tool - such as NetSight MIB tools - that behaves correctly.

Workaround:
DFE firmware 6.01.01.0020 introduced a new command which can accommodate SNMP browsers that are not timeFilter-aware.

Release notes state, in the "Software Changes and Enhancements" section:

A new SNMP control, "set snmp timefilter break", allows users to configure the
GET-NEXT behavior of MIBs indexed with timeMark. When this is set to 'enabled',
SNMP will not return incrementing index values. Many SNMP tools do not properly
support timefiltered MIBs and will benefit from this new setting. When disabled,
SNMP returns RFC conformant indexing.

Here is the command syntax, as seen in a sample cli session:
  NSeries(rw)->set snmp timefilter

  Command: set snmp Create SNMP agent entries

  Object: timefilter             SNMP timefilter configuration
  Usage:  set snmp timefilter break {disable | enable}

So maybe NetXMS doesn't support timeFiltered MIBs, or it could be something else?

Best Regards,
Nikk

Victor Kirhenshtein

Hi,

no, we do not support time filtered MIBs. I'll add this as feature request.

Best regards,
Victor

Nikk