[Freeswitch-users] extra Bye message from Freeswitch

[Jurijs Ivolga]

Hi!

I started to run some performance tests against Freeswitch and in 5-10%
tests are failing because of Freeswitch sending extra bye message. I would
like to add that I got such messages on very low load, 1 new call in 5
seconds and first fail was after 9th call.

Here how call looks like in 90-95% of time:

SIPp UAC            Freeswitch
    |(1) INVITE         |
    |------------------>|
    |(2) 100 (optional) |
    |<------------------|
    |(3) 200            |
    |<------------------|
    |(4) ACK            |
    |------------------>|
    |(5) BYE            |
    |------------------>|
    |(6) 200            |
    |<------------------|


Below you can see how call looks like in 5-10% of time.
Somehow Freeswitch replies on bye message from Sipp with extra bye(around
5-10% of all calls) and it creates a mess:

SIPp UAC            Freeswitch
    |(1) INVITE         |
    |------------------>|
    |(2) 100 (optional) |
    |<------------------|
    |(3) 200            |
    |<------------------|
    |(4) ACK            |
    |------------------>|
    |(5) BYE            |
    |------------------>|
    |(6) BYE            |
    |<------------------|
    |(7) 200            |
    |------------------>|
    |(8) 200            |
    |<------------------|

I'm not sure, but I think such behavior is not expected. Maybe somebody can
let me know if it is proper Freeswitch behavior and if it is, why such
behavior only happens with 5-10% of calls. Below you can find full sip
trace, for a call with extra bye message.


U 2015/07/09 11:07:07.269998 sippserver:5060 -> freeswitchserver:5060
INVITE sip:service at freeswitchserver:5060 SIP/2.0.
Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-0.
From: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
To: service <sip:service at freeswitchserver:5060>.
Call-ID: 9-11560 at sippserver.
CSeq: 1 INVITE.
Contact: sip:sipp at sippserver:5060.
Max-Forwards: 70.
Subject: Performance Test.
Content-Type: application/sdp.
Content-Length:   139.
.
v=0.
o=user1 53655765 2353687637 IN IP4 sippserver.
s=-.
c=IN IP4 sippserver.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.

#
U 2015/07/09 11:07:07.271005 freeswitchserver:5060 -> sippserver:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-0.
From: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
To: service <sip:service at freeswitchserver:5060>.
Call-ID: 9-11560 at sippserver.
CSeq: 1 INVITE.
User-Agent: FreeSWITCH-mod_sofia/1.4.18~64bit.
Content-Length: 0.
.

#
U 2015/07/09 11:07:07.276784 freeswitchserver:5060 -> sippserver:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-0.
From: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
To: service <sip:service at freeswitchserver:5060>;tag=S3Kvy09a3BrtS.
Call-ID: 9-11560 at sippserver.
CSeq: 1 INVITE.
Contact: <sip:service at freeswitchserver:5060;transport=udp>.
User-Agent: FreeSWITCH-mod_sofia/1.4.18~64bit.
Accept: application/sdp.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER,
REFER, NOTIFY.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, refer.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 168.
Remote-Party-ID: "service" <sip:service at freeswitchserver
>;party=calling;privacy=off;screen=no.
.
v=0.
o=FreeSWITCH 1436408221 1436408222 IN IP4 freeswitchserver.
s=FreeSWITCH.
c=IN IP4 freeswitchserver.
t=0 0.
m=audio 21006 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
a=ptime:20.

#
U 2015/07/09 11:07:07.277349 sippserver:5060 -> freeswitchserver:5060
ACK sip:service at freeswitchserver:5060 SIP/2.0.
Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-5.
From: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
To: service <sip:service at freeswitchserver:5060>;tag=S3Kvy09a3BrtS.
Call-ID: 9-11560 at sippserver.
CSeq: 1 ACK.
Contact: sip:sipp at sippserver:5060.
Max-Forwards: 70.
Subject: Performance Test.
Content-Length: 0.
.

#
U 2015/07/09 11:07:07.278861 sippserver:5060 -> freeswitchserver:5060
BYE sip:service at freeswitchserver:5060 SIP/2.0.
Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-7.
From: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
To: service <sip:service at freeswitchserver:5060>;tag=S3Kvy09a3BrtS.
Call-ID: 9-11560 at sippserver.
CSeq: 2 BYE.
Contact: sip:sipp at sippserver:5060.
Max-Forwards: 70.
Subject: Performance Test.
Content-Length: 0.
.

#
U 2015/07/09 11:07:07.278931 freeswitchserver:5060 -> sippserver:5060
BYE sip:sipp at sippserver:5060 SIP/2.0.
Via: SIP/2.0/UDP freeswitchserver;rport;branch=z9hG4bKF5jjXD7vrF3Qp.
Max-Forwards: 70.
From: service <sip:service at freeswitchserver:5060>;tag=S3Kvy09a3BrtS.
To: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
Call-ID: 9-11560 at sippserver.
CSeq: 77878549 BYE.
User-Agent: FreeSWITCH-mod_sofia/1.4.18~64bit.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER,
REFER, NOTIFY.
Supported: timer, path, replaces.
Reason: Q.850;cause=16;text="NORMAL_CLEARING".
Content-Length: 0.
.

#
U 2015/07/09 11:07:07.279599 sippserver:5060 -> freeswitchserver:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP freeswitchserver;rport;branch=z9hG4bKF5jjXD7vrF3Qp.
From: service <sip:service at freeswitchserver:5060>;tag=S3Kvy09a3BrtS.
To: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
Call-ID: 9-11560 at sippserver.
CSeq: 77878549 BYE.
Contact: <sip:sippserver:5060;transport=UDP>.
Content-Length: 0.
.

#
U 2015/07/09 11:07:07.280338 freeswitchserver:5060 -> sippserver:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-7.
From: sipp <sip:sipp at sippserver:5060>;tag=11560SIPpTag009.
To: service <sip:service at freeswitchserver:5060>;tag=S3Kvy09a3BrtS.
Call-ID: 9-11560 at sippserver.
CSeq: 2 BYE.
Content-Length: 0.
.

I will appreciate any help!

Thank you!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20150709/b1c6826f/attachment-0001.html