DX NetOps

Hi All,

We have HTTP(S) SPM Tests created in Spectrum on SysEDGE host (test host) with the Service Response AIM installed. We are observing that, the tests are running fine always at SysEDGE host and sometimes getting the bad result events in Spectrum. This is happening most of the SPM tests. Tests are running fine most of the times and turning into bad result events some times. What is the meaning of this event? What could be the reason and how to address this?

Below is an example.

SPM HTTP Bad Result Event -
Test Name: EXAMPLE - TESTING - PROTAL 
Test Host Address: 10.0.0.1 
Source Address: 10.0.0.1
Destination Address: http://exampletesting.com/login.do
Test Type: HTTP
Layer 4 Port Number: 0
Current Test Interval: 120 seconds
Packet Size: 0
Sample Count: 2
Test Host Position: EndPoint
DNS Lookup String: Approximate round trip times in milli-seconds: Min = 1, Avg = 1, Max = 1
DNS Resolution Time (msec): 1
TCP Connect Time (msec): 1
HTTP Page Download Time (msec): 1
Timeout data filtered: FALSE

Thank you.

Regards,

Raj

Can anyone provide insight into the query please?

Hi Rajashekar,

                Maybe try putting SPM in debug and enable a sniffer trace (review the SPM events after turning on the debug and review the sniffer for errors/time).

Cheers

Jay

1. Open a terminal window or bash shell on the SpectroSERVER system

2. cd to the $SPECROOT/vnmsh directory

3. Enter the following command to start a Command Line Interface (CLI) session to the SpectroSERVER

./connect

4. Enter the following command to find the Model Handle of the SPM Test model where

6. Recreate the issue.

7. Review events from the test model showing duplicates.

Just amending steps by Jay above as it seems truncated/missing somehow.

1. Open a terminal window or bash shell on the SpectroSERVER system

2. cd to the $SPECROOT/vnmsh directory

3. Enter the following command to start a Command Line Interface (CLI) session to the SpectroSERVER

./connect

4. Enter the following command to find the Model Handle of the SPM Test model where <SPM Test> is the name of the SPM Test model. The Model Handle will be the first column of data.

./show models | grep -i <SPM Test>

5. Enter the following command to enable the debug on the SPM Test model where <MH> is the Model Handle from step 4 above:

./update action=0x456000e mh=<MH>

7. Recreate the issue.

8. Review the SPM test events

Thank you Jay and Widjaja for your response. I have already tried enabling the debugging on specific SPM tests and for timeout situations it is appending the additional info and error in the events and for normal result, Bad Result and Duplicate results, it is not providing any error or additional information. Seems, debugging is not applicable in this case.

As suggested by Jay, I will try to run sniffer trace against the SPM servers to see what kind of information it is fetching during that time.

Thank you.

Rajashekar

Hi Jay,

As suggested, here is the TCP DUMP output for a test.

<SPM_TEST_HOS_IP>.empire-empuma > <SPECTRUMSERVER.50790>: { SNMPv2c C=COMMUNITY { GetResponse(333) R=175746995 E:546.16.6.10.1.13.1131340400=1 E:546.16.6.10.1.15.1131340400=1 E:546.16.6.10.1.14.1131340400=1 E:546.16.6.10.1.21.1131340400=1 E:546.16.6.10.1.26.1131340400=1 E:546.16.6.10.1.31.1131340400=1 E:546.16.6.10.1.17.1131340400=100 E:546.16.6.10.1.37.1131340400=10825000 E:546.16.6.10.1.46.1131340400=0 E:546.16.6.10.1.48.1131340400=1 E:546.16.6.10.1.35.1131340400=43300 E:546.16.6.10.1.36.1131340400=0 E:546.16.6.10.1.47.1131340400=1 } }

Below is the log I see in SPM test host (SysEDGE host with Service Response AIM) and I can see the test has completed successfully.

[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: Started thread Thread-376
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: Started thread Thread-376
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] Test index: 1131340400 (class jcollector.HTTPTest) --- START ---
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] Starting jcollector.HTTPTest #1131340400.
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: Getting main URL http://dummyurl.com
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: - main URL [10517 bytes]: http://dummyurl.com
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] !!!!successfully downloaded the PAGE
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] HTTP TEST: Index 1131340400
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] name_time :1
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] conn_time :1
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] tran_time :14
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] total_time :16
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] bytes_in :10825
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] bytes_out : 0
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] error_field : 0
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] results_field : 0

