CIM discovery fails with "5 000 milliseconds timeout on connection http-outgoing"

[Ricky S Larsson]

The last week we've noticed that our IBM SVC discovery have started to fail. The problem is at the CIM classification. In the CIM - Classify input payload the following result is returned:

<results error="5 000 milliseconds timeout on connection http-outgoing-5 [ACTIVE]" probe_time="10141" result_code="900000">
<result/>

The http-outgoing have had other numbers like 1 or 3. I have tried changing the value of CIM probe parameters "connection_timeout" and "socket_timeout" without any different result.

I have confirmed that the wbem port is opened, both by telnet from the MID server and in the shazzam input

<scanner name="GenericTCP" port="5989" portprobe="wbem" protocol="tcp" result="open" service="wbem_https"/>

The SVC discovery was working about 1-2 weeks ago. Sadly the ECC queue records are now gone so it's hard to compare and see what has changed.

Anyone else that encountered this issue?

EDIT: By advice from ServiceNow Support I added credentials for SSH to complete the UNIX Classify. This didn't solve the 5000 milliseconds timeout issue And another warning message now appears as well:

No shell detected and probe parameter 'allow_unsupported_shells' is set to 'false'

[Maik Skoddow]

Hi

have you tried to set the MID Server Parameters

• mid.log.level = DEBUG
• mid.cim.debug = true

in order to get more information?

Kind regards
Maik

If my answer replied your question please mark appropriate response as correct so that the question will appear as resolved for other users who may have a similar question in the future.

[Ricky S Larsson]

Thank you Maik, I didn't thought of using those parameters.

Unfortunately I couldn't get any more info from setting those. I assume I should find that debugging info through the Node Log File Browser?

EDIT: Remembered that there are agent0.logs... I will check them first! 🙂

[Maik Skoddow]

Hi @Richard S Larsson ,

yes, Discovery writes to the node's log files.

Kind regards
Maik

If my answer replied your question please mark appropriate response as correct so that the question will appear as resolved for other users who may have a similar question in the future.

[Ricky S Larsson]

I checked the agent0.log after turning on debugging on the MID server and this is what I found regarding the CIM classify probe:

