freeswitch icon indicating copy to clipboard operation
freeswitch copied to clipboard

Published 20 hours ago • verified publisher icon signalwire

switch_core_media.c:16221 sofia/internal/*@* not enough buffer space for required resample operation!

Open zhouzz1986 opened this issue 3 years ago • 1 comments

Describe the bug 当我接入ims,发现一些被叫会时不时提示有转码错误

特意挑选一个有问题的被叫 如果将语音编码指定为g729,是可以正常通话,但是没有彩铃回铃, 如果增加PMCA,能听到语音回铃,但被叫接通出现秒断 现在我理解是转码设置有问题,需要怎么处理?

Package version or git hash

  • Version 1.10.7

Trace logs 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.455102 98.90% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/@:5060 [095faf46-116f-11ed-9624-a79ea9c0433f] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.455102 98.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/@:5060) Running State Change CS_NEW (Cur 1 Tot 90) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.455102 98.90% [INFO] sofia.c:10462 sofia/internal/@:5060 receiving invite from 125.84.84.112:15119 version: 1.10.7-release 64bit call-id: kx115e1zm6pg95u8azwn 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.455102 98.90% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/@:5060) State NEW 2022-08-01 15:53:31.455102 98.90% [DEBUG] sofia.c:2419 detaching session 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.475100 98.90% [DEBUG] sofia.c:2532 Re-attaching to session 095faf46-116f-11ed-9624-a79ea9c0433f 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.495108 98.90% [INFO] sofia.c:10462 sofia/internal/@:5060 receiving invite from 125.84.84.112:15119 version: 1.10.7-release 64bit call-id: kx115e1zm6pg95u8azwn 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] sofia.c:11672 Setting NAT mode based on websockets 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] sofia.c:7499 Channel sofia/internal/@:5060 entering state [received][100] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] sofia.c:7509 Remote SDP: 095faf46-116f-11ed-9624-a79ea9c0433f v=0 095faf46-116f-11ed-9624-a79ea9c0433f o=- 5620800463173752282 2 IN IP4 127.0.0.1 095faf46-116f-11ed-9624-a79ea9c0433f s=- 095faf46-116f-11ed-9624-a79ea9c0433f t=0 0 095faf46-116f-11ed-9624-a79ea9c0433f a=group:BUNDLE 0 095faf46-116f-11ed-9624-a79ea9c0433f a=extmap-allow-mixed 095faf46-116f-11ed-9624-a79ea9c0433f a=msid-semantic: WMS 90a0fcb1-356e-457d-bcfb-59f68b54b722 095faf46-116f-11ed-9624-a79ea9c0433f m=audio 43686 UDP/TLS/RTP/SAVPF 111 63 103 104 9 102 0 8 106 105 13 110 112 113 126 095faf46-116f-11ed-9624-a79ea9c0433f c=IN IP4 192.168.8.73 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:111 opus/48000/2 095faf46-116f-11ed-9624-a79ea9c0433f a=fmtp:111 minptime=10;useinbandfec=1 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:63 red/48000/2 095faf46-116f-11ed-9624-a79ea9c0433f a=fmtp:63 111/111 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:103 ISAC/16000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:104 ISAC/32000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:9 G722/8000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:102 ILBC/8000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:0 PCMU/8000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:8 PCMA/8000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:106 CN/32000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:105 CN/16000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:13 CN/8000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:110 telephone-event/48000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:112 telephone-event/32000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:113 telephone-event/16000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:126 telephone-event/8000 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp:9 IN IP4 0.0.0.0 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:4217872757 1 udp 2122129151 192.168.8.73 43686 typ host generation 0 network-id 5 network-cost 10 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:559267639 1 udp 2122071295 ::1 44165 typ host generation 0 network-id 2 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:1510613869 1 udp 2121998079 127.0.0.1 40935 typ host generation 0 network-id 1 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:3400055329 1 tcp 1518283007 2409:8161:48:1618:1:0:e175:4d3a 9 typ host tcptype active generation 0 network-id 3 network-cost 50 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:3408793074 1 tcp 1518217471 240e:531:24:f81a::1 9 typ host tcptype active generation 0 network-id 4 network-cost 50 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:1876313031 1 tcp 1518091519 ::1 42301 typ host tcptype passive generation 0 network-id 2 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:344579997 1 tcp 1518018303 127.0.0.1 45385 typ host tcptype passive generation 0 network-id 1 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-ufrag:sDtb 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-pwd:IYlNnnZ0pRKhnvNMV+OdTIgk 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-options:trickle renomination 095faf46-116f-11ed-9624-a79ea9c0433f a=fingerprint:sha-256 C5:DD:79:ED:28:96:72:6B:2E:6F:96:86:7F:3E:37:D0:5F:79:DF:CC:17:1C:1F:F7:11:18:92:95:F5:0B:B6:D7 095faf46-116f-11ed-9624-a79ea9c0433f a=setup:actpass 095faf46-116f-11ed-9624-a79ea9c0433f a=mid:0 095faf46-116f-11ed-9624-a79ea9c0433f a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level 095faf46-116f-11ed-9624-a79ea9c0433f a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time 095faf46-116f-11ed-9624-a79ea9c0433f a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 095faf46-116f-11ed-9624-a79ea9c0433f a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid 095faf46-116f-11ed-9624-a79ea9c0433f a=msid:90a0fcb1-356e-457d-bcfb-59f68b54b722 45381044-9187-4539-a9e8-f2820dcce8f5 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp-mux 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp-fb:111 transport-cc 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:901030142 cname:LGRRanvxNmRTjn4r 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:901030142 msid:90a0fcb1-356e-457d-bcfb-59f68b54b722 45381044-9187-4539-a9e8-f2820dcce8f5 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:901030142 mslabel:90a0fcb1-356e-457d-bcfb-59f68b54b722 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:901030142 label:45381044-9187-4539-a9e8-f2820dcce8f5 095faf46-116f-11ed-9624-a79ea9c0433f 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] sofia.c:7912 (sofia/internal/@:5060) State Change CS_NEW -> CS_INIT 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/@:5060) Running State Change CS_INIT (Cur 1 Tot 90) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/@:5060) State INIT 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] mod_sofia.c:97 sofia/internal/@:5060 SOFIA INIT 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:40 sofia/internal/@:5060 Standard INIT 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/@:5060) State Change CS_INIT -> CS_ROUTING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/@:5060) State INIT going to sleep 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/@:5060) Running State Change CS_ROUTING (Cur 1 Tot 90) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_channel.c:2380 (sofia/internal/@:5060) Callstate Change DOWN -> RINGING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/@:5060) State ROUTING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] mod_sofia.c:158 sofia/internal/@:5060 SOFIA ROUTING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [DEBUG] switch_core_state_machine.c:230 sofia/internal/@:5060 Standard ROUTING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.515098 98.90% [INFO] mod_dialplan_xml.c:639 Processing 1510 <>->fs1890000 in context default 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 parsing [default->yidong999] continue=false 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Regex (PASS) [yidong999] destination_number(fs1890000) =~ /^fs(\d+)$/ break=on-false 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(media_bug_answer_req=true) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(RECORD_STEREO=true) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(enable_file_write_buffering=true) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action record_session(/opt/fs_record_dir/upload/fs_record/2022/08/01/75077f5b-5811-40aa-a363-a19bc50813b0.wav) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(fs_call_id=75077f5b-5811-40aa-a363-a19bc50813b0) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(continue_on_fail=USER_BUSY,NO_USER_RESPONSE,NORMAL_TEMPORARY_FAILURE,UNALLOCATED_NUMBER,RECOVERY_ON_TIMER_EXPIRE) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(hangup_after_bridge=true) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action set(ringback=/usr/local/freeswitch/sounds/en/us/callie/calling.wav) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action bridge({origination_caller_id_number=62766978,absolute_codec_string=G729,OPUS,G722,PCMU,PCMA,H264,execute_on_answer=sched_hangup +1800}sofia/gateway/gw1/1890000;user=phone) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action sleep(1000) 095faf46-116f-11ed-9624-a79ea9c0433f Dialplan: sofia/internal/@:5060 Action endless_playback(${originate_disposition}.wav) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/@:5060) State Change CS_ROUTING -> CS_EXECUTE 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/@:5060) State ROUTING going to sleep 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/@:5060) Running State Change CS_EXECUTE (Cur 1 Tot 90) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/@:5060) State EXECUTE 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] mod_sofia.c:213 sofia/internal/@:5060 SOFIA EXECUTE 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_state_machine.c:323 sofia/internal/@:5060 Standard EXECUTE 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(media_bug_answer_req=true) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [media_bug_answer_req]=[true] 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(RECORD_STEREO=true) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [RECORD_STEREO]=[true] 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(enable_file_write_buffering=true) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [enable_file_write_buffering]=[true] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_session.c:2795 Application record_session Requires media! pre_answering channel sofia/internal/@:5060 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [INFO] switch_core_session.c:2797 Sending early media 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [opus:111:48000:20:0:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [opus:111:48000:20:0:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [opus:111:48000:20:0:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [opus:111:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [opus:111:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [red:63:48000:20:0:2]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [red:63:48000:20:0:2]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [red:63:48000:20:0:2]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [red:63:48000:20:0:2]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [red:63:48000:20:0:2]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ILBC:102:8000:30:13330:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ILBC:102:8000:30:13330:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ILBC:102:8000:30:13330:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ILBC:102:8000:30:13330:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [ILBC:102:8000:30:13330:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:105:16000:20:0:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:105:16000:20:0:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:105:16000:20:0:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:105:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:105:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:13:8000:20:0:1]/[G729:18:8000:20:8000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:13:8000:20:0:1]/[opus:116:48000:20:0:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:13:8000:20:0:1]/[G722:9:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:13:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [CN:13:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 110@48000 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:3870 Set Codec sofia/internal/@:5060 opus/48000 20 ms 960 samples 0 bits 1 channels 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_codec.c:111 sofia/internal/@:5060 Original read codec set to opus:116 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4344 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.8.73:43686 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4338 Drop audio Candidate cid: 1 proto: udp type: host addr: ::1:44165 (no network path) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4344 Save audio Candidate cid: 1 proto: udp type: host addr: 127.0.0.1:40935 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4389 Searching for rtp candidate. 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4398 Choose rtp candidate, index 0, 192.168.8.73:43686 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4138 sofia/internal/@:5060 choosing family v4 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4409 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 192.168.8.73:43686 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4461 setting remote audio ice addr to index 0 192.168.8.73:43686 based on candidate 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:4496 Setting remote rtcp audio addr to 192.168.8.73:43686 based on candidate 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 110@48000 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:5973 sofia/internal/@:5060 Set 2833 dtmf send payload to 110 recv payload to 110 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/internal/@:5060] ***** port 20352 -> 192.168.8.73 port 43686 codec: 111 ms: 20 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 960 bytes per 20ms 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [INFO] switch_core_media.c:8957 Activating Audio ICE 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [NOTICE] switch_rtp.c:5122 Activating RTP audio ICE: sDtb:afBll7Gf6DQOYU4v 192.168.8.73:43686 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:8997 Activating RTCP PORT 43686 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_rtp.c:5017 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 43686 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [INFO] switch_core_media.c:9008 Skipping RTCP ICE (Same as RTP) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [INFO] switch_rtp.c:3913 Activate RTP/RTCP audio DTLS client 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [INFO] switch_rtp.c:4096 Changing audio DTLS state from OFF to HANDSHAKE 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:9089 sofia/internal/@:5060 Set 2833 dtmf send payload to 110 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:9096 sofia/internal/@:5060 Set 2833 dtmf receive payload to 110 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:9119 sofia/internal/@:5060 Set rtp dtmf delay to 40 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/@:5060! 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_channel.c:3622 (sofia/internal/@:5060) Callstate Change RINGING -> EARLY 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/internal/@:5060. 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] mod_sofia.c:2610 Ring SDP: 095faf46-116f-11ed-9624-a79ea9c0433f v=0 095faf46-116f-11ed-9624-a79ea9c0433f o=FreeSWITCH 1659320059 1659320060 IN IP4 ***** 095faf46-116f-11ed-9624-a79ea9c0433f s=FreeSWITCH 095faf46-116f-11ed-9624-a79ea9c0433f c=IN IP4 ***** 095faf46-116f-11ed-9624-a79ea9c0433f t=0 0 095faf46-116f-11ed-9624-a79ea9c0433f a=msid-semantic: WMS JlVv991u5n45YmHBuXijkfGu497KRveq 095faf46-116f-11ed-9624-a79ea9c0433f m=audio 20352 UDP/TLS/RTP/SAVPF 111 110 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:111 opus/48000/2 095faf46-116f-11ed-9624-a79ea9c0433f a=fmtp:111 useinbandfec=1; minptime=10 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:110 telephone-event/48000 095faf46-116f-11ed-9624-a79ea9c0433f a=ptime:20 095faf46-116f-11ed-9624-a79ea9c0433f a=sendrecv 095faf46-116f-11ed-9624-a79ea9c0433f a=fingerprint:sha-256 E2:79:38:0E:44:40:DC:23:2C:8C:BB:92:D5:50:B0:2D:01:F2:1E:06:10:89:18:D2:A3:00:55:A3:09:CE:E9:BD 095faf46-116f-11ed-9624-a79ea9c0433f a=setup:active 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp-mux 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp:20352 IN IP4 ***** 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-ufrag:afBll7Gf6DQOYU4v 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-pwd:KH0zaRjRCZmzdjRepipAfWGc 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:9191849089 1 udp 2130706431 ***** 20352 typ host generation 0 095faf46-116f-11ed-9624-a79ea9c0433f a=end-of-candidates 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 cname:GZMFZD0UQVPF7n6r 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 msid:JlVv991u5n45YmHBuXijkfGu497KRveq a0 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 mslabel:JlVv991u5n45YmHBuXijkfGu497KRveq 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 label:JlVv991u5n45YmHBuXijkfGu497KRveqa0 095faf46-116f-11ed-9624-a79ea9c0433f 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 record_session(/opt/fs_record_dir/upload/fs_record/2022/08/01/75077f5b-5811-40aa-a363-a19bc50813b0.wav) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.555089 98.90% [DEBUG] sofia.c:7499 Channel sofia/internal/@:5060 entering state [early][183] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] switch_ivr_async.c:1503 Record session sample rate: 48000 -> 48000 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/internal/@:5060 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(fs_call_id=75077f5b-5811-40aa-a363-a19bc50813b0) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [fs_call_id]=[75077f5b-5811-40aa-a363-a19bc50813b0] 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(continue_on_fail=USER_BUSY,NO_USER_RESPONSE,NORMAL_TEMPORARY_FAILURE,UNALLOCATED_NUMBER,RECOVERY_ON_TIMER_EXPIRE) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [continue_on_fail]=[USER_BUSY,NO_USER_RESPONSE,NORMAL_TEMPORARY_FAILURE,UNALLOCATED_NUMBER,RECOVERY_ON_TIMER_EXPIRE] 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(hangup_after_bridge=true) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [hangup_after_bridge]=[true] 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 set(ringback=/usr/local/freeswitch/sounds/en/us/callie/calling.wav) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] mod_dptools.c:1685 SET sofia/internal/@:5060 [ringback]=[/usr/local/freeswitch/sounds/en/us/callie/calling.wav] 095faf46-116f-11ed-9624-a79ea9c0433f EXECUTE [depth=0] sofia/internal/@:5060 bridge({origination_caller_id_number=62766978,absolute_codec_string=G729,OPUS,G722,PCMU,PCMA,H264,execute_on_answer=sched_hangup +1800}sofia/gateway/gw1/1890000;user=phone) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.575088 98.90% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.735102 98.90% [NOTICE] switch_rtp.c:1314 Auto Changing audio stun/rtp/dtls port from 192.168.8.73:43686 to 125.84.84.112:15121 idx:-1 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.775105 98.90% [INFO] switch_rtp.c:3425 Changing audio DTLS state from HANDSHAKE to SETUP 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.795117 98.90% [INFO] switch_rtp.c:3332 audio Fingerprint Verified. 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.795117 98.90% [INFO] switch_rtp.c:4423 Activating audio Secure RTP SEND 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.795117 98.90% [INFO] switch_rtp.c:4401 Activating audio Secure RTP RECV 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.795117 98.90% [INFO] switch_rtp.c:3374 Changing audio DTLS state from SETUP to READY 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.955103 98.90% [DEBUG] switch_core_io.c:448 Setting BUG Codec opus:116 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:31.975102 98.90% [DEBUG] switch_rtp.c:1982 rtcp_stats_init: audio ssrc[901030142] base_seq[23212] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.395100 98.93% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/external/189****0000] Peer UUID: 09717c1c-116f-11ed-9635-a79ea9c0433f 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.395100 98.93% [NOTICE] switch_core_media.c:16151 Activating write resampler 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.535105 98.93% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.535105 98.93% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[7] Bytes encoded[265] Encoded length ms[140] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.555106 98.93% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[4] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.555106 98.93% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.595101 98.93% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.595101 98.93% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[3] Bytes encoded[150] Encoded length ms[60] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.615093 98.93% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[3] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:33.615093 98.93% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.115103 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.115103 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[176] Bytes encoded[20253] Encoded length ms[3520] Average encoded bitrate bps[54008] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.135106 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[173] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.135106 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.195065 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.195065 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[3] Bytes encoded[199] Encoded length ms[60] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.215118 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[3] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.215118 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.275103 99.27% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/internal/@:5060. 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.275103 99.27% [DEBUG] mod_sofia.c:913 Local SDP sofia/internal/@:5060: 095faf46-116f-11ed-9624-a79ea9c0433f v=0 095faf46-116f-11ed-9624-a79ea9c0433f o=FreeSWITCH 1659320059 1659320061 IN IP4 ***** 095faf46-116f-11ed-9624-a79ea9c0433f s=FreeSWITCH 095faf46-116f-11ed-9624-a79ea9c0433f c=IN IP4 ***** 095faf46-116f-11ed-9624-a79ea9c0433f t=0 0 095faf46-116f-11ed-9624-a79ea9c0433f a=msid-semantic: WMS JlVv991u5n45YmHBuXijkfGu497KRveq 095faf46-116f-11ed-9624-a79ea9c0433f m=audio 20352 UDP/TLS/RTP/SAVPF 111 110 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:111 opus/48000/2 095faf46-116f-11ed-9624-a79ea9c0433f a=fmtp:111 useinbandfec=1; minptime=10 095faf46-116f-11ed-9624-a79ea9c0433f a=rtpmap:110 telephone-event/48000 095faf46-116f-11ed-9624-a79ea9c0433f a=ptime:20 095faf46-116f-11ed-9624-a79ea9c0433f a=sendrecv 095faf46-116f-11ed-9624-a79ea9c0433f a=fingerprint:sha-256 E2:79:38:0E:44:40:DC:23:2C:8C:BB:92:D5:50:B0:2D:01:F2:1E:06:10:89:18:D2:A3:00:55:A3:09:CE:E9:BD 095faf46-116f-11ed-9624-a79ea9c0433f a=setup:active 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp-mux 095faf46-116f-11ed-9624-a79ea9c0433f a=rtcp:20352 IN IP4 ***** 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-ufrag:afBll7Gf6DQOYU4v 095faf46-116f-11ed-9624-a79ea9c0433f a=ice-pwd:KH0zaRjRCZmzdjRepipAfWGc 095faf46-116f-11ed-9624-a79ea9c0433f a=candidate:1948260275 1 udp 2130706431 ***** 20352 typ host generation 0 095faf46-116f-11ed-9624-a79ea9c0433f a=end-of-candidates 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 cname:GZMFZD0UQVPF7n6r 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 msid:JlVv991u5n45YmHBuXijkfGu497KRveq a0 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 mslabel:JlVv991u5n45YmHBuXijkfGu497KRveq 095faf46-116f-11ed-9624-a79ea9c0433f a=ssrc:1995197011 label:JlVv991u5n45YmHBuXijkfGu497KRveqa0 095faf46-116f-11ed-9624-a79ea9c0433f 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.275103 99.27% [NOTICE] switch_ivr_bridge.c:731 Channel [sofia/internal/@:5060] has been answered 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.275103 99.27% [DEBUG] switch_channel.c:3950 (sofia/internal/@:5060) Callstate Change EARLY -> ACTIVE 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.275103 99.27% [DEBUG] sofia.c:7499 Channel sofia/internal/@:5060 entering state [completed][200] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.295103 99.27% [DEBUG] switch_ivr_async.c:1777 No silence detection configured; assuming start of speech 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.315103 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.315103 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[6] Bytes encoded[315] Encoded length ms[120] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.335096 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[6] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.335096 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.355121 99.27% [DEBUG] sofia.c:7499 Channel sofia/internal/@:5060 entering state [ready][200] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.395103 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.395103 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[4] Bytes encoded[183] Encoded length ms[80] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.395103 99.27% [CRIT] switch_core_media.c:16221 sofia/internal/@:5060 not enough buffer space for required resample operation! 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.395103 99.27% [NOTICE] switch_core_media.c:16223 Hangup sofia/internal/@:5060 [CS_EXECUTE] [DESTINATION_OUT_OF_ORDER] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_ivr_bridge.c:826 sofia/internal/@:5060 ending bridge by request from read function 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/internal/@:5060] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_ivr_bridge.c:1895 sofia/internal/@:5060 skip receive message [UNBRIDGE] (channel is hungup already) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_session.c:2983 sofia/internal/@:5060 skip receive message [PHONE_EVENT] (channel is hungup already) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/@:5060) State EXECUTE going to sleep 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/@:5060) Running State Change CS_HANGUP (Cur 3 Tot 93) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_ivr_async.c:1596 Stop recording file /opt/fs_record_dir/upload/fs_record/2022/08/01/75077f5b-5811-40aa-a363-a19bc50813b0.wav 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_ivr_async.c:1677 Channel is hung up 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_media_bug.c:1328 Removing BUG from sofia/internal/@:5060 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/@:5060) Callstate Change ACTIVE -> HANGUP 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/@:5060) State HANGUP 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] mod_sofia.c:468 Channel sofia/internal/@:5060 hanging up, cause: DESTINATION_OUT_OF_ORDER 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/internal/@:5060 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:59 sofia/internal/@:5060 Standard HANGUP, cause: DESTINATION_OUT_OF_ORDER 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/@:5060) State HANGUP going to sleep 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/@:5060) State Change CS_HANGUP -> CS_REPORTING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/@:5060) Running State Change CS_REPORTING (Cur 3 Tot 93) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.415104 99.27% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/@:5060) State REPORTING 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:168 sofia/internal/@:5060 Standard REPORTING, cause: DESTINATION_OUT_OF_ORDER 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/@:5060) State REPORTING going to sleep 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/@:5060) State Change CS_REPORTING -> CS_DESTROY 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_session.c:1753 Session 90 (sofia/internal/@:5060) Locked, Waiting on external entities 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [NOTICE] switch_core_session.c:1771 Session 90 (sofia/internal/@:5060) Ended 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [NOTICE] switch_core_session.c:1775 Close Channel sofia/internal/@:5060 [CS_DESTROY] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/@:5060) Running State Change CS_DESTROY (Cur 2 Tot 93) 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/@:5060) State DESTROY 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] mod_sofia.c:379 sofia/internal/@:5060 SOFIA DESTROY 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[4] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:175 sofia/internal/@:5060 Standard DESTROY 095faf46-116f-11ed-9624-a79ea9c0433f 2022-08-01 15:53:37.455102 99.27% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/@:5060) State DESTROY going to sleep

zhouzz1986 avatar Aug 09 '22 07:08 zhouzz1986

This is an English-only project, so the bug description should be in English. You're supposed to attach logs, not copy-paste on the GH issue. We'll need network trace in pcap format too. Please try with FS master branch.

dragos-oancea avatar Aug 09 '22 10:08 dragos-oancea