SNMP traps are not processed by midServer

[rambhatia2017]

Traps are received by midServer but they are not seen in Event form.

Have installed mid server in a Linux server

Have configured config.xml as follows

<parameter name="url" value="https://xxxx.service-now.com/"/>
<parameter name="mid.instance.username" value="xxxxx"/>
<parameter encrypt="true" name="mid.instance.password" value="encrypted:xxxx"/>
<parameter name="name" value="xxxxx"/>
<parameter name="mid.proxy.use_proxy" value="false"/>

One of my server is sending SNMP traps to mid Server. I can see that the traps are received by mid server using tcpdump

But for some reason, these traps are not seen in event form

Am able to ping xxxx.service-now.com from mid server

Have ensured that provided username & password are correct

In ServiceNow,

Mid Sever->servers, value of my midServer status is up & value of Validated = yes
Mid Server->Extensions->MID SNMP Trap Listener, for my trap extension value of status = started

No errors are seen in agent/logs/agent0.log.0

Can someone hep me - what else to check for ?

Thank you,
Ram

[rambhatia2017]

They are not from vCenterExtension. Contents doesn't contain any string vm_ or vcenter

As this is SNMP trap, am not sure, why do you think if would be from vCenterExtension ? Shouldn't they be from SNMP Trap Listener extension ?

Now I see lot of entries in ecc queue.

They are of type: Heartbeatprobe, queue.processing & queue.stats

Entries for queue.processing contains payload as

<?xml version="1.0" encoding="UTF-8"?><queue.processing output_message_count="1"><sys_id state="processing">1cacff13db928f00b90b7b6b8c961933</sys_id></queue.processing>

No entries are seen for any of the SNMP traps

Thank you

Ram

[tim_broberg]

Ok, so, whatever the problem is, it's on the mid server side.

That would seem to mean, either the mid isn't getting the events or the extension isn't responding to the events.

[rambhatia2017]

As tcpdump is seeing the traps in the mid-server, it is confirmed that traps are reaching mid-server. My guess is that, extension is not responding to the events.

Thank you

Ram

[tim_broberg]

Try setting mid config parameter mid.log.level = debug, or if that's too chatty, mid.log.level = EventsMonitor=debug.

If it's enabled and getting events, you should see messages like "Received event of type " <event type> in the agent log in the agent/logs directory.

If not, it's probably time to check whether the monitor got hooked up at all.

[rambhatia2017]

Set the logging level to Debug and restarted mid server

Please see below for log messages

Couldn't find anything of type "Received event of type "

Couldn't find the option to attach log file

Hence have copy pasted the log. Sorry about that.

11/14/17 14:05:34 (577) ECCSender.1 DEBUG: Event: MessageResponseDeliveredEvent, sysID: 9f1301334412030042798e5f50c1e018

11/14/17 14:05:34 (577) ECCSender.1 DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:05:34 (577) ECCSender.1 DEBUG: ** sending file /servicenow/agent/work/monitors/ECCSender/output_2/ecc_queue.d71301334412030042798e5f50c1e00c.xml

11/14/17 14:05:34 (577) ECCSender.1 Sending ecc_queue.d71301334412030042798e5f50c1e00c.xml

11/14/17 14:05:34 (610) ECCSender.1 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:05:34 (610) ECCSender.1 DEBUG: Sent ecc_queue sys_id=ef134173db1a8f00adc05c98dc961977

11/14/17 14:05:34 (610) ECCSender.1 DEBUG: Event: MessageResponseDeliveredEvent, sysID: d71301334412030042798e5f50c1e00c

11/14/17 14:05:34 (610) ECCSender.1 DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:05:34 (722) MIB Initializer Base MIBS loaded

11/14/17 14:05:35 (133) MIB Initializer Extended MIBS loaded

11/14/17 14:05:37 (518) MIB Initializer Remote MIBs loaded

11/14/17 14:05:54 (129) ECCQueueMonitor.40 DEBUG: TrapListenerExtension: started.   Listening on port 1162

11/14/17 14:05:54 (130) ECCQueueMonitor.40 DEBUG: Event: ExtensionMessageProcessedEvent, sysID: cf130173db1a8f00adc05c98dc961974

11/14/17 14:05:54 (130) ECCQueueMonitor.40 DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:05:54 (131) ECCQueueMonitor.40 DEBUG: Event: MessageDispatchedEvent, message: MIDExtension:TrapListenerExtension TrapExtension:MidServerTrapCollector-xxxxx(f234e61bdb9e4f00b90b7b6b8c9619c3)   cf130173db1a8f00adc05c98dc961974

11/14/17 14:05:54 (131) ECCQueueMonitor.40 DEBUG: Received message with timestamp: 2017-11-14 19:05:32. Updated the query window to: 2017-11-14 18:35:32

11/14/17 14:05:54 (132) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 1

11/14/17 14:05:54 (173) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:06:13 (527) ECCQueueMonitor.40 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:06:13 (529) ECCQueueMonitor.40 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:06:13 (563) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:06:13 (563) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0

