SBC bridged call: DTMF delay
Hi all, FS in SBC mode, 'external' and 'internal' sip calls are bridged. DTMF sequence '11234567890' gets passed with a delay, - 2 sec between the last digit '0' is received and sent (see log below). There is a consistent 500ms+ between 'Queue digit delay of 40ms' and 'Send start packet' for the next digit. Haven't found a way to fix it so far (wiki, user list, parameters such as auto-rtp-bugs), help will be appreciated. CentOS 6.1, Xen, rfc2833. Thank you. Alex 2012-09-17 12:52:20.714917 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 1:1120 2012-09-17 12:52:20.714917 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:20.774914 [DEBUG] switch_rtp.c:2420 Send start packet for [1] ts=325320 dur=160/160/1120 seq=6880 lw=325320 2012-09-17 12:52:20.794915 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=325320 dur=320/320/1120 seq=6881 lw=325480 2012-09-17 12:52:20.814914 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=325320 dur=480/480/1120 seq=6882 lw=325640 2012-09-17 12:52:20.834915 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=325320 dur=640/640/1120 seq=6883 lw=325800 2012-09-17 12:52:20.874917 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=325320 dur=800/800/1120 seq=6884 lw=161 2012-09-17 12:52:20.894918 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=325320 dur=960/960/1120 seq=6885 lw=321 2012-09-17 12:52:20.914916 [DEBUG] switch_rtp.c:2323 Send end packet for [1] ts=325320 dur=1120/1120/1120 seq=6886 lw=321 2012-09-17 12:52:20.914916 [DEBUG] switch_rtp.c:2323 Send end packet for [1] ts=325320 dur=1120/1120/1120 seq=6887 lw=321 2012-09-17 12:52:20.914916 [DEBUG] switch_rtp.c:2323 Send end packet for [1] ts=325320 dur=1120/1120/1120 seq=6888 lw=321 2012-09-17 12:52:20.914916 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:21.054920 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 1:960 2012-09-17 12:52:21.054920 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:21.454915 [DEBUG] switch_rtp.c:2420 Send start packet for [1] ts=331880 dur=160/160/960 seq=6907 lw=331880 2012-09-17 12:52:21.474918 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=331880 dur=320/320/960 seq=6908 lw=332040 2012-09-17 12:52:21.494916 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 2:800 2012-09-17 12:52:21.494916 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=331880 dur=480/480/960 seq=6909 lw=332200 2012-09-17 12:52:21.494916 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:21.514915 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=331880 dur=640/640/960 seq=6910 lw=332360 2012-09-17 12:52:21.534920 [DEBUG] switch_rtp.c:2323 Send middle packet for [1] ts=331880 dur=800/800/960 seq=6911 lw=332520 2012-09-17 12:52:21.554917 [DEBUG] switch_rtp.c:2323 Send end packet for [1] ts=331880 dur=960/960/960 seq=6912 lw=332520 2012-09-17 12:52:21.554917 [DEBUG] switch_rtp.c:2323 Send end packet for [1] ts=331880 dur=960/960/960 seq=6913 lw=332520 2012-09-17 12:52:21.554917 [DEBUG] switch_rtp.c:2323 Send end packet for [1] ts=331880 dur=960/960/960 seq=6914 lw=332520 2012-09-17 12:52:21.554917 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:21.934916 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 3:800 2012-09-17 12:52:21.934916 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:22.094915 [DEBUG] switch_rtp.c:2420 Send start packet for [2] ts=337000 dur=160/160/800 seq=6934 lw=337000 2012-09-17 12:52:22.114914 [DEBUG] switch_rtp.c:2323 Send middle packet for [2] ts=337000 dur=320/320/800 seq=6935 lw=337160 2012-09-17 12:52:22.134920 [DEBUG] switch_rtp.c:2323 Send middle packet for [2] ts=337000 dur=480/480/800 seq=6936 lw=337320 2012-09-17 12:52:22.154919 [DEBUG] switch_rtp.c:2323 Send middle packet for [2] ts=337000 dur=640/640/800 seq=6937 lw=337480 2012-09-17 12:52:22.174917 [DEBUG] switch_rtp.c:2323 Send end packet for [2] ts=337000 dur=800/800/800 seq=6938 lw=337480 2012-09-17 12:52:22.174917 [DEBUG] switch_rtp.c:2323 Send end packet for [2] ts=337000 dur=800/800/800 seq=6939 lw=337480 2012-09-17 12:52:22.174917 [DEBUG] switch_rtp.c:2323 Send end packet for [2] ts=337000 dur=800/800/800 seq=6940 lw=337480 2012-09-17 12:52:22.174917 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:22.554917 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 4:960 2012-09-17 12:52:22.554917 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:22.714915 [DEBUG] switch_rtp.c:2420 Send start packet for [3] ts=341960 dur=160/160/800 seq=6959 lw=341960 2012-09-17 12:52:22.734917 [DEBUG] switch_rtp.c:2323 Send middle packet for [3] ts=341960 dur=320/320/800 seq=6960 lw=342120 2012-09-17 12:52:22.754918 [DEBUG] switch_rtp.c:2323 Send middle packet for [3] ts=341960 dur=480/480/800 seq=6961 lw=342280 2012-09-17 12:52:22.774919 [DEBUG] switch_rtp.c:2323 Send middle packet for [3] ts=341960 dur=640/640/800 seq=6962 lw=342440 2012-09-17 12:52:22.794916 [DEBUG] switch_rtp.c:2323 Send end packet for [3] ts=341960 dur=800/800/800 seq=6963 lw=342440 2012-09-17 12:52:22.794916 [DEBUG] switch_rtp.c:2323 Send end packet for [3] ts=341960 dur=800/800/800 seq=6964 lw=342440 2012-09-17 12:52:22.794916 [DEBUG] switch_rtp.c:2323 Send end packet for [3] ts=341960 dur=800/800/800 seq=6965 lw=342440 2012-09-17 12:52:22.794916 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:22.994918 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 5:800 2012-09-17 12:52:22.994918 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:23.334917 [DEBUG] switch_rtp.c:2420 Send start packet for [4] ts=346920 dur=160/160/960 seq=6985 lw=346920 2012-09-17 12:52:23.354917 [DEBUG] switch_rtp.c:2323 Send middle packet for [4] ts=346920 dur=320/320/960 seq=6986 lw=347080 2012-09-17 12:52:23.374915 [DEBUG] switch_rtp.c:2323 Send middle packet for [4] ts=346920 dur=480/480/960 seq=6987 lw=347240 2012-09-17 12:52:23.394913 [DEBUG] switch_rtp.c:2323 Send middle packet for [4] ts=346920 dur=640/640/960 seq=6988 lw=347400 2012-09-17 12:52:23.414914 [DEBUG] switch_rtp.c:2323 Send middle packet for [4] ts=346920 dur=800/800/960 seq=6989 lw=347560 2012-09-17 12:52:23.434914 [DEBUG] switch_rtp.c:2323 Send end packet for [4] ts=346920 dur=960/960/960 seq=6990 lw=347560 2012-09-17 12:52:23.434914 [DEBUG] switch_rtp.c:2323 Send end packet for [4] ts=346920 dur=960/960/960 seq=6991 lw=347560 2012-09-17 12:52:23.434914 [DEBUG] switch_rtp.c:2323 Send end packet for [4] ts=346920 dur=960/960/960 seq=6992 lw=347560 2012-09-17 12:52:23.434914 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:23.474915 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 6:800 2012-09-17 12:52:23.474915 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] nta: timer J fired, terminate 200 response nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free 2012-09-17 12:52:23.974919 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 7:960 2012-09-17 12:52:23.974919 [DEBUG] switch_rtp.c:2420 Send start packet for [5] ts=351560 dur=160/160/800 seq=7012 lw=351560 2012-09-17 12:52:23.974919 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:23.994918 [DEBUG] switch_rtp.c:2323 Send middle packet for [5] ts=351560 dur=320/320/800 seq=7013 lw=351720 2012-09-17 12:52:24.014914 [DEBUG] switch_rtp.c:2323 Send middle packet for [5] ts=351560 dur=480/480/800 seq=7014 lw=351880 2012-09-17 12:52:24.034914 [DEBUG] switch_rtp.c:2323 Send middle packet for [5] ts=351560 dur=640/640/800 seq=7015 lw=352040 2012-09-17 12:52:24.054913 [DEBUG] switch_rtp.c:2323 Send end packet for [5] ts=351560 dur=800/800/800 seq=7016 lw=352040 2012-09-17 12:52:24.054913 [DEBUG] switch_rtp.c:2323 Send end packet for [5] ts=351560 dur=800/800/800 seq=7017 lw=352040 2012-09-17 12:52:24.054913 [DEBUG] switch_rtp.c:2323 Send end packet for [5] ts=351560 dur=800/800/800 seq=7018 lw=352040 2012-09-17 12:52:24.054913 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:24.394917 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 8:960 2012-09-17 12:52:24.394917 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:24.594915 [DEBUG] switch_rtp.c:2420 Send start packet for [6] ts=357000 dur=160/160/800 seq=7037 lw=357000 2012-09-17 12:52:24.614924 [DEBUG] switch_rtp.c:2323 Send middle packet for [6] ts=357000 dur=320/320/800 seq=7038 lw=357160 2012-09-17 12:52:24.634922 [DEBUG] switch_rtp.c:2323 Send middle packet for [6] ts=357000 dur=480/480/800 seq=7039 lw=357320 2012-09-17 12:52:24.654919 [DEBUG] switch_rtp.c:2323 Send middle packet for [6] ts=357000 dur=640/640/800 seq=7040 lw=357480 2012-09-17 12:52:24.674918 [DEBUG] switch_rtp.c:2323 Send end packet for [6] ts=357000 dur=800/800/800 seq=7041 lw=357480 2012-09-17 12:52:24.674918 [DEBUG] switch_rtp.c:2323 Send end packet for [6] ts=357000 dur=800/800/800 seq=7042 lw=357480 2012-09-17 12:52:24.674918 [DEBUG] switch_rtp.c:2323 Send end packet for [6] ts=357000 dur=800/800/800 seq=7043 lw=357480 2012-09-17 12:52:24.674918 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:24.814915 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 9:800 2012-09-17 12:52:24.814915 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:25.214926 [DEBUG] switch_rtp.c:2420 Send start packet for [7] ts=361960 dur=160/160/960 seq=7063 lw=361960 2012-09-17 12:52:25.234921 [DEBUG] switch_rtp.c:2323 Send middle packet for [7] ts=361960 dur=320/320/960 seq=7064 lw=362120 2012-09-17 12:52:25.254920 [DEBUG] switch_rtp.c:2323 Send middle packet for [7] ts=361960 dur=480/480/960 seq=7065 lw=362280 2012-09-17 12:52:25.274919 [DEBUG] switch_rtp.c:2323 Send middle packet for [7] ts=361960 dur=640/640/960 seq=7066 lw=362440 2012-09-17 12:52:25.294926 [DEBUG] switch_rtp.c:3410 RTP RECV DTMF 0:800 2012-09-17 12:52:25.294926 [DEBUG] switch_rtp.c:2323 Send middle packet for [7] ts=361960 dur=800/800/960 seq=7067 lw=362600 2012-09-17 12:52:25.294926 [DEBUG] switch_ivr_bridge.c:391 Send signal sofia/internal/9910@Kate-conf02-dev.webley.com:5080 [BREAK] 2012-09-17 12:52:25.314920 [DEBUG] switch_rtp.c:2323 Send end packet for [7] ts=361960 dur=960/960/960 seq=7068 lw=362600 2012-09-17 12:52:25.314920 [DEBUG] switch_rtp.c:2323 Send end packet for [7] ts=361960 dur=960/960/960 seq=7069 lw=362600 2012-09-17 12:52:25.314920 [DEBUG] switch_rtp.c:2323 Send end packet for [7] ts=361960 dur=960/960/960 seq=7070 lw=362600 2012-09-17 12:52:25.314920 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:25.874915 [DEBUG] switch_rtp.c:2420 Send start packet for [8] ts=161 dur=160/160/960 seq=7096 lw=161 2012-09-17 12:52:25.894918 [DEBUG] switch_rtp.c:2323 Send middle packet for [8] ts=161 dur=320/320/960 seq=7097 lw=321 2012-09-17 12:52:25.914916 [DEBUG] switch_rtp.c:2323 Send middle packet for [8] ts=161 dur=480/480/960 seq=7098 lw=481 2012-09-17 12:52:25.934917 [DEBUG] switch_rtp.c:2323 Send middle packet for [8] ts=161 dur=640/640/960 seq=7099 lw=641 2012-09-17 12:52:25.954921 [DEBUG] switch_rtp.c:2323 Send middle packet for [8] ts=161 dur=800/800/960 seq=7100 lw=801 2012-09-17 12:52:25.974930 [DEBUG] switch_rtp.c:2323 Send end packet for [8] ts=161 dur=960/960/960 seq=7101 lw=801 2012-09-17 12:52:25.974930 [DEBUG] switch_rtp.c:2323 Send end packet for [8] ts=161 dur=960/960/960 seq=7102 lw=801 2012-09-17 12:52:25.974930 [DEBUG] switch_rtp.c:2323 Send end packet for [8] ts=161 dur=960/960/960 seq=7103 lw=801 2012-09-17 12:52:25.974930 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:26.514917 [DEBUG] switch_rtp.c:2420 Send start packet for [9] ts=372360 dur=160/160/800 seq=7128 lw=372360 2012-09-17 12:52:26.534917 [DEBUG] switch_rtp.c:2323 Send middle packet for [9] ts=372360 dur=320/320/800 seq=7129 lw=372520 2012-09-17 12:52:26.554924 [DEBUG] switch_rtp.c:2323 Send middle packet for [9] ts=372360 dur=480/480/800 seq=7130 lw=372680 2012-09-17 12:52:26.574918 [DEBUG] switch_rtp.c:2323 Send middle packet for [9] ts=372360 dur=640/640/800 seq=7131 lw=372840 2012-09-17 12:52:26.594915 [DEBUG] switch_rtp.c:2323 Send end packet for [9] ts=372360 dur=800/800/800 seq=7132 lw=372840 2012-09-17 12:52:26.594915 [DEBUG] switch_rtp.c:2323 Send end packet for [9] ts=372360 dur=800/800/800 seq=7133 lw=372840 2012-09-17 12:52:26.594915 [DEBUG] switch_rtp.c:2323 Send end packet for [9] ts=372360 dur=800/800/800 seq=7134 lw=372840 2012-09-17 12:52:26.594915 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms 2012-09-17 12:52:27.134920 [DEBUG] switch_rtp.c:2420 Send start packet for [0] ts=377480 dur=160/160/800 seq=7160 lw=377480 2012-09-17 12:52:27.154916 [DEBUG] switch_rtp.c:2323 Send middle packet for [0] ts=377480 dur=320/320/800 seq=7161 lw=377640 2012-09-17 12:52:27.174916 [DEBUG] switch_rtp.c:2323 Send middle packet for [0] ts=377480 dur=480/480/800 seq=7162 lw=377800 2012-09-17 12:52:27.194919 [DEBUG] switch_rtp.c:2323 Send middle packet for [0] ts=377480 dur=640/640/800 seq=7163 lw=377960 2012-09-17 12:52:27.214916 [DEBUG] switch_rtp.c:2323 Send end packet for [0] ts=377480 dur=800/800/800 seq=7164 lw=377960 2012-09-17 12:52:27.214916 [DEBUG] switch_rtp.c:2323 Send end packet for [0] ts=377480 dur=800/800/800 seq=7165 lw=377960 2012-09-17 12:52:27.214916 [DEBUG] switch_rtp.c:2323 Send end packet for [0] ts=377480 dur=800/800/800 seq=7166 lw=377960 2012-09-17 12:52:27.214916 [DEBUG] switch_rtp.c:2271 Queue digit delay of 40ms This message and any attachments to it are intended only for the addressee(s) identified above and may contain CONFIDENTIAL information. It is not intended for transmission to, or receipt by, any unauthorized persons. If you are not an intended recipient or an agent responsible for delivering it to an intended recipient, you have received this e-mail in error and any dissemination, distribution, or copying of this message or any attachment to it is strictly prohibited. If you have received this email in error, please (i) do not read it, (ii) reply to the sender that you received the message in error, and (iii) erase or destroy the message from your system.
On 17/09/12 19:58, Alex Zarubin wrote:
FS in SBC mode, ‘external’ and ‘internal’ sip calls are bridged. DTMF sequence ‘11234567890’ gets passed with a delay, - 2 sec between the last digit ‘0’ is received and sent (see log below). There is a consistent 500ms+ between ‘Queue digit delay of 40ms’ and ‘Send start packet’ for the next digit.
Haven’t found a way to fix it so far (wiki, user list, parameters such as auto-rtp-bugs), help will be appreciated. CentOS 6.1, Xen, rfc2833.
Have you tried setting pass_rfc2833=true? http://wiki.freeswitch.org/wiki/Variable_pass_rfc2833 Regards,
Thank you Paul but it didn't work either. I'm still seeing inter-digit 500ms... Alex -----Original Message----- From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Paul Cupis Sent: Monday, September 17, 2012 3:32 PM To: FreeSWITCH Users Help Subject: Re: [Freeswitch-users] SBC bridged call: DTMF delay On 17/09/12 19:58, Alex Zarubin wrote:
FS in SBC mode, 'external' and 'internal' sip calls are bridged. DTMF sequence '11234567890' gets passed with a delay, - 2 sec between the last digit '0' is received and sent (see log below). There is a consistent 500ms+ between 'Queue digit delay of 40ms' and 'Send start packet' for the next digit.
Haven't found a way to fix it so far (wiki, user list, parameters such
as auto-rtp-bugs), help will be appreciated. CentOS 6.1, Xen, rfc2833.
Have you tried setting pass_rfc2833=true? http://wiki.freeswitch.org/wiki/Variable_pass_rfc2833 Regards, ________________________________________________________________________ _ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org This message and any attachments to it are intended only for the addressee(s) identified above and may contain CONFIDENTIAL information. It is not intended for transmission to, or receipt by, any unauthorized persons. If you are not an intended recipient or an agent responsible for delivering it to an intended recipient, you have received this e-mail in error and any dissemination, distribution, or copying of this message or any attachment to it is strictly prohibited. If you have received this email in error, please (i) do not read it, (ii) reply to the sender that you received the message in error, and (iii) erase or destroy the message from your system.
participants (2)
-
Alex Zarubin
-
Paul Cupis