[Freeswitch-users] webrtc/Sip issue
Craig Stevenson
craig at stevenson.com
Mon Aug 3 07:07:16 MSD 2015
Thanks for everyone's help on IRC... we have now blocked the IPv6
addresses in the ACL.
Good news, now "drops" any candidate that has IPv6 address.
Bad news, it still goes ahead and "chooses" a v6 candidate anyway.
See the attached log. You can see this behavior if you search for actions
on "fdae:f681:faac:a135:c091:fd50:ad03:6802".
As an aside, the command "acl fdae:f681:faac:a135:c091:fd50:ad03:6802 lan"
returns "false".
Same for "acl fdae:f681:faac:a135:c091:fd50:ad03:6802:56850 lan"
Thanks,
Craig
(p.s., look forward to seeing you all in person tomorrow morning)
On Fri, Jul 31, 2015 at 7:20 PM, Michael Jerris <mike at jerris.com> wrote:
> The issue is its matching the IPv6 address. if you don't have any v6 on
> the box you can override the default acl for candidates to not match v6 ever
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20150802/7d028215/attachment-0001.html
-------------- next part --------------
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
freeswitch at internal>
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f511c0929c0) msg 0x7f511c071760 from (wss/50.242.22.166:51514) has 5039 bytes, veclen = 1
recv 5039 bytes from wss/[50.242.22.166]:51514 at 02:47:54.377924:
------------------------------------------------------------------------
INVITE sip:9199 at theta.soniccloud.com SIP/2.0
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK2276635
Max-Forwards: 70
To: <sip:9199 at theta.soniccloud.com>
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7004 INVITE
Contact: <sip:a1tmbiov at s0n17dlvrqjp.invalid;transport=ws;ob>
Allow: ACK,CANCEL,BYE,OPTIONS,INFO,NOTIFY,INVITE
Content-Type: application/sdp
Supported: outbound
User-Agent: SIP.js/0.6.4
Content-Length: 4559
v=0
o=- 4000227983672578466 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio video
a=msid-semantic: WMS ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
m=audio 55301 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP4 50.242.22.166
a=rtcp:57837 IN IP4 50.242.22.166
a=candidate:3806812431 1 udp 2122265343 fdae:f681:faac:a135:c091:fd50:ad03:6802 56850 typ host generation 0
a=candidate:2795255774 1 udp 2122194687 192.168.1.7 55301 typ host generation 0
a=candidate:3806812431 2 udp 2122265342 fdae:f681:faac:a135:c091:fd50:ad03:6802 55302 typ host generation 0
a=candidate:2795255774 2 udp 2122194686 192.168.1.7 57837 typ host generation 0
a=candidate:264484875 1 udp 1685987071 50.242.22.166 55301 typ srflx raddr 192.168.1.7 rport 55301 generation 0
a=candidate:264484875 2 udp 1685987070 50.242.22.166 57837 typ srflx raddr 192.168.1.7 rport 57837 generation 0
a=candidate:2892277247 1 tcp 1518285567 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 1 tcp 1518214911 192.168.1.7 0 typ host tcptype active generation 0
a=candidate:2892277247 2 tcp 1518285566 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 2 tcp 1518214910 192.168.1.7 0 typ host tcptype active generation 0
a=ice-ufrag:XyBgNIACzzGNqI97
a=ice-pwd:TUBwo4YdjnM7i/+HFeLPmqug
a=fingerprint:sha-256 28:77:D9:33:B5:5D:63:2D:86:FC:92:42:83:A1:8C:D9:D2:D8:1D:06:2B:86:B9:D9:55:C9:54:E4:6B:35:12:62
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; stereo=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/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:126 telephone-event/8000
a=maxptime:60
a=ssrc:2034035072 cname:tZtF7mNLC/xSKnuV
a=ssrc:2034035072 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 132504cc-7836-4e1f-a6a3-fe7f9d23b7e9
a=ssrc:2034035072 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:2034035072 label:132504cc-7836-4e1f-a6a3-fe7f9d23b7e9
m=video 57487 UDP/TLS/RTP/SAVPF 100 116 117 96
c=IN IP4 50.242.22.166
a=rtcp:49625 IN IP4 50.242.22.166
a=candidate:3806812431 1 udp 2122265343 fdae:f681:faac:a135:c091:fd50:ad03:6802 57838 typ host generation 0
a=candidate:2795255774 1 udp 2122194687 192.168.1.7 57487 typ host generation 0
a=candidate:3806812431 2 udp 2122265342 fdae:f681:faac:a135:c091:fd50:ad03:6802 57488 typ host generation 0
a=candidate:2795255774 2 udp 2122194686 192.168.1.7 49625 typ host generation 0
a=candidate:264484875 1 udp 1685987071 50.242.22.166 57487 typ srflx raddr 192.168.1.7 rport 57487 generation 0
a=candidate:264484875 2 udp 1685987070 50.242.22.166 49625 typ srflx raddr 192.168.1.7 rport 49625 generation 0
a=candidate:2892277247 1 tcp 1518285567 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 1 tcp 1518214911 192.168.1.7 0 typ host tcptype active generation 0
a=candidate:2892277247 2 tcp 1518285566 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 2 tcp 1518214910 192.168.1.7 0 typ host tcptype active generation 0
a=ice-ufrag:XyBgNIACzzGNqI97
a=ice-pwd:TUBwo4YdjnM7i/+HFeLPmqug
a=fingerprint:sha-256 28:77:D9:33:B5:5D:63:2D:86:FC:92:42:83:A1:8C:D9:D2:D8:1D:06:2B:86:B9:D9:55:C9:54:E4:6B:35:12:62
a=setup:actpass
a=mid:video
a=extmap:2 urn:ietf:params:rtp-hdrext:toffset
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:4 urn:3gpp:video-orientation
a=sendrecv
a=rtcp-mux
a=rtpmap:100 VP8/90000
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=rtcp-fb:100 goog-remb
a=rtpmap:116 red/90000
a=rtpmap:117 ulpfec/90000
a=rtpmap:96 rtx/90000
a=fmtp:96 apt=100
a=ssrc-group:FID 1802433736 2112122417
a=ssrc:1802433736 cname:tZtF7mNLC/xSKnuV
a=ssrc:1802433736 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:1802433736 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:1802433736 label:8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:2112122417 cname:tZtF7mNLC/xSKnuV
a=ssrc:2112122417 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:2112122417 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:2112122417 label:8a07e9a9-4132-4f85-be18-2a25dcedb961
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f511c0929c0): msg 0x7f511c071760 (5039 bytes) from wss/50.242.22.166:51514/sips next=(nil)
nta.c:2880 agent_recv_request() nta: received INVITE sip:9199 at theta.soniccloud.com SIP/2.0 (CSeq 7004)
nta.c:3174 agent_check_request_via() nta: Via check: received=50.242.22.166
nta.c:3085 agent_recv_request() nta: INVITE (7004) 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::0x7f511c001930, 0x7f511c001130, 0x7f511c068c80) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c069520, ...) called
nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f511c069c90)
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f511c069520) called
soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f511c069520, (nil), 0x7f511c0628d0, 4559) called
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f511c068c80): adding session usage
tport.c:3257 tport_tsend() tport_tsend(0x7f511c0929c0) tpn = WSS/50.242.22.166:51514
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0bc9f0 116 (116)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c062792 54 (54)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c06276d 37 (37)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0627c8 50 (50)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0bca64 99 (99)
tport.c:3594 tport_vsend() tport_vsend(0x7f511c0929c0): 356 bytes of 356 to wss/50.242.22.166:51514
tport.c:3492 tport_send_msg() tport_vsend returned 356
send 356 bytes to wss/[50.242.22.166]:51514 at 02:47:54.378422:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK2276635;received=50.242.22.166;rport=51514
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
To: <sip:9199 at theta.soniccloud.com>
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7004 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~64bit
Content-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (7004)
nua_stack.c:271 nua_stack_event() nua(0x7f511c068c80): event i_invite 100 Trying
nua_session.c:4139 signal_call_state_change() nua(0x7f511c068c80): call state changed: init -> received, received offer
soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f511c069520, [0x7f515ae748c8], [0x7f515ae748d0], [(nil)]) called
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
2015-08-03 02:47:54.377062 [NOTICE] switch_channel.c:1089 New Channel sofia/internal/1000 at theta.soniccloud.com [4a3065b6-4ded-4776-bca5-617f192efb30]
2015-08-03 02:47:54.377062 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_NEW
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-08-03 02:47:54.377062 [DEBUG] sofia.c:9093 sofia/internal/1000 at theta.soniccloud.com receiving invite from 50.242.22.166:51514 version: 1.7.0 git 01672dc 2015-07-30 03:16:34Z 64bit
nua_stack.c:271 nua_stack_event() nua(0x7f511c068c80): event i_state 100 Trying
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
2015-08-03 02:47:54.377062 [ALERT] switch_core_media.c:408 Looking for zrtp-hash
2015-08-03 02:47:54.377062 [ALERT] switch_core_media.c:363 Deciding whether to pass zrtp-hash between legs
2015-08-03 02:47:54.377062 [ALERT] switch_core_media.c:365 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2015-08-03 02:47:54.377062 [DEBUG] sofia.c:9260 IP 50.242.22.166 Rejected by acl "domains". Falling back to Digest auth.
nua.c:879 nua_respond() nua: nua_respond: entering
nua_stack.c:529 nua_signal() nua(0x7f511c068c80): sent signal r_respond
2015-08-03 02:47:54.377062 [WARNING] sofia_reg.c:1744 SIP auth challenge (INVITE) on sofia profile 'internal' for [9199 at theta.soniccloud.com] from ip 50.242.22.166
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
2015-08-03 02:47:54.377062 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/1000 at theta.soniccloud.com) State NEW
nua_stack.c:573 nua_stack_signal() nua(0x7f511c068c80): recv signal r_respond 407 Proxy Authentication Required
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c069520, ...) called
nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f511c069520) called
tport.c:3257 tport_tsend() tport_tsend(0x7f511c0929c0) tpn = WSS/50.242.22.166:51514
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0becd0 139 (139)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c062792 54 (54)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0bed5b 55 (55)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0627c8 50 (50)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0bed92 423 (423)
tport.c:3594 tport_vsend() tport_vsend(0x7f511c0929c0): 721 bytes of 721 to wss/50.242.22.166:51514
tport.c:3492 tport_send_msg() tport_vsend returned 721
send 721 bytes to wss/[50.242.22.166]:51514 at 02:47:54.379621:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK2276635;received=50.242.22.166;rport=51514
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
To: <sip:9199 at theta.soniccloud.com>;tag=2g8g6e9XvgDmr
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7004 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~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
Proxy-Authenticate: Digest realm="theta.soniccloud.com", nonce="2c8a0a03-dc5d-4e15-b8f6-52c4c867714a", algorithm=MD5, qop="auth"
Content-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (7004)
nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f511c068c80): removing session usage
nua_session.c:4139 signal_call_state_change() nua(0x7f511c068c80): call state changed: received -> terminated
nua_stack.c:271 nua_stack_event() nua(0x7f511c068c80): event i_state 407 Proxy Authentication Required
nua_stack.c:271 nua_stack_event() nua(0x7f511c068c80): event i_terminated 407 Proxy Authentication Required
soa.c:356 soa_destroy() soa_destroy(static::0x7f511c069520) called
nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f511c069c90)
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
2015-08-03 02:47:54.377062 [DEBUG] sofia.c:2147 detaching session 4a3065b6-4ded-4776-bca5-617f192efb30
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f511c068c80): sent signal r_destroy
nua_stack.c:569 nua_stack_signal() nua(0x7f511c068c80): recv signal r_destroy
nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f511c0929c0) msg 0x7f511c068ba0 from (wss/50.242.22.166:51514) has 262 bytes, veclen = 1
recv 262 bytes from wss/[50.242.22.166]:51514 at 02:47:54.458714:
------------------------------------------------------------------------
ACK sip:9199 at theta.soniccloud.com SIP/2.0
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK2276635
To: <sip:9199 at theta.soniccloud.com>;tag=2g8g6e9XvgDmr
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7004 ACK
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f511c0929c0): bad msg 0x7f511c068ba0 (262 bytes) from wss/50.242.22.166:51514/sips next=(nil)
nta.c:2880 agent_recv_request() nta: received ACK sip:9199 at theta.soniccloud.com SIP/2.0 (CSeq 7004)
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f511c0929c0) msg 0x7f511c068ba0 from (wss/50.242.22.166:51514) has 5303 bytes, veclen = 1
recv 5303 bytes from wss/[50.242.22.166]:51514 at 02:47:54.486900:
------------------------------------------------------------------------
INVITE sip:9199 at theta.soniccloud.com SIP/2.0
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK3655087
Max-Forwards: 70
To: <sip:9199 at theta.soniccloud.com>
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7005 INVITE
Proxy-Authorization: Digest algorithm=MD5, username="1000", realm="theta.soniccloud.com", nonce="2c8a0a03-dc5d-4e15-b8f6-52c4c867714a", uri="sip:9199 at theta.soniccloud.com", response="4318442d55232a4df07428604c06283d", qop=auth, cnonce="vh8m6sfb4rbf", nc=00000001
Contact: <sip:a1tmbiov at s0n17dlvrqjp.invalid;transport=ws;ob>
Allow: ACK,CANCEL,BYE,OPTIONS,INFO,NOTIFY,INVITE
Content-Type: application/sdp
Supported: outbound
User-Agent: SIP.js/0.6.4
Content-Length: 4559
v=0
o=- 4000227983672578466 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio video
a=msid-semantic: WMS ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
m=audio 55301 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP4 50.242.22.166
a=rtcp:57837 IN IP4 50.242.22.166
a=candidate:3806812431 1 udp 2122265343 fdae:f681:faac:a135:c091:fd50:ad03:6802 56850 typ host generation 0
a=candidate:2795255774 1 udp 2122194687 192.168.1.7 55301 typ host generation 0
a=candidate:3806812431 2 udp 2122265342 fdae:f681:faac:a135:c091:fd50:ad03:6802 55302 typ host generation 0
a=candidate:2795255774 2 udp 2122194686 192.168.1.7 57837 typ host generation 0
a=candidate:264484875 1 udp 1685987071 50.242.22.166 55301 typ srflx raddr 192.168.1.7 rport 55301 generation 0
a=candidate:264484875 2 udp 1685987070 50.242.22.166 57837 typ srflx raddr 192.168.1.7 rport 57837 generation 0
a=candidate:2892277247 1 tcp 1518285567 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 1 tcp 1518214911 192.168.1.7 0 typ host tcptype active generation 0
a=candidate:2892277247 2 tcp 1518285566 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 2 tcp 1518214910 192.168.1.7 0 typ host tcptype active generation 0
a=ice-ufrag:XyBgNIACzzGNqI97
a=ice-pwd:TUBwo4YdjnM7i/+HFeLPmqug
a=fingerprint:sha-256 28:77:D9:33:B5:5D:63:2D:86:FC:92:42:83:A1:8C:D9:D2:D8:1D:06:2B:86:B9:D9:55:C9:54:E4:6B:35:12:62
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; stereo=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/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:126 telephone-event/8000
a=maxptime:60
a=ssrc:2034035072 cname:tZtF7mNLC/xSKnuV
a=ssrc:2034035072 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 132504cc-7836-4e1f-a6a3-fe7f9d23b7e9
a=ssrc:2034035072 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:2034035072 label:132504cc-7836-4e1f-a6a3-fe7f9d23b7e9
m=video 57487 UDP/TLS/RTP/SAVPF 100 116 117 96
c=IN IP4 50.242.22.166
a=rtcp:49625 IN IP4 50.242.22.166
a=candidate:3806812431 1 udp 2122265343 fdae:f681:faac:a135:c091:fd50:ad03:6802 57838 typ host generation 0
a=candidate:2795255774 1 udp 2122194687 192.168.1.7 57487 typ host generation 0
a=candidate:3806812431 2 udp 2122265342 fdae:f681:faac:a135:c091:fd50:ad03:6802 57488 typ host generation 0
a=candidate:2795255774 2 udp 2122194686 192.168.1.7 49625 typ host generation 0
a=candidate:264484875 1 udp 1685987071 50.242.22.166 57487 typ srflx raddr 192.168.1.7 rport 57487 generation 0
a=candidate:264484875 2 udp 1685987070 50.242.22.166 49625 typ srflx raddr 192.168.1.7 rport 49625 generation 0
a=candidate:2892277247 1 tcp 1518285567 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 1 tcp 1518214911 192.168.1.7 0 typ host tcptype active generation 0
a=candidate:2892277247 2 tcp 1518285566 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 2 tcp 1518214910 192.168.1.7 0 typ host tcptype active generation 0
a=ice-ufrag:XyBgNIACzzGNqI97
a=ice-pwd:TUBwo4YdjnM7i/+HFeLPmqug
a=fingerprint:sha-256 28:77:D9:33:B5:5D:63:2D:86:FC:92:42:83:A1:8C:D9:D2:D8:1D:06:2B:86:B9:D9:55:C9:54:E4:6B:35:12:62
a=setup:actpass
a=mid:video
a=extmap:2 urn:ietf:params:rtp-hdrext:toffset
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:4 urn:3gpp:video-orientation
a=sendrecv
a=rtcp-mux
a=rtpmap:100 VP8/90000
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=rtcp-fb:100 goog-remb
a=rtpmap:116 red/90000
a=rtpmap:117 ulpfec/90000
a=rtpmap:96 rtx/90000
a=fmtp:96 apt=100
a=ssrc-group:FID 1802433736 2112122417
a=ssrc:1802433736 cname:tZtF7mNLC/xSKnuV
a=ssrc:1802433736 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:1802433736 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:1802433736 label:8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:2112122417 cname:tZtF7mNLC/xSKnuV
a=ssrc:2112122417 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:2112122417 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:2112122417 label:8a07e9a9-4132-4f85-be18-2a25dcedb961
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f511c0929c0): msg 0x7f511c068ba0 (5303 bytes) from wss/50.242.22.166:51514/sips next=(nil)
nta.c:2880 agent_recv_request() nta: received INVITE sip:9199 at theta.soniccloud.com SIP/2.0 (CSeq 7005)
nta.c:3174 agent_check_request_via() nta: Via check: received=50.242.22.166
nta.c:3085 agent_recv_request() nta: INVITE (7005) going to a default leg
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::0x7f511c001930, 0x7f511c001130, 0x7f511c069b50) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c06a3f0, ...) called
nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f511c06ab60)
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f511c06a3f0) called
soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f511c06a3f0, (nil), 0x7f511c0645c8, 4559) called
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f511c069b50): adding session usage
tport.c:3257 tport_tsend() tport_tsend(0x7f511c0929c0) tpn = WSS/50.242.22.166:51514
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0b7cb0 116 (116)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c064382 54 (54)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c06435d 37 (37)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0643b8 50 (50)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0b7d24 99 (99)
tport.c:3594 tport_vsend() tport_vsend(0x7f511c0929c0): 356 bytes of 356 to wss/50.242.22.166:51514
tport.c:3492 tport_send_msg() tport_vsend returned 356
send 356 bytes to wss/[50.242.22.166]:51514 at 02:47:54.487369:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK3655087;received=50.242.22.166;rport=51514
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
To: <sip:9199 at theta.soniccloud.com>
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7005 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~64bit
Content-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (7005)
nua_stack.c:271 nua_stack_event() nua(0x7f511c069b50): event i_invite 100 Trying
nua_session.c:4139 signal_call_state_change() nua(0x7f511c069b50): call state changed: init -> received, received offer
soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f511c06a3f0, [0x7f515ae748c8], [0x7f515ae748d0], [(nil)]) called
nua_stack.c:271 nua_stack_event() nua(0x7f511c069b50): event i_state 100 Trying
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): 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-08-03 02:47:54.477054 [DEBUG] sofia.c:2255 Re-attaching to session 4a3065b6-4ded-4776-bca5-617f192efb30
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-08-03 02:47:54.497052 [DEBUG] sofia.c:9093 sofia/internal/1000 at theta.soniccloud.com receiving invite from 50.242.22.166:51514 version: 1.7.0 git 01672dc 2015-07-30 03:16:34Z 64bit
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:408 Looking for zrtp-hash
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:363 Deciding whether to pass zrtp-hash between legs
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:365 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2015-08-03 02:47:54.497052 [DEBUG] sofia.c:9260 IP 50.242.22.166 Rejected by acl "domains". Falling back to Digest auth.
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-08-03 02:47:54.497052 [DEBUG] sofia.c:10392 Setting NAT mode based on websockets
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-08-03 02:47:54.497052 [DEBUG] sofia.c:6715 Channel sofia/internal/1000 at theta.soniccloud.com entering state [received][100]
2015-08-03 02:47:54.497052 [DEBUG] sofia.c:6725 Remote SDP:
v=0
o=- 4000227983672578466 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio video
a=msid-semantic: WMS ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
m=audio 55301 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP4 50.242.22.166
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1; stereo=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/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:126 telephone-event/8000
a=rtcp:57837 IN IP4 50.242.22.166
a=candidate:3806812431 1 udp 2122265343 fdae:f681:faac:a135:c091:fd50:ad03:6802 56850 typ host generation 0
a=candidate:2795255774 1 udp 2122194687 192.168.1.7 55301 typ host generation 0
a=candidate:3806812431 2 udp 2122265342 fdae:f681:faac:a135:c091:fd50:ad03:6802 55302 typ host generation 0
a=candidate:2795255774 2 udp 2122194686 192.168.1.7 57837 typ host generation 0
a=candidate:264484875 1 udp 1685987071 50.242.22.166 55301 typ srflx raddr 192.168.1.7 rport 55301 generation 0
a=candidate:264484875 2 udp 1685987070 50.242.22.166 57837 typ srflx raddr 192.168.1.7 rport 57837 generation 0
a=candidate:2892277247 1 tcp 1518285567 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 1 tcp 1518214911 192.168.1.7 0 typ host tcptype active generation 0
a=candidate:2892277247 2 tcp 1518285566 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 2 tcp 1518214910 192.168.1.7 0 typ host tcptype active generation 0
a=ice-ufrag:XyBgNIACzzGNqI97
a=ice-pwd:TUBwo4YdjnM7i/+HFeLPmqug
a=fingerprint:sha-256 28:77:D9:33:B5:5D:63:2D:86:FC:92:42:83:A1:8C:D9:D2:D8:1D:06:2B:86:B9:D9:55:C9:54:E4:6B:35:12:62
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:2034035072 cname:tZtF7mNLC/xSKnuV
a=ssrc:2034035072 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 132504cc-7836-4e1f-a6a3-fe7f9d23b7e9
a=ssrc:2034035072 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:2034035072 label:132504cc-7836-4e1f-a6a3-fe7f9d23b7e9
m=video 57487 UDP/TLS/RTP/SAVPF 100 116 117 96
c=IN IP4 50.242.22.166
a=rtpmap:100 VP8/90000
a=rtpmap:116 red/90000
a=rtpmap:117 ulpfec/90000
a=rtpmap:96 rtx/90000
a=fmtp:96 apt=100
a=rtcp:49625 IN IP4 50.242.22.166
a=candidate:3806812431 1 udp 2122265343 fdae:f681:faac:a135:c091:fd50:ad03:6802 57838 typ host generation 0
a=candidate:2795255774 1 udp 2122194687 192.168.1.7 57487 typ host generation 0
a=candidate:3806812431 2 udp 2122265342 fdae:f681:faac:a135:c091:fd50:ad03:6802 57488 typ host generation 0
a=candidate:2795255774 2 udp 2122194686 192.168.1.7 49625 typ host generation 0
a=candidate:264484875 1 udp 1685987071 50.242.22.166 57487 typ srflx raddr 192.168.1.7 rport 57487 generation 0
a=candidate:264484875 2 udp 1685987070 50.242.22.166 49625 typ srflx raddr 192.168.1.7 rport 49625 generation 0
a=candidate:2892277247 1 tcp 1518285567 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 1 tcp 1518214911 192.168.1.7 0 typ host tcptype active generation 0
a=candidate:2892277247 2 tcp 1518285566 fdae:f681:faac:a135:c091:fd50:ad03:6802 0 typ host tcptype active generation 0
a=candidate:3894397742 2 tcp 1518214910 192.168.1.7 0 typ host tcptype active generation 0
a=ice-ufrag:XyBgNIACzzGNqI97
a=ice-pwd:TUBwo4YdjnM7i/+HFeLPmqug
a=fingerprint:sha-256 28:77:D9:33:B5:5D:63:2D:86:FC:92:42:83:A1:8C:D9:D2:D8:1D:06:2B:86:B9:D9:55:C9:54:E4:6B:35:12:62
a=setup:actpass
a=mid:video
a=extmap:2 urn:ietf:params:rtp-hdrext:toffset
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:4 urn:3gpp:video-orientation
a=rtcp-mux
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=rtcp-fb:100 goog-remb
a=ssrc-group:FID 1802433736 2112122417
a=ssrc:1802433736 cname:tZtF7mNLC/xSKnuV
a=ssrc:1802433736 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:1802433736 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:1802433736 label:8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:2112122417 cname:tZtF7mNLC/xSKnuV
a=ssrc:2112122417 msid:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4 8a07e9a9-4132-4f85-be18-2a25dcedb961
a=ssrc:2112122417 mslabel:ACciN4J8V3yizg5BA5kMVqFdf5ewCOmCoih4
a=ssrc:2112122417 label:8a07e9a9-4132-4f85-be18-2a25dcedb961
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:408 Looking for zrtp-hash
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:363 Deciding whether to pass zrtp-hash between legs
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:365 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [opus:111:48000:60:0:2]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4138 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [opus:111:48000:60:0:2]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [opus:111:48000:60:0:2]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [opus:111:48000:60:0:2]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [G722:9:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [G722:9:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4138 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4138 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4138 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:106:32000:60:0:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:106:32000:60:0:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:106:32000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:106:32000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:105:16000:60:0:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:13:8000:60:0:1]/[G722:9:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4083 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3999 Set telephone-event payload to 126
2015-08-03 02:47:54.497052 [DEBUG] mod_opus.c:419 Opus encoder set bitrate to local settings [-1000bps]
2015-08-03 02:47:54.497052 [DEBUG] mod_opus.c:419 Opus encoder set bitrate to local settings [-1000bps]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:2869 Set Codec sofia/internal/1000 at theta.soniccloud.com opus/48000 20 ms 960 samples 0 bits 2 channels
2015-08-03 02:47:54.497052 [DEBUG] switch_core_codec.c:111 sofia/internal/1000 at theta.soniccloud.com Original read codec set to opus:116
2015-08-03 02:47:54.497052 [WARNING] switch_core_media.c:3205 NO candidate ACL defined, Defaulting to wan.auto
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [3806812431]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [1]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122265343]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [fdae:f681:faac:a135:c091:fd50:ad03:6802]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [56850]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3229 Drop audio Candidate cid: 1 proto: udp type: host addr: fdae:f681:faac:a135:c091:fd50:ad03:6802:56850 (no network path)
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [2795255774]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [1]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122194687]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [55301]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.1.7:55301
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [3806812431]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [2]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122265342]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [fdae:f681:faac:a135:c091:fd50:ad03:6802]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [55302]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3229 Drop audio Candidate cid: 2 proto: udp type: host addr: fdae:f681:faac:a135:c091:fd50:ad03:6802:55302 (no network path)
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [2795255774]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [2]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122194686]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [57837]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save audio Candidate cid: 2 proto: udp type: host addr: 192.168.1.7:57837
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [264484875]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [1]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [1685987071]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [50.242.22.166]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [55301]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [srflx]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [raddr]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 10 [rport]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 11 [55301]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 12 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 13 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save audio Candidate cid: 1 proto: udp type: srflx addr: 50.242.22.166:55301
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [264484875]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [2]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [1685987070]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [50.242.22.166]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [57837]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [srflx]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [raddr]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 10 [rport]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 11 [57837]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 12 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 13 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save audio Candidate cid: 2 proto: udp type: srflx addr: 50.242.22.166:57837
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3274 Searching for rtp candidate.
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3279 Choose rtp candidate, index 0, fdae:f681:faac:a135:c091:fd50:ad03:6802:56850
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3290 Choose same candidate, index 3, for rtcp based on rtcp-mux attribute fdae:f681:faac:a135:c091:fd50:ad03:6802:56850
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3335 setting remote audio ice addr to index 0 fdae:f681:faac:a135:c091:fd50:ad03:6802:56850 based on candidate
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3356 Setting remote rtcp audio addr to fdae:f681:faac:a135:c091:fd50:ad03:6802:56850 based on candidate
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4350 Set 2833 dtmf send/recv payload to 126
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4496 Video Codec Compare [VP8:100]/[VP8:99]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4508 Video Codec Compare [VP8:99] +++ is saved as a match
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4496 Video Codec Compare [red:116]/[VP8:99]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4496 Video Codec Compare [ulpfec:117]/[VP8:99]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:4496 Video Codec Compare [rtx:96]/[VP8:99]
2015-08-03 02:47:54.497052 [DEBUG] mod_vpx.c:504 VPX VER:v1.4.0 VPX_IMAGE_ABI_VERSION:3 VPX_CODEC_ABI_VERSION:6
2015-08-03 02:47:54.497052 [DEBUG] mod_vpx.c:504 VPX VER:v1.4.0 VPX_IMAGE_ABI_VERSION:3 VPX_CODEC_ABI_VERSION:6
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:2685 Set VIDEO Codec sofia/internal/1000 at theta.soniccloud.com VP8/90000 0 ms
2015-08-03 02:47:54.497052 [WARNING] switch_core_media.c:3205 NO candidate ACL defined, Defaulting to wan.auto
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [3806812431]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [1]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122265343]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [fdae:f681:faac:a135:c091:fd50:ad03:6802]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [57838]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3229 Drop video Candidate cid: 1 proto: udp type: host addr: fdae:f681:faac:a135:c091:fd50:ad03:6802:57838 (no network path)
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [2795255774]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [1]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122194687]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [57487]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save video Candidate cid: 1 proto: udp type: host addr: 192.168.1.7:57487
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [3806812431]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [2]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122265342]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [fdae:f681:faac:a135:c091:fd50:ad03:6802]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [57488]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3229 Drop video Candidate cid: 2 proto: udp type: host addr: fdae:f681:faac:a135:c091:fd50:ad03:6802:57488 (no network path)
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [2795255774]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [2]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [2122194686]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [49625]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [host]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save video Candidate cid: 2 proto: udp type: host addr: 192.168.1.7:49625
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [264484875]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [1]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [1685987071]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [50.242.22.166]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [57487]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [srflx]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [raddr]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 10 [rport]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 11 [57487]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 12 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 13 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save video Candidate cid: 1 proto: udp type: srflx addr: 50.242.22.166:57487
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 0 [264484875]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 1 [2]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 2 [udp]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 3 [1685987070]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 4 [50.242.22.166]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 5 [49625]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 6 [typ]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 7 [srflx]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 8 [raddr]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 9 [192.168.1.7]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 10 [rport]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 11 [49625]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 12 [generation]
2015-08-03 02:47:54.497052 [ALERT] switch_core_media.c:3225 CAND 13 [0]
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3234 Save video Candidate cid: 2 proto: udp type: srflx addr: 50.242.22.166:49625
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3274 Searching for rtp candidate.
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3279 Choose rtp candidate, index 0, fdae:f681:faac:a135:c091:fd50:ad03:6802:57838
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3290 Choose same candidate, index 3, for rtcp based on rtcp-mux attribute fdae:f681:faac:a135:c091:fd50:ad03:6802:57838
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3335 setting remote video ice addr to index 0 fdae:f681:faac:a135:c091:fd50:ad03:6802:57838 based on candidate
2015-08-03 02:47:54.497052 [DEBUG] switch_core_media.c:3356 Setting remote rtcp video addr to fdae:f681:faac:a135:c091:fd50:ad03:6802:57838 based on candidate
2015-08-03 02:47:54.497052 [DEBUG] sofia.c:7011 (sofia/internal/1000 at theta.soniccloud.com) State Change CS_NEW -> CS_INIT
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
2015-08-03 02:47:54.497052 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_INIT
2015-08-03 02:47:54.497052 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1000 at theta.soniccloud.com) State INIT
2015-08-03 02:47:54.497052 [DEBUG] mod_sofia.c:88 sofia/internal/1000 at theta.soniccloud.com SOFIA INIT
2015-08-03 02:47:54.497052 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000 at theta.soniccloud.com Standard INIT
2015-08-03 02:47:54.497052 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000 at theta.soniccloud.com) State Change CS_INIT -> CS_ROUTING
2015-08-03 02:47:54.497052 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1000 at theta.soniccloud.com) State INIT going to sleep
2015-08-03 02:47:54.518218 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_ROUTING
2015-08-03 02:47:54.518218 [DEBUG] switch_channel.c:2239 (sofia/internal/1000 at theta.soniccloud.com) Callstate Change DOWN -> RINGING
2015-08-03 02:47:54.518218 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1000 at theta.soniccloud.com) State ROUTING
2015-08-03 02:47:54.518218 [DEBUG] mod_sofia.c:141 sofia/internal/1000 at theta.soniccloud.com SOFIA ROUTING
2015-08-03 02:47:54.518218 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1000 at theta.soniccloud.com Standard ROUTING
2015-08-03 02:47:54.518218 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->9199 in context default
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->Check for special extensions] continue=true
Dialplan: sofia/internal/1000 at theta.soniccloud.com Absolute Condition [Check for special extensions]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_larrys_faust_layout=1018|1019) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_larrys_faust_layout=1018|1019)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_larrys_faust_layout]=[1018|1019]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_larrys_test_faust_layout=1014) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_larrys_test_faust_layout=1014)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_larrys_test_faust_layout]=[1014]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_tarnow_jay_faust_layout=1199) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_tarnow_jay_faust_layout=1199)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_tarnow_jay_faust_layout]=[1199]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_troy_robert_blend_faust_layout=1121) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_troy_robert_blend_faust_layout=1121)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_troy_robert_blend_faust_layout]=[1121]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_troy_robert_left_faust_layout=1122) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_troy_robert_left_faust_layout=1122)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_troy_robert_left_faust_layout]=[1122]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_troy_robert_right_faust_layout=1123) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_troy_robert_right_faust_layout=1123)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_troy_robert_right_faust_layout]=[1123]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_troy_robert_left_alt_faust_layout=1125) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_troy_robert_left_alt_faust_layout=1125)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_troy_robert_left_alt_faust_layout]=[1125]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_murray_john_faust_layout=1126) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_murray_john_faust_layout=1126)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_murray_john_faust_layout]=[1126]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(extensions_using_brown_marshall_faust_layout=1132) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(extensions_using_brown_marshall_faust_layout=1132)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [extensions_using_brown_marshall_faust_layout]=[1132]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(audio_weaver_user_extensions=1015|1016|1027) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(audio_weaver_user_extensions=1015|1016|1027)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [audio_weaver_user_extensions]=[1015|1016|1027]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action set(use_audio_weaver_always_extension=9200) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(use_audio_weaver_always_extension=9200)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [use_audio_weaver_always_extension]=[9200]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1018|1019$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com ANTI-Action set(caller_faust_layout=filter_bank) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(caller_faust_layout=filter_bank)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [caller_faust_layout]=[filter_bank]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1014$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1199$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1121$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1122$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1123$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1125$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1126$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1132$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1018|1019$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com ANTI-Action set(destination_faust_layout=filter_bank) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(destination_faust_layout=filter_bank)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [destination_faust_layout]=[filter_bank]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1014$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1199$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1121$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1122$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1123$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1125$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1126$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1132$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] ani(1000) =~ /^1015|1016|1027$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com ANTI-Action set(caller_uses_audio_weaver=false) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(caller_uses_audio_weaver=false)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [caller_uses_audio_weaver]=[false]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Check for special extensions] destination_number(9199) =~ /^1015|1016|1027$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com ANTI-Action set(destination_uses_audio_weaver=false) INLINE
EXECUTE sofia/internal/1000 at theta.soniccloud.com set(destination_uses_audio_weaver=false)
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2911 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC]
2015-08-03 02:47:54.518218 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at theta.soniccloud.com [destination_uses_audio_weaver]=[false]
2015-08-03 02:47:54.518218 [ALERT] switch_core_session.c:2926 sofia/internal/1000 at theta.soniccloud.com receive message [APPLICATION_EXEC_COMPLETE]
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->limit_exceeded] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [limit_exceeded] ani(1000) =~ /^limit_exceeded$/ match=any
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [limit_exceeded] destination_number(9199) =~ /^limit_exceeded$/ match=any
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->limit] continue=true
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [limit] ani(1000) =~ /^1015|1016|1027$/ match=any
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [limit] destination_number(9199) =~ /^9200$/ match=any
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [limit] destination_number(9199) =~ /^1015|1016|1027$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->unloop] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->tod_example] continue=true
2015-08-03 02:47:54.518218 [ALERT] switch_xml.c:3171 XML DateTime Check: day of week[tue] =~ 2-6 (PASS)
2015-08-03 02:47:54.518218 [ALERT] switch_xml.c:3177 XML DateTime Check: hour[2] =~ 9-18 (FAIL)
Dialplan: sofia/internal/1000 at theta.soniccloud.com Date/TimeMatch (FAIL) [tod_example] break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->holiday_example] continue=true
2015-08-03 02:47:54.518218 [ALERT] switch_xml.c:3134 XML DateTime Check: month[8] =~ 1 (FAIL)
Dialplan: sofia/internal/1000 at theta.soniccloud.com Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [global-intercept] destination_number(9199) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [group-intercept] destination_number(9199) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [intercept-ext] destination_number(9199) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->redial] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [redial] destination_number(9199) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->global] continue=true
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [global] ${default_password}(27183300) =~ /^1234$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [global] ${endpoint_disposition}(RECEIVED) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [snom-demo-2] destination_number(9199) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [snom-demo-1] destination_number(9199) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [eavesdrop] destination_number(9199) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [eavesdrop] destination_number(9199) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->call_return] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [call_return] destination_number(9199) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->del-group] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [del-group] destination_number(9199) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->add-group] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [add-group] destination_number(9199) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [call-group-simo] destination_number(9199) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [call-group-order] destination_number(9199) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [extension-intercom] destination_number(9199) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Local_Extension] destination_number(9199) =~ /^(1[0-1][0-9][0-9])$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->Local_Extension_Skinny] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [Local_Extension_Skinny] destination_number(9199) =~ /^(11[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->group_dial_sales] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [group_dial_sales] destination_number(9199) =~ /^2000$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->group_dial_support] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [group_dial_support] destination_number(9199) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->group_dial_billing] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [group_dial_billing] destination_number(9199) =~ /^2002$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->operator] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [operator] destination_number(9199) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->vmain] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [vmain] destination_number(9199) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->sip_uri] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [sip_uri] destination_number(9199) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->nb_conferences] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [nb_conferences] destination_number(9199) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->wb_conferences] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [wb_conferences] destination_number(9199) =~ /^(31\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->uwb_conferences] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [uwb_conferences] destination_number(9199) =~ /^(32\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->cdquality_conferences] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [cdquality_conferences] destination_number(9199) =~ /^(33\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(9199) =~ /^9(888|8888|1616|3232)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [mad_boss_intercom] destination_number(9199) =~ /^0911$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [mad_boss_intercom] destination_number(9199) =~ /^0912$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->mad_boss] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [mad_boss] destination_number(9199) =~ /^0913$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ivr_demo] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ivr_demo] destination_number(9199) =~ /^5000$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->dynamic_conference] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [dynamic_conference] destination_number(9199) =~ /^5001$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->rtp_multicast_page] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [rtp_multicast_page] destination_number(9199) =~ /^pagegroup$|^7243$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->park] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [park] destination_number(9199) =~ /^5900$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->unpark] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [unpark] destination_number(9199) =~ /^5901$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->valet_park] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [valet_park] destination_number(9199) =~ /^(6000)$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->valet_park] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [valet_park] destination_number(9199) =~ /^((?!6000)60\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->park] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [park] destination_number(9199) =~ /park\+(\d+)/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->unpark] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [unpark] destination_number(9199) =~ /^parking$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->park] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [park] destination_number(9199) =~ /callpark/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->unpark] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [unpark] destination_number(9199) =~ /pickup/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->wait] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [wait] destination_number(9199) =~ /^wait$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->fax_receive] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [fax_receive] destination_number(9199) =~ /^9178$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->fax_transmit] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [fax_transmit] destination_number(9199) =~ /^9179$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ringback_180] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ringback_180] destination_number(9199) =~ /^9180$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ringback_183_uk_ring] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ringback_183_uk_ring] destination_number(9199) =~ /^9181$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ringback_183_music_ring] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ringback_183_music_ring] destination_number(9199) =~ /^9182$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ringback_post_answer_uk_ring] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(9199) =~ /^9183$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ringback_post_answer_music] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ringback_post_answer_music] destination_number(9199) =~ /^9184$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->ClueCon] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [ClueCon] destination_number(9199) =~ /^9191$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->show_info] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [show_info] destination_number(9199) =~ /^9192$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->video_record] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [video_record] destination_number(9199) =~ /^9193$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->video_playback] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [video_playback] destination_number(9199) =~ /^9194$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->delay_echo] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [delay_echo] destination_number(9199) =~ /^9195$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->echo] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [echo] destination_number(9199) =~ /^9196$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->milliwatt] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [milliwatt] destination_number(9199) =~ /^9197$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->tone_stream] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (FAIL) [tone_stream] destination_number(9199) =~ /^9198$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com parsing [default->investor_demo_tuning_stream] continue=false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [investor_demo_tuning_stream] destination_number(9199) =~ /^9199$/ break=on-false
Dialplan: sofia/internal/1000 at theta.soniccloud.com Regex (PASS) [investor_demo_tuning_stream] ${caller_uses_audio_weaver}(false) =~ /false/ break=never
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action ladspa_tune_run(w|${caller_faust_layout}||)
Dialplan: sofia/internal/1000 at theta.soniccloud.com Absolute Condition [investor_demo_tuning_stream]
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action answer()
Dialplan: sofia/internal/1000 at theta.soniccloud.com Action endless_playback(/usr/local/freeswitch/sounds/en/us/SonicCloud/48000/tuning_combo_male_female_music.wav)
2015-08-03 02:47:54.557050 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1000 at theta.soniccloud.com) State Change CS_ROUTING -> CS_EXECUTE
2015-08-03 02:47:54.557050 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1000 at theta.soniccloud.com) State ROUTING going to sleep
2015-08-03 02:47:54.557050 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_EXECUTE
2015-08-03 02:47:54.557050 [DEBUG] switch_core_state_machine.c:539 (sofia/internal/1000 at theta.soniccloud.com) State EXECUTE
2015-08-03 02:47:54.557050 [DEBUG] mod_sofia.c:196 sofia/internal/1000 at theta.soniccloud.com SOFIA EXECUTE
2015-08-03 02:47:54.557050 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1000 at theta.soniccloud.com Standard EXECUTE
2015-08-03 02:47:54.557050 [DEBUG] switch_core_session.c:2758 Application ladspa_tune_run Requires media! pre_answering channel sofia/internal/1000 at theta.soniccloud.com
2015-08-03 02:47:54.557050 [ALERT] switch_core_session.c:2760 sofia/internal/1000 at theta.soniccloud.com receive message [PROGRESS]
2015-08-03 02:47:54.557050 [INFO] switch_core_session.c:2760 Sending early media
2015-08-03 02:47:54.617054 [DEBUG] switch_core_media.c:5430 STUN Success [146.148.34.105]:[26208]
2015-08-03 02:47:54.617054 [DEBUG] switch_core_media.c:5902 AUDIO RTP [sofia/internal/1000 at theta.soniccloud.com] 10.240.168.2 port 26208 -> fdae:f681:faac:a135:c091:fd50:ad03:6802 port 56850 codec: 111 ms: 20
2015-08-03 02:47:54.617054 [DEBUG] switch_rtp.c:3694 Starting timer [soft] 960 bytes per 20ms
2015-08-03 02:47:54.617054 [ERR] switch_core_media.c:6584 AUDIO RTP REPORTS ERROR: [Remote Address Error!]
2015-08-03 02:47:54.617054 [NOTICE] switch_core_media.c:6585 Hangup sofia/internal/1000 at theta.soniccloud.com [CS_EXECUTE] [DESTINATION_OUT_OF_ORDER]
2015-08-03 02:47:54.617054 [DEBUG] mod_sofia.c:2293 Ring SDP:
v=0
o=FreeSWITCH 1438543866 1438543867 IN IP4 146.148.34.105
s=FreeSWITCH
c=IN IP4 146.148.34.105
t=0 0
a=msid-semantic: WMS 53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS
m=audio 26208 UDP/TLS/RTP/SAVPF 111 126
a=rtpmap:111 opus/48000/2
a=fmtp:111 useinbandfec=1; minptime=10; stereo=1
a=rtpmap:126 telephone-event/48000
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 9B:03:E4:FA:C8:C8:62:73:2A:AD:32:F8:22:3F:16:89:C9:9B:FB:48:EC:9D:5C:A3:2E:21:A4:44:58:A6:71:70
a=setup:active
a=rtcp-mux
a=rtcp:26208 IN IP4 146.148.34.105
a=ice-ufrag:nAkdk9BjADlmU454
a=ice-pwd:5JpTUV9cTQ0bwanKAyOLxfUY
a=candidate:5225391105 1 udp 659136 146.148.34.105 26208 typ host generation 0
a=ssrc:2109935738 cname:kbOuYkGpr8RYrPjm
a=ssrc:2109935738 msid:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS a0
a=ssrc:2109935738 mslabel:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS
a=ssrc:2109935738 label:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSSa0
m=video 22468 UDP/TLS/RTP/SAVPF 100
a=rtpmap:100 VP8/90000
a=fingerprint:sha-256 9B:03:E4:FA:C8:C8:62:73:2A:AD:32:F8:22:3F:16:89:C9:9B:FB:48:EC:9D:5C:A3:2E:21:A4:44:58:A6:71:70
a=setup:active
a=rtcp-mux
a=rtcp:22468 IN IP4 146.148.34.105
b=AS:1024
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=ssrc:1390671565 cname:kbOuYkGpr8RYrPjm
a=ssrc:1390671565 msid:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS v0
a=ssrc:1390671565 mslabel:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS
a=ssrc:1390671565 label:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSSv0
a=ice-ufrag:LFHOqQvkk3RRDJ0w
a=ice-pwd:Mq5ditVPVmjoUjkvOSa4yweJ
a=candidate:0538110337 1 udp 659136 146.148.34.105 22468 typ host generation 0
2015-08-03 02:47:54.617054 [NOTICE] mod_sofia.c:2296 Pre-Answer sofia/internal/1000 at theta.soniccloud.com!
2015-08-03 02:47:54.617054 [DEBUG] switch_channel.c:3460 (sofia/internal/1000 at theta.soniccloud.com) Callstate Change RINGING -> EARLY
2015-08-03 02:47:54.617054 [ALERT] mod_sofia.c:2296 sofia/internal/1000 at theta.soniccloud.com receive message [HEARTBEAT_EVENT]
2015-08-03 02:47:54.617054 [DEBUG] mod_sofia.c:2296 sofia/internal/1000 at theta.soniccloud.com skip receive message [HEARTBEAT_EVENT] (channel is hungup already)
nua.c:879 nua_respond() nua: nua_respond: entering
nua_stack.c:529 nua_signal() nua(0x7f511c069b50): sent signal r_respond
2015-08-03 02:47:54.617054 [DEBUG] switch_core_session.c:2761 Well, that didn't work very well did it? ...
2015-08-03 02:47:54.617054 [DEBUG] switch_core_state_machine.c:539 (sofia/internal/1000 at theta.soniccloud.com) State EXECUTE going to sleep
nua_stack.c:573 nua_stack_signal() nua(0x7f511c069b50): recv signal r_respond 183 Session Progress
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c06a3f0, ...) called
soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f511c06a3f0, (nil), 0xd40a1f, -1) called
2015-08-03 02:47:54.617054 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_HANGUP
soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f511c06a3f0, (nil), 0xd40a1f, -1) called
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1000 at theta.soniccloud.com) Callstate Change EARLY -> HANGUP
nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f511c06a3f0) called
soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7f511c06a3f0, soa_generate_answer): called
soa_static.c:1187 offer_answer_step() soa_static(0x7f511c06a3f0, soa_generate_answer): generating local description
soa_static.c:1228 offer_answer_step() soa_static(0x7f511c06a3f0, soa_generate_answer): upgrade with remote description
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f515ae72b00, 0x7f511c0b8410, ""): called
soa_static.c:1444 offer_answer_step() soa_static(0x7f511c06a3f0, soa_generate_answer): storing local description
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000 at theta.soniccloud.com) State HANGUP
soa.c:1730 soa_activate() soa_activate(static::0x7f511c06a3f0, (nil)) called
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f511c06a3f0, [(nil)], [0x7f515ae74c38], [0x7f515ae74c34]) called
2015-08-03 02:47:54.637099 [DEBUG] mod_sofia.c:431 Channel sofia/internal/1000 at theta.soniccloud.com hanging up, cause: DESTINATION_OUT_OF_ORDER
tport.c:3257 tport_tsend() tport_tsend(0x7f511c0929c0) tpn = WSS/50.242.22.166:51514
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0c0b10 126 (126)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c064382 54 (54)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0c0b8e 55 (55)
2015-08-03 02:47:54.637099 [DEBUG] mod_sofia.c:568 Responding to INVITE with: 502
nua.c:879 nua_respond() nua: nua_respond: entering
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0643b8 50 (50)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0c0bc5 505 (505)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c06c450 1596 (1596)
tport.c:3594 tport_vsend() tport_vsend(0x7f511c0929c0): 2386 bytes of 2386 to wss/50.242.22.166:51514
tport.c:3492 tport_send_msg() tport_vsend returned 2386
send 2386 bytes to wss/[50.242.22.166]:51514 at 02:47:54.638748:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK3655087;received=50.242.22.166;rport=51514
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
To: <sip:9199 at theta.soniccloud.com>;tag=3S1979S1SS36K
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7005 INVITE
nua_stack.c:529 nua_signal() nua(0x7f511c069b50): sent signal r_respond
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000 at theta.soniccloud.com Standard HANGUP, cause: DESTINATION_OUT_OF_ORDER
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000 at theta.soniccloud.com) State HANGUP going to sleep
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1000 at theta.soniccloud.com) State Change CS_HANGUP -> CS_REPORTING
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_REPORTING
Contact: <sip:9199 at 146.148.34.105:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~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: 1596
Remote-Party-ID: "9199" <sip:9199 at theta.soniccloud.com>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1438543866 1438543867 IN IP4 146.148.34.105
s=FreeSWITCH
c=IN IP4 146.148.34.105
t=0 0
a=msid-semantic: WMS 53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS
m=audio 26208 UDP/TLS/RTP/SAVPF 111 96
a=rtpmap:111 opus/48000/2
a=fmtp:111 useinbandfec=1; minptime=10; stereo=1
a=rtpmap:96 telephone-event/48000
a=silenceSupp:off - - - -
a=ptime:20
a=fingerprint:sha-256 9B:03:E4:FA:C8:C8:62:73:2A:AD:32:F8:22:3F:16:89:C9:9B:FB:48:EC:9D:5C:A3:2E:21:A4:44:58:A6:71:70
a=setup:active
a=rtcp-mux
a=rtcp:26208 IN IP4 146.148.34.105
a=ice-ufrag:nAkdk9BjADlmU454
a=ice-pwd:5JpTUV9cTQ0bwanKAyOLxfUY
a=candidate:5225391105 1 udp 659136 146.148.34.105 26208 typ host generation 0
a=ssrc:2109935738 cname:kbOuYkGpr8RYrPjm
a=ssrc:2109935738 msid:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS a0
a=ssrc:2109935738 mslabel:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS
a=ssrc:2109935738 label:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSSa0
m=video 22468 UDP/TLS/RTP/SAVPF 100
b=AS:1024
a=rtpmap:100 VP8/90000
a=fingerprint:sha-256 9B:03:E4:FA:C8:C8:62:73:2A:AD:32:F8:22:3F:16:89:C9:9B:FB:48:EC:9D:5C:A3:2E:21:A4:44:58:A6:71:70
a=setup:active
a=rtcp-mux
a=rtcp:22468 IN IP4 146.148.34.105
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=ssrc:1390671565 cname:kbOuYkGpr8RYrPjm
a=ssrc:1390671565 msid:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS v0
a=ssrc:1390671565 mslabel:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSS
a=ssrc:1390671565 label:53s6kXGlAgCCGt8v5Hr80TYx8BbcWqSSv0
a=ice-ufrag:LFHOqQvkk3RRDJ0w
a=ice-pwd:Mq5ditVPVmjoUjkvOSa4yweJ
a=candidate:0538110337 1 udp 659136 146.148.34.105 22468 typ host generation 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nta.c:6791 incoming_reply() nta: sent 183 Session Progress for INVITE (7005)
nua_session.c:4139 signal_call_state_change() nua(0x7f511c069b50): call state changed: received -> early, sent answer
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f511c06a3f0, [0x7f515ae74ce8], [0x7f515ae74cf0], [(nil)]) called
soa.c:616 soa_get_params() soa_get_params(static::0x7f511c06a3f0, ...) called
nua_stack.c:271 nua_stack_event() nua(0x7f511c069b50): event i_state 183 Session Progress
nua_stack.c:573 nua_stack_signal() nua(0x7f511c069b50): recv signal r_respond 502 Bad Gateway
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c06a3f0, ...) called
nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f511c06a3f0) called
tport.c:3257 tport_tsend() tport_tsend(0x7f511c0929c0) tpn = WSS/50.242.22.166:51514
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0b7cb0 139 (139)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c064382 54 (54)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0b7d3b 55 (55)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0643b8 50 (50)
tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7f511c092bb0 0x7f511c0b7d72 417 (417)
tport.c:3594 tport_vsend() tport_vsend(0x7f511c0929c0): 715 bytes of 715 to wss/50.242.22.166:51514
tport.c:3492 tport_send_msg() tport_vsend returned 715
send 715 bytes to wss/[50.242.22.166]:51514 at 02:47:54.640774:
------------------------------------------------------------------------
SIP/2.0 502 Bad Gateway
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK3655087;received=50.242.22.166;rport=51514
Max-Forwards: 70
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
To: <sip:9199 at theta.soniccloud.com>;tag=3S1979S1SS36K
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7005 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Reason: Q.850;cause=27;text="DESTINATION_OUT_OF_ORDER"
Content-Length: 0
Remote-Party-ID: "9199" <sip:9199 at theta.soniccloud.com>;party=calling;privacy=off;screen=no
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nta.c:6791 incoming_reply() nta: sent 502 Bad Gateway for INVITE (7005)
nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f511c069b50): removing session usage
nua_session.c:4139 signal_call_state_change() nua(0x7f511c069b50): call state changed: early -> terminated
nua_stack.c:271 nua_stack_event() nua(0x7f511c069b50): event i_state 502 Bad Gateway
nua_stack.c:271 nua_stack_event() nua(0x7f511c069b50): event i_terminated 502 Bad Gateway
soa.c:356 soa_destroy() soa_destroy(static::0x7f511c06a3f0) called
nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f511c06ab60)
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:359 nua_application_event() nua: nua_application_event: 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
nua.c:342 nua_handle_bind() nua: nua_handle_bind: 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:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f511c069b50): sent signal r_destroy
nua_stack.c:569 nua_stack_signal() nua(0x7f511c069b50): recv signal r_destroy
nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1000 at theta.soniccloud.com) State REPORTING
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1000 at theta.soniccloud.com Standard REPORTING, cause: DESTINATION_OUT_OF_ORDER
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1000 at theta.soniccloud.com) State REPORTING going to sleep
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1000 at theta.soniccloud.com) State Change CS_REPORTING -> CS_DESTROY
2015-08-03 02:47:54.637099 [DEBUG] switch_core_session.c:1639 Session 19 (sofia/internal/1000 at theta.soniccloud.com) Locked, Waiting on external entities
2015-08-03 02:47:54.637099 [NOTICE] switch_core_session.c:1657 Session 19 (sofia/internal/1000 at theta.soniccloud.com) Ended
2015-08-03 02:47:54.637099 [NOTICE] switch_core_session.c:1661 Close Channel sofia/internal/1000 at theta.soniccloud.com [CS_DESTROY]
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/1000 at theta.soniccloud.com) Running State Change CS_DESTROY
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000 at theta.soniccloud.com) State DESTROY
2015-08-03 02:47:54.637099 [DEBUG] mod_sofia.c:341 sofia/internal/1000 at theta.soniccloud.com SOFIA DESTROY
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1000 at theta.soniccloud.com Standard DESTROY
2015-08-03 02:47:54.637099 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000 at theta.soniccloud.com) State DESTROY going to sleep
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c0929c0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c0929c0)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f511c0929c0) msg 0x7f511c06ab60 from (wss/50.242.22.166:51514) has 262 bytes, veclen = 1
recv 262 bytes from wss/[50.242.22.166]:51514 at 02:47:54.694276:
------------------------------------------------------------------------
ACK sip:9199 at theta.soniccloud.com SIP/2.0
Via: SIP/2.0/WSS s0n17dlvrqjp.invalid;branch=z9hG4bK3655087
To: <sip:9199 at theta.soniccloud.com>;tag=3S1979S1SS36K
From: <sip:1000 at theta.soniccloud.com>;tag=ob96natff0
Call-ID: gv0040gcg8k6hmf8hmmu
CSeq: 7005 ACK
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f511c0929c0): bad msg 0x7f511c06ab60 (262 bytes) from wss/50.242.22.166:51514/sips next=(nil)
nta.c:2880 agent_recv_request() nta: received ACK sip:9199 at theta.soniccloud.com SIP/2.0 (CSeq 7005)
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c0929c0): reset timer
nta.c:1296 agent_timer() nta: timer set next to 30000 ms
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c032020): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c032020)
tport_type_tcp.c:302 tport_recv_stream() tport_recv_stream(0x7f511c032020): received keepalive (total 0)
tport_type_tcp.c:542 tport_tcp_pong() tport_tcp_pong(0x7f511c032020): sending PONG to tcp/172.56.12.78:30765/sip
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c032020): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f511c032020): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f511c032020)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f511c032020) msg 0x7f511c06ab60 from (tcp/172.56.12.78:30765) has 747 bytes, veclen = 1
recv 747 bytes from tcp/[172.56.12.78]:30765 at 02:47:57.735286:
------------------------------------------------------------------------
REGISTER sip:theta.soniccloud.com SIP/2.0
Via: SIP/2.0/TCP 21.218.119.176:63383;alias;branch=z9hG4bK.g1cCr-qb1;rport
From: <sip:1010 at theta.soniccloud.com>;tag=zaIBKnZ0D
To: sip:1010 at theta.soniccloud.com
CSeq: 23 REGISTER
Call-ID: SlpiJjyMrU
Max-Forwards: 70
Supported: outbound
Contact: <sip:1010 at 172.56.12.78:30765;transport=tcp>;+sip.instance="<urn:uuid:6ac30609-e495-42e2-87c0-20c2f46141a1>"
Expires: 3600
User-Agent: SonicCloudIphone/f036671 (belle-sip/1.3.3)
Content-Length: 0
Authorization: Digest realm="theta.soniccloud.com", nonce="ed3d9972-9a0e-47ee-8932-52eb1d934bc1", algorithm=MD5, username="1010", uri="sip:theta.soniccloud.com", response="c15a0767e9b6c4da0e72a6bca4af43c1", cnonce="faaad1b5", nc=00000003, qop=auth
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f511c032020): msg 0x7f511c06ab60 (747 bytes) from tcp/172.56.12.78:30765/sip next=(nil)
nta.c:2880 agent_recv_request() nta: received REGISTER sip:theta.soniccloud.com SIP/2.0 (CSeq 23)
nta.c:3174 agent_check_request_via() nta: Via check: received=172.56.12.78
nta.c:3085 agent_recv_request() nta: REGISTER (23) going to a default leg
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::0x7f511c001930, 0x7f511c001130, 0x7f511c030470) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c05b390, ...) called
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f511c030470): adding registrar usage
tport.c:4160 tport_pend() tport_pend(0x7f511c032020): pending (nil) for tcp/172.56.12.78:30765 (already 0)
nua_stack.c:271 nua_stack_event() nua(0x7f511c030470): event i_register 100 Trying
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c032020): 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
nua.c:879 nua_respond() nua: nua_respond: entering
nua_stack.c:529 nua_signal() nua(0x7f511c030470): sent signal r_respond
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f511c030470): sent signal r_destroy
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:573 nua_stack_signal() nua(0x7f511c030470): recv signal r_respond 200 OK
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f511c05b390, ...) called
tport.c:3257 tport_tsend() tport_tsend(0x7f511c032020) tpn = TCP/172.56.12.78:30765
tport.c:3594 tport_vsend() tport_vsend(0x7f511c032020): 595 bytes of 595 to tcp/172.56.12.78:30765
tport.c:3492 tport_send_msg() tport_vsend returned 595
send 595 bytes to tcp/[172.56.12.78]:30765 at 02:47:57.737558:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 21.218.119.176:63383;alias;branch=z9hG4bK.g1cCr-qb1;rport=30765;received=172.56.12.78
From: <sip:1010 at theta.soniccloud.com>;tag=zaIBKnZ0D
To: <sip:1010 at theta.soniccloud.com>;tag=42t294a5p2SSF
Call-ID: SlpiJjyMrU
CSeq: 23 REGISTER
Contact: <sip:1010 at 172.56.12.78:30765;transport=tcp>;expires=3600
Date: Mon, 03 Aug 2015 02:47:57 GMT
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c032020): reset timer
nta.c:6791 incoming_reply() nta: sent 200 OK for REGISTER (23)
nta.c:5744 incoming_free() nta: incoming_free(0x7f511c06b170)
nua_stack.c:569 nua_stack_signal() nua(0x7f511c030470): recv signal r_destroy
nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f511c030470): removing registrar usage
tport.c:4222 tport_release() tport_release(0x7f511c032020): (nil) by 0x7f511c030470 with (nil)
tport.c:2296 tport_set_secondary_timer() tport(0x7f511c032020): reset timer
nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
soa.c:356 soa_destroy() soa_destroy(static::0x7f511c05b390) called
nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
nua.c:657 nua_options() nua: nua_options: entering
nua_stack.c:529 nua_signal() nua(0x7f5124012e70): sent signal r_options
nua_stack.c:569 nua_stack_signal() nua(0x7f5124012e70): recv signal r_options
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:280 soa_clone() soa_clone(static::0x7f512c0035e0, 0x7f512c001790, 0x7f5124012e70) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f512c005ec0, ...) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f512c005ec0, ...) called
nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f512c002220, SRV, "_sip._tcp.sip.flowroute.com.") called
sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f512c002220, SRV, "_sip._tcp.sip.flowroute.com.") returned 1 entries
nta.c:10598 outgoing_query_srv() nta: for "sip.flowroute.com" query "_sip._tcp.sip.flowroute.com" SRV (cached)
sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f512c002220, A, "sip.flowroute.com.") called
sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f512c002220, A, "sip.flowroute.com.") returned 1 entries
nta.c:10803 outgoing_query_a() nta: for "sip.flowroute.com" query "sip.flowroute.com" A (cached)
nta.c:10856 outgoing_answer_a() nta: sip.flowroute.com. IN A 216.115.69.144
tport.c:3257 tport_tsend() tport_tsend(0x7f512c004d30) tpn = tcp/216.115.69.144:5060
tport.c:4046 tport_resolve() tport_resolve addrinfo = 216.115.69.144:5060
tport.c:4677 tport_by_addrinfo() tport_by_addrinfo(0x7f512c004d30): found 0x7f512c0158d0 by name tcp/216.115.69.144:5060
tport.c:3594 tport_vsend() tport_vsend(0x7f512c0158d0): 560 bytes of 560 to tcp/216.115.69.144:5060
tport.c:3492 tport_send_msg() tport_vsend returned 560
send 560 bytes to tcp/[216.115.69.144]:5060 at 02:48:03.310658:
------------------------------------------------------------------------
OPTIONS sip:sip.flowroute.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 146.148.34.105:5080;rport;branch=z9hG4bKNK4cg9Ztjpa5m
Max-Forwards: 70
From: <sip:sip.flowroute.com>;tag=037FrZQ04j4Nr
To: <sip:sip.flowroute.com>
Call-ID: e6e01684-b42c-1233-a1a1-42010af0a802
CSeq: 78946384 OPTIONS
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f512c0158d0): reset timer
nta.c:8304 outgoing_send() nta: sent OPTIONS (78946384) to tcp/216.115.69.144:5060
tport.c:4160 tport_pend() tport_pend(0x7f512c0158d0): pending 0x7f512c03df00 for tcp/216.115.69.144:5060 (already 1)
tport.c:2773 tport_wakeup() tport_wakeup(0x7f512c0158d0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f512c0158d0)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f512c0158d0) msg 0x7f512c03e370 from (tcp/216.115.69.144:5060) has 372 bytes, veclen = 1
recv 372 bytes from tcp/[216.115.69.144]:5060 at 02:48:03.359954:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 146.148.34.105:5080;rport=44102;branch=z9hG4bKNK4cg9Ztjpa5m
From: <sip:sip.flowroute.com>;tag=037FrZQ04j4Nr
To: <sip:sip.flowroute.com>;tag=20e1698a3241cbcc6677a39fcb65a0aa.4ecd
Call-ID: e6e01684-b42c-1233-a1a1-42010af0a802
CSeq: 78946384 OPTIONS
Accept: */*
Accept-Encoding:
Accept-Language: en
Supported:
Content-Length: 0
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f512c0158d0): msg 0x7f512c03e370 (372 bytes) from tcp/216.115.69.144:5060/sip next=(nil)
nta.c:3299 agent_recv_response() nta: received 200 OK for OPTIONS (78946384)
nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 49.426 ms
tport.c:4222 tport_release() tport_release(0x7f512c0158d0): 0x7f512c03df00 by 0x7f512c042720 with 0x7f512c03e370
nua_stack.c:271 nua_stack_event() nua(0x7f5124012e70): event r_options 200 OK
nta.c:8722 outgoing_free() nta: outgoing_free(0x7f512c042720)
tport.c:2296 tport_set_secondary_timer() tport(0x7f512c0158d0): 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
nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f5124012e70): sent signal r_destroy
nua_stack.c:569 nua_stack_signal() nua(0x7f5124012e70): recv signal r_destroy
nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
soa.c:356 soa_destroy() soa_destroy(static::0x7f512c005ec0) called
tport.c:2773 tport_wakeup() tport_wakeup(0x7f512c0158d0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f512c0158d0)
tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f512c0158d0) msg 0x7f512c0150d0 from (tcp/216.115.69.144:5060) has 564 bytes, veclen = 1
recv 564 bytes from tcp/[216.115.69.144]:5060 at 02:48:04.419999:
------------------------------------------------------------------------
OPTIONS sip:146.148.34.105:44102;transport=tcp SIP/2.0
Max-Forwards: 10
Record-Route: <sip:216.115.69.144;transport=tcp;r2=on;lr>
Record-Route: <sip:216.115.69.144;r2=on;lr>
Via: SIP/2.0/TCP 216.115.69.144;branch=z9hG4bK7abf.b1ec7ed77a1020c1c641a34dedb8edfd.0
Via: SIP/2.0/UDP 216.115.69.131:5060;branch=0
Route: <sip:216.115.69.144;lr;received='sip:146.148.34.105:44102;transport=tcp'>
From: sip:ping at invalid;tag=a66f906f
To: sip:146.148.34.105:44102;transport=tcp
Call-ID: 95f5da82-0beffb31-6ae1f52 at 216.115.69.131
CSeq: 1 OPTIONS
Content-Length: 0
------------------------------------------------------------------------
tport.c:3023 tport_deliver() tport_deliver(0x7f512c0158d0): msg 0x7f512c0150d0 (564 bytes) from tcp/216.115.69.144:5060/sip next=(nil)
nta.c:2880 agent_recv_request() nta: received OPTIONS sip:146.148.34.105:44102;transport=tcp SIP/2.0 (CSeq 1)
nta.c:3085 agent_recv_request() nta: OPTIONS (1) going to a default leg
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::0x7f512c0035e0, 0x7f512c001790, 0x7f512c017c50) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f512c042a20, ...) called
nua_stack.c:271 nua_stack_event() nua(0x7f512c017c50): event i_options 100 Trying
tport.c:2296 tport_set_secondary_timer() tport(0x7f512c0158d0): 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
nua.c:879 nua_respond() nua: nua_respond: entering
nua_stack.c:529 nua_signal() nua(0x7f512c017c50): sent signal r_respond
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f512c017c50): sent signal r_destroy
nua_stack.c:573 nua_stack_signal() nua(0x7f512c017c50): recv signal r_respond 200 OK
nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f512c042a20, ...) called
soa.c:845 soa_get_capability_sdp() soa_get_capability_sdp(static::0x7f512c042a20, [(nil)], [0x7f51590b4c68], [0x7f51590b4c64]) called
tport.c:3257 tport_tsend() tport_tsend(0x7f512c0158d0) tpn = TCP/216.115.69.144:5060
tport.c:3594 tport_vsend() tport_vsend(0x7f512c0158d0): 813 bytes of 813 to tcp/216.115.69.144:5060
tport.c:3492 tport_send_msg() tport_vsend returned 813
send 813 bytes to tcp/[216.115.69.144]:5060 at 02:48:04.420276:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 216.115.69.144;branch=z9hG4bK7abf.b1ec7ed77a1020c1c641a34dedb8edfd.0;rport=5060
Via: SIP/2.0/UDP 216.115.69.131:5060;branch=0
Record-Route: <sip:216.115.69.144;transport=tcp;r2=on;lr>
Record-Route: <sip:216.115.69.144;r2=on;lr>
From: sip:ping at invalid;tag=a66f906f
To: <sip:146.148.34.105:44102>;transport=tcp;tag=1c18St831Ut8K
Call-ID: 95f5da82-0beffb31-6ae1f52 at 216.115.69.131
CSeq: 1 OPTIONS
Contact: <sip:gw+flowroute at 146.148.34.105:5080;tport=tcp;transport=tcp;gw=flowroute>
User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20150730T031634Z~01672dc96b~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-Length: 0
------------------------------------------------------------------------
tport.c:2296 tport_set_secondary_timer() tport(0x7f512c0158d0): reset timer
nta.c:6791 incoming_reply() nta: sent 200 OK for OPTIONS (1)
nta.c:5744 incoming_free() nta: incoming_free(0x7f512c041cf0)
nua_stack.c:569 nua_stack_signal() nua(0x7f512c017c50): recv signal r_destroy
nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
soa.c:356 soa_destroy() soa_destroy(static::0x7f512c042a20) called
freeswitch at internal>
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list