11/14/17 14:06:33 (534) LogStatusMonitor.60 DEBUG: Event: RequestProcessingQueueSizeEvent, priority INTERACTIVE processing: 0, priority EXPEDITED processing: 0, priority STANDARD processing: 0

11/14/17 14:06:33 (534) LogStatusMonitor.60 DEBUG: Event: RequestHandlerQueueSizeEvent, priority INTERACTIVE queue size: 0, priority EXPEDITED queue size: 0, priority STANDARD queue size: 0

11/14/17 14:06:33 (772) LogStatusMonitor.60 stats threads: 32, memory max: 910.0mb, allocated: 272.0mb, used: 58.0mb, standard.queued: 0 probes, standard.processing: 0 probes expedited.queued: 0 probes, expedited.processing: 0 probes interactive.queued: 0 probes, interactive.processing: 0 probes

11/14/17 14:06:33 (773) LogStatusMonitor.60 DEBUG: Event: OneMinuteEvent

11/14/17 14:06:38 (459) RefreshMonitor.65 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:06:38 (488) RefreshMonitor.65 DEBUG: Event: RefreshInstanceInformationEvent

11/14/17 14:06:53 (527) ECCQueueMonitor.40 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:06:53 (529) ECCQueueMonitor.40 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:06:53 (561) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:06:53 (561) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0

11/14/17 14:07:33 (528) ECCQueueMonitor.40 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:07:33 (529) ECCQueueMonitor.40 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:07:33 (533) LogStatusMonitor.60 DEBUG: Event: RequestProcessingQueueSizeEvent, priority INTERACTIVE processing: 0, priority EXPEDITED processing: 0, priority STANDARD processing: 0

11/14/17 14:07:33 (534) LogStatusMonitor.60 DEBUG: Event: RequestHandlerQueueSizeEvent, priority INTERACTIVE queue size: 0, priority EXPEDITED queue size: 0, priority STANDARD queue size: 0

11/14/17 14:07:33 (707) LogStatusMonitor.60 stats threads: 32, memory max: 910.0mb, allocated: 242.0mb, used: 59.0mb, standard.queued: 0 probes, standard.processing: 0 probes expedited.queued: 0 probes, expedited.processing: 0 probes interactive.queued: 0 probes, interactive.processing: 0 probes

11/14/17 14:07:33 (707) LogStatusMonitor.60 DEBUG: Event: OneMinuteEvent

11/14/17 14:07:33 (879) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:07:33 (879) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0

11/14/17 14:07:43 (458) RefreshMonitor.65 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:07:43 (484) RefreshMonitor.65 DEBUG: Event: RefreshInstanceInformationEvent

11/14/17 14:08:13 (529) ECCQueueMonitor.40 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:08:13 (529) ECCQueueMonitor.40 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:08:13 (567) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:08:13 (568) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0

11/14/17 14:08:33 (533) LogStatusMonitor.60 DEBUG: Event: RequestProcessingQueueSizeEvent, priority INTERACTIVE processing: 0, priority EXPEDITED processing: 0, priority STANDARD processing: 0

11/14/17 14:08:33 (534) LogStatusMonitor.60 DEBUG: Event: RequestHandlerQueueSizeEvent, priority INTERACTIVE queue size: 0, priority EXPEDITED queue size: 0, priority STANDARD queue size: 0

11/14/17 14:08:33 (732) LogStatusMonitor.60 stats threads: 32, memory max: 910.0mb, allocated: 270.0mb, used: 58.0mb, standard.queued: 0 probes, standard.processing: 0 probes expedited.queued: 0 probes, expedited.processing: 0 probes interactive.queued: 0 probes, interactive.processing: 0 probes

11/14/17 14:08:33 (732) LogStatusMonitor.60 DEBUG: Event: OneMinuteEvent

11/14/17 14:08:48 (657) RefreshMonitor.65 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:08:48 (682) RefreshMonitor.65 DEBUG: Event: RefreshInstanceInformationEvent

11/14/17 14:08:53 (528) ECCQueueMonitor.40 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:08:53 (529) ECCQueueMonitor.40 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:08:53 (571) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:08:53 (571) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0

11/14/17 14:09:07 (554) HttpClient-39 DEBUG: Changing polling frequency of ECCQueueMonitor to 1 seconds

11/14/17 14:09:07 (564) ECCQueueMonitor.1 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:09:07 (565) ECCQueueMonitor.1 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:09:07 (608) ECCQueueMonitor.1 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:09:07 (608) ECCQueueMonitor.1 DEBUG: Event: RequestCheckIfProcessedEvent

11/14/17 14:09:07 (608) ECCQueueMonitor.1 DEBUG: Event: CheckSessionCanceledEvent, correlator: , sysID: 9be3053fdb9e8f00b90b7b6b8c9619d1, canceled: false

11/14/17 14:09:07 (616) ECCQueueMonitor.1 DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:09:07 (617) ECCQueueMonitor.1 DEBUG: Added processing (1): 9be3053fdb9e8f00b90b7b6b8c9619d1

11/14/17 14:09:07 (617) ECCQueueMonitor.1 DEBUG: Event: MessageDispatchedEvent, message: HeartbeatProbe     9be3053fdb9e8f00b90b7b6b8c9619d1

