I try to do an stress test on a manually installed version. However users are successfully registered but the call is aborted with the following error.
sipp: The following events occured: 2018-07-16 12:48:02.879689 1531729082.879689: 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:17027 ;received=192.168.122.251;branch=z9hG4bK-29085-1-0 Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-term> Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-orig> Call-ID: [email protected] From: <sip:[email protected]>;tag=29085SIPpTag001 To: <sip:[email protected] >;tag=z9hG4bKPjkqlLv4G9J3y5Ay7UJ-yjI1FVg2jNqOe6 CSeq: 1 INVITE P-Charging-Vector: icid-value="29085SIPpTag001";orig-ioi=example.amir;term-ioi=example.amir P-Charging-Function-Addresses: ccf=0.0.0.0 Content-Length: 0 I set the log level to 4 in sprout and a part of this is included. looks like pjsip finds a connection problem. 16-07-2018 08:18:03.618 UTC [7f9af379e700] Verbose sproutletproxy.cpp:2284: scscf-proxy-0x7f9b24172ba0 pass initial request Request msg INVITE/cseq=1 (tdta0x7f9b24174170) to Sproutlet 16-07-2018 08:18:03.618 UTC [7f9af379e700] Info scscfsproutlet.cpp:442: S-CSCF received initial request 16-07-2018 08:18:03.618 UTC [7f9af379e700] Info scscfsproutlet.cpp:973: Original dialog for odi_b31nIgVSUL found: AsChain-term[0x7f9b2415da20]:2/1 16-07-2018 08:18:03.618 UTC [7f9af379e700] Verbose static_dns_cache.cpp:327: No matching CNAME record found in static cache 16-07-2018 08:18:03.618 UTC [7f9af379e700] Verbose dnscachedresolver.cpp:314: Check cache for hs.example.amir type 1 16-07-2018 08:18:03.619 UTC [7f9af379e700] Info scscfsproutlet.cpp:606: Found served user, so apply services 16-07-2018 08:18:03.619 UTC [7f9af379e700] Info scscfsproutlet.cpp:1550: Completed applying terminating services 16-07-2018 08:18:03.619 UTC [7f9af379e700] Info scscfsproutlet.cpp:1776: Route request to registered UE bindings 16-07-2018 08:18:03.619 UTC [7f9af379e700] Info scscfsproutlet.cpp:244: Look up bindings for sip:[email protected] in subscriber manager 16-07-2018 08:18:03.619 UTC [7f9af379e700] Verbose static_dns_cache.cpp:327: No matching CNAME record found in static cache 16-07-2018 08:18:03.619 UTC [7f9af379e700] Verbose dnscachedresolver.cpp:314: Check cache for vellum.example.amir type 1 16-07-2018 08:18:03.620 UTC [7f9af379e700] Verbose sproutletproxy.cpp:1995: scscf-proxy-0x7f9b24172ba0 sending Request msg INVITE/cseq=1 (tdta0x7f9b24174170) on fork 0 16-07-2018 08:18:03.620 UTC [7f9af379e700] Info pjutils.cpp:1001: Resolved destination URI sip:127.0.1.1:5082;transport=tcp;lr 16-07-2018 08:18:03.620 UTC [7f9af379e700] Verbose pjsip: tcpc0x7f9b2418 tcp->base.local_name: 192.168.122.59 16-07-2018 08:18:03.620 UTC [7f9af379e700] Verbose pjsip: tcpc0x7f9b2418 TCP client transport created 16-07-2018 08:18:03.620 UTC [7f9af379e700] Verbose pjsip: tcpc0x7f9b2418 TCP transport 192.168.122.59:5052 is connecting to 127.0.1.1:5082... 16-07-2018 08:18:03.620 UTC [7f9af379e700] Verbose common_sip_processing.cpp:103: TX 3166 bytes Request msg INVITE/cseq=1 (tdta0x7f9b24174170) to TCP 127.0.1.1:5082: --start msg-- INVITE sip:[email protected]:26268 SIP/2.0 Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-term> Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-orig> Via: SIP/2.0/TCP 192.168.122.59:5052;rport;branch=z9hG4bKPjAPniom2E9LBwFkQV5tQmnAjbbNSEYjFq Via: SIP/2.0/TCP mmtel.sprout.example.amir;branch=z9hG4bKPjkqlLv4G9J3y5Ay7UJ-yjI1FVg2jNqOe6 Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjA3-iG2tALLWhnc7.DVbVgxGicTIAmADn Via: SIP/2.0/TCP icscf.sprout.example.amir;branch=z9hG4bKPjhA8NyujPVgl2qMEADF4S7T87NEY-YWPL Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjdHHGQkTLRkC0a3IhU2xcw6THXK6b3VjE Via: SIP/2.0/TCP mmtel.sprout.example.amir;branch=z9hG4bKPj4GDzedM6HbxvCs4LztENsDY3gJ0XbBxx Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjYSOuqmNTNkKa3oOf25TBkxrKnSUgUqvw Via: SIP/2.0/TCP 127.0.1.1:17027;received=192.168.122.251;branch=z9hG4bK-29085-1-0 From: <sip:[email protected]>;tag=29085SIPpTag001 To: <sip:[email protected]> CSeq: 1 INVITE Expires: 180 Call-Info: <sip:127.0.1.1:17027>;method="NOTIFY;Event=telephone-event;Duration=2000" P-Charging-Function-Addresses: ccf=0.0.0.0 Supported: timer, precondition, sec-agree, histinfo, 100rel P-Charging-Vector: icid-value="29085SIPpTag001";orig-ioi=example.amir;term-ioi=example.amir Contact: <sip:[email protected]:17027>;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel";video;+sip.instance="<urn:gsma:imei:35283606-360704-0>" P-Early-Media: supported Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, UPDATE, INFO, REFER, NOTIFY, MESSAGE, PRACK P-Asserted-Identity: <sip:[email protected]> Security-Verify: ipsec-3gpp;q=0.1;alg=hmac-md5-96;mod=trans;ealg=aes-cbc;spi-c=265324728;spi-s=83307704;port-c=16381;port-s=5061 User-Agent: AAAAA IMS 4.0.0 Accept-Contact: *;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel" Session-Expires: 600;refresher=uac Call-ID: [email protected] Max-Forwards: 62 P-Visited-Network-ID: example.amir X-Dummy-Header: abcd Accept: application/sdp, application/dtmf-relay P-Served-User: <sip:[email protected]>;sescase=term;regstate=reg P-Called-Party-ID: <sip:[email protected]> Route: <sip:127.0.1.1:5082;transport=tcp;lr> Content-Type: application/sdp Content-Length: 823 v=0 o=AAAAAA-IMS-UE 18567144687033 18567144687033 IN IP4 127.0.1.1 s=- c=IN IP4 127.0.1.1 t=0 0 m=audio 16404 RTP/AVP 116 107 118 96 0 8 111 110 b=AS:38 b=RS:375 b=RR:1125 a=inactive a=rtpmap:116 AMR-WB/16000/1 a=rtpmap:107 AMR-WB/16000/1 a=rtpmap:118 AMR/8000/1 a=rtpmap:96 AMR/8000/1 a=rtpmap:111 telephone-event/16000 a=rtpmap:110 telephone-event/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=fmtp:116 mode-change-capability=2; max-red=220 a=fmtp:107 octet-align=1;mode-change-capability=2; max-red=220 a=fmtp:118 mode-change-capability=2; max-red=220 a=fmtp:96 octet-align=1;mode-change-capability=2; max-red=220 a=fmtp:111 0-15 a=fmtp:110 0-15 a=curr:qos local none a=curr:qos remote none a=des:qos mandatory local sendrecv a=des:qos optional remote sendrecv a=maxptime:240 a=ptime:20 --end msg-- 16-07-2018 08:18:03.630 UTC [7f9aa8708700] Info pjsip: tcpc0x7f9b2418 TCP connect() error: Connection refused [code=120111] 16-07-2018 08:18:03.630 UTC [7f9aa8708700] Info pjsip: tcpc0x7f9b2418 Unable to connect to 127.0.1.1:5082 16-07-2018 08:18:03.630 UTC [7f9aa8708700] Info pjsip: tsx0x7f9b2418d Failed to send Request msg INVITE/cseq=1 (tdta0x7f9b24174170)! err=120111 (Connection refused) 16-07-2018 08:18:03.630 UTC [7f9aa8708700] Verbose pjsip: tcpc0x7f9b2418 TCP transport destroyed with reason 120111: Connection refused 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:1007: Notifying upstream sproutlet scscf-proxy of client failure: TRANSPORT_ERROR 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:2392: scscf-proxy-0x7f9b24172ba0 received error TRANSPORT_ERROR on fork 0, state = Calling 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Info pjutils.cpp:1809: Cloning header! 140304302170008 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Info pjutils.cpp:1809: Cloning header! 140304302169072 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Info scscfsproutlet.cpp:699: S-CSCF received response 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:2031: scscf-proxy-0x7f9b24172ba0 sending Response msg 503/INVITE/cseq=1 (tdta0x7f9b3c0250b0) 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:2825: Routing Response msg 503/INVITE/cseq=1 (tdta0x7f9b3c0250b0) (1101 bytes) to upstream sproutlet mmtel: --start msg-- SIP/2.0 503 Service Unavailable Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjA3-iG2tALLWhnc7.DVbVgxGicTIAmADn Via: SIP/2.0/TCP icscf.sprout.example.amir;branch=z9hG4bKPjhA8NyujPVgl2qMEADF4S7T87NEY-YWPL Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjdHHGQkTLRkC0a3IhU2xcw6THXK6b3VjE Via: SIP/2.0/TCP mmtel.sprout.example.amir;branch=z9hG4bKPj4GDzedM6HbxvCs4LztENsDY3gJ0XbBxx Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjYSOuqmNTNkKa3oOf25TBkxrKnSUgUqvw Via: SIP/2.0/TCP 127.0.1.1:17027;received=192.168.122.251;branch=z9hG4bK-29085-1-0 Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-term> Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-orig> Call-ID: [email protected] From: <sip:[email protected]>;tag=29085SIPpTag001 To: <sip:[email protected]>;tag=z9hG4bKPjkqlLv4G9J3y5Ay7UJ-yjI1FVg2jNqOe6 CSeq: 1 INVITE P-Charging-Vector: icid-value="29085SIPpTag001";orig-ioi=example.amir;term-ioi=example.amir P-Charging-Function-Addresses: ccf=0.0.0.0 Content-Length: 0 --end msg-- 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:2341: mmtel-0x7f9b2415d900 received final response Response msg 503/INVITE/cseq=1 (tdta0x7f9b3c0250b0) on fork 0, state = Terminated 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:2031: mmtel-0x7f9b2415d900 sending Response msg 503/INVITE/cseq=1 (tdta0x7f9b3c0250b0) 16-07-2018 08:18:03.630 UTC [7f9aecf91700] Verbose sproutletproxy.cpp:2825: Routing Response msg 503/INVITE/cseq=1 (tdta0x7f9b3c0250b0) (1008 bytes) to upstream sproutlet scscf-proxy: --start msg-- SIP/2.0 503 Service Unavailable Via: SIP/2.0/TCP icscf.sprout.example.amir;branch=z9hG4bKPjhA8NyujPVgl2qMEADF4S7T87NEY-YWPL Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjdHHGQkTLRkC0a3IhU2xcw6THXK6b3VjE Via: SIP/2.0/TCP mmtel.sprout.example.amir;branch=z9hG4bKPj4GDzedM6HbxvCs4LztENsDY3gJ0XbBxx Via: SIP/2.0/TCP scscf.sprout.example.amir;branch=z9hG4bKPjYSOuqmNTNkKa3oOf25TBkxrKnSUgUqvw Via: SIP/2.0/TCP 127.0.1.1:17027;received=192.168.122.251;branch=z9hG4bK-29085-1-0 Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-term> Record-Route: <sip:scscf.sprout.example.amir;transport=TCP;lr;billing-role=charge-orig> Call-ID: [email protected] From: <sip:[email protected]>;tag=29085SIPpTag001 To: <sip:[email protected]>;tag=z9hG4bKPjkqlLv4G9J3y5Ay7UJ-yjI1FVg2jNqOe6 CSeq: 1 INVITE P-Charging-Vector: icid-value="29085SIPpTag001";orig-ioi=example.amir;term-ioi=example.amir P-Charging-Function-Addresses: ccf=0.0.0.0 Content-Length: 0 --end msg--
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
