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@freeswitchserver:5060 SIP/2.0. Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-0. From: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>. Call-ID: 9-11560@sippserver. CSeq: 1 INVITE. Contact: sip:sipp@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@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>. Call-ID: 9-11560@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@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 1 INVITE. Contact: <sip:service@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@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@freeswitchserver:5060 SIP/2.0. Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-5. From: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 1 ACK. Contact: sip:sipp@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@freeswitchserver:5060 SIP/2.0. Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-7. From: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 2 BYE. Contact: sip:sipp@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@sippserver:5060 SIP/2.0. Via: SIP/2.0/UDP freeswitchserver;rport;branch=z9hG4bKF5jjXD7vrF3Qp. Max-Forwards: 70. From: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. To: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. Call-ID: 9-11560@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@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. To: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. Call-ID: 9-11560@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@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 2 BYE. Content-Length: 0. . I will appreciate any help! Thank you!
Hi, Issue is solved. :) Problem was in my dialplan. Basically there was empty dialplan and when call hit Freeswitch, Freeswitch immediately hanged up a call, cause there was nothing to do, that why I got that extra bye message. In other cases sipp hanged up a call before Freeswitch and this was that 90%-95%. To fix this I just needed to add sleep dialplan tool to my dialplan. 2015-07-09 11:49 GMT+03:00 Jurijs Ivolga <jurij.ivo@gmail.com>:
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@freeswitchserver:5060 SIP/2.0. Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-0. From: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>. Call-ID: 9-11560@sippserver. CSeq: 1 INVITE. Contact: sip:sipp@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@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>. Call-ID: 9-11560@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@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 1 INVITE. Contact: <sip:service@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@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@freeswitchserver:5060 SIP/2.0. Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-5. From: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 1 ACK. Contact: sip:sipp@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@freeswitchserver:5060 SIP/2.0. Via: SIP/2.0/UDP sippserver:5060;branch=z9hG4bK-11560-9-7. From: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 2 BYE. Contact: sip:sipp@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@sippserver:5060 SIP/2.0. Via: SIP/2.0/UDP freeswitchserver;rport;branch=z9hG4bKF5jjXD7vrF3Qp. Max-Forwards: 70. From: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. To: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. Call-ID: 9-11560@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@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. To: sipp <sip:sipp@sippserver:5060>;tag=11560SIPpTag009. Call-ID: 9-11560@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@sippserver:5060>;tag=11560SIPpTag009. To: service <sip:service@freeswitchserver:5060>;tag=S3Kvy09a3BrtS. Call-ID: 9-11560@sippserver. CSeq: 2 BYE. Content-Length: 0. .
I will appreciate any help!
Thank you!
participants (1)
-
Jurijs Ivolga