[Freeswitch-users] FreeSWITCH and TLS using pjsip
Adam Ben-Ayoun
adam.ben.ayoun1 at gmail.com
Tue Jun 16 10:50:33 MSD 2015
Hi guys,
We are using FreeSWITCH as our audio MCU using mod_conference with pjsip on
the client (iOS/Android). I am trying to use TLS for signalling (sip) and
it seems like FreeSWITCH is returning the Contact header with "sip" instead
of "sips" which causes pjsip to terminate the session, although the contact
sent from the client is sips:991234 at X.X.X.X:443;transport=tls. I hardcoded
the correct Contact header with "sips" schema and compiled FS and it worked
but I want to avoid that.
Here is the sip trace:
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params
nua.c:575 nua_set_params() nua: nua_set_params: entering
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f7a4c002f10, ...)
called
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params
nua.c:575 nua_set_params() nua: nua_set_params: entering
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f7a38021500, ...)
called
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params
nua.c:575 nua_set_params() nua: nua_set_params: entering
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f7a4c002f10, ...)
called
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f7a4c008350): events IN
tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f7a4c008350):
new secondary tport 0x7f7a4c004330
tport_type_tcp.c:203 tport_tcp_init_secondary()
tport_tcp_init_secondary(0x7f7a4c004330): Setting TCP_KEEPIDLE to 30
tport_type_tcp.c:209 tport_tcp_init_secondary()
tport_tcp_init_secondary(0x7f7a4c004330): Setting TCP_KEEPINTVL to 30
tport_type_tls.c:610 tport_tls_accept() tport_tls_accept(0x7f7a4c004330):
new connection from tls/80.246.136.250:55539/sips
tport_tls.c:940 tls_connect() tls_connect(0x7f7a4c004330): events
NEGOTIATING
tport_tls.c:940 tls_connect() tls_connect(0x7f7a4c004330): events
NEGOTIATING
tport_tls.c:584 tls_post_connection_check()
tls_post_connection_check(0x7f7a4c004330): TLS cipher chosen (name):
ECDHE-RSA-AES256-GCM-SHA384
tport_tls.c:586 tls_post_connection_check()
tls_post_connection_check(0x7f7a4c004330): TLS cipher chosen (version):
TLSv1/SSLv3
tport_tls.c:589 tls_post_connection_check()
tls_post_connection_check(0x7f7a4c004330): TLS cipher chosen
(bits/alg_bits): 256/256
tport_tls.c:592 tls_post_connection_check()
tls_post_connection_check(0x7f7a4c004330): TLS cipher chosen (description):
ECDHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(256)
Mac=AEAD
tport_tls.c:597 tls_post_connection_check()
tls_post_connection_check(0x7f7a4c004330): Peer did not provide X.509
Certificate.
tport.c:2296 tport_set_secondary_timer() tport(0x7f7a4c004330): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f7a4c004330): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f7a4c004330)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f7a4c004330):
tls_read() returned -1
tport_type_tls.c:338 tport_tls_set_events()
tport_tls_set_events(0x7f7a4c004330): logical events IN real IN
tport.c:2296 tport_set_secondary_timer() tport(0x7f7a4c004330): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f7a4c004330): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f7a4c004330)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f7a4c004330):
tls_read() returned 1939
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f7a4c004330) msg
0x7f7a4c0060b0 from (tls/80.246.136.250:55539) has 1939 bytes, veclen = 1
recv 1939 bytes from tls/[80.246.136.250]:55539 at 06:47:10.268278:
------------------------------------------------------------------------
INVITE sips:991234 at X.X.X.X:5061;transport=tls SIP/2.0
Via: SIP/2.0/TLS 10.0.185.61:60531
;rport;branch=z9hG4bKPj1UT4BuHQa-5RJHPnQ5y0KpsQ1AjlLea5;alias
Max-Forwards: 70
From: <sips:budapp at 10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I
To: <sips:991234 at X.X.X.X>
Contact: <sips:budapp at 10.0.185.61>
Call-ID: SUqEUDnopKxqF5MCGGtKE1wkXaACpF61
CSeq: 3628 INVITE
Allow: INVITE, ACK, BYE, CANCEL, UPDATE, PRACK
Supported: 100rel
Content-Type: application/sdp
Content-Length: 1443
v=0
o=- 3992108604 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS ARDAMS
m=audio 62359 RTP/SAVPF 111 103 104 9 102 0 8 106 105 13 127 126
c=IN IP4 10.0.185.61
a=rtcp:64256 IN IP4 10.0.185.61
a=candidate:2231189199 1 udp 2122260223 10.0.185.61 62359 typ host
generation 0
a=candidate:2231189199 2 udp 2122260222 10.0.185.61 64256 typ host
generation 0
a=candidate:3397304895 1 tcp 1518280447 10.0.185.61 60528 typ host
tcptype passive generation 0
a=candidate:3397304895 2 tcp 1518280446 10.0.185.61 60529 typ host
tcptype passive generation 0
a=ice-ufrag:h6j3vcmJYQE9TZva
a=ice-pwd:ZlyVrFpcbV193dGPa6jNhMlt
a=fingerprint:sha-256
AC:F4:3E:85:7F:75:7F:5F:C1:22:5A:DE:45:79:F9:89:44:EA:2C:F6:4D:8D:E0:2B:00:E3:63:C0:1E:20:18:21
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=sendrecv
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:102 ILBC/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:127 red/8000
a=rtpmap:126 telephone-event/8000
a=maxptime:60
a=ssrc:3143484071 cname:kPDG+J7xHnUUYKeb
a=ssrc:3143484071 msid:ARDAMS ARDAMSa0
a=ssrc:3143484071 mslabel:ARDAMS
a=ssrc:3143484071 label:ARDAMSa0
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f7a4c004330): msg
0x7f7a4c0060b0 (1939 bytes) from tls/80.246.136.250:55539/sips next=(nil)
nta.c:2880 agent_recv_request() nta: received INVITE
sips:991234 at X.X.X.X:5061;transport=tls
SIP/2.0 (CSeq 3628)
nta.c:3174 agent_check_request_via() nta: Via check: received=80.246.136.250
nta.c:3085 agent_recv_request() nta: INVITE (3628) going to a default leg
nta.c:1350 set_timeout() nta: timer set to 2000 ms
nua_server.c:102 nua_stack_process_request() nua:
nua_stack_process_request: entering
nua_stack.c:899 nh_create() nua: nh_create: entering
nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:280 soa_clone() soa_clone(static::0x7f7a4c002f10, 0x7f7a4c0023b0,
0x7f7a4c039e70) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f7a4c03a6e0, ...)
called
nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f7a4c0041e0)
soa.c:1302 soa_init_offer_answer()
soa_init_offer_answer(static::0x7f7a4c03a6e0) called
soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f7a4c03a6e0,
(nil), 0x7f7a4c02fe60, 1443) called
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f7a4c039e70): adding session
usage
tport.c:3257 tport_tsend() tport_tsend(0x7f7a4c004330) tpn = TLS/
80.246.136.250:55539
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c03bac0 147 (147)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c02fd1e 101 (101)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c02fda7 62 (62)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c03bb53 99 (99)
tport.c:3492 tport_send_msg() tport_vsend returned 409
send 409 bytes to tls/[80.246.136.250]:55539 at 06:47:10.268547:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 10.0.185.61:60531
;rport=55539;branch=z9hG4bKPj1UT4BuHQa-5RJHPnQ5y0KpsQ1AjlLea5;alias;received=80.246.136.250
From: <sips:budapp at 10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I
To: <sips:991234 at X.X.X.X>
Call-ID: SUqEUDnopKxqF5MCGGtKE1wkXaACpF61
CSeq: 3628 INVITE
User-Agent:
FreeSWITCH-mod_sofia/1.7.0+git~20150608T182614Z~f8853ac620~64bit
Content-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f7a4c004330): reset timer
nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (3628)
nua_session.c:4139 signal_call_state_change() nua(0x7f7a4c039e70): call
state changed: init -> received, received offer
soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f7a4c03a6e0,
[0x7f7a52f028b8], [0x7f7a52f028c0], [(nil)]) called
tport.c:2296 tport_set_secondary_timer() tport(0x7f7a4c004330): reset timer
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
2015-06-16 06:47:10.249856 [NOTICE] switch_channel.c:1089 New Channel
sofia/internal/budapp at 10.0.185.61 [e013f9cd-3fc7-4b14-85b8-9788bd7f8803]
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
2015-06-16 06:47:10.249856 [DEBUG] switch_core_state_machine.c:473
(sofia/internal/budapp at 10.0.185.61) Running State Change CS_NEW
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-06-16 06:47:10.249856 [DEBUG] sofia.c:8933 sofia/internal/
budapp at 10.0.185.61 receiving invite from 80.246.136.250:55539 version:
1.7.0 git f8853ac 2015-06-08 18:26:14Z 64bit
2015-06-16 06:47:10.249856 [DEBUG] sofia.c:9045 IP 80.246.136.250 Approved
by acl "domains[]". Access Granted.
nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering
nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil)
2015-06-16 06:47:10.269817 [DEBUG] sofia.c:10198 Setting NAT mode based on
via received
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-06-16 06:47:10.269817 [DEBUG] sofia.c:6701 Channel sofia/internal/
budapp at 10.0.185.61 entering state [received][100]
2015-06-16 06:47:10.269817 [DEBUG] sofia.c:6711 Remote SDP:
v=0
o=- 3992108604 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS ARDAMS
m=audio 62359 RTP/SAVPF 111 103 104 9 102 0 8 106 105 13 127 126
c=IN IP4 10.0.185.61
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:102 ILBC/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:127 red/8000
a=rtpmap:126 telephone-event/8000
a=rtcp:64256 IN IP4 10.0.185.61
a=candidate:2231189199 1 udp 2122260223 10.0.185.61 62359 typ host
generation 0
a=candidate:2231189199 2 udp 2122260222 10.0.185.61 64256 typ host
generation 0
a=candidate:3397304895 1 tcp 1518280447 10.0.185.61 60528 typ host tcptype
passive generation 0
a=candidate:3397304895 2 tcp 1518280446 10.0.185.61 60529 typ host tcptype
passive generation 0
a=ice-ufrag:h6j3vcmJYQE9TZva
a=ice-pwd:ZlyVrFpcbV193dGPa6jNhMlt
a=fingerprint:sha-256
AC:F4:3E:85:7F:75:7F:5F:C1:22:5A:DE:45:79:F9:89:44:EA:2C:F6:4D:8D:E0:2B:00:E3:63:C0:1E:20:18:21
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=rtcp-mux
a=maxptime:60
a=ssrc:3143484071 cname:kPDG+J7xHnUUYKeb
a=ssrc:3143484071 msid:ARDAMS ARDAMSa0
a=ssrc:3143484071 mslabel:ARDAMS
a=ssrc:3143484071 label:ARDAMSa0
2015-06-16 06:47:10.269817 [DEBUG] sofia.c:6977 (sofia/internal/
budapp at 10.0.185.61) State Change CS_NEW -> CS_INIT
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:492
(sofia/internal/budapp at 10.0.185.61) State NEW
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:473
(sofia/internal/budapp at 10.0.185.61) Running State Change CS_INIT
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:516
(sofia/internal/budapp at 10.0.185.61) State INIT
2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:88 sofia/internal/
budapp at 10.0.185.61 SOFIA INIT
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:40
sofia/internal/budapp at 10.0.185.61 Standard INIT
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/budapp at 10.0.185.61) State Change CS_INIT -> CS_ROUTING
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:516
(sofia/internal/budapp at 10.0.185.61) State INIT going to sleep
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:473
(sofia/internal/budapp at 10.0.185.61) Running State Change CS_ROUTING
2015-06-16 06:47:10.269817 [DEBUG] switch_channel.c:2239 (sofia/internal/
budapp at 10.0.185.61) Callstate Change DOWN -> RINGING
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:532
(sofia/internal/budapp at 10.0.185.61) State ROUTING
2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:141 sofia/internal/
budapp at 10.0.185.61 SOFIA ROUTING
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:166
sofia/internal/budapp at 10.0.185.61 Standard ROUTING
2015-06-16 06:47:10.269817 [INFO] mod_dialplan_xml.c:642 Processing budapp
<budapp>->991234 in context public
Dialplan: sofia/internal/budapp at 10.0.185.61 parsing
[public->cdquality_conferences_with_api] continue=false
Dialplan: sofia/internal/budapp at 10.0.185.61 Regex (FAIL)
[cdquality_conferences_with_api] destination_number(991234) =~
/^(75\d{4,36})$/ break=on-false
Dialplan: sofia/internal/budapp at 10.0.185.61 parsing
[public->test_conferences] continue=false
Dialplan: sofia/internal/budapp at 10.0.185.61 Regex (PASS) [test_conferences]
destination_number(991234) =~ /^99(\d{4,36})$/ break=on-false
Dialplan: sofia/internal/budapp at 10.0.185.61 Action
set(jitterbuffer_msec=60:200:20)
Dialplan: sofia/internal/budapp at 10.0.185.61 Action answer()
Dialplan: sofia/internal/budapp at 10.0.185.61 Action
conference(1234-${domain_name}@test)
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:216
(sofia/internal/budapp at 10.0.185.61) State Change CS_ROUTING -> CS_EXECUTE
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:532
(sofia/internal/budapp at 10.0.185.61) State ROUTING going to sleep
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:473
(sofia/internal/budapp at 10.0.185.61) Running State Change CS_EXECUTE
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:539
(sofia/internal/budapp at 10.0.185.61) State EXECUTE
2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:196 sofia/internal/
budapp at 10.0.185.61 SOFIA EXECUTE
2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:258
sofia/internal/budapp at 10.0.185.61 Standard EXECUTE
EXECUTE sofia/internal/budapp at 10.0.185.61 set(jitterbuffer_msec=60:200:20)
2015-06-16 06:47:10.269817 [DEBUG] mod_dptools.c:1469 sofia/internal/
budapp at 10.0.185.61 SET [jitterbuffer_msec]=[60:200:20]
EXECUTE sofia/internal/budapp at 10.0.185.61 answer()
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [opus:111:48000:60:0:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [opus:111:48000:60:0:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4120 Bah HUMBUG!
Sticking with opus at 48000h@20i
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4146 Audio Codec
Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [opus:111:48000:60:0:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [opus:111:48000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:103:16000:30:32000:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4120 Bah HUMBUG!
Sticking with isac at 16000h@30i
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4146 Audio Codec
Compare [isac:99:16000:30:53400:1] ++++ is saved as a match
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:103:16000:30:32000:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:104:32000:30:32000:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:104:32000:30:32000:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [G722:9:8000:60:64000:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [G722:9:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [G722:9:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4120 Bah HUMBUG!
Sticking with G722 at 8000h@20i
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4146 Audio Codec
Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [G722:9:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ILBC:102:8000:30:13330:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ILBC:102:8000:30:13330:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ILBC:102:8000:30:13330:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [ILBC:102:8000:30:13330:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMU:0:8000:60:64000:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMU:0:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMA:8:8000:60:64000:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMA:8:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4120 Bah HUMBUG!
Sticking with PCMA at 8000h@20i
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4146 Audio Codec
Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:105:16000:60:0:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:105:16000:60:0:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:105:16000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:13:8000:60:0:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:13:8000:60:0:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [CN:13:8000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [red:127:8000:60:0:1]/[isac:99:16000:30:53400:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [red:127:8000:60:0:1]/[opus:116:48000:20:0:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [red:127:8000:60:0:1]/[G722:9:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4091 Audio Codec
Compare [red:127:8000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4007 Set
telephone-event payload to 126
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:2848 Set Codec
sofia/internal/budapp at 10.0.185.61 isac/16000 30 ms 480 samples 53400 bits 1
channels
2015-06-16 06:47:10.269817 [DEBUG] switch_core_codec.c:111 sofia/internal/
budapp at 10.0.185.61 Original read codec set to isac:99
2015-06-16 06:47:10.269817 [WARNING] switch_core_media.c:3184 NO candidate
ACL defined, Defaulting to wan.auto
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3213 Save audio
Candidate cid: 1 proto: udp type: host addr: 10.0.185.61:62359
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3213 Save audio
Candidate cid: 2 proto: udp type: host addr: 10.0.185.61:64256
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3253 Searching for
rtp candidate.
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3253 Searching for
rtcp candidate.
2015-06-16 06:47:10.269817 [NOTICE] switch_core_media.c:3300 No audio rtp
candidate found; defaulting to the first one.
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3305 Choose same
candidate, index 1, for rtcp based on rtcp-mux attribute 10.0.185.61:62359
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3343 setting remote
audio ice addr to index 0 10.0.185.61:62359 based on candidate
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:3364 Setting remote
rtcp audio addr to 10.0.185.61:62359 based on candidate
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:4358 Set 2833 dtmf
send/recv payload to 126
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:5867 AUDIO RTP
[sofia/internal/budapp at 10.0.185.61] 172.30.0.123 port 21174 -> 10.0.185.61
port 62359 codec: 103 ms: 30
2015-06-16 06:47:10.269817 [DEBUG] switch_rtp.c:3682 Starting timer [soft]
480 bytes per 30ms
2015-06-16 06:47:10.269817 [INFO] switch_core_media.c:6042 Activating Audio
ICE
2015-06-16 06:47:10.269817 [NOTICE] switch_rtp.c:4201 Activating RTP audio
ICE: h6j3vcmJYQE9TZva:Ob1rNvtW0b5cWDek 10.0.185.61:62359
2015-06-16 06:47:10.269817 [INFO] switch_core_media.c:6085 Activating RTCP
PORT 62359
2015-06-16 06:47:10.269817 [DEBUG] switch_rtp.c:4098 RTCP send rate is:
5000 and packet rate is: 30000 Remote Port: 62359
2015-06-16 06:47:10.269817 [INFO] switch_core_media.c:6093 Skipping RTCP
ICE (Same as RTP)
2015-06-16 06:47:10.269817 [INFO] switch_rtp.c:3212 Activate RTP/RTCP audio
DTLS client
2015-06-16 06:47:10.269817 [INFO] switch_rtp.c:3332 Changing audio DTLS
state from OFF to HANDSHAKE
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:1914 Setting
Jitterbuffer to 60ms (2 frames) (6 max frames) (20 max drift)
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:6166 Set 2833 dtmf
send payload to 126
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:6172 Set 2833 dtmf
receive payload to 126
2015-06-16 06:47:10.269817 [DEBUG] switch_core_media.c:6194 sofia/internal/
budapp at 10.0.185.61 Set rtp dtmf delay to 40
2015-06-16 06:47:10.269817 [NOTICE] sofia_media.c:92 Pre-Answer
sofia/internal/budapp at 10.0.185.61!
2015-06-16 06:47:10.269817 [DEBUG] switch_channel.c:3460 (sofia/internal/
budapp at 10.0.185.61) Callstate Change RINGING -> EARLY
2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:798 Local SDP sofia/internal/
budapp at 10.0.185.61:
v=0
o=FreeSWITCH 1434416056 1434416057 IN IP4 X.X.X.X
s=FreeSWITCH
c=IN IP4 X.X.X.X
t=0 0
a=msid-semantic: WMS 0M0k1onHJJZZtiOv47wmNMEcjERilVIb
m=audio 21174 RTP/SAVPF 103 126
a=rtpmap:103 ISAC/16000
a=rtpmap:126 telephone-event/8000
a=ptime:30
a=sendrecv
a=fingerprint:sha-256
08:41:F1:A2:26:14:A7:3C:C8:A4:1D:2C:E0:06:56:A6:9B:6D:61:85:A2:22:32:83:3E:B8:CD:14:C4:25:36:B4
a=setup:active
a=rtcp-mux
a=rtcp:21174 IN IP4 X.X.X.X
a=ice-ufrag:Ob1rNvtW0b5cWDek
a=ice-pwd:2qzFQmSQYU9IBOngQfxuBRgs
a=candidate:9326003068 1 udp 659136 X.X.X.X 21174 typ host generation 0
a=ssrc:2642995214 cname:xympNAWm9LctUQPO
a=ssrc:2642995214 msid:0M0k1onHJJZZtiOv47wmNMEcjERilVIb a0
a=ssrc:2642995214 mslabel:0M0k1onHJJZZtiOv47wmNMEcjERilVIb
a=ssrc:2642995214 label:0M0k1onHJJZZtiOv47wmNMEcjERilVIba0
nua.c:879 nua_respond() nua: nua_respond: entering
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f7a4c03a6e0, ...)
called
soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f7a4c03a6e0,
(nil), 0x7f7a3003c9db, -1) called
soa.c:890 soa_set_capability_sdp()
soa_set_capability_sdp(static::0x7f7a4c03a6e0, (nil), 0x7f7a3003c9db, -1)
called
nua_session.c:2320 nua_invite_server_respond() nua:
nua_invite_server_respond: entering
soa.c:1515 soa_generate_answer()
soa_generate_answer(static::0x7f7a4c03a6e0) called
soa_static.c:1146 offer_answer_step()
soa_static_offer_answer_action(0x7f7a4c03a6e0, soa_generate_answer): called
soa_static.c:1187 offer_answer_step() soa_static(0x7f7a4c03a6e0,
soa_generate_answer): generating local description
soa_static.c:1228 offer_answer_step() soa_static(0x7f7a4c03a6e0,
soa_generate_answer): upgrade with remote description
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f7a52f00b00,
0x7f7a4c045800, ""): called
soa_static.c:1444 offer_answer_step() soa_static(0x7f7a4c03a6e0,
soa_generate_answer): storing local description
soa.c:1730 soa_activate() soa_activate(static::0x7f7a4c03a6e0, (nil)) called
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f7a4c03a6e0,
[(nil)], [0x7f7a52f02c38], [0x7f7a52f02c34]) called
tport.c:3257 tport_tsend() tport_tsend(0x7f7a4c004330) tpn = TLS/
80.246.136.250:55539
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c017100 143 (143)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c02fd1e 70 (70)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c01718f 49 (49)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c02fda7 62 (62)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c0171c0 637 (637)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c01b570 808 (808)
tport.c:3492 tport_send_msg() tport_vsend returned 1769
send 1769 bytes to tls/[80.246.136.250]:55539 at 06:47:10.275555:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TLS 10.0.185.61:60531
;rport=55539;branch=z9hG4bKPj1UT4BuHQa-5RJHPnQ5y0KpsQ1AjlLea5;alias;received=80.246.136.250
From: <sips:budapp at 10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I
To: <sips:991234 at X.X.X.X>;tag=UvNpmQ5rme77D
Call-ID: SUqEUDnopKxqF5MCGGtKE1wkXaACpF61
CSeq: 3628 INVITE
Contact: <sip:991234 at X.X.X.X:5061;transport=tls>
User-Agent:
FreeSWITCH-mod_sofia/1.7.0+git~20150608T182614Z~f8853ac620~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event,
dialog, line-seize, call-info, sla, include-session-description,
presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 808
Remote-Party-ID: "991234" <sip:991234 at X.X.X.X
>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1434416056 1434416057 IN IP4 X.X.X.X
s=FreeSWITCH
c=IN IP4 X.X.X.X
t=0 0
a=msid-semantic: WMS 0M0k1onHJJZZtiOv47wmNMEcjERilVIb
m=audio 21174 RTP/SAVPF 103 126
a=rtpmap:103 ISAC/16000
a=rtpmap:126 telephone-event/8000
a=ptime:30
a=fingerprint:sha-256
08:41:F1:A2:26:14:A7:3C:C8:A4:1D:2C:E0:06:56:A6:9B:6D:61:85:A2:22:32:83:3E:B8:CD:14:C4:25:36:B4
a=setup:active
a=rtcp-mux
a=rtcp:21174 IN IP4 X.X.X.X
a=ice-ufrag:Ob1rNvtW0b5cWDek
a=ice-pwd:2qzFQmSQYU9IBOngQfxuBRgs
a=candidate:9326003068 1 udp 659136 X.X.X.X 21174 typ host generation 0
a=ssrc:2642995214 cname:xympNAWm9LctUQPO
a=ssrc:2642995214 msid:0M0k1onHJJZZtiOv47wmNMEcjERilVIb a0
a=ssrc:2642995214 mslabel:0M0k1onHJJZZtiOv47wmNMEcjERilVIb
a=ssrc:2642995214 label:0M0k1onHJJZZtiOv47wmNMEcjERilVIba0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f7a4c004330): reset timer
nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (3628)
nta.c:1348 set_timeout() nta: timer shortened to 500 ms
nua_session.c:4139 signal_call_state_change() nua(0x7f7a4c039e70): call
state changed: received -> completed, sent answer
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f7a4c03a6e0,
[0x7f7a52f02ce8], [0x7f7a52f02cf0], [(nil)]) called
soa.c:616 soa_get_params() soa_get_params(static::0x7f7a4c03a6e0, ...)
called
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:529 nua_signal() nua(0x7f7a4c039e70): sent signal r_respond
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-06-16 06:47:10.269817 [DEBUG] sofia.c:6701 Channel sofia/internal/
budapp at 10.0.185.61 entering state [completed][200]
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
tport.c:2773 tport_wakeup() tport_wakeup(0x7f7a4c004330): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f7a4c004330)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f7a4c004330):
tls_read() returned 413
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f7a4c004330) msg
0x7f7a4c03bac0 from (tls/80.246.136.250:55539) has 413 bytes, veclen = 1
recv 413 bytes from tls/[80.246.136.250]:55539 at 06:47:10.499036:
------------------------------------------------------------------------
BYE sip:991234 at X.X.X.X:5061;transport=tls SIP/2.0
Via: SIP/2.0/TLS 10.0.185.61:60531
;rport;branch=z9hG4bKPjkviJEl84G-mIBM80lf2Tn35igY2eXfSk;alias
Max-Forwards: 70
From: <sips:budapp at 10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I
To: <sips:991234 at X.X.X.X>;tag=UvNpmQ5rme77D
Call-ID: SUqEUDnopKxqF5MCGGtKE1wkXaACpF61
CSeq: 3629 BYE
Warning: 381 Adams-iPhone "SIPS Required"
Content-Length: 0
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f7a4c004330): msg
0x7f7a4c03bac0 (413 bytes) from tls/80.246.136.250:55539/sips next=(nil)
nta.c:2880 agent_recv_request() nta: received BYE
sip:991234 at X.X.X.X:5061;transport=tls
SIP/2.0 (CSeq 3629)
nta.c:3174 agent_check_request_via() nta: Via check: received=80.246.136.250
nta.c:3060 agent_recv_request() nta: BYE (3629) going to existing leg
nua_server.c:102 nua_stack_process_request() nua:
nua_stack_process_request: entering
tport.c:2296 tport_set_secondary_timer() tport(0x7f7a4c004330): reset timer
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-06-16 06:47:10.509831 [NOTICE] sofia.c:952 Hangup sofia/internal/
budapp at 10.0.185.61 [CS_EXECUTE] [NORMAL_CLEARING]
nua.c:879 nua_respond() nua: nua_respond: entering
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f7a4c03a6e0, ...)
called
tport.c:3257 tport_tsend() tport_tsend(0x7f7a4c004330) tpn = TLS/
80.246.136.250:55539
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c019070 143 (143)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c03abaa 178 (178)
tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec
0x7f7a4c004620 0x7f7a4c0190ff 236 (236)
tport.c:3492 tport_send_msg() tport_vsend returned 557
send 557 bytes to tls/[80.246.136.250]:55539 at 06:47:10.513449:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TLS 10.0.185.61:60531
;rport=55539;branch=z9hG4bKPjkviJEl84G-mIBM80lf2Tn35igY2eXfSk;alias;received=80.246.136.250
From: <sips:budapp at 10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I
To: <sips:991234 at X.X.X.X>;tag=UvNpmQ5rme77D
Call-ID: SUqEUDnopKxqF5MCGGtKE1wkXaACpF61
CSeq: 3629 BYE
User-Agent:
FreeSWITCH-mod_sofia/1.7.0+git~20150608T182614Z~f8853ac620~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Length: 0
Any idea on how to go about it? Is this intentional? If so, can I somehow
force FS to return "sips" schema?
Thanks,
Adam
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20150616/c93c3426/attachment-0001.html
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list