Hi CW team, Anyone out there please help me. I am facing problem in stress testing. I have installed CW manually. whenever I was running 1 or less than 20 it give some errors like:
*[]ubuntu@stress:~$ sudo /usr/share/clearwater/bin/run_stress ims.com <http://ims.com> 1 2* [sudo] password for ubuntu: Starting initial registration, will take 0 seconds Initial registration succeeded Starting test Test complete Traceback (most recent call last): File "/usr/share/clearwater/bin/run_stress", line 340, in <module> with open(CALLER_STATS) as f: IOError: [Errno 2] No such file or directory: '/var/log/clearwater-sip-stress/18065_caller_stats.log' *[]ubuntu@stress:~$ sudo /usr/share/clearwater/bin/run_stress ims.com <http://ims.com> 10 5* Starting initial registration, will take 0 seconds Initial registration succeeded Starting test Test complete Traceback (most recent call last): File "/usr/share/clearwater/bin/run_stress", line 346, in <module> call_success_rate = 100 * float(row['SuccessfulCall(C)']) / float(row['TotalCallCreated']) ZeroDivisionError: float division by zero *[]ubuntu@stress:~$ sudo /usr/share/clearwater/bin/run_stress iind.intel.com <http://iind.intel.com> 50 5* Starting initial registration, will take 0 seconds Initial registration succeeded Starting test Test complete Elapsed time: 00:03:41 Start: 2018-03-20 17:46:43.268136 End: 2018-03-20 17:51:31.363406 Total calls: 2 Successful calls: 0 (0.0%) Failed calls: 2 (100.0%) Unfinished calls: 0 Retransmissions: 0 Average time from INVITE to 180 Ringing: 0.0ms # of calls with 0-2ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 2-10ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 10-20ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 20-50ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 50-100ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 100-200ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 200-500ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 500-1000ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 1000-2000ms from INVITE to 180 Ringing: 0 (0.0%) # of calls with 2000+ms from INVITE to 180 Ringing: 0 (0.0%) Failed: call success rate 0.0% is lower than target 100.0%! Total re-REGISTERs: 8 Successful re-REGISTERs: 8 (100.0%) Failed re-REGISTERS: 0 (0.0%) REGISTER retransmissions: 0 Average time from REGISTER to 200 OK: 86.0ms Log files at /var/log/clearwater-sip-stress/18566_* *[]ubuntu@stress:~$ cat /var/log/clearwater-sip-stress/18566_caller_errors.log* sipp: The following events occured: 2018-03-20 17:48:34.125945 1521548314.125945: Aborting call on unexpected message for Call-Id '[email protected]': while expecting '183' (index 2), received '*SIP/2.0 503 Service Unavailable* Via: SIP/2.0/TCP 127.0.1.1:42276 ;received=10.224.61.13;branch=z9hG4bK-18576-1-0 Record-Route: <sip:scscf.sprout.ims.com ;transport=TCP;lr;billing-role=charge-term> Record-Route: <sip:scscf.sprout. ims.com ;transport=TCP;lr;billing-role=charge-orig> Call-ID: [email protected] From: <sip:2010000042@ ims.com >;tag=18576SIPpTag001 To: <sip:2010000015@ ims.co>;tag=z9hG4bKPj1Lm9whhQMslKrcZxnN6qCH0tb9Lj5Neu CSeq: 1 INVITE P-Charging-Vector: icid-value="18576SIPpTag001";orig-ioi= ims.com ;term-ioi= ims.com P-Charging-Function-Addresses: ccf=0.0.0.0 Content-Length: 0 *[sprout]ubuntu@sprout:/var/log/sprout$ cat sprout_current.txt* --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 10.224.61.22;rport=49294;received=10.224.61.22;branch=z9hG4bK-670172 Call-ID: poll-sip-670172 From: "poll-sip" <sip:[email protected]>;tag=670172 To: <sip:[email protected]>;tag=z9hG4bK-670172 CSeq: 670172 OPTIONS Content-Length: 0 --end msg-- 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug common_sip_processing.cpp:275: Skipping SAS logging for OPTIONS response 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug pjsip: tdta0x7f35841b Destroying txdata Response msg 200/OPTIONS/cseq=670172 (tdta0x7f35841bfe80) 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug thread_dispatcher.cpp:270: Worker thread completed processing message 0x7f34ec34a3e8 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug thread_dispatcher.cpp:284: Request latency = 254us 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug event_statistic_accumulator.cpp:32: Accumulate 254 for 0x1d8f778 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug event_statistic_accumulator.cpp:32: Accumulate 254 for 0x1d8f820 20-03-2018 12:27:23.234 UTC [7f35577d6700] Info load_monitor.cpp:217: Rate adjustment calculation inputs: err -0.981500, smoothed latency 185, target latency 10000 20-03-2018 12:27:23.234 UTC [7f35577d6700] Info load_monitor.cpp:302: Maximum incoming request rate/second unchanged at 2000.000000 (current request rate is 0.200000 requests/sec, minimum threshold for a change is 1000.000000 requests/sec). 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug snmp_continuous_accumulator_by_scope_table.cpp:86: Accumulating sample 2000ui into continuous accumulator statistic 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug snmp_continuous_accumulator_by_scope_table.cpp:86: Accumulating sample 2000ui into continuous accumulator statistic 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug utils.cpp:878: Removed IOHook 0x7f35577d5e30 to stack. There are now 0 hooks 20-03-2018 12:27:23.234 UTC [7f35577d6700] Debug thread_dispatcher.cpp:158: Attempting to process queue element 20-03-2018 12:27:25.235 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP connection closed 20-03-2018 12:27:25.235 UTC [7f34f170a700] Debug connection_tracker.cpp:67: Connection 0x7f34ec027358 has been destroyed 20-03-2018 12:27:25.235 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) 20-03-2018 12:27:28.790 UTC [7f3573109700] Warning (Net-SNMP): Warning: Failed to connect to the agentx master agent ([NIL]): 20-03-2018 12:27:31.277 UTC [7f34f170a700] Verbose pjsip: tcplis:5054 TCP listener 10.224.61.22:5054: got incoming TCP connection from 10.224.61.22:42848, sock=573 20-03-2018 12:27:31.277 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 tcp->base.local_name: 10.224.61.22 20-03-2018 12:27:31.277 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP server transport created 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug pjsip: sip_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=670180 (rdata0x7f34ec027690) 20-03-2018 12:27:31.314 UTC [7f34f170a700] Verbose common_sip_processing.cpp:87: RX 351 bytes Request msg OPTIONS/cseq=670180 (rdata0x7f34ec027690) from TCP 10.224.61.22:42848: --start msg-- OPTIONS sip:[email protected]:5054 SIP/2.0 Via: SIP/2.0/TCP 10.224.61.22;rport;branch=z9hG4bK-670180 Max-Forwards: 2 To: <sip:[email protected]:5054> From: poll-sip <sip:[email protected]>;tag=670180 Call-ID: poll-sip-670180 CSeq: 670180 OPTIONS Contact: <sip:10.224.61.22> Accept: application/sdp Content-Length: 0 User-Agent: poll-sip --end msg-- 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug uri_classifier.cpp:139: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug uri_classifier.cpp:172: Classified URI as 3 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug common_sip_processing.cpp:180: Skipping SAS logging for OPTIONS request 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug thread_dispatcher.cpp:554: Recieved message 0x7f34ec027690 on worker thread 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug thread_dispatcher.cpp:571: Admitted request 0x7f34ec027690 on worker thread 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug thread_dispatcher.cpp:606: Incoming message 0x7f34ec027690 cloned to 0x7f34ec34a3e8 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug thread_dispatcher.cpp:625: Queuing cloned received message 0x7f34ec34a3e8 for worker threads with priority 15 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug event_statistic_accumulator.cpp:32: Accumulate 0 for 0x1d93708 20-03-2018 12:27:31.314 UTC [7f34f170a700] Debug event_statistic_accumulator.cpp:32: Accumulate 0 for 0x1d937b0 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug utils.cpp:872: Added IOHook 0x7f353ffa6e30 to stack. There are now 1 hooks 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug thread_dispatcher.cpp:178: Worker thread dequeue message 0x7f34ec34a3e8 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug thread_dispatcher.cpp:183: Request latency so far = 57us 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=670180 (rdata0x7f34ec34a3e8) 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug uri_classifier.cpp:139: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug uri_classifier.cpp:172: Classified URI as 3 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug pjsip: endpoint Response msg 200/OPTIONS/cseq=670180 (tdta0x7f34d8091300) created 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Verbose common_sip_processing.cpp:103: TX 282 bytes Response msg 200/OPTIONS/cseq=670180 (tdta0x7f34d8091300) to TCP 10.224.61.22:42848: --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 10.224.61.22;rport=42848;received=10.224.61.22;branch=z9hG4bK-670180 Call-ID: poll-sip-670180 From: "poll-sip" <sip:[email protected]>;tag=670180 To: <sip:[email protected]>;tag=z9hG4bK-670180 CSeq: 670180 OPTIONS Content-Length: 0 --end msg-- 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug common_sip_processing.cpp:275: Skipping SAS logging for OPTIONS response 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug pjsip: tdta0x7f34d809 Destroying txdata Response msg 200/OPTIONS/cseq=670180 (tdta0x7f34d8091300) 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug thread_dispatcher.cpp:270: Worker thread completed processing message 0x7f34ec34a3e8 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug thread_dispatcher.cpp:284: Request latency = 129us 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug event_statistic_accumulator.cpp:32: Accumulate 129 for 0x1d8f778 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug event_statistic_accumulator.cpp:32: Accumulate 129 for 0x1d8f820 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug load_monitor.cpp:341: Not recalculating rate as we haven't processed 20 requests yet (only 1). 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug utils.cpp:878: Removed IOHook 0x7f353ffa6e30 to stack. There are now 0 hooks 20-03-2018 12:27:31.314 UTC [7f353ffa7700] Debug thread_dispatcher.cpp:158: Attempting to process queue element 20-03-2018 12:27:31.333 UTC [7f34f0f09700] Verbose httpstack.cpp:327: Process request for URL /ping, args (null) 20-03-2018 12:27:31.333 UTC [7f34f0f09700] Verbose httpstack.cpp:68: Sending response 200 to request for URL /ping, args (null) 20-03-2018 12:27:33.315 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP connection closed 20-03-2018 12:27:33.316 UTC [7f34f170a700] Debug connection_tracker.cpp:67: Connection 0x7f34ec027358 has been destroyed 20-03-2018 12:27:33.316 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) 20-03-2018 12:27:33.328 UTC [7f34f170a700] Verbose pjsip: tcplis:5053 TCP listener 10.224.61.22:5053: got incoming TCP connection from 10.224.61.22:49356, sock=573 20-03-2018 12:27:33.328 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 tcp->base.local_name: 10.224.61.22 20-03-2018 12:27:33.328 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP server transport created 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug pjsip: sip_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=670182 (rdata0x7f34ec027690) 20-03-2018 12:27:33.329 UTC [7f34f170a700] Verbose common_sip_processing.cpp:87: RX 351 bytes Request msg OPTIONS/cseq=670182 (rdata0x7f34ec027690) from TCP 10.224.61.22:49356: --start msg-- OPTIONS sip:[email protected]:5053 SIP/2.0 Via: SIP/2.0/TCP 10.224.61.22;rport;branch=z9hG4bK-670182 Max-Forwards: 2 To: <sip:[email protected]:5053> From: poll-sip <sip:[email protected]>;tag=670182 Call-ID: poll-sip-670182 CSeq: 670182 OPTIONS Contact: <sip:10.224.61.22> Accept: application/sdp Content-Length: 0 User-Agent: poll-sip --end msg-- 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug uri_classifier.cpp:139: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug uri_classifier.cpp:172: Classified URI as 3 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug common_sip_processing.cpp:180: Skipping SAS logging for OPTIONS request 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug thread_dispatcher.cpp:554: Recieved message 0x7f34ec027690 on worker thread 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug thread_dispatcher.cpp:571: Admitted request 0x7f34ec027690 on worker thread 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug thread_dispatcher.cpp:606: Incoming message 0x7f34ec027690 cloned to 0x7f34ec34a3e8 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug thread_dispatcher.cpp:625: Queuing cloned received message 0x7f34ec34a3e8 for worker threads with priority 15 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug event_statistic_accumulator.cpp:32: Accumulate 0 for 0x1d93708 20-03-2018 12:27:33.329 UTC [7f34f170a700] Debug event_statistic_accumulator.cpp:32: Accumulate 0 for 0x1d937b0 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug utils.cpp:872: Added IOHook 0x7f354d7c1e30 to stack. There are now 1 hooks 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug thread_dispatcher.cpp:178: Worker thread dequeue message 0x7f34ec34a3e8 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug thread_dispatcher.cpp:183: Request latency so far = 102us 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=670182 (rdata0x7f34ec34a3e8) 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug uri_classifier.cpp:139: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug uri_classifier.cpp:172: Classified URI as 3 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug pjsip: endpoint Response msg 200/OPTIONS/cseq=670182 (tdta0x7f34ec004350) created 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Verbose common_sip_processing.cpp:103: TX 282 bytes Response msg 200/OPTIONS/cseq=670182 (tdta0x7f34ec004350) to TCP 10.224.61.22:49356: --start msg-- SIP/2.0 200 OK Via: SIP/2.0/TCP 10.224.61.22;rport=49356;received=10.224.61.22;branch=z9hG4bK-670182 Call-ID: poll-sip-670182 From: "poll-sip" <sip:[email protected]>;tag=670182 To: <sip:[email protected]>;tag=z9hG4bK-670182 CSeq: 670182 OPTIONS Content-Length: 0 --end msg-- 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug common_sip_processing.cpp:275: Skipping SAS logging for OPTIONS response 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug pjsip: tdta0x7f34ec00 Destroying txdata Response msg 200/OPTIONS/cseq=670182 (tdta0x7f34ec004350) 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug thread_dispatcher.cpp:270: Worker thread completed processing message 0x7f34ec34a3e8 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug thread_dispatcher.cpp:284: Request latency = 232us 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug event_statistic_accumulator.cpp:32: Accumulate 232 for 0x1d8f778 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug event_statistic_accumulator.cpp:32: Accumulate 232 for 0x1d8f820 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug load_monitor.cpp:341: Not recalculating rate as we haven't processed 20 requests yet (only 2). 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug utils.cpp:878: Removed IOHook 0x7f354d7c1e30 to stack. There are now 0 hooks 20-03-2018 12:27:33.329 UTC [7f354d7c2700] Debug thread_dispatcher.cpp:158: Attempting to process queue element 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:244: Reraising all alarms with a known state 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1001.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1005.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1011.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1012.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1013.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1004.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1002.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1009.1 alarm 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Debug alarm.cpp:303: AlarmReqAgent: queue overflowed 20-03-2018 12:27:34.994 UTC [7f358b7fe700] Status alarm.cpp:37: sprout issued 1010.1 alarm 20-03-2018 12:27:35.330 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP connection closed 20-03-2018 12:27:35.330 UTC [7f34f170a700] Debug connection_tracker.cpp:67: Connection 0x7f34ec027358 has been destroyed 20-03-2018 12:27:35.330 UTC [7f34f170a700] Verbose pjsip: tcps0x7f34ec02 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) all calls are failing I don't know what is going on, I am newbie to CW please guide some solution it will be great help. Thanks, Sunil
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