11/14/17 14:09:07 (617) ECCQueueMonitor.1 DEBUG: Number of messages added to threadpool queue in current polling cycle: 1

11/14/17 14:09:07 (621) Worker-Interactive:HeartbeatProbe Worker starting: HeartbeatProbe

11/14/17 14:09:07 (621) Worker-Interactive:HeartbeatProbe Probing heartbeatprobe

11/14/17 14:09:07 (621) Worker-Interactive:HeartbeatProbe DEBUG: Event: RequestProcessingQueueSizeEvent, priority INTERACTIVE processing: 1, priority EXPEDITED processing: 0, priority STANDARD processing: 0

11/14/17 14:09:07 (621) Worker-Interactive:HeartbeatProbe DEBUG: Event: RequestHandlerQueueSizeEvent, priority INTERACTIVE queue size: 0, priority EXPEDITED queue size: 0, priority STANDARD queue size: 0

11/14/17 14:09:07 (622) Worker-Interactive:HeartbeatProbe Finished firing the heartbeatprobe

11/14/17 14:09:07 (627) Worker-Interactive:HeartbeatProbe DEBUG: Event: GenericScalarMetricEvent

11/14/17 14:09:07 (627) Worker-Interactive:HeartbeatProbe DEBUG: Event: CheckSessionCanceledEvent, correlator: , sysID: 9be3053fdb9e8f00b90b7b6b8c9619d1, canceled: false

11/14/17 14:09:07 (628) Worker-Interactive:HeartbeatProbe Enqueuing: /servicenow/agent/work/monitors/ECCSender/output_0/ecc_queue.9be3053fdb9e8f00b90b7b6b8c9619d1.xml

11/14/17 14:09:07 (629) Worker-Interactive:HeartbeatProbe DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:09:07 (630) Worker-Interactive:HeartbeatProbe DEBUG: ** enqueued /servicenow/agent/work/monitors/ECCSender/output_0/ecc_queue.9be3053fdb9e8f00b90b7b6b8c9619d1.xml

11/14/17 14:09:07 (630) Worker-Interactive:HeartbeatProbe DEBUG: Event: MessageProcessedEvent, sysID: 9be3053fdb9e8f00b90b7b6b8c9619d1

11/14/17 14:09:07 (630) Worker-Interactive:HeartbeatProbe DEBUG: Event: SendMessageEvent, message: HeartbeatProbe

11/14/17 14:09:07 (630) Worker-Interactive:HeartbeatProbe Worker completed: HeartbeatProbe time: 0:00:00.001

11/14/17 14:09:07 (631) Worker-Interactive:HeartbeatProbe DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:09:07 (631) Worker-Interactive:HeartbeatProbe DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:09:07 (655) ECCQueueMonitor.1 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:09:07 (787) ECCSender.1 DEBUG: ** MemDir: REFRESH from disk. Had 0 files in mem cache, now have 1   /servicenow/agent/work/monitors/ECCSender/output_0

11/14/17 14:09:07 (787) ECCSender.1 DEBUG: ** MemDir: got 1 from mem cache /servicenow/agent/work/monitors/ECCSender/output_0

11/14/17 14:09:07 (788) ECCSender.1 DEBUG: ** sending file /servicenow/agent/work/monitors/ECCSender/output_0/ecc_queue.9be3053fdb9e8f00b90b7b6b8c9619d1.xml

11/14/17 14:09:07 (788) ECCSender.1 Sending ecc_queue.9be3053fdb9e8f00b90b7b6b8c9619d1.xml

11/14/17 14:09:07 (828) ECCSender.1 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:09:07 (828) ECCSender.1 DEBUG: Sent ecc_queue sys_id=23e30973db1a8f00adc05c98dc961907

11/14/17 14:09:07 (829) ECCSender.1 DEBUG: Removed processing (0): 9be3053fdb9e8f00b90b7b6b8c9619d1

11/14/17 14:09:07 (829) ECCSender.1 DEBUG: Event: MessageResponseDeliveredEvent, sysID: 9be3053fdb9e8f00b90b7b6b8c9619d1

11/14/17 14:09:07 (830) ECCSender.1 DEBUG: Event: GenericCounterMetricEvent

11/14/17 14:09:08 (564) ECCQueueMonitor.1 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:09:08 (565) ECCQueueMonitor.1 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:09:08 (599) ECCQueueMonitor.1 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:09:08 (599) ECCQueueMonitor.1 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0

11/14/17 14:09:08 (599) ECCQueueMonitor.1 DEBUG: Changing polling frequency of ECCQueueMonitor to 40 seconds

11/14/17 14:09:08 (610) ECCQueueMonitor.40 DEBUG: Event: CheckSenderReadyEvent

11/14/17 14:09:08 (611) ECCQueueMonitor.40 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.xxxxx^sys_created_on>=2017-11-14 18:35:32^ORDERBYpriority^ORDERBYsys_created_on

11/14/17 14:09:08 (643) ECCQueueMonitor.40 DEBUG: Event: RGRPerfMetricEvent

11/14/17 14:09:08 (643) ECCQueueMonitor.40 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0