Hi,
I am trying to build a test environment for our PBX. To test the set up
and to have base data for comparison I connected two sipp instances, one
sending INVITEs as uac, the other receiving them as uas. When I try
higher call rates then many calls are aborted on 'unexpected messages'.
When I checked the logs I found out the 'unexpected messages' are just
retransmissions – expected when load is high.
It seems sipp will stop recognizing INVITE retransmissions as soon, as
it sends a 200 OK response – it remembers just one 'hash' of received
request and clears it when sending response.
Here is my call debug log excerpt (all responses are sent
unrealistically fast, but it shows the problem):
-------------------------------------------------------------------------------
Call debugging information for call 2-6871@10.28.45.27:
2013-06-24 14:00:24:252 1372075224.252843 Starting call
2-6871@10.28.45.27 2013-06-24 14:00:24:252 1372075224.252861
Processing 535 byte incoming message for call-ID 2-6871@10.28.45.27
(hash 1565712711): INVITE sip:5550000@10.28.45.72:5060 SIP/2.0^M Via:
SIP/2.0/UDP 10.28.45.27:35015;branch=z9hG4bK-6871-2-0^M From:
testphone001 <sip:testphone001@localhost>/g;tag=6871SIPpTag002^M To:
5550000 <sip:5550000@10.28.45.72:5060>^M Call-ID: 2-6871@10.28.45.27^M
CSeq: 1 INVITE^M
Contact: sip:sipp@10.28.45.27:35015^M
Max-Forwards: 70^M
Subject: Performance Test^M
Content-Type: application/sdp^M
Content-Length: 133^M
^M
v=0^M
o=user1 53655765 2353687637 IN IP4 10.28.45.27^M
s=-^M
c=IN IP4 10.28.45.27^M
t=0 0^M
m=audio 6004 RTP/AVP 0^M
a=rtpmap:0 PCMA/8000^M
2013-06-24 14:00:24:252 1372075224.252917 Set Last Recv Hash:
1565712711 (recv index 1) 2013-06-24 14:00:24:252
1372075224.252928 Processing message 2 of type 2 for call
2-6871@10.28.45.27 at 779. 2013-06-24 14:00:24:252
1372075224.252957 Sending UDP message for call 2-6871@10.28.45.27
(index 2, hash 2846259221): SIP/2.0 100 Trying^M Via: SIP/2.0/UDP
10.28.45.27:35015;branch=z9hG4bK-6871-2-0^M From: testphone001
<sip:testphone001@localhost>/g;tag=6871SIPpTag002^M To: 5550000
<sip:5550000@10.28.45.72:5060>;tag=6891SIPpTag012^M Call-ID:
2-6871@10.28.45.27^M CSeq: 1 INVITE^M Contact:
<sip:10.28.45.72:5060;transport=UDP>^M Content-Length: 0^M
^M
2013-06-24 14:00:24:253 1372075224.253035 Set Retransmission
Hash: 1565712711 (recv index 1, send index 2) 2013-06-24
14:00:24:253 1372075224.253046 Processing message 3 of type 2 for
call 2-6871@10.28.45.27 at 779. 2013-06-24 14:00:24:253
1372075224.253073 Sending UDP message for call 2-6871@10.28.45.27
(index 3, hash 751853496): SIP/2.0 180 Ringing^M Via: SIP/2.0/UDP
10.28.45.27:35015;branch=z9hG4bK-6871-2-0^M From: testphone001
<sip:testphone001@localhost>/g;tag=6871SIPpTag002^M To: 5550000
<sip:5550000@10.28.45.72:5060>;tag=6891SIPpTag012^M Call-ID:
2-6871@10.28.45.27^M CSeq: 1 INVITE^M Contact:
<sip:10.28.45.72:5060;transport=UDP>^M Content-Length: 0^M
^M
2013-06-24 14:00:24:253 1372075224.253128 Set Retransmission
Hash: 0 (recv index 1, send index 3) 2013-06-24 14:00:24:253
1372075224.253138 Processing message 4 of type 2 for call
2-6871@10.28.45.27 at 779. 2013-06-24 14:00:24:253
1372075224.253168 Sending UDP message for call 2-6871@10.28.45.27
(index 4, hash 916878743): SIP/2.0 200 OK^M Via: SIP/2.0/UDP
10.28.45.27:35015;branch=z9hG4bK-6871-2-0^M From: testphone001
<sip:testphone001@localhost>/g;tag=6871SIPpTag002^M To: 5550000
<sip:5550000@10.28.45.72:5060>;tag=6891SIPpTag012^M Call-ID:
2-6871@10.28.45.27^M CSeq: 1 INVITE^M Contact:
<sip:10.28.45.72:5060;transport=UDP>^M Content-Type: application/sdp^M
Content-Length: 133^M
^M
v=0^M
o=user1 53655765 2353687637 IN IP4 10.28.45.72^M
s=-^M
c=IN IP4 10.28.45.72^M
t=0 0^M
m=audio 6000 RTP/AVP 0^M
a=rtpmap:0 PCMA/8000^M
2013-06-24 14:00:24:253 1372075224.253211 Set Retransmission
Hash: 0 (recv index 1, send index 4) 2013-06-24 14:00:24:253
1372075224.253220 Processing message 5 of type 3 for call
2-6871@10.28.45.27 at 780. 2013-06-24 14:00:24:257
1372075224.257380 Processing 535 byte incoming message for call-ID
2-6871@10.28.45.27 (hash 1565712711): INVITE
sip:5550000@10.28.45.72:5060 SIP/2.0^M Via: SIP/2.0/UDP
10.28.45.27:35015;branch=z9hG4bK-6871-2-0^M From: testphone001
<sip:testphone001@localhost>/g;tag=6871SIPpTag002^M To: 5550000
<sip:5550000@10.28.45.72:5060>^M Call-ID: 2-6871@10.28.45.27^M CSeq: 1
INVITE^M Contact: sip:sipp@10.28.45.27:35015^M Max-Forwards: 70^M
Subject: Performance Test^M
Content-Type: application/sdp^M
Content-Length: 133^M
^M
v=0^M
o=user1 53655765 2353687637 IN IP4 10.28.45.27^M
s=-^M
c=IN IP4 10.28.45.27^M
t=0 0^M
m=audio 6004 RTP/AVP 0^M
a=rtpmap:0 PCMA/8000^M
2013-06-24 14:00:24:257 1372075224.257503 Unexpected UDP
message received (index 5, hash 1565712711):
INVITE sip:5550000@10.28.45.72:5060 SIP/2.0^M
Via: SIP/2.0/UDP 10.28.45.27:35015;branch=z9hG4bK-6871-2-0^M
From: testphone001 <sip:testphone001@localhost>/g;tag=6871SIPpTag002^M
To: 5550000 <sip:5550000@10.28.45.72:5060>^M
Call-ID: 2-6871@10.28.45.27^M
CSeq: 1 INVITE^M
Contact: sip:sipp@10.28.45.27:35015^M
Max-Forwards: 70^M
Subject: Performance Test^M
Content-Type: application/sdp^M
Content-Length: 133^M
^M
v=0^M
o=user1 53655765 2353687637 IN IP4 10.28.45.27^M
s=-^M
c=IN IP4 10.28.45.27^M
t=0 0^M
m=audio 6004 RTP/AVP 0^M
a=rtpmap:0 PCMA/8000^M
2013-06-24 14:00:24:257 1372075224.257516 Aborting call
2-6871@10.28.45.27 (index 5).
-------------------------------------------------------------------------------
The first and the last messages are exactly the same, but the latter is
considered unexpected.
The following patch seems to fix the problem for me, though I am not
sure if it doesn't break anything:
diff -dur sipp-3.3.orig/call.cpp sipp-3.3/call.cpp
--- sipp-3.3.orig/call.cpp 2013-06-24 13:57:09.000000000 +0200
+++ sipp-3.3/call.cpp 2013-06-24 14:30:33.150172351 +0200
@@ -1564,7 +1564,7 @@
if(last_recv_index >= 0) {
/* We are sending just after msg reception. There is a great
* chance that we will be asked to retransmit this message */
- recv_retrans_hash = last_recv_hash;
+ if (last_recv_hash) recv_retrans_hash = last_recv_hash;
recv_retrans_recv_index = last_recv_index;
recv_retrans_send_index = curmsg->index;
Greets,
Jacek
------------------------------------------------------------------------------
This SF.net email is sponsored by Windows:
Build for Windows Store.
http://p.sf.net/sfu/windows-dev2dev
_______________________________________________
Sipp-users mailing list
Sipp-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/sipp-users
