FreeSWITCH and TLS using pjsip
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@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@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@10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I To: <sips:991234@X.X.X.X> Contact: <sips:budapp@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@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@10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I To: <sips:991234@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@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@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@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@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@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@10.0.185.61) State NEW 2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/budapp@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@10.0.185.61) State INIT 2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:88 sofia/internal/ budapp@10.0.185.61 SOFIA INIT 2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:40 sofia/internal/budapp@10.0.185.61 Standard INIT 2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/budapp@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@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@10.0.185.61) Running State Change CS_ROUTING 2015-06-16 06:47:10.269817 [DEBUG] switch_channel.c:2239 (sofia/internal/ budapp@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@10.0.185.61) State ROUTING 2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:141 sofia/internal/ budapp@10.0.185.61 SOFIA ROUTING 2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:166 sofia/internal/budapp@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@10.0.185.61 parsing [public->cdquality_conferences_with_api] continue=false Dialplan: sofia/internal/budapp@10.0.185.61 Regex (FAIL) [cdquality_conferences_with_api] destination_number(991234) =~ /^(75\d{4,36})$/ break=on-false Dialplan: sofia/internal/budapp@10.0.185.61 parsing [public->test_conferences] continue=false Dialplan: sofia/internal/budapp@10.0.185.61 Regex (PASS) [test_conferences] destination_number(991234) =~ /^99(\d{4,36})$/ break=on-false Dialplan: sofia/internal/budapp@10.0.185.61 Action set(jitterbuffer_msec=60:200:20) Dialplan: sofia/internal/budapp@10.0.185.61 Action answer() Dialplan: sofia/internal/budapp@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@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@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@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@10.0.185.61) State EXECUTE 2015-06-16 06:47:10.269817 [DEBUG] mod_sofia.c:196 sofia/internal/ budapp@10.0.185.61 SOFIA EXECUTE 2015-06-16 06:47:10.269817 [DEBUG] switch_core_state_machine.c:258 sofia/internal/budapp@10.0.185.61 Standard EXECUTE EXECUTE sofia/internal/budapp@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@10.0.185.61 SET [jitterbuffer_msec]=[60:200:20] EXECUTE sofia/internal/budapp@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@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@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@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@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@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@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@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@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@10.0.185.61! 2015-06-16 06:47:10.269817 [DEBUG] switch_channel.c:3460 (sofia/internal/ budapp@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@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@10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I To: <sips:991234@X.X.X.X>;tag=UvNpmQ5rme77D Call-ID: SUqEUDnopKxqF5MCGGtKE1wkXaACpF61 CSeq: 3628 INVITE Contact: <sip:991234@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@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@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@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@10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I To: <sips:991234@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@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@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@10.0.185.61>;tag=oSYCSnuYopXMC9YOp91FJQ0WvW.rkB-I To: <sips:991234@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
participants (1)
-
Adam Ben-Ayoun