[Kamailio-Users] Kamailio 1.4.2 : Weird Retransmission
Aurelien Grimaud
gstelzz at yahoo.fr
Mon Dec 8 16:43:41 CET 2008
Hi, I am using kamailio 1.4.2 and testing it with sipp.
one sipp is client a uac (port 5066), the other is a uas (port 5063).
kamailio is using 5060.
I am generating 100 calls per second for 1000 calls and message were
retransmitted 4 times.
Here is a tcpdump of sip packets.
Can anyone tell me why there is an INVITE retransmission at
16:16:38.627198 though the ACK for invite was received at 16:16:38.126096 ?
Is there a known problem with retransmission timers ?
16:16:38.120384 IP 192.168.168.33.5066 > 192.168.168.33.5060: SIP,
length: 579
E.._.. at .@.f....!...!.....K..INVITE sip:otest at testg5 SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5066;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 70
Expires: 180
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 188
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 8925 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
16:16:38.123426 IP 192.168.168.33.5060 > 192.168.168.33.5066: SIP,
length: 325
E..a.. at .@.g....!...!.....M..SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP
127.0.0.1:5066;branch=z9hG4bK-23096-730-1;received=192.168.168.33
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Server: Kamailio (1.4.2-notls (i386/linux))
Content-Length: 0
16:16:38.123554 IP 192.168.168.33.5060 > 192.168.168.33.5063: SIP,
length: 731
E..... at .@.fZ...!...!........INVITE sip:otest at testg5 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Expires: 180
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 188
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 8925 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
16:16:38.123830 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 451
E..... at .@.gz...!...!.......pSIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.0,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:38.124169 IP 192.168.168.33.5060 > 192.168.168.33.5066: SIP,
length: 393
E..... at .@.g....!...!.......6SIP/2.0 180 Ringing
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:38.124326 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 634
E..... at .@.f....!...!.......'SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.0,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Type: application/sdp
Content-Length: 153
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 6004 RTP/AVP 0 8
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
16:16:38.124883 IP 192.168.168.33.5060 > 192.168.168.33.5066: SIP,
length: 581
E..a.. at .@.f....!...!.....M..SIP/2.0 200 OK
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:192.168.168.33:5063>
Content-Type: application/sdp
Content-Length: 153
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 6004 RTP/AVP 0 8
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
16:16:38.125532 IP 192.168.168.33.5066 > 192.168.168.33.5060: SIP,
length: 427
E..... at .@.g....!...!.......XACK sip:192.168.168.33:5063 SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5066;branch=z9hG4bK-23096-730-11
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696
Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 70
Subject: Performance Test
Content-Length: 0
16:16:38.126096 IP 192.168.168.33.5060 > 192.168.168.33.5063: SIP,
length: 521
E..%.. at .@.g,...!...!........ACK sip:192.168.168.33:5063 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.2
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-11
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Subject: Performance Test
Content-Length: 0
16:16:38.627198 IP 192.168.168.33.5060 > 192.168.168.33.5063: SIP,
length: 731
E..... at .@.fZ...!...!........INVITE sip:otest at testg5 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Expires: 180
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 188
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 8925 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
16:16:38.627677 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 474
E..... at .@.gc...!...!........SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.2,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-11
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:38.627970 IP 192.168.168.33.5060 > 192.168.168.33.5066: SIP,
length: 416
E..... at .@.g....!...!.......MSIP/2.0 180 Ringing
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-11
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:39.642356 IP 192.168.168.33.5060 > 192.168.168.33.5063: SIP,
length: 731
E..... at .@.fZ...!...!........INVITE sip:otest at testg5 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Expires: 180
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 188
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 8925 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
16:16:39.642587 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 474
E..... at .@.gc...!...!........SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.2,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-11
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:39.643723 IP 192.168.168.33.5060 > 192.168.168.33.5066: SIP,
length: 416
E..... at .@.g....!...!.......MSIP/2.0 180 Ringing
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-11
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>;tag=17278SIPpTag01696;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:39.797641 IP 192.168.168.33.5066 > 192.168.168.33.5060: SIP,
length: 434
E..... at .@.g....!...!......._BYE sip:127.0.0.1:5063 SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5066;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 70
Subject: Performance Test
Content-Length: 0
16:16:39.798436 IP 192.168.168.33.5060 > 127.0.0.1.5063: SIP, length: 528
E..,.. at .@.P....!............BYE sip:127.0.0.1:5063 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Subject: Performance Test
Content-Length: 0
16:16:39.798535 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 394
E..... at .@.g....!...!.......7SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:39.798814 IP 192.168.168.33.5060 > 192.168.168.33.5066: SIP,
length: 336
E..l.. at .@.g....!...!.....X..SIP/2.0 200 OK
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:40.257973 IP 192.168.168.33.5060 > 127.0.0.1.5063: SIP, length: 528
E..,.. at .@.P....!............BYE sip:127.0.0.1:5063 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Subject: Performance Test
Content-Length: 0
16:16:40.258080 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 394
E..... at .@.g....!...!.......7SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:41.285493 IP 192.168.168.33.5060 > 127.0.0.1.5063: SIP, length: 528
E..,.. at .@.P....!............BYE sip:127.0.0.1:5063 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Subject: Performance Test
Content-Length: 0
16:16:41.285593 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 394
E..... at .@.g....!...!.......7SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: <sip:127.0.0.1:5063>
Content-Length: 0
16:16:41.695686 IP 192.168.168.33.5060 > 192.168.168.33.5063: SIP,
length: 731
E..... at .@.fZ...!...!........INVITE sip:otest at testg5 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bKcb7d.7c08af34.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-1
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:otest at testg5>
Call-ID: 730-23096-127.0.0.1
CSeq: 1 INVITE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Expires: 180
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 188
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0.1
s=-
c=IN IP4 127.0.0.1
t=0 0
m=audio 8925 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11,16
16:16:43.338592 IP 192.168.168.33.5060 > 127.0.0.1.5063: SIP, length: 528
E..,.. at .@.P....!............BYE sip:127.0.0.1:5063 SIP/2.0
Record-Route: <sip:192.168.168.33;lr=on;ftag=23096SIPpTag09730>
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0
Via: SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: sip:sipp at 127.0.0.1:5066
Max-Forwards: 69
Subject: Performance Test
Content-Length: 0
16:16:43.338785 IP 192.168.168.33.5063 > 192.168.168.33.5060: SIP,
length: 408
E..... at .@.g....!...!.......ESIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.168.33;branch=z9hG4bK9b7d.0423bf25.0,
SIP/2.0/UDP
127.0.0.1:5066;received=192.168.168.33;branch=z9hG4bK-23096-730-46
From: sipp <sip:730-23096-127.0.0.1 at 127.0.0.1:5066>;tag=23096SIPpTag09730
To: sut <sip:service at 192.168.168.33:5060>;tag=17278SIPpTag01696
Call-ID: 730-23096-127.0.0.1
CSeq: 2 BYE
Contact: <sip:127.0.0.1:5063;transport=UDP>
Content-Length: 0
More information about the Users
mailing list