[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: Getting main URL http://dummyurl.com
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: - main URL [10517 bytes]: http://dummyurl.com
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] !!!!successfully downloaded the PAGE
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] HTTP TEST: Index 1131340400
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] name_time :1
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] conn_time :1
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] tran_time :1
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] total_time :1
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] bytes_in :10825
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] bytes_out : 0
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] error_field : 0
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] results_field : 0
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] Test Index: 1131340400 updated Total Samples 6 (class jcollector.HTTPTest) --- END ---
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: [#1131340400] Finished jcollector.HTTPTest #1131340400
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: Ended thread Thread-376
[LOG_DEBUG][2018-06-07 06:48:35][Thread:Thread-376][Pass #9]: Ended thread Thread-376

With the above information, please let me know how it is treating the test result as Bad Result? Also, what is the exact meaning of Bad Result Event?

Regards,

Rajashekar

Any help on this please? what can be checked further?

Can anyone from CA help me to answer the query please?

Hi Rajashekar,

I think at this point it might be best to open a support issue and provide the sniffer trace results of your previous tests in pcap format so we can easily read it in Wireshark.

From my discussion with SysEdge Engineering team in the past, Spectrum is looking mostly at these SysOID objects:

svcRspTableNumSamples (if this does not change they treat that test as not running) and then svcRspTableTotalAvailability to see how successful the test was.

If you can get wireshark sniffer traces from a "good result" and one from a "bad result" we can check these two OIDs and perhaps we can determine the problem in a support issue.

Best regards,

Glenn

Hi Rajashehar,

This is specifically related to the question you mentioned right in the starting.
Q1) What is the meaning of the Bad Result Event or what does it represents?

Ans->

The Bad Result event is generated when we receive what we perceive to be unreliable data. This is set when the sum of these values? dnsRtt + tcpConnectRtt + downLoadRtt are greater or less than 2 ms from the average result value.

So for the Bad result event [A]: 1+1+19=21 which is greater than 2ms than the average of 17

Whereas, for the normal result event [B]: 1+1+18=20 which is equal to the average of 20

What skewed the results on the Bad Result event was one exceptionally quick response of 2ms. Since it is, so far out of the "norm" we throw the result away as potentially unreliable.

Causes of this problem:
~~~~~~~~~~~~~~~~~~~~~~~~~
The two events below are seen and the data in each looks very similar, yet one event is labeled as a "Bad Result" event.

[A]
~~~
[Event Type 0x4560056]
SPM HTTP Bad Result Event -
Test Name: ehealth WebServer
Test Host Address: 101.21.13.9
Source Address: 101.21.13.9
Destination Address: http://ehealth01.ca.com
Test Type: HTTP
Layer 4 Port Number: 0
Current Test Interval: 120 seconds
Packet Size: 0
Sample Count: 5
Test Host Position: EndPoint
DNS Lookup String:
Approximate round trip times in milli-seconds: Min = 2, Avg = 17, Max = 33
DNS Resolution Time (msec): 1
TCP Connect Time (msec): 1
HTTP Page Download Time (msec): 19
Timeout data filtered: TRUE

[B]
~~~~
[Event Type 0x456002e]
SPM HTTP Result Event -
Test Name: ehealth WebServer
Test Host Address: 101.21.13.9
Source Address: 101.21.13.9
Destination Address: http://ehealth01.ca.com
Test Type: HTTP
Layer 4 Port Number: 0
Current Test Interval: 120 seconds
Packet Size: 0
Sample Count: 5
Test Host Position: EndPoint
DNS Lookup String:
Approximate round trip times in milli-seconds: Min = 17, Avg = 20, Max = 33
DNS Resolution Time (msec): 1
TCP Connect Time (msec): 1
HTTP Page Download Time (msec): 18
Timeout data filtered: TRUE

Best Regards

Vanshdeep Khurana

Thank you Vanshdeep. It helps me to understand what Bad result event is.

I am glad I was able to answer it and help you. 

Thanks & Regards

Vanshdeep Khurana