2019-04-30 10:24:41.201567 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables 2019-04-30 10:24:41.201567 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/16144444444 [e2657cb0-7dea-4ad1-a999-ef0519157363] 2019-04-30 10:24:41.201567 [DEBUG] mod_sofia.c:5018 (sofia/internal/16144444444) State Change CS_NEW -> CS_INIT 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444) Running State Change CS_INIT (Cur 1 Tot 6504) 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/16144444444) State INIT 2019-04-30 10:24:41.201567 [DEBUG] mod_sofia.c:93 sofia/internal/16144444444 SOFIA INIT 2019-04-30 10:24:41.201567 [DEBUG] sofia_glue.c:1302 sofia/internal/16144444444 sending invite version: 1.8.4 git 749a6e1 2018-12-27 01:10:58Z 64bit Local SDP: v=0 o=FreeSWITCH 1556576821 1556576822 IN IP4 192.168.80.26 s=FreeSWITCH c=IN IP4 192.168.80.26 t=0 0 m=audio 26860 RTP/AVP 102 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; cbr=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 a=rtpmap:101 telephone-event/48000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:40 sofia/internal/16144444444 Standard INIT 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/16144444444) State Change CS_INIT -> CS_ROUTING 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/16144444444) State INIT going to sleep 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444) Running State Change CS_ROUTING (Cur 1 Tot 6504) 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/16144444444) State ROUTING 2019-04-30 10:24:41.201567 [DEBUG] mod_sofia.c:154 sofia/internal/16144444444 SOFIA ROUTING 2019-04-30 10:24:41.201567 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/16144444444) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/16144444444) State ROUTING going to sleep 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 6504) 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/16144444444) State CONSUME_MEDIA send 1311 bytes to udp/[192.168.80.65]:5060 at 10:24:41.210694: ------------------------------------------------------------------------ INVITE sip:16144444444@192.168.80.65 SIP/2.0 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/16144444444) State CONSUME_MEDIA going to sleep Via: SIP/2.0/UDP 192.168.80.26;rport;branch=z9hG4bKrpZN0vvD50a9D Max-Forwards: 70 From: "" ;tag=XFNaNBm26tgjF To: Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 3748048 INVITE Contact: 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: 348 X-FS-Support: update_display,send_info Remote-Party-ID: ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1556576821 1556576822 IN IP4 192.168.80.26 s=FreeSWITCH c=IN IP4 192.168.80.26 t=0 0 m=audio 26860 RTP/AVP 102 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; cbr=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 a=rtpmap:101 telephone-event/48000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2019-04-30 10:24:41.201567 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [calling][0] recv 347 bytes from udp/[192.168.80.65]:5060 at 10:24:41.219184: ------------------------------------------------------------------------ SIP/2.0 100 Giving a try Via: SIP/2.0/UDP 192.168.80.26;received=192.168.80.26;rport=5060;branch=z9hG4bKrpZN0vvD50a9D From: "" ;tag=XFNaNBm26tgjF To: Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 3748048 INVITE Server: OpenSIPS (2.3.6 (x86_64/linux)) Content-Length: 0 ------------------------------------------------------------------------ recv 454 bytes from udp/[192.168.80.65]:5060 at 10:24:41.460118: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.80.26;received=192.168.80.26;rport=5060;branch=z9hG4bKrpZN0vvD50a9D Record-Route: From: "" ;tag=XFNaNBm26tgjF To: ;tag=41 Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 3748048 INVITE Contact: User-Agent: navamessenger Content-Length: 0 ------------------------------------------------------------------------ 2019-04-30 10:24:41.461519 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [proceeding][180] 2019-04-30 10:24:41.461519 [NOTICE] sofia.c:7401 Ring-Ready sofia/internal/16144444444! 2019-04-30 10:24:41.461519 [DEBUG] switch_channel.c:3354 (sofia/internal/16144444444) Callstate Change DOWN -> RINGING recv 507 bytes from tcp/[107.172.39.18]:50091 at 10:24:42.113901: ------------------------------------------------------------------------ REGISTER sip:192.168.80.26:5060 SIP/2.0 Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK0748c5abdc8a4f7a9bb0619510b2b90b;rport To: "72" From: "72";tag=opj865wnwu CSeq: 1 REGISTER Call-ID: d80e2c1a96a748e0aeac948c30920190 Max-Forwards: 70 Contact: User-Agent: UsaAirport Content-Length: 0 Expires: 3600 Supported: 100rel Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE ------------------------------------------------------------------------ send 648 bytes to tcp/[107.172.39.18]:50091 at 10:24:42.115467: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK0748c5abdc8a4f7a9bb0619510b2b90b;rport=50091 From: "72";tag=opj865wnwu To: "72" ;tag=yre3p6453364a Call-ID: d80e2c1a96a748e0aeac948c30920190 CSeq: 1 REGISTER 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 WWW-Authenticate: Digest realm="192.168.80.26", nonce="e224a4b7-97ad-4fe2-ba02-9f65b80e75da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 782 bytes from tcp/[107.172.39.18]:50091 at 10:24:42.338703: ------------------------------------------------------------------------ REGISTER sip:192.168.80.26:5060 SIP/2.0 Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK11a18b6ea5664e7d8c3f723c438ce6b1;rport To: "72" From: "72";tag=opj865wnwu CSeq: 2 REGISTER Call-ID: d80e2c1a96a748e0aeac948c30920190 Max-Forwards: 70 Contact: User-Agent: UsaAirport Content-Length: 0 Expires: 3600 Supported: 100rel Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE Authorization: Digest username="72",realm="192.168.80.26",nonce="e224a4b7-97ad-4fe2-ba02-9f65b80e75da",uri="sip:80.191.36.20",response="9096a4c90d9938594c0591b7120dc528",cnonce="ca6404a106f2488e9f021475fb28fb7f",nc=00000001,qop=auth,algorithm=MD5 ------------------------------------------------------------------------ 2019-04-30 10:24:42.321559 [WARNING] sofia_reg.c:2935 Can't find user [72@192.168.80.26] from 107.172.39.18 You must define a domain called '192.168.80.26' in your directory and add a user with the id="72" attribute and you must configure your device to use the proper domain in it's authentication credentials. send 524 bytes to tcp/[107.172.39.18]:50091 at 10:24:42.340561: ------------------------------------------------------------------------ SIP/2.0 403 Forbidden Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK11a18b6ea5664e7d8c3f723c438ce6b1;rport=50091 From: "72";tag=opj865wnwu To: "72" ;tag=Z17Ur1N90cXQp Call-ID: d80e2c1a96a748e0aeac948c30920190 CSeq: 2 REGISTER 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 ------------------------------------------------------------------------ recv 915 bytes from udp/[192.168.80.65]:5060 at 10:24:46.193643: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.80.26;received=192.168.80.26;rport=5060;branch=z9hG4bKrpZN0vvD50a9D Record-Route: From: "" ;tag=XFNaNBm26tgjF To: ;tag=41 Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 3748048 INVITE Contact: Content-Type: application/sdp User-Agent: navamessenger Content-Length: 433 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 23816 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:24:46.181580 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [completing][200] 2019-04-30 10:24:46.181580 [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 23816 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:24:46.181580 [NOTICE] sofia.c:7304 Pre-Answer sofia/internal/16144444444! 2019-04-30 10:24:46.181580 [DEBUG] switch_channel.c:3482 (sofia/internal/16144444444) Callstate Change RINGING -> EARLY send 452 bytes to udp/[192.168.80.65]:5060 at 10:24:46.197176: ------------------------------------------------------------------------ ACK sip:16144444444@80.191.36.252:51544;nat=yes SIP/2.0 Via: SIP/2.0/UDP 192.168.80.26;rport;branch=z9hG4bKSZre2QDH290US Route: Max-Forwards: 70 From: "" ;tag=XFNaNBm26tgjF To: ;tag=41 Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 3748048 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 2019-04-30 10:24:46.181580 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [ready][200] 2019-04-30 10:24:46.181580 [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:24:46.181580 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2019-04-30 10:24:46.181580 [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:24:46.181580 [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:24:46.181580 [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:24:46.181580 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:636 Opus encoder: CBR mode enabled 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:636 Opus encoder: CBR mode enabled 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/16144444444 opus/48000 20 ms 960 samples 0 bits 1 channels 2019-04-30 10:24:46.181580 [DEBUG] switch_core_codec.c:111 sofia/internal/16144444444 Original read codec set to opus:116 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:5795 sofia/internal/16144444444 Set 2833 dtmf send payload to 101 recv payload to 101 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/16144444444] 192.168.80.26 port 26860 -> 192.168.80.30 port 23816 codec: 107 ms: 20 2019-04-30 10:24:46.181580 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 960 bytes per 20ms 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8815 sofia/internal/16144444444 Set 2833 dtmf send payload to 101 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8822 sofia/internal/16144444444 Set 2833 dtmf receive payload to 101 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8845 sofia/internal/16144444444 Set rtp dtmf delay to 40 2019-04-30 10:24:46.181580 [NOTICE] sofia.c:8429 Channel [sofia/internal/16144444444] has been answered 2019-04-30 10:24:46.181580 [DEBUG] switch_channel.c:3781 (sofia/internal/16144444444) Callstate Change EARLY -> ACTIVE 2019-04-30 10:24:46.201509 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/internal/16144444444] 2019-04-30 10:24:46.201509 [INFO] switch_channel.c:3130 sofia/internal/16144444444 Flipping CID from "" <0000000000> to "Outbound Call" <16144444444> 2019-04-30 10:24:46.201509 [DEBUG] mod_commands.c:5072 (sofia/internal/16144444444) State Change CS_CONSUME_MEDIA -> CS_EXECUTE 2019-04-30 10:24:46.201509 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444) Running State Change CS_EXECUTE (Cur 1 Tot 6504) 2019-04-30 10:24:46.201509 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/16144444444) State EXECUTE 2019-04-30 10:24:46.201509 [DEBUG] mod_sofia.c:209 sofia/internal/16144444444 SOFIA EXECUTE 2019-04-30 10:24:46.201509 [DEBUG] switch_core_state_machine.c:328 sofia/internal/16144444444 Standard EXECUTE EXECUTE sofia/internal/16144444444 conference(test) 2019-04-30 10:24:46.201509 [DEBUG] mod_conference.c:3384 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie 2019-04-30 10:24:46.201509 [DEBUG] conference_member.c:1758 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2019-04-30 10:24:46.201509 [DEBUG] mod_conference.c:233 Setup timer success interval: 20 samples: 160 2019-04-30 10:24:46.201509 [DEBUG] conference_member.c:1805 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2019-04-30 10:24:46.201509 [DEBUG] switch_core_codec.c:223 sofia/internal/16144444444 Push codec L16:100 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '0' to 'mute' 2019-04-30 10:24:46.221518 [INFO] switch_ivr_async.c:219 Digit parser mod_conference: Setting realm to 'conf' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 0/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2eb8 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '*' to 'deaf mute' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding */conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2ee8 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '9' to 'energy up' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2f18 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '8' to 'energy equ' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 8/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2f48 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '7' to 'energy dn' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2f78 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '3' to 'vol talk up' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 3/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2fa8 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '2' to 'vol talk zero' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 2/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2fd8 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '1' to 'vol talk dn' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 1/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b3008 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '6' to 'vol listen up' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 6/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b3038 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '5' to 'vol listen zero' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 5/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b3068 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '4' to 'vol listen dn' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding 4/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b3098 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '#' to 'hangup' 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding #/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b30c8 2019-04-30 10:24:46.221518 [DEBUG] conference_loop.c:1334 Setup timer soft success interval: 20 samples: 960 from codec opus 2019-04-30 10:24:46.221518 [DEBUG] conference_loop.c:1492 Outbound conference channel answered, setting CFLAG_ANSWERED 2019-04-30 10:24:46.221518 [DEBUG] mod_local_stream.c:907 Opening Stream [moh/8000] 8000hz 2019-04-30 10:24:46.241506 [NOTICE] switch_core_media.c:15578 Activating write resampler 2019-04-30 10:24:46.421508 [DEBUG] conference_member.c:1758 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2019-04-30 10:24:46.421508 [DEBUG] conference_member.c:1805 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2019-04-30 10:24:46.441507 [DEBUG] conference_loop.c:1334 Setup timer soft success interval: 20 samples: 960 from codec opus recv 452 bytes from udp/[192.168.80.65]:5060 at 10:24:50.493398: ------------------------------------------------------------------------ BYE sip:gw+nava@192.168.80.26:5060;transport=udp;gw=nava SIP/2.0 Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK6d23.1cb57e57.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK41 From: ;tag=41 To: "" ;tag=XFNaNBm26tgjF Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 2 BYE Max-Forwards: 69 User-Agent: navamessenger Content-Length: 0 ------------------------------------------------------------------------ 2019-04-30 10:24:50.501568 [NOTICE] sofia.c:1079 Hangup sofia/internal/16144444444 [CS_EXECUTE] [NORMAL_CLEARING] send 579 bytes to udp/[192.168.80.65]:5060 at 10:24:50.508170: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK6d23.1cb57e57.0 Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK41 From: ;tag=41 To: "" ;tag=XFNaNBm26tgjF Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b CSeq: 2 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:24:50.501568 [INFO] conference_loop.c:1670 Channel leaving conference, cause: NORMAL_CLEARING 2019-04-30 10:24:50.501568 [DEBUG] mod_conference.c:2467 sofia/internal/16144444444 skip receive message [UNBRIDGE] (channel is hungup already) 2019-04-30 10:24:50.501568 [DEBUG] switch_core_media.c:12213 sofia/internal/16144444444 skip receive message [HARD_MUTE] (channel is hungup already) 2019-04-30 10:24:50.501568 [DEBUG] switch_core_codec.c:260 Restore original codec. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_session.c:2887 sofia/internal/16144444444 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/16144444444) State EXECUTE going to sleep 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444) Running State Change CS_HANGUP (Cur 1 Tot 6504) 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/16144444444) Callstate Change ACTIVE -> HANGUP 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/16144444444) State HANGUP 2019-04-30 10:24:50.501568 [DEBUG] mod_sofia.c:449 Channel sofia/internal/16144444444 hanging up, cause: NORMAL_CLEARING 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:60 sofia/internal/16144444444 Standard HANGUP, cause: NORMAL_CLEARING 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/16144444444) State HANGUP going to sleep 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/16144444444) State Change CS_HANGUP -> CS_REPORTING 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/16144444444) Running State Change CS_REPORTING (Cur 1 Tot 6504) 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/16144444444) State REPORTING 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:174 sofia/internal/16144444444 Standard REPORTING, cause: NORMAL_CLEARING 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/16144444444) State REPORTING going to sleep 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/16144444444) State Change CS_REPORTING -> CS_DESTROY 2019-04-30 10:24:50.521508 [DEBUG] switch_core_session.c:1715 Session 6504 (sofia/internal/16144444444) Locked, Waiting on external entities 2019-04-30 10:24:50.521508 [NOTICE] switch_core_session.c:1733 Session 6504 (sofia/internal/16144444444) Ended 2019-04-30 10:24:50.521508 [NOTICE] switch_core_session.c:1737 Close Channel sofia/internal/16144444444 [CS_DESTROY] 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:738 (sofia/internal/16144444444) Running State Change CS_DESTROY (Cur 0 Tot 6504) 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/16144444444) State DESTROY 2019-04-30 10:24:50.521508 [DEBUG] mod_sofia.c:354 sofia/internal/16144444444 SOFIA DESTROY 2019-04-30 10:24:50.521508 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2019-04-30 10:24:50.521508 [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:24:50.521508 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2019-04-30 10:24:50.521508 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[213] Bytes encoded[27264] Encoded length ms[4260] Average encoded bitrate bps[54528] 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:181 sofia/internal/16144444444 Standard DESTROY 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/16144444444) State DESTROY going to sleep 2019-04-30 10:24:50.521508 [DEBUG] mod_conference.c:833 Write Lock ON 2019-04-30 10:24:50.521508 [DEBUG] mod_conference.c:836 Write Lock OFF