2021-03-01 10:30:16 (221) ECCQueueMonitor.1 DEBUG: Event: MessageDispatchedEvent, message: CimProbe CIM - Classify 194.14.142.82 9d0056b21be6e050b6f4eb52b24bcb1f
2021-03-01 10:30:16 (221) ECCQueueMonitor.1 DEBUG: Number of messages added to threadpool queue in current polling cycle: 1
2021-03-01 10:30:16 (221) Worker-Interactive:CimProbe-9d0056b21be6e050b6f4eb52b24bcb1f Worker starting: CimProbe source: 194.14.142.82
2021-03-01 10:30:16 (221) Worker-Interactive:CimProbe-9d0056b21be6e050b6f4eb52b24bcb1f DEBUG: CimIQL: Registered session: 4
2021-03-01 10:30:16 (221) pool-9-thread-1 DEBUG: CimIQL: StatementTreeProcessor: Processing session: 4
2021-03-01 10:30:16 (221) pool-9-thread-1 DEBUG: CimIQL: StatementTreeProcessor: Queuing send for message 4.6.6.2 to CIM-XML
2021-03-01 10:30:16 (221) pool-9-thread-1 DEBUG: CimIQL: Attempting to authenticate with untried credential: #0
2021-03-01 10:30:16 (236) pool-9-thread-1 DEBUG: CimIQL: HTTP: Enqueued message #2
2021-03-01 10:30:16 (236) pool-9-thread-1 DEBUG: CimIQL: CIM-XML: Sent request #2 to https://194.14.142.82:5989/cimom
2021-03-01 10:30:16 (236) pool-9-thread-1 DEBUG: CimIQL: Transaction: {
"ip": "194.14.142.82",
"port": 5989,
"requestMessage": {
"id": 2,
"headers": {
"CIMMethod": "EnumerateInstances",
"CIMObject": "interop",
"CIMProtocolVersion": "1.0",
"CIMOperation": "MethodCall"
},
"xml": "<?xml version=\"1.0\" encoding=\"UTF-8\"?><CIM CIMVERSION=\"2.0\" DTDVERSION=\"2.0\"><MESSAGE ID=\"2\" PROTOCOLVERSION=\"1.0\"><SIMPLEREQ><IMETHODCALL NAME=\"EnumerateInstances\"><LOCALNAMESPACEPATH><NAMESPACE NAME=\"interop\"/></LOCALNAMESPACEPATH><IPARAMVALUE NAME=\"ClassName\"><CLASSNAME NAME=\"CIM_ObjectManager\"/></IPARAMVALUE></IMETHODCALL></SIMPLEREQ></MESSAGE></CIM>"
}
}
2021-03-01 10:30:16 (236) pool-9-thread-1 DEBUG: CimIQL: StatementTreeProcessor: Requests queued for send: 1
2021-03-01 10:30:16 (299) ECCQueueMonitor.1 DEBUG: Event: RGRPerfMetricEvent
2021-03-01 10:30:17 (096) ECCQueueMonitor.1 DEBUG: Event: CheckSenderReadyEvent
2021-03-01 10:30:17 (096) ECCQueueMonitor.1 DEBUG: Monitor query: state=ready^queue=output^agent=mid.server.MIDTEST03_Sand_Disco^sys_created_on>=2021-01-30 09:08:04^ORDERBYpriority^ORDERBYsys_created_on
2021-03-01 10:30:17 (174) ECCQueueMonitor.1 DEBUG: Event: RGRPerfMetricEvent
2021-03-01 10:30:17 (174) ECCQueueMonitor.1 DEBUG: Number of messages added to threadpool queue in current polling cycle: 0
2021-03-01 10:30:17 (174) ECCQueueMonitor.1 DEBUG: Changing polling frequency of ECCQueueMonitor to 40 seconds
2021-03-01 10:30:17 (174) ECCQueueMonitor.1 DEBUG: [ECCQueueMonitor] A new schedule is created with initial delay 18008 ms and interval 40000 ms
2021-03-01 10:30:21 (254) I/O dispatcher 13 WARNING *** WARNING *** CimIQL: HttpResponseFutureCallback: Timed out. Retries remaining: 0
2021-03-01 10:30:21 (254) I/O dispatcher 13 DEBUG: CimIQL: Attempting to authenticate with untried credential: #0
2021-03-01 10:30:21 (254) I/O dispatcher 13 DEBUG: CimIQL: HTTP: Enqueued message #2
2021-03-01 10:30:26 (271) I/O dispatcher 14 SEVERE *** ERROR *** CimIQL: ResponseMessageCallback: Failed on response message: 4.6.6.2
java.net.SocketTimeoutException: 5 000 milliseconds timeout on connection http-outgoing-3 [ACTIVE]
at org.shaded.apache.http.nio.protocol.HttpAsyncRequestExecutor.timeout(HttpAsyncRequestExecutor.java:381)
at org.shaded.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:92)
at org.shaded.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:39)
at org.shaded.apache.http.impl.nio.reactor.AbstractIODispatch.timeout(AbstractIODispatch.java:175)
at org.shaded.apache.http.impl.nio.reactor.BaseIOReactor.sessionTimedOut(BaseIOReactor.java:263)
at org.shaded.apache.http.impl.nio.reactor.AbstractIOReactor.timeoutCheck(AbstractIOReactor.java:492)
at org.shaded.apache.http.impl.nio.reactor.BaseIOReactor.validate(BaseIOReactor.java:213)
at org.shaded.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:280)
at org.shaded.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
at org.shaded.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
at java.lang.Thread.run(Thread.java:748)