FreeSWITCH Pastebin

opus negotiation problem

From babak yakhchali, 4 Years ago, written in FreeSWITCH.
- view diff
URL https://pastebin.freeswitch.org/view/3a084039
Embed
Download Paste or View Raw
  1. span style="color: goldenrod; font-weight: bold;"> 2019-04-30 10:24:41.201567 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables
  2. 2019-04-30 10:24:41.201567 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/16144444444 [e2657cb0-7dea-4ad1-a999-ef0519157363]
  3. 2019-04-30 10:24:41.201567 [DEBUG] mod_sofia.c:5018 (sofia/internal/16144444444) State Change CS_NEW -> CS_INIT
  4. 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)
  5. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/16144444444) State INIT
  6. 2019-04-30 10:24:41.201567 [DEBUG] mod_sofia.c:93 sofia/internal/16144444444 SOFIA INIT
  7. 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
  8. Local SDP:
  9. v=0
  10. o=FreeSWITCH 1556576821 1556576822 IN IP4 192.168.80.26
  11. s=FreeSWITCH
  12. c=IN IP4 192.168.80.26
  13. t=0 0
  14. m=audio 26860 RTP/AVP 102 101
  15. a=rtpmap:102 opus/48000/2
  16. a=fmtp:102 useinbandfec=1; cbr=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  17. a=rtpmap:101 telephone-event/48000
  18. a=fmtp:101 0-16
  19. a=ptime:20
  20. a=sendrecv
  21.  
  22. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:40 sofia/internal/16144444444 Standard INIT
  23. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/16144444444) State Change CS_INIT -> CS_ROUTING
  24. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/16144444444) State INIT going to sleep
  25. 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)
  26. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/16144444444) State ROUTING
  27. 2019-04-30 10:24:41.201567 [DEBUG] mod_sofia.c:154 sofia/internal/16144444444 SOFIA ROUTING
  28. 2019-04-30 10:24:41.201567 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/16144444444) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  29. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/16144444444) State ROUTING going to sleep
  30. 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)
  31. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/16144444444) State CONSUME_MEDIA
  32. send 1311 bytes to udp/[192.168.80.65]:5060 at 10:24:41.210694:
  33.    ------------------------------------------------------------------------
  34.    INVITE sip:16144444444@192.168.80.65 SIP/2.0
  35. 2019-04-30 10:24:41.201567 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/16144444444) State CONSUME_MEDIA going to sleep
  36.    Via: SIP/2.0/UDP 192.168.80.26;rport;branch=z9hG4bKrpZN0vvD50a9D
  37.    Max-Forwards: 70
  38.    From: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  39.    To: <sip:16144444444@192.168.80.65>
  40.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  41.    CSeq: 3748048 INVITE
  42.    Contact: <sip:gw+nava@192.168.80.26:5060;transport=udp;gw=nava>
  43.    User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit
  44.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  45.    Supported: timer, path, replaces
  46.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  47.    Content-Type: application/sdp
  48.    Content-Disposition: session
  49.    Content-Length: 348
  50.    X-FS-Support: update_display,send_info
  51.    Remote-Party-ID: <sip:0000000000@192.168.80.65>;party=calling;screen=yes;privacy=off
  52.  
  53.    v=0
  54.    o=FreeSWITCH 1556576821 1556576822 IN IP4 192.168.80.26
  55.    s=FreeSWITCH
  56.    c=IN IP4 192.168.80.26
  57.    t=0 0
  58.    m=audio 26860 RTP/AVP 102 101
  59.    a=rtpmap:102 opus/48000/2
  60.    a=fmtp:102 useinbandfec=1; cbr=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  61.    a=rtpmap:101 telephone-event/48000
  62.    a=fmtp:101 0-16
  63.    a=ptime:20
  64.    ------------------------------------------------------------------------
  65. 2019-04-30 10:24:41.201567 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [calling][0]
  66. recv 347 bytes from udp/[192.168.80.65]:5060 at 10:24:41.219184:
  67.    ------------------------------------------------------------------------
  68.    SIP/2.0 100 Giving a try
  69.    Via: SIP/2.0/UDP 192.168.80.26;received=192.168.80.26;rport=5060;branch=z9hG4bKrpZN0vvD50a9D
  70.    From: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  71.    To: <sip:16144444444@192.168.80.65>
  72.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  73.    CSeq: 3748048 INVITE
  74.    Server: OpenSIPS (2.3.6 (x86_64/linux))
  75.    Content-Length: 0
  76.  
  77.    ------------------------------------------------------------------------
  78. recv 454 bytes from udp/[192.168.80.65]:5060 at 10:24:41.460118:
  79.    ------------------------------------------------------------------------
  80.    SIP/2.0 180 Ringing
  81.    Via: SIP/2.0/UDP 192.168.80.26;received=192.168.80.26;rport=5060;branch=z9hG4bKrpZN0vvD50a9D
  82.    Record-Route: <sip:192.168.80.65;lr;nat=yes;did=2a2.fe881716>
  83.    From: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  84.    To: <sip:16144444444@192.168.80.65>;tag=41
  85.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  86.    CSeq: 3748048 INVITE
  87.    Contact: <sip:16144444444@80.191.36.252:51544;nat=yes>
  88.    User-Agent: navamessenger
  89.    Content-Length: 0
  90.  
  91.    ------------------------------------------------------------------------
  92. 2019-04-30 10:24:41.461519 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [proceeding][180]
  93. 2019-04-30 10:24:41.461519 [NOTICE] sofia.c:7401 Ring-Ready sofia/internal/16144444444!
  94. 2019-04-30 10:24:41.461519 [DEBUG] switch_channel.c:3354 (sofia/internal/16144444444) Callstate Change DOWN -> RINGING
  95. recv 507 bytes from tcp/[107.172.39.18]:50091 at 10:24:42.113901:
  96.    ------------------------------------------------------------------------
  97.    REGISTER sip:192.168.80.26:5060 SIP/2.0
  98.    Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK0748c5abdc8a4f7a9bb0619510b2b90b;rport
  99.    To: "72"<sip:72@192.168.80.26>
  100.    From: "72"<sip:72@192.168.80.26>;tag=opj865wnwu
  101.    CSeq: 1 REGISTER
  102.    Call-ID: d80e2c1a96a748e0aeac948c30920190
  103.    Max-Forwards: 70
  104.    Contact: <sip:72@107.172.39.18:50091;transport=TCP>
  105.    User-Agent: UsaAirport
  106.    Content-Length: 0
  107.    Expires: 3600
  108.    Supported: 100rel
  109.   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
  110.  
  111.    ------------------------------------------------------------------------
  112. send 648 bytes to tcp/[107.172.39.18]:50091 at 10:24:42.115467:
  113.    ------------------------------------------------------------------------
  114.    SIP/2.0 401 Unauthorized
  115.    Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK0748c5abdc8a4f7a9bb0619510b2b90b;rport=50091
  116.    From: "72"<sip:72@192.168.80.26>;tag=opj865wnwu
  117.    To: "72" <sip:72@192.168.80.26>;tag=yre3p6453364a
  118.    Call-ID: d80e2c1a96a748e0aeac948c30920190
  119.    CSeq: 1 REGISTER
  120.    User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit
  121.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  122.    Supported: timer, path, replaces
  123.    WWW-Authenticate: Digest realm="192.168.80.26", nonce="e224a4b7-97ad-4fe2-ba02-9f65b80e75da", algorithm=MD5, qop="auth"
  124.    Content-Length: 0
  125.  
  126.    ------------------------------------------------------------------------
  127. recv 782 bytes from tcp/[107.172.39.18]:50091 at 10:24:42.338703:
  128.    ------------------------------------------------------------------------
  129.    REGISTER sip:192.168.80.26:5060 SIP/2.0
  130.    Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK11a18b6ea5664e7d8c3f723c438ce6b1;rport
  131.    To: "72"<sip:72@192.168.80.26>
  132.    From: "72"<sip:72@192.168.80.26>;tag=opj865wnwu
  133.    CSeq: 2 REGISTER
  134.    Call-ID: d80e2c1a96a748e0aeac948c30920190
  135.    Max-Forwards: 70
  136.    Contact: <sip:72@107.172.39.18:50091;transport=TCP;rinstance=8366194973240287>
  137.    User-Agent: UsaAirport
  138.    Content-Length: 0
  139.    Expires: 3600
  140.    Supported: 100rel
  141.   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
  142.    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
  143.  
  144.    ------------------------------------------------------------------------
  145. 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
  146. You must define a domain called '192.168.80.26' in your directory and add a user with the id="72" attribute
  147. and you must configure your device to use the proper domain in it's authentication credentials.
  148. send 524 bytes to tcp/[107.172.39.18]:50091 at 10:24:42.340561:
  149.    ------------------------------------------------------------------------
  150.    SIP/2.0 403 Forbidden
  151.    Via: SIP/2.0/TCP 107.172.39.18:50091;branch=z9hG4bK11a18b6ea5664e7d8c3f723c438ce6b1;rport=50091
  152.    From: "72"<sip:72@192.168.80.26>;tag=opj865wnwu
  153.    To: "72" <sip:72@192.168.80.26>;tag=Z17Ur1N90cXQp
  154.    Call-ID: d80e2c1a96a748e0aeac948c30920190
  155.    CSeq: 2 REGISTER
  156.    User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit
  157.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  158.    Supported: timer, path, replaces
  159.    Content-Length: 0
  160.  
  161.    ------------------------------------------------------------------------
  162. recv 915 bytes from udp/[192.168.80.65]:5060 at 10:24:46.193643:
  163.    ------------------------------------------------------------------------
  164.    SIP/2.0 200 OK
  165.    Via: SIP/2.0/UDP 192.168.80.26;received=192.168.80.26;rport=5060;branch=z9hG4bKrpZN0vvD50a9D
  166.    Record-Route: <sip:192.168.80.65;lr;nat=yes;did=2a2.fe881716>
  167.    From: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  168.    To: <sip:16144444444@192.168.80.65>;tag=41
  169.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  170.    CSeq: 3748048 INVITE
  171.    Contact: <sip:16144444444@80.191.36.252:51544;nat=yes>
  172.    Content-Type: application/sdp
  173.    User-Agent: navamessenger
  174.    Content-Length: 433
  175.  
  176.    v=0
  177.    o=navamessenger 0 0 IN IP4 192.168.80.30
  178.    s=navamessenger
  179.    c=IN IP4 192.168.80.30
  180.    t=0 0
  181.    m=audio 23816 RTP/AVP 107 18 0 8 101
  182.    a=rtpmap:107 opus/48000/2
  183.    a=fmtp:107 maxplaybackrate=48000; sprop-maxcapturerate=48000
  184.    a=ptime:20
  185.    a=maxptime:20
  186.    a=rtpmap:18 G729/8000
  187.    a=fmtp:18 annexb=no
  188.    a=ptime:20
  189.    a=sendrecv
  190.    a=rtpmap:0 PCMU/8000/1
  191.    a=rtpmap:8 PCMA/8000/1
  192.    a=rtpmap:101 telephone-event/8000
  193.    a=fmtp:101 0-15
  194.    a=nortpproxy:yes
  195.    ------------------------------------------------------------------------
  196. 2019-04-30 10:24:46.181580 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [completing][200]
  197. 2019-04-30 10:24:46.181580 [DEBUG] sofia.c:7301 Remote SDP:
  198. v=0
  199. o=navamessenger 0 0 IN IP4 192.168.80.30
  200. s=navamessenger
  201. c=IN IP4 192.168.80.30
  202. t=0 0
  203. m=audio 23816 RTP/AVP 107 18 0 8 101
  204. a=rtpmap:107 opus/48000/2
  205. a=fmtp:107 maxplaybackrate=48000; sprop-maxcapturerate=48000
  206. a=rtpmap:18 G729/8000
  207. a=fmtp:18 annexb=no
  208. a=rtpmap:0 PCMU/8000/1
  209. a=rtpmap:8 PCMA/8000/1
  210. a=rtpmap:101 telephone-event/8000
  211. a=fmtp:101 0-15
  212. a=ptime:20
  213. a=maxptime:20
  214. a=ptime:20
  215. a=nortpproxy:yes
  216.  
  217. 2019-04-30 10:24:46.181580 [NOTICE] sofia.c:7304 Pre-Answer sofia/internal/16144444444!
  218. 2019-04-30 10:24:46.181580 [DEBUG] switch_channel.c:3482 (sofia/internal/16144444444) Callstate Change RINGING -> EARLY
  219. send 452 bytes to udp/[192.168.80.65]:5060 at 10:24:46.197176:
  220.    ------------------------------------------------------------------------
  221.    ACK sip:16144444444@80.191.36.252:51544;nat=yes SIP/2.0
  222.    Via: SIP/2.0/UDP 192.168.80.26;rport;branch=z9hG4bKSZre2QDH290US
  223.    Route: <sip:192.168.80.65;lr;nat=yes;did=2a2.fe881716>
  224.    Max-Forwards: 70
  225.    From: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  226.    To: <sip:16144444444@192.168.80.65>;tag=41
  227.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  228.    CSeq: 3748048 ACK
  229.    Contact: <sip:gw+nava@192.168.80.26:5060;transport=udp;gw=nava>
  230.    Content-Length: 0
  231.  
  232.    ------------------------------------------------------------------------
  233. 2019-04-30 10:24:46.181580 [DEBUG] sofia.c:7291 Channel sofia/internal/16144444444 entering state [ready][200]
  234. 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]
  235. 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
  236. 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]
  237. 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]
  238. 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]
  239. 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
  240. 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
  241. 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:636 Opus encoder: CBR mode enabled
  242. 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
  243. 2019-04-30 10:24:46.181580 [DEBUG] mod_opus.c:636 Opus encoder: CBR mode enabled
  244. 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
  245. 2019-04-30 10:24:46.181580 [DEBUG] switch_core_codec.c:111 sofia/internal/16144444444 Original read codec set to opus:116
  246. 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
  247. 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
  248. 2019-04-30 10:24:46.181580 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 960 bytes per 20ms
  249. 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8815 sofia/internal/16144444444 Set 2833 dtmf send payload to 101
  250. 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8822 sofia/internal/16144444444 Set 2833 dtmf receive payload to 101
  251. 2019-04-30 10:24:46.181580 [DEBUG] switch_core_media.c:8845 sofia/internal/16144444444 Set rtp dtmf delay to 40
  252. 2019-04-30 10:24:46.181580 [NOTICE] sofia.c:8429 Channel [sofia/internal/16144444444] has been answered
  253. 2019-04-30 10:24:46.181580 [DEBUG] switch_channel.c:3781 (sofia/internal/16144444444) Callstate Change EARLY -> ACTIVE
  254. 2019-04-30 10:24:46.201509 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/internal/16144444444]
  255. 2019-04-30 10:24:46.201509 [INFO] switch_channel.c:3130 sofia/internal/16144444444 Flipping CID from "" <0000000000> to "Outbound Call" <16144444444>
  256. 2019-04-30 10:24:46.201509 [DEBUG] mod_commands.c:5072 (sofia/internal/16144444444) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
  257. 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)
  258. 2019-04-30 10:24:46.201509 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/16144444444) State EXECUTE
  259. 2019-04-30 10:24:46.201509 [DEBUG] mod_sofia.c:209 sofia/internal/16144444444 SOFIA EXECUTE
  260. 2019-04-30 10:24:46.201509 [DEBUG] switch_core_state_machine.c:328 sofia/internal/16144444444 Standard EXECUTE
  261. EXECUTE sofia/internal/16144444444 conference(test)
  262. 2019-04-30 10:24:46.201509 [DEBUG] mod_conference.c:3384 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie
  263. 2019-04-30 10:24:46.201509 [DEBUG] conference_member.c:1758 Raw Codec Activation Success L16@48000hz 1 channel 20ms
  264. 2019-04-30 10:24:46.201509 [DEBUG] mod_conference.c:233 Setup timer success interval: 20  samples: 160
  265. 2019-04-30 10:24:46.201509 [DEBUG] conference_member.c:1805 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  266. 2019-04-30 10:24:46.201509 [DEBUG] switch_core_codec.c:223 sofia/internal/16144444444 Push codec L16:100
  267. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '0' to 'mute'
  268. 2019-04-30 10:24:46.221518 [INFO] switch_ivr_async.c:219 Digit parser mod_conference: Setting realm to 'conf'
  269. 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
  270. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '*' to 'deaf mute'
  271. 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding */conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b2ee8
  272. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '9' to 'energy up'
  273. 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
  274. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '8' to 'energy equ'
  275. 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
  276. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '7' to 'energy dn'
  277. 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
  278. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '3' to 'vol talk up'
  279. 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
  280. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '2' to 'vol talk zero'
  281. 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
  282. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '1' to 'vol talk dn'
  283. 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
  284. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '6' to 'vol listen up'
  285. 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
  286. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '5' to 'vol listen zero'
  287. 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
  288. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '4' to 'vol listen dn'
  289. 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
  290. 2019-04-30 10:24:46.221518 [DEBUG] conference_member.c:105 sofia/internal/16144444444 binding '#' to 'hangup'
  291. span style="color: goldenrod; font-weight: bold;"> 2019-04-30 10:24:46.221518 [DEBUG] switch_ivr_async.c:344 Digit parser mod_conference: binding #/conf/0 callback: 0x7fa8b50e21c0 data: 0x7fa8404b30c8
  292. span style="color: goldenrod; font-weight: bold;"> 2019-04-30 10:24:46.221518 [DEBUG] conference_loop.c:1334 Setup timer soft success interval: 20  samples: 960 from codec opus
  293. 2019-04-30 10:24:46.221518 [DEBUG] conference_loop.c:1492 Outbound conference channel answered, setting CFLAG_ANSWERED
  294. 2019-04-30 10:24:46.221518 [DEBUG] mod_local_stream.c:907 Opening Stream [moh/8000] 8000hz
  295. 2019-04-30 10:24:46.241506 [NOTICE] switch_core_media.c:15578 Activating write resampler
  296. 2019-04-30 10:24:46.421508 [DEBUG] conference_member.c:1758 Raw Codec Activation Success L16@48000hz 1 channel 20ms
  297. 2019-04-30 10:24:46.421508 [DEBUG] conference_member.c:1805 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  298. 2019-04-30 10:24:46.441507 [DEBUG] conference_loop.c:1334 Setup timer soft success interval: 20  samples: 960 from codec opus
  299. recv 452 bytes from udp/[192.168.80.65]:5060 at 10:24:50.493398:
  300.    ------------------------------------------------------------------------
  301.    BYE sip:gw+nava@192.168.80.26:5060;transport=udp;gw=nava SIP/2.0
  302.    Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK6d23.1cb57e57.0
  303.    Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK41
  304.    From: <sip:16144444444@192.168.80.65>;tag=41
  305.    To: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  306.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  307.    CSeq: 2 BYE
  308.    Max-Forwards: 69
  309.    User-Agent: navamessenger
  310.    Content-Length: 0
  311.  
  312.    ------------------------------------------------------------------------
  313. 2019-04-30 10:24:50.501568 [NOTICE] sofia.c:1079 Hangup sofia/internal/16144444444 [CS_EXECUTE] [NORMAL_CLEARING]
  314. send 579 bytes to udp/[192.168.80.65]:5060 at 10:24:50.508170:
  315.    ------------------------------------------------------------------------
  316.    SIP/2.0 200 OK
  317.    Via: SIP/2.0/UDP 192.168.80.65:5060;branch=z9hG4bK6d23.1cb57e57.0
  318.    Via: SIP/2.0/UDP 80.191.36.252:51544;received=80.191.36.252;rport=51544;branch=z9hG4bK41
  319.    From: <sip:16144444444@192.168.80.65>;tag=41
  320.    To: "" <sip:confserver@192.168.80.65>;tag=XFNaNBm26tgjF
  321.    Call-ID: 499e868b-e5af-1237-fba2-0050569b4f7b
  322.    CSeq: 2 BYE
  323.    User-Agent: FreeSWITCH-mod_sofia/1.8.4+git~20181227T011058Z~749a6e108b~64bit
  324.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  325.    Supported: timer, path, replaces
  326.    Content-Length: 0
  327.  
  328.    ------------------------------------------------------------------------
  329. 2019-04-30 10:24:50.501568 [INFO] conference_loop.c:1670 Channel leaving conference, cause: NORMAL_CLEARING
  330. 2019-04-30 10:24:50.501568 [DEBUG] mod_conference.c:2467 sofia/internal/16144444444 skip receive message [UNBRIDGE] (channel is hungup already)
  331. 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)
  332. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_codec.c:260 Restore original codec.
  333. 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)
  334. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/16144444444) State EXECUTE going to sleep
  335. 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)
  336. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/16144444444) Callstate Change ACTIVE -> HANGUP
  337. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/16144444444) State HANGUP
  338. 2019-04-30 10:24:50.501568 [DEBUG] mod_sofia.c:449 Channel sofia/internal/16144444444 hanging up, cause: NORMAL_CLEARING
  339. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:60 sofia/internal/16144444444 Standard HANGUP, cause: NORMAL_CLEARING
  340. 2019-04-30 10:24:50.501568 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/16144444444) State HANGUP going to sleep
  341. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/16144444444) State Change CS_HANGUP -> CS_REPORTING
  342. 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)
  343. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/16144444444) State REPORTING
  344. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:174 sofia/internal/16144444444 Standard REPORTING, cause: NORMAL_CLEARING
  345. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/16144444444) State REPORTING going to sleep
  346. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/16144444444) State Change CS_REPORTING -> CS_DESTROY
  347. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_session.c:1715 Session 6504 (sofia/internal/16144444444) Locked, Waiting on external entities
  348. 2019-04-30 10:24:50.521508 [NOTICE] switch_core_session.c:1733 Session 6504 (sofia/internal/16144444444) Ended
  349. 2019-04-30 10:24:50.521508 [NOTICE] switch_core_session.c:1737 Close Channel sofia/internal/16144444444 [CS_DESTROY]
  350. 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)
  351. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/16144444444) State DESTROY
  352. 2019-04-30 10:24:50.521508 [DEBUG] mod_sofia.c:354 sofia/internal/16144444444 SOFIA DESTROY
  353. 2019-04-30 10:24:50.521508 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  354. 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]
  355. 2019-04-30 10:24:50.521508 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  356. 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]
  357. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:181 sofia/internal/16144444444 Standard DESTROY
  358. 2019-04-30 10:24:50.521508 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/16144444444) State DESTROY going to sleep
  359. 2019-04-30 10:24:50.521508 [DEBUG] mod_conference.c:833 Write Lock ON
  360. 2019-04-30 10:24:50.521508 [DEBUG] mod_conference.c:836 Write Lock OFF
  361.  

Reply to "opus negotiation problem"