SIPp
Last Error: Discarding message which can't be mapped to a known SIPp cal when UAS receive INVITE message
Hi,
I'm trying to make end to end call in Clearwater IMS environment using SIPp, but I'm getting Error “Discarding message which can't be mapped to a known SIPp call” on SIPp UAS endpoint for the incoming INVITE from SIPp Client(UAC). But when i use Jitsi as UAS i'm successful in making end to end call. Could someone help here.
UAS Command: "sipp 34.68.201.203 -sf uas.xml -m 1 -t t1 -trace_msg -trace_err"
UAS Output: ------------------------------ Scenario Screen -------- [1-9]: Change Screen -- Call-rate(length) Port Total-time Total-calls Remote-host 10.0(0 ms)/1.000s 5062 184.33 s 1 34.68.201.203:5060(TCP)
Call limit reached (-m 1), 1.002 s period 1 ms scheduler resolution 1 calls (limit 120) Peak was 1 calls, after 0 s 0 Running, 2 Paused, 3 Woken up 0 dead call msg (discarded) 1 out-of-call msg (discarded) 4 open sockets
Messages Retrans Timeout Unexpected-Msg
REGISTER ----------> 1 0 0
100 <---------- 0 0 0 0
401 <---------- 1 0 0 0
REGISTER ----------> 1 0 0
100 <---------- 0 0 0 0
200 <---------- 1 0 0 0
INVITE <---------- 0 0 0 0
180 ----------> 0 0
200 ----------> 0 0 0
ACK <---------- E-RTD1 0 0 0 0
BYE <---------- 0 0 0 0
200 ----------> 0 0
Pause [ 4000ms] 0 0
------- Waiting for active calls to end. Press [q] again to force exit. -------
Last Error: Discarding message which can't be mapped to a known SIPp cal...
UAC command: "sipp 34.68.201.203 -sf sippCall.xml -inf sippCall.csv -m 1 -t t1 -trace_msg -trace_err"
UAC Output: ------------------------------ Scenario Screen -------- [1-9]: Change Screen -- Call-rate(length) Port Total-time Total-calls Remote-host 10.0(0 ms)/1.000s 5063 34.27 s 1 34.68.201.203:5060(TCP)
Call limit reached (-m 1), 0.000 s period 0 ms scheduler resolution 0 calls (limit 960) Peak was 1 calls, after 0 s 0 Running, 3 Paused, 0 Woken up 0 dead call msg (discarded) 0 out-of-call msg (discarded) 0 open sockets
Messages Retrans Timeout Unexpected-Msg
REGISTER ----------> 1 0 0
100 <---------- 0 0 0 0
401 <---------- 1 0 0 0
REGISTER ----------> 1 0 0
100 <---------- 0 0 0 0
200 <---------- 1 0 0 0
Pause [ 2000ms] 1 0
INVITE ----------> 1 0 0
100 <---------- 1 0 0 0
180 <---------- 0 0 0 1
200 <---------- E-RTD1 0 0 0 0
ACK ----------> 0 0
[ NOP ]
Pause [ 30.0s] 0 0
BYE ----------> 0 0 0
200 <---------- 0 0 0 0
------------------------------ Test Terminated --------------------------------
----------------------------- Statistics Screen ------- [1-9]: Change Screen -- Start Time | 2019-07-30 19:04:11.633714 1564513451.633714 Last Reset Time | 2019-07-30 19:04:45.905139 1564513485.905139 Current Time | 2019-07-30 19:04:45.905300 1564513485.905300 -------------------------+---------------------------+-------------------------- Counter Name | Periodic value | Cumulative value -------------------------+---------------------------+-------------------------- Elapsed Time | 00:00:00:000000 | 00:00:34:271000 Call Rate | 0.000 cps | 0.029 cps -------------------------+---------------------------+-------------------------- Incoming call created | 0 | 0 OutGoing call created | 0 | 1 Total Call created | | 1 Current Call | 0 | -------------------------+---------------------------+-------------------------- Successful call | 0 | 0 Failed call | 0 | 1 -------------------------+---------------------------+-------------------------- Response Time 1 | 00:00:00:000000 | 00:00:00:000000 Call Length | 00:00:00:000000 | 00:00:34:153000 ------------------------------ Test Terminated --------------------------------
2019-07-30 19:04:45.891481 1564513485.891481: Aborting call on unexpected message for Call-Id '[email protected]': while expecting '180' (index 10), received 'SIP/2.0 408 Request Timeout Via: SIP/2.0/TCP 172.18.0.4:5063;rport=39243;received=10.16.0.1;branch=z9hG4bK-21223-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-term Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Call-ID: [email protected] From: sip:[email protected];tag=11234 To: sip:[email protected];tag=z9hG4bKPj5cKdnkBC3Kd39-k4kWZi6LecMQAhnESt CSeq: 1 INVITE Content-Length: 0
Hi Mohanraj612,
I faced the same situation with Asterisk. Actually, UAS needs to run in "server mode". In your scenario, it is not because it is sending REGISTER requests. I guess that you tried to send REGISTER in the scenario to use same TCP socket to receive the INVITE message. One solution I found is using -oocsf, that is generally used to reply requests in the background of UAC. To realize this, you should divide your UAS scenario into two parts: one is for REGISTER and the other for the rest. Then, run like
$ sipp 34.68.201.203 -sf register.xml -inf register.csv -oocsf uas.xml -m 1 -t t1 -trace_msg -trace_err
If you embedded the user information, including authentication, you do not have to use -inf and specify csv file. This would work because same command uses the same setting; however, the problem is the scenario screen shows the stat of register. Besides that, it should work well.
It can be great if we can select the scenario to display on the screen or run UAS in server mode with background request scenario by the same command.
Other way for Asterisk is to specify the host IPs for the usernames that you use in UAS in sip.conf and run UAS without REGISTER; however, this works differently when we want to simulate a phone-to-phone-call. It is like UAS runs as not a phone but an another SIP server.
Thanks a lot @muramasa8191 !!! Looks your solution works well.
I'm getting error for BYE message as below, could you please suggest what i'm missing here, Screen output: _------------------------------ Scenario Screen -------- [1-9]: Change Screen -- Call-rate(length) Port Total-time Total-calls Remote-host 10.0(0 ms)/1.000s 5061 32.23 s 1 34.68.201.203:5060(TCP)
Call limit reached (-m 1), 0.176 s period 1 ms scheduler resolution 0 calls (limit 960) Peak was 1 calls, after 0 s 0 Running, 3 Paused, 2 Woken up 0 dead call msg (discarded) 0 out-of-call msg (discarded) 0 open sockets 236 Total RTP pckts sent 0.000 last period RTP rate (kB/s)
Messages Retrans Timeout Unexpected-Msg
REGISTER ----------> 1 0 0
100 <---------- 0 0 0 0
401 <---------- 1 0 0 0
REGISTER ----------> 1 0 0
100 <---------- 0 0 0 0
200 <---------- 1 0 0 0
Pause [ 2000ms] 1 0
INVITE ----------> 1 0 0
100 <---------- 1 0 0 0
180 <---------- 1 0 0 0
200 <---------- E-RTD1 1 0 0 0
ACK ----------> 1 0
[ NOP ]
Pause [ 30.0s] 1 0
BYE ----------> 1 0 0
200 <---------- 0 0 0 1
------------------------------ Test Terminated -------------------------------- Counter Name | Periodic value | Cumulative value -------------------------+---------------------------+-------------------------- Elapsed Time | 00:00:00:000000 | 00:00:32:240000 Call Rate | 0.000 cps | 0.031 cps -------------------------+---------------------------+-------------------------- Incoming call created | 0 | 0 OutGoing call created | 0 | 1 Total Call created | | 1 Current Call | 0 | -------------------------+---------------------------+-------------------------- Successful call | 0 | 0 Failed call | 0 | 1 -------------------------+---------------------------+-------------------------- Response Time 1 | 00:00:00:000000 | 00:00:02:125000 Call Length | 00:00:00:000000 | 00:00:32:134000 ------------------------------ Test Terminated --------------------------------_ **2019-08-17 16:29:08.924885 1566059348.924885: Aborting call on unexpected message for Call-Id '[email protected]': while expecting '200' (index 16), received 'SIP/2.0 503 Service Unavailable**
Apart from above error, few queries below, it will be great if you help me with answer,
- Why i'm getting below error in UAS side, even it responds for INVITE,
2019-08-17 16:28:38.878962 1566059318.878962: Received out-of-call INVITE message, using the out-of-call scenario2019-08-17 16:28:47.834183 1566059327.834183: Aborted call with Call-ID '[email protected]'
- Why multiple times i'm getting ACK & 200 OK in UAC side, TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
----------------------------------------------- 2019-08-17 16:28:40.445415 TCP message received [825] bytes :
SIP/2.0 200 OK CSeq: 1 INVITE Call-ID: [email protected] From: "sipp" sip:[email protected];tag=2246SIPpTag001 To: "sut" sip:[email protected];tag=16931631_7a443279_e15cd509_4e7c0a23 Via: SIP/2.0/TCP 172.18.0.3:5061;rport=44017;received=10.16.0.1;branch=z9hG4bK-2246-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Server: Mobicents Sip Servlets 3.0.0-SNAPSHOT Contact: sip:35.232.133.59:5080;transport=tcp Content-Type: application/sdp Content-Length: 131
v=0 o=user1 53655765 2353687637 IN IP4 172.18.0.3 s=- c=IN IP4 172.18.0.3 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000
----------------------------------------------- 2019-08-17 16:28:40.445710 TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
----------------------------------------------- 2019-08-17 16:28:42.417383 TCP message received [825] bytes :
SIP/2.0 200 OK CSeq: 1 INVITE Call-ID: [email protected] From: "sipp" sip:[email protected];tag=2246SIPpTag001 To: "sut" sip:[email protected];tag=16931631_7a443279_e15cd509_4e7c0a23 Via: SIP/2.0/TCP 172.18.0.3:5061;rport=44017;received=10.16.0.1;branch=z9hG4bK-2246-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Server: Mobicents Sip Servlets 3.0.0-SNAPSHOT Contact: sip:35.232.133.59:5080;transport=tcp Content-Type: application/sdp Content-Length: 131
v=0 o=user1 53655765 2353687637 IN IP4 172.18.0.3 s=- c=IN IP4 172.18.0.3 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000
----------------------------------------------- 2019-08-17 16:28:42.417605 TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
----------------------------------------------- 2019-08-17 16:28:46.419223 TCP message received [825] bytes :
SIP/2.0 200 OK CSeq: 1 INVITE Call-ID: [email protected] From: "sipp" sip:[email protected];tag=2246SIPpTag001 To: "sut" sip:[email protected];tag=16931631_7a443279_e15cd509_4e7c0a23 Via: SIP/2.0/TCP 172.18.0.3:5061;rport=44017;received=10.16.0.1;branch=z9hG4bK-2246-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Server: Mobicents Sip Servlets 3.0.0-SNAPSHOT Contact: sip:35.232.133.59:5080;transport=tcp Content-Type: application/sdp Content-Length: 131
v=0 o=user1 53655765 2353687637 IN IP4 172.18.0.3 s=- c=IN IP4 172.18.0.3 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000
----------------------------------------------- 2019-08-17 16:28:46.419460 TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
----------------------------------------------- 2019-08-17 16:28:50.420959 TCP message received [825] bytes :
SIP/2.0 200 OK CSeq: 1 INVITE Call-ID: [email protected] From: "sipp" sip:[email protected];tag=2246SIPpTag001 To: "sut" sip:[email protected];tag=16931631_7a443279_e15cd509_4e7c0a23 Via: SIP/2.0/TCP 172.18.0.3:5061;rport=44017;received=10.16.0.1;branch=z9hG4bK-2246-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Server: Mobicents Sip Servlets 3.0.0-SNAPSHOT Contact: sip:35.232.133.59:5080;transport=tcp Content-Type: application/sdp Content-Length: 131
v=0 o=user1 53655765 2353687637 IN IP4 172.18.0.3 s=- c=IN IP4 172.18.0.3 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000
----------------------------------------------- 2019-08-17 16:28:50.421145 TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
----------------------------------------------- 2019-08-17 16:28:54.421646 TCP message received [825] bytes :
SIP/2.0 200 OK CSeq: 1 INVITE Call-ID: [email protected] From: "sipp" sip:[email protected];tag=2246SIPpTag001 To: "sut" sip:[email protected];tag=16931631_7a443279_e15cd509_4e7c0a23 Via: SIP/2.0/TCP 172.18.0.3:5061;rport=44017;received=10.16.0.1;branch=z9hG4bK-2246-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Server: Mobicents Sip Servlets 3.0.0-SNAPSHOT Contact: sip:35.232.133.59:5080;transport=tcp Content-Type: application/sdp Content-Length: 131
v=0 o=user1 53655765 2353687637 IN IP4 172.18.0.3 s=- c=IN IP4 172.18.0.3 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000
----------------------------------------------- 2019-08-17 16:28:54.421891 TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
----------------------------------------------- 2019-08-17 16:28:58.424407 TCP message received [825] bytes :
SIP/2.0 200 OK CSeq: 1 INVITE Call-ID: [email protected] From: "sipp" sip:[email protected];tag=2246SIPpTag001 To: "sut" sip:[email protected];tag=16931631_7a443279_e15cd509_4e7c0a23 Via: SIP/2.0/TCP 172.18.0.3:5061;rport=44017;received=10.16.0.1;branch=z9hG4bK-2246-1-8 Record-Route: sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Record-Route: sip:10.16.0.12:5058;transport=TCP;lr Record-Route: sip:[email protected]:5060;transport=TCP;lr Server: Mobicents Sip Servlets 3.0.0-SNAPSHOT Contact: sip:35.232.133.59:5080;transport=tcp Content-Type: application/sdp Content-Length: 131
v=0 o=user1 53655765 2353687637 IN IP4 172.18.0.3 s=- c=IN IP4 172.18.0.3 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000
----------------------------------------------- 2019-08-17 16:28:58.424601 TCP message sent (576 bytes):
ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/TCP 172.18.0.3:5061;branch=z9hG4bK-2246-1-12 From: sip:[email protected]:5061;tag=2246SIPpTag001 To: sip:[email protected]:5060;tag=16931631_7a443279_e15cd509_4e7c0a23 Route: sip:[email protected]:5060;transport=TCP;lr, sip:10.16.0.12:5058;transport=TCP;lr, sip:sprout.default.svc.cluster.local:5054;transport=tcp;lr;billing-role=charge-orig Call-ID: [email protected] CSeq: 1 ACK Max-Forwards: 70 Subject: Performance Test Content-Length: 0
Logs and xml files are attached, Thanks again for your support!
uac_2246_errors.log uac_2246_messages.log RegUAS_2245_errors.log RegUAS_2245_messages.log InviteUAS.txt uac.txt RegUAS.txt
My suspicion is that these are not SIPp problems, and you should be looking in the logs of the system you're testing (your initial message says Clearwater but your messages suggest that Mobicents Sip Servlets 3.0.0-SNAPSHOT is involved somewhere).
- SIPp is reporting 'unexpected message for Call-Id '[email protected]': while expecting '200' (index 16), received 'SIP/2.0 503 Service Unavailable' - that is, something is replying to your BYE with a 503 error instead of a 200 OK. I'd check the logs of other SIP servers and/or use
tcpdumpto see what is sending that 503, and why it's doing so. - Repeatedly receiving 200 OK messages suggests that the ACK you're sending isn't accepted/treated as a valid acknowledgement by something you're sending it to. I'd check the logs of other SIP servers and/or use
tcpdumpto see what is resending the 200 OK, and why it's doing so. - 'Aborted call with Call-ID '[email protected]' looks like it would only happen at the end of the program. I see that RegUAS.txt ends with
<pause milliseconds="14000"/>, so I think what's happening is:- you REGISTER
- ~5 seconds after REGISTERing, an INVITE is received, triggering an out-of-call scenario
- that INVITE never completes successfully, because the BYE from the other end is rejected with a 503 by an intermediate server, so we never see the BYE
- 14 seconds after the REGISTER completes, that pause ends. All main scenario calls are finished so SIPp exits, terminating the out-of-call scenario call and triggering that "Aborted call with..." log.
Sorry to interrupt, when I use both uac & oocsf options, I get below error Automatic calls (created by -aa, -oocsn or -oocsf) cannot use input files!
./sipp $PROXY_IP -i $LOCAL_IP -p $PORT -t t1 -m 1 -sf ./register.xml -inf ./B_user.csv -oocsf ./answer.xml -trace_msg -trace_err
SIPp v3.7-dev-9-ga284f3a-PCAP-RTPSTREAM-RTPCHECK.
