recv 1031 bytes from udp/[192.168.80.65]:5060 at 10:25:57.644013: ------------------------------------------------------------------------ INVITE sip:800981234@192.168.80.26:5060 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK773e.16ed8dd7.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK16215 From: ;tag=15724 To: Call-ID: 11478 CSeq: 21 INVITE Contact: Content-Type: application/sdp Max-Forwards: 69 User-Agent: navamessenger Subject: This is a call for a conversation Content-Length: 433 P-hint: outbound v=0 o=navamessenger 0 0 IN IP4 192.168.80.30 s=navamessenger c=IN IP4 192.168.80.30 t=0 0 m=audio 21574 RTP/AVP 107 18 0 8 101 a=rtpmap:107 opus/48000/2 a=fmtp:107 maxplaybackrate=48000; sprop-maxcapturerate=48000 a=ptime:20 a=maxptime:20 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 a=sendrecv a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=nortpproxy:yes ------------------------------------------------------------------------ 2019-04-30 10:25:57.641516 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/16144444444@192.168.80.65 [3aae4d2b-e731-4929-98ae-0fbb7910e1ec] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_NEW (Cur 1 Tot 6506) 2019-04-30 10:25:57.641516 [DEBUG] sofia.c:10092 sofia/internal/16144444444@192.168.80.65 receiving invite from 192.168.80.65:5060 version: 1.8.4 git 749a6e1 2018-12-27 01:10:58Z 64bit 2019-04-30 10:25:57.641516 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444@192.168.80.65 entering state [received][100] 2019-04-30 10:25:57.641516 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=navamessenger 0 0 IN IP4 192.168.80.30 s=navamessenger c=IN IP4 192.168.80.30 t=0 0 m=audio 21574 RTP/AVP 107 18 0 8 101 a=rtpmap:107 opus/48000/2 a=fmtp:107 maxplaybackrate=48000; sprop-maxcapturerate=48000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=maxptime:20 a=ptime:20 a=nortpproxy:yes 2019-04-30 10:25:57.641516 [DEBUG] sofia.c:7695 (sofia/internal/16144444444@192.168.80.65) State Change CS_NEW -> CS_INIT 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/16144444444@192.168.80.65) State NEW 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_INIT (Cur 1 Tot 6506) 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/16144444444@192.168.80.65) State INIT 2019-04-30 10:25:57.641516 [DEBUG] mod_sofia.c:93 sofia/internal/16144444444@192.168.80.65 SOFIA INIT 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:40 sofia/internal/16144444444@192.168.80.65 Standard INIT 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/16144444444@192.168.80.65) State Change CS_INIT -> CS_ROUTING 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/16144444444@192.168.80.65) State INIT going to sleep 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_ROUTING (Cur 1 Tot 6506) 2019-04-30 10:25:57.641516 [DEBUG] switch_channel.c:2249 (sofia/internal/16144444444@192.168.80.65) Callstate Change DOWN -> RINGING 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/16144444444@192.168.80.65) State ROUTING 2019-04-30 10:25:57.641516 [DEBUG] mod_sofia.c:154 sofia/internal/16144444444@192.168.80.65 SOFIA ROUTING 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:236 sofia/internal/16144444444@192.168.80.65 Standard ROUTING 2019-04-30 10:25:57.641516 [INFO] mod_dialplan_xml.c:637 Processing 16144444444 <16144444444>->800981234 in context sgas send 303 bytes to udp/[192.168.80.65]:5060 at 10:25:57.647334: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK773e.16ed8dd7.0 From: ;tag=15724 To: Call-ID: 11478 CSeq: 21 INVITE User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit Content-Length: 0 ------------------------------------------------------------------------ Dialplan: sofia/internal/16144444444@192.168.80.65 parsing [sgas->park] continue=false Dialplan: sofia/internal/16144444444@192.168.80.65 Regex (FAIL) [park] destination_number(800981234) =~ /^park$/ break=on-false Dialplan: sofia/internal/16144444444@192.168.80.65 parsing [sgas->park] continue=false Dialplan: sofia/internal/16144444444@192.168.80.65 Regex (FAIL) [park] destination_number(800981234) =~ /^hold|999$/ break=on-false Dialplan: sofia/internal/16144444444@192.168.80.65 parsing [sgas->add-to-conf] continue=false Dialplan: sofia/internal/16144444444@192.168.80.65 Regex (FAIL) [add-to-conf] destination_number(800981234) =~ /^add_to_conf$/ break=on-false Dialplan: sofia/internal/16144444444@192.168.80.65 parsing [sgas->conf] continue=false Dialplan: sofia/internal/16144444444@192.168.80.65 Regex (FAIL) [conf] destination_number(800981234) =~ /^conf-(.*)$/ break=on-false Dialplan: sofia/internal/16144444444@192.168.80.65 parsing [sgas->nava-rec] continue=false Dialplan: sofia/internal/16144444444@192.168.80.65 Regex (FAIL) [nava-rec] destination_number(800981234) =~ /^800980000$/ break=on-false Dialplan: sofia/internal/16144444444@192.168.80.65 parsing [sgas->nava-conf] continue=false Dialplan: sofia/internal/16144444444@192.168.80.65 Regex (PASS) [nava-conf] destination_number(800981234) =~ /^800981234$/ break=on-false Dialplan: sofia/internal/16144444444@192.168.80.65 Action conference(test) 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/16144444444@192.168.80.65) State Change CS_ROUTING -> CS_EXECUTE 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/16144444444@192.168.80.65) State ROUTING going to sleep 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_EXECUTE (Cur 1 Tot 6506) 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/16144444444@192.168.80.65) State EXECUTE 2019-04-30 10:25:57.641516 [DEBUG] mod_sofia.c:209 sofia/internal/16144444444@192.168.80.65 SOFIA EXECUTE 2019-04-30 10:25:57.641516 [DEBUG] switch_core_state_machine.c:328 sofia/internal/16144444444@192.168.80.65 Standard EXECUTE 2019-04-30 10:25:57.641516 [DEBUG] switch_core_session.c:2710 Application conference Requires media! pre_answering channel sofia/internal/16144444444@192.168.80.65 2019-04-30 10:25:57.641516 [INFO] switch_core_session.c:2712 Sending early media 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:107:48000:20:0:1]/[opus:116:48000:20:0:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:107:48000:20:0:1]/[G729:18:8000:20:8000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:107:48000:20:0:1]/[G722:9:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:107:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:107:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000 2019-04-30 10:25:57.641516 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2019-04-30 10:25:57.641516 [DEBUG] mod_opus.c:636 Opus encoder: CBR mode enabled 2019-04-30 10:25:57.641516 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2019-04-30 10:25:57.641516 [DEBUG] mod_opus.c:636 Opus encoder: CBR mode enabled 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/16144444444@192.168.80.65 opus/48000 20 ms 960 samples 0 bits 1 channels 2019-04-30 10:25:57.641516 [DEBUG] switch_core_codec.c:111 sofia/internal/16144444444@192.168.80.65 Original read codec set to opus:116 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:5795 sofia/internal/16144444444@192.168.80.65 Set 2833 dtmf send payload to 101 recv payload to 101 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/16144444444@192.168.80.65] 192.168.80.26 port 20102 -> 192.168.80.30 port 21574 codec: 107 ms: 20 2019-04-30 10:25:57.641516 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 960 bytes per 20ms 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:8815 sofia/internal/16144444444@192.168.80.65 Set 2833 dtmf send payload to 101 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:8822 sofia/internal/16144444444@192.168.80.65 Set 2833 dtmf receive payload to 101 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:8845 sofia/internal/16144444444@192.168.80.65 Set rtp dtmf delay to 40 2019-04-30 10:25:57.641516 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/16144444444@192.168.80.65! 2019-04-30 10:25:57.641516 [DEBUG] switch_channel.c:3482 (sofia/internal/16144444444@192.168.80.65) Callstate Change RINGING -> EARLY 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:8494 Audio params are unchanged for sofia/internal/16144444444@192.168.80.65. 2019-04-30 10:25:57.641516 [DEBUG] mod_sofia.c:2504 Ring SDP: v=0 o=FreeSWITCH 1556583655 1556583656 IN IP4 192.168.80.26 s=FreeSWITCH c=IN IP4 192.168.80.26 t=0 0 m=audio 20102 RTP/AVP 107 101 a=rtpmap:107 opus/48000/2 a=fmtp:107 useinbandfec=1; cbr=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv EXECUTE sofia/internal/16144444444@192.168.80.65 conference(test) send 1308 bytes to udp/[192.168.80.65]:5060 at 10:25:57.652760: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK773e.16ed8dd7.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK16215 Record-Route: From: ;tag=15724 To: ;tag=1KtDvQQgUy9vD Call-ID: 11478 CSeq: 21 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 263 Remote-Party-ID: "800981234" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1556583655 1556583656 IN IP4 192.168.80.26 s=FreeSWITCH c=IN IP4 192.168.80.26 t=0 0 m=audio 20102 RTP/AVP 107 101 a=rtpmap:107 opus/48000/2 a=fmtp:107 useinbandfec=1; cbr=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2019-04-30 10:25:57.641516 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444@192.168.80.65 entering state [early][183] 2019-04-30 10:25:57.641516 [DEBUG] switch_core_media.c:8494 Audio params are unchanged for sofia/internal/16144444444@192.168.80.65. 2019-04-30 10:25:57.641516 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/16144444444@192.168.80.65: v=0 o=FreeSWITCH 1556583655 1556583657 IN IP4 192.168.80.26 s=FreeSWITCH c=IN IP4 192.168.80.26 t=0 0 m=audio 20102 RTP/AVP 107 101 a=rtpmap:107 opus/48000/2 a=fmtp:107 useinbandfec=1; cbr=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1277 bytes to udp/[192.168.80.65]:5060 at 10:25:57.653931: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK773e.16ed8dd7.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK16215 Record-Route: From: ;tag=15724 To: ;tag=1KtDvQQgUy9vD Call-ID: 11478 CSeq: 21 INVITE Contact: ;isfocus User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 263 Remote-Party-ID: "800981234" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1556583655 1556583656 IN IP4 192.168.80.26 s=FreeSWITCH c=IN IP4 192.168.80.26 t=0 0 m=audio 20102 RTP/AVP 107 101 a=rtpmap:107 opus/48000/2 2019-04-30 10:25:57.641516 [NOTICE] mod_conference.c:1885 Channel [sofia/internal/16144444444@192.168.80.65] has been answered a=fmtp:107 useinbandfec=1; cbr=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2019-04-30 10:25:57.641516 [DEBUG] switch_channel.c:3781 (sofia/internal/16144444444@192.168.80.65) Callstate Change EARLY -> ACTIVE 2019-04-30 10:25:57.641516 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444@192.168.80.65 entering state [completed][200] 2019-04-30 10:25:57.641516 [DEBUG] mod_conference.c:3384 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie 2019-04-30 10:25:57.641516 [DEBUG] conference_member.c:1758 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2019-04-30 10:25:57.641516 [DEBUG] mod_conference.c:233 Setup timer success interval: 20 samples: 160 2019-04-30 10:25:57.641516 [DEBUG] conference_member.c:1805 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2019-04-30 10:25:57.641516 [DEBUG] switch_core_codec.c:223 sofia/internal/16144444444@192.168.80.65 Push codec L16:100 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '0' to 'mute' 2019-04-30 10:25:57.661517 [INFO] switch_ivr_async.c:219 Digit parser mod_conference: Setting realm to 'conf' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 0/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b03e8 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '*' to 'deaf mute' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding */conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0418 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '9' to 'energy up' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0448 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '8' to 'energy equ' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 8/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0478 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '7' to 'energy dn' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b04a8 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '3' to 'vol talk up' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 3/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b04d8 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '2' to 'vol talk zero' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 2/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0508 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '1' to 'vol talk dn' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 1/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0538 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '6' to 'vol listen up' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 6/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0568 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '5' to 'vol listen zero' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 5/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b0598 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '4' to 'vol listen dn' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 4/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b05c8 2019-04-30 10:25:57.661517 [DEBUG] conference_member.c:105 sofia/internal/16144444444@192.168.80.65 binding '#' to 'hangup' 2019-04-30 10:25:57.661517 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding #/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8402b05f8 2019-04-30 10:25:57.661517 [DEBUG] conference_loop.c:1334 Setup timer soft success interval: 20 samples: 960 from codec opus 2019-04-30 10:25:57.661517 [DEBUG] mod_local_stream.c:907 Opening Stream [moh/8000] 8000hz 2019-04-30 10:25:57.681509 [NOTICE] switch_core_media.c:15578 Activating write resampler 2019-04-30 10:25:57.881529 [DEBUG] conference_member.c:1758 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2019-04-30 10:25:57.881529 [DEBUG] conference_member.c:1805 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2019-04-30 10:25:57.881529 [DEBUG] conference_loop.c:1334 Setup timer soft success interval: 20 samples: 960 from codec opus recv 740 bytes from udp/[192.168.80.65]:5060 at 10:25:57.962387: ------------------------------------------------------------------------ ACK sip:800981234@192.168.80.26:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK773e.16ed8dd7.2 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK31547 From: ;tag=15724 To: ;tag=1KtDvQQgUy9vD Call-ID: 11478 CSeq: 21 ACK Contact: Proxy-Authorization: Digest username="16144444444", realm="192.168.80.65", nonce="5cc7e38b0000e67c7cdb6a068b832a3d08e2715e0d147afd", uri="sip:800981234@192.168.80.40:5060", response="328513d9102634924edcb49646e32031", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001 Max-Forwards: 69 User-Agent: navamessenger Content-Length: 0 ------------------------------------------------------------------------ 2019-04-30 10:25:57.961579 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444@192.168.80.65 entering state [ready][200] 2019-04-30 10:25:58.101569 [DEBUG] switch_rtp.c:7550 Correct audio ip/port confirmed. recv 715 bytes from udp/[192.168.80.65]:5060 at 10:26:03.644411: ------------------------------------------------------------------------ BYE sip:800981234@192.168.80.26:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK473e.b18ae6d1.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK26962 From: ;tag=15724 To: ;tag=1KtDvQQgUy9vD Call-ID: 11478 CSeq: 22 BYE Proxy-Authorization: Digest username="16144444444", realm="192.168.80.65", nonce="5cc7e38b0000e67c7cdb6a068b832a3d08e2715e0d147afd", uri="sip:800981234@192.168.80.40:49263;transport=udp;nat=yes", response="80bd7bdd075fd33cb0234defe0c2ce01", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000002 Max-Forwards: 69 User-Agent: navamessenger Content-Length: 0 ------------------------------------------------------------------------ 2019-04-30 10:26:03.641566 [NOTICE] sofia.c:1079 Hangup sofia/internal/16144444444@192.168.80.65 [CS_EXECUTE] [NORMAL_CLEARING] send 551 bytes to udp/[192.168.80.65]:5060 at 10:26:03.653086: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK473e.b18ae6d1.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK26962 From: ;tag=15724 To: ;tag=1KtDvQQgUy9vD Call-ID: 11478 CSeq: 22 BYE User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2019-04-30 10:26:03.661518 [INFO] conference_loop.c:1670 Channel leaving conference, cause: NORMAL_CLEARING 2019-04-30 10:26:03.661518 [DEBUG] mod_conference.c:2467 sofia/internal/16144444444@192.168.80.65 skip receive message [UNBRIDGE] (channel is hungup already) 2019-04-30 10:26:03.661518 [DEBUG] switch_core_media.c:12213 sofia/internal/16144444444@192.168.80.65 skip receive message [HARD_MUTE] (channel is hungup already) 2019-04-30 10:26:03.661518 [DEBUG] switch_core_codec.c:260 Restore original codec. 2019-04-30 10:26:03.661518 [DEBUG] switch_core_session.c:2887 sofia/internal/16144444444@192.168.80.65 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/16144444444@192.168.80.65) State EXECUTE going to sleep 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_HANGUP (Cur 1 Tot 6506) 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/16144444444@192.168.80.65) Callstate Change ACTIVE -> HANGUP 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/16144444444@192.168.80.65) State HANGUP 2019-04-30 10:26:03.661518 [DEBUG] mod_sofia.c:449 Channel sofia/internal/16144444444@192.168.80.65 hanging up, cause: NORMAL_CLEARING 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:60 sofia/internal/16144444444@192.168.80.65 Standard HANGUP, cause: NORMAL_CLEARING 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/16144444444@192.168.80.65) State HANGUP going to sleep 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/16144444444@192.168.80.65) State Change CS_HANGUP -> CS_REPORTING 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_REPORTING (Cur 1 Tot 6506) 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/16144444444@192.168.80.65) State REPORTING 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:174 sofia/internal/16144444444@192.168.80.65 Standard REPORTING, cause: NORMAL_CLEARING 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/16144444444@192.168.80.65) State REPORTING going to sleep 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/16144444444@192.168.80.65) State Change CS_REPORTING -> CS_DESTROY 2019-04-30 10:26:03.661518 [DEBUG] switch_core_session.c:1715 Session 6506 (sofia/internal/16144444444@192.168.80.65) Locked, Waiting on external entities 2019-04-30 10:26:03.661518 [NOTICE] switch_core_session.c:1733 Session 6506 (sofia/internal/16144444444@192.168.80.65) Ended 2019-04-30 10:26:03.661518 [NOTICE] switch_core_session.c:1737 Close Channel sofia/internal/16144444444@192.168.80.65 [CS_DESTROY] 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:738 (sofia/internal/16144444444@192.168.80.65) Running State Change CS_DESTROY (Cur 0 Tot 6506) 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/16144444444@192.168.80.65) State DESTROY 2019-04-30 10:26:03.661518 [DEBUG] mod_sofia.c:354 sofia/internal/16144444444@192.168.80.65 SOFIA DESTROY 2019-04-30 10:26:03.661518 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[265] PLC[0] FEC[0] 2019-04-30 10:26:03.661518 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2019-04-30 10:26:03.661518 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2019-04-30 10:26:03.661518 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[298] Bytes encoded[38144] Encoded length ms[5960] Average encoded bitrate bps[61030] 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:181 sofia/internal/16144444444@192.168.80.65 Standard DESTROY 2019-04-30 10:26:03.661518 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/16144444444@192.168.80.65) State DESTROY going to sleep 2019-04-30 10:26:03.661518 [DEBUG] mod_conference.c:833 Write Lock ON 2019-04-30 10:26:03.661518 [DEBUG] mod_conference.c:836 Write Lock OFF