I have issue making encrypted video call from one terminal to the other. Both terminals (one video phone and one softphone) have been setup to use SRTP (mandatory). And in the dial plan local_extension, an export action rtp_secure_media=true has been added. When making voice only call, there is no issue, and the terminals can establish SRTP media stream. However, even switching to (or making) video call, there is a "SRTP video unprotect failed with code 7 (auth check failed)" message, and call will be dropped.
Without SRTP encryption setting, the video between the terminals works.
Below is the log. Is there anything I can do to make it work?
Thanks.
Without SRTP encryption setting, the video between the terminals works.
Below is the log. Is there anything I can do to make it work?
Thanks.
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud set(caller_id_number=3168)
2020-10-19 21:59:18.712625 [DEBUG] mod_dptools.c:1672 SET sofia/internal/3168@demo.talk.cloudplay.cloud [caller_id_number]=[3168]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud set(RFC2822_DATE=Mon, 19 Oct 2020 21:59:18 +0800)
2020-10-19 21:59:18.712625 [DEBUG] mod_dptools.c:1672 SET sofia/internal/3168@demo.talk.cloudplay.cloud [RFC2822_DATE]=[Mon, 19 Oct 2020 21:59:18 +0800]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud export(origination_callee_id_name=3115)
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[3115]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud hash(insert/demo.talk.cloudplay.cloud-last_dial/3168/3115)
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud eval(not_secure)
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud eval(not_secure)
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud limit(hash demo.talk.cloudplay.cloud 3115 5 error/user_busy)
2020-10-19 21:59:18.712625 [DEBUG] switch_limit.c:124 incr called: demo.talk.cloudplay.cloud_3115 max:5, interval:0
2020-10-19 21:59:18.712625 [DEBUG] mod_hash.c:196 Usage for demo.talk.cloudplay.cloud_3115 is now 1/5
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud set(hangup_after_bridge=true)
2020-10-19 21:59:18.712625 [DEBUG] mod_dptools.c:1672 SET sofia/internal/3168@demo.talk.cloudplay.cloud [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud set(continue_on_fail=true)
2020-10-19 21:59:18.712625 [DEBUG] mod_dptools.c:1672 SET sofia/internal/3168@demo.talk.cloudplay.cloud [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud hash(insert/demo.talk.cloudplay.cloud-call_return/3115/3168)
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud hash(insert/demo.talk.cloudplay.cloud-last_dial_ext/3115/98f1cac1-b661-4de5-9692-b3bf3933fcd6)
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud set(called_party_call_group=)
2020-10-19 21:59:18.712625 [DEBUG] mod_dptools.c:1672 SET sofia/internal/3168@demo.talk.cloudplay.cloud [called_party_call_group]=[UNDEF]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud hash(insert/demo.talk.cloudplay.cloud-last_dial//98f1cac1-b661-4de5-9692-b3bf3933fcd6)
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud set(api_hangup_hook=lua app.lua hangup)
2020-10-19 21:59:18.712625 [DEBUG] mod_dptools.c:1672 SET sofia/internal/3168@demo.talk.cloudplay.cloud [api_hangup_hook]=[lua app.lua hangup]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud export(domain_name=demo.talk.cloudplay.cloud)
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [domain_name]=[demo.talk.cloudplay.cloud]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud export(nolocal:rtp_secure_media=true)
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) (REMOTE ONLY) [rtp_secure_media]=[true]
EXECUTE [depth=0] sofia/internal/3168@demo.talk.cloudplay.cloud bridge(user/3115@demo.talk.cloudplay.cloud)
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [domain_name]=[demo.talk.cloudplay.cloud] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [call_direction]=[local] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [dialed_extension]=[3115] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [origination_callee_id_name]=[3115] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [domain_name]=[demo.talk.cloudplay.cloud] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [rtp_secure_media]=[true] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [domain_name]=[demo.talk.cloudplay.cloud] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [call_direction]=[local] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [dialed_extension]=[3115] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [origination_callee_id_name]=[3115] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [domain_name]=[demo.talk.cloudplay.cloud] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_channel.c:1264 sofia/internal/3168@demo.talk.cloudplay.cloud EXPORTING[export_vars] [rtp_secure_media]=[true] to event
2020-10-19 21:59:18.712625 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2020-10-19 21:59:18.712625 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/3115@172.16.110.6:63282 [0a5057a5-7f19-485a-a9f9-e299acf22e90]
2020-10-19 21:59:18.712625 [DEBUG] mod_sofia.c:5089 (sofia/internal/3115@172.16.110.6:63282) State Change CS_NEW -> CS_INIT
2020-10-19 21:59:18.712625 [DEBUG] switch_ivr_originate.c:3111 sofia/internal/3115@172.16.110.6:63282 Setting leg timeout to 30
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/3115@172.16.110.6:63282) Running State Change CS_INIT (Cur 2 Tot 238)
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/3115@172.16.110.6:63282) State INIT
2020-10-19 21:59:18.712625 [DEBUG] mod_sofia.c:93 sofia/internal/3115@172.16.110.6:63282 SOFIA INIT
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [1 AEAD_AES_256_GCM_8 inline:tS/7pQBOCiRQ5eeGtYBer/DP5N5rb2pSiq39q8lHTYLsYHhZdLvmTvyHgSc=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [1 AEAD_AES_256_GCM_8 inline:tHVWju2mAbBSPLFb3FlSjxzgcXdOCJXzadz5PVcFEQzbelBeRaCmowRS6Hs=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [1 AEAD_AES_256_GCM_8 inline:9h5q0NhBkkAJ5/4QoSixRZ8surebhFFBojD6HJh+tZqcl0CqIGiiYb92qRA=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [2 AEAD_AES_256_GCM inline:kI1h2mKSqAp4M7gVnzCE++e1ZgHdC3kLXGPIeMHDUu+sptQLTEe7GlP6F1A=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [2 AEAD_AES_256_GCM inline:RPKJ3DMhyBaf7xjvy7Jo/uDt8kJureEGAdJ0GHWrJFd8ED0YXzLV2Kw1eGM=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [2 AEAD_AES_256_GCM inline:f0OkoOeF7t3bc4PPXLGswFZN7MbVJKwrijpT4SiQI2xRzBs6/jXkWzCayXA=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [3 AEAD_AES_128_GCM_8 inline:nO6iasT1KGk6G0jSQyqx7+4gENSOSwgChN8QxA==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [3 AEAD_AES_128_GCM_8 inline:22/zoa1RJ4jMVFQ+kXakYjp7FrR9iMP70/KY/w==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [3 AEAD_AES_128_GCM_8 inline:9w1XSaO1PYZqytcmNIXgUzBZH1cfnmxVG5BKHQ==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [4 AEAD_AES_128_GCM inline:0sKCpK2DsUP2jeQfa/Wgc5LrTsyHvWtlEUXPKA==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [4 AEAD_AES_128_GCM inline:M4a2cRdN9OPVeaxPVzn0h7OHgu8cC+1Rci6w1w==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [4 AEAD_AES_128_GCM inline:34oKaw94yyHpinsDjpO5tPe6lkj9glasvfACkw==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [5 AES_256_CM_HMAC_SHA1_80 inlineYcrKGz/uqS+R2vntCI/795j4AMVlfl9dqVZ+jFtAidm9UJFVJceH/OMTmhqhQ==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [5 AES_256_CM_HMAC_SHA1_80 inline:iDRjFTmEUKDg5zOcZkvJFRQ9aHOMZReM6CggCjUVs/YYXbf0ahLJBtysPaWptQ==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [5 AES_256_CM_HMAC_SHA1_80 inline
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [6 AES_192_CM_HMAC_SHA1_80 inline:BTC/xwmmearGogVeC12v9n6gfdYoAYGw/yOepTZjWPoG2fpuDME=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [6 AES_192_CM_HMAC_SHA1_80 inline:WHTFJ2djM0z1S/7dx6aeWa2px0LS8RZUP7t2FQdxCMVR0ZquaCA=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [6 AES_192_CM_HMAC_SHA1_80 inline:mILCDoOFAf9Z3ED8uaKQYXcd8ummuw8wlsdeVfDCOvRwzaTmbRc=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [7 AES_CM_128_HMAC_SHA1_80 inline:Tn8WHSIcPS1Xpuxmb5CElKRVlYjxUNuzR09GJHnY]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [7 AES_CM_128_HMAC_SHA1_80 inline:CzKXmaa40vXBS9F+1cFLll4qV8I4iurMAPlhFjmT]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [7 AES_CM_128_HMAC_SHA1_80 inline:BiBlwbARdp7LfLjm4Q5qcba2udMb5SA6cLONddSr]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [8 AES_256_CM_HMAC_SHA1_32 inline:AIaIHmulr33cMnG7q4dXDsFvhi73WdaTrZcI+d6howwxtKP8zit9NHFw8FqSHA==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [8 AES_256_CM_HMAC_SHA1_32 inline:rSlA+6IpxiDoQJNL0+hgYUBINE21/op3OzBJrY6gZ859MDx3mERP9KDWbJ/Fpw==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [8 AES_256_CM_HMAC_SHA1_32 inline:MZKJsX15jzI2n7E3w/GF6tcczOHe2SIUMuiSBGzhbk3J6/FRGocrLp1UuATOXw==]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [9 AES_192_CM_HMAC_SHA1_32 inline:5cVp/iC3U5M17qDExOMQzHcrgMoWMU/IsV5l84B9fzMdWGVUDdU=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [9 AES_192_CM_HMAC_SHA1_32 inline:hzXnw6sRNJsnD0nUrPjVmWmlq4pedSoTQbNbTeo/19r59nykl4Y=]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [9 AES_192_CM_HMAC_SHA1_32 inline
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [10 AES_CM_128_HMAC_SHA1_32 inline:qIx0EsDKopQbjXHp09ePwkaWHfw/3H+Np2O1misZ]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [10 AES_CM_128_HMAC_SHA1_32 inline:tbMTHpjCUUlAVMOcS+x3U2olUHGSIVkx/9yYlA+/]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [10 AES_CM_128_HMAC_SHA1_32 inline:Y9kup6wyLck0EbySTjTYLyvah5gcmUKUjp6lzWBu]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local audio crypto Key [11 AES_CM_128_NULL_AUTH inline:60IGd7UNc7bkcYCvYO8qpbuEKLk+xMukXiSzTXdj]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [11 AES_CM_128_NULL_AUTH inline:yI8/UDQK4OWwS1bqxM2ptGrBgT/Z6B/Ot3q04gK/]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_media.c:1217 Set Local text crypto Key [11 AES_CM_128_NULL_AUTH inline:TYZPsOH/GB4gNs0K3PEGqspHC3PF7KwNeG9nxQOV]
2020-10-19 21:59:18.712625 [DEBUG] sofia_glue.c:1587 sip:3115@101.127.231.146:56320;transport=TLS;ob Setting proxy route to sofia/internal/3115@172.16.110.6:63282
2020-10-19 21:59:18.712625 [DEBUG] sofia_glue.c:1618 sofia/internal/3115@172.16.110.6:63282 sending invite version: 1.10.5 -release-17-25569c1631 64bit
Local SDP:
v=0
o=FreeSWITCH 1603089036 1603089037 IN IP4 158.101.139.40
s=FreeSWITCH
c=IN IP4 158.101.139.40
t=0 0
m=audio 26922 RTP/SAVP 9 0 8 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=crypto:1 AEAD_AES_256_GCM_8 inline:tS/7pQBOCiRQ5eeGtYBer/DP5N5rb2pSiq39q8lHTYLsYHhZdLvmTvyHgSc=
a=crypto:2 AEAD_AES_256_GCM inline:kI1h2mKSqAp4M7gVnzCE++e1ZgHdC3kLXGPIeMHDUu+sptQLTEe7GlP6F1A=
a=crypto:3 AEAD_AES_128_GCM_8 inline:nO6iasT1KGk6G0jSQyqx7+4gENSOSwgChN8QxA==
a=crypto:4 AEAD_AES_128_GCM inline:0sKCpK2DsUP2jeQfa/Wgc5LrTsyHvWtlEUXPKA==
a=crypto:5 AES_256_CM_HMAC_SHA1_80 inline
a=crypto:6 AES_192_CM_HMAC_SHA1_80 inline:BTC/xwmmearGogVeC12v9n6gfdYoAYGw/yOepTZjWPoG2fpuDME=
a=crypto:7 AES_CM_128_HMAC_SHA1_80 inline:Tn8WHSIcPS1Xpuxmb5CElKRVlYjxUNuzR09GJHnY
a=crypto:8 AES_256_CM_HMAC_SHA1_32 inline:AIaIHmulr33cMnG7q4dXDsFvhi73WdaTrZcI+d6howwxtKP8zit9NHFw8FqSHA==
a=crypto:9 AES_192_CM_HMAC_SHA1_32 inline:5cVp/iC3U5M17qDExOMQzHcrgMoWMU/IsV5l84B9fzMdWGVUDdU=
a=crypto:10 AES_CM_128_HMAC_SHA1_32 inline:qIx0EsDKopQbjXHp09ePwkaWHfw/3H+Np2O1misZ
a=crypto:11 AES_CM_128_NULL_AUTH inline:60IGd7UNc7bkcYCvYO8qpbuEKLk+xMukXiSzTXdj
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
m=video 24742 RTP/SAVP 102
b=AS:1024
a=rtpmap:102 H264/90000
a=inactive
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
a=crypto:1 AEAD_AES_256_GCM_8 inline:tHVWju2mAbBSPLFb3FlSjxzgcXdOCJXzadz5PVcFEQzbelBeRaCmowRS6Hs=
a=crypto:2 AEAD_AES_256_GCM inline:RPKJ3DMhyBaf7xjvy7Jo/uDt8kJureEGAdJ0GHWrJFd8ED0YXzLV2Kw1eGM=
a=crypto:3 AEAD_AES_128_GCM_8 inline:22/zoa1RJ4jMVFQ+kXakYjp7FrR9iMP70/KY/w==
a=crypto:4 AEAD_AES_128_GCM inline:M4a2cRdN9OPVeaxPVzn0h7OHgu8cC+1Rci6w1w==
a=crypto:5 AES_256_CM_HMAC_SHA1_80 inline:iDRjFTmEUKDg5zOcZkvJFRQ9aHOMZReM6CggCjUVs/YYXbf0ahLJBtysPaWptQ==
a=crypto:6 AES_192_CM_HMAC_SHA1_80 inline:WHTFJ2djM0z1S/7dx6aeWa2px0LS8RZUP7t2FQdxCMVR0ZquaCA=
a=crypto:7 AES_CM_128_HMAC_SHA1_80 inline:CzKXmaa40vXBS9F+1cFLll4qV8I4iurMAPlhFjmT
a=crypto:8 AES_256_CM_HMAC_SHA1_32 inline:rSlA+6IpxiDoQJNL0+hgYUBINE21/op3OzBJrY6gZ859MDx3mERP9KDWbJ/Fpw==
a=crypto:9 AES_192_CM_HMAC_SHA1_32 inline:hzXnw6sRNJsnD0nUrPjVmWmlq4pedSoTQbNbTeo/19r59nykl4Y=
a=crypto:10 AES_CM_128_HMAC_SHA1_32 inline:tbMTHpjCUUlAVMOcS+x3U2olUHGSIVkx/9yYlA+/
a=crypto:11 AES_CM_128_NULL_AUTH inline:yI8/UDQK4OWwS1bqxM2ptGrBgT/Z6B/Ot3q04gK/
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:40 sofia/internal/3115@172.16.110.6:63282 Standard INIT
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/3115@172.16.110.6:63282) State Change CS_INIT -> CS_ROUTING
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/3115@172.16.110.6:63282) State INIT going to sleep
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/3115@172.16.110.6:63282) Running State Change CS_ROUTING (Cur 2 Tot 238)
2020-10-19 21:59:18.712625 [DEBUG] sofia.c:7326 Channel sofia/internal/3115@172.16.110.6:63282 entering state [calling][0]
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/3115@172.16.110.6:63282) State ROUTING
2020-10-19 21:59:18.712625 [DEBUG] mod_sofia.c:154 sofia/internal/3115@172.16.110.6:63282 SOFIA ROUTING
2020-10-19 21:59:18.712625 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/3115@172.16.110.6:63282) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/3115@172.16.110.6:63282) State ROUTING going to sleep
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/3115@172.16.110.6:63282) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 238)
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/3115@172.16.110.6:63282) State CONSUME_MEDIA
2020-10-19 21:59:18.712625 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/3115@172.16.110.6:63282) State CONSUME_MEDIA going to sleep
2020-10-19 21:59:18.932617 [DEBUG] sofia.c:7326 Channel sofia/internal/3115@172.16.110.6:63282 entering state [proceeding][180]
2020-10-19 21:59:18.932617 [NOTICE] sofia.c:7437 Ring-Ready sofia/internal/3115@172.16.110.6:63282!
2020-10-19 21:59:18.932617 [DEBUG] switch_channel.c:3437 (sofia/internal/3115@172.16.110.6:63282) Callstate Change DOWN -> RINGING
2020-10-19 21:59:18.952624 [INFO] switch_ivr_originate.c:1275 Sending early media
2020-10-19 21:59:18.952624 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/internal/3168@demo.talk.cloudplay.cloud] 10.20.0.14 port 17348 -> 192.168.178.117 port 10284 codec: 9 ms: 20
2020-10-19 21:59:18.952624 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
2020-10-19 21:59:18.952624 [DEBUG] switch_core_media.c:8977 sofia/internal/3168@demo.talk.cloudplay.cloud Set 2833 dtmf send payload to 101
2020-10-19 21:59:18.952624 [DEBUG] switch_core_media.c:8984 sofia/internal/3168@demo.talk.cloudplay.cloud Set 2833 dtmf receive payload to 101
2020-10-19 21:59:18.952624 [DEBUG] switch_core_media.c:9007 sofia/internal/3168@demo.talk.cloudplay.cloud Set rtp dtmf delay to 40
2020-10-19 21:59:18.952624 [INFO] switch_rtp.c:4254 Activating audio Secure RTP SEND
2020-10-19 21:59:18.952624 [DEBUG] switch_core_sqldb.c:2836 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:18.952624 [INFO] switch_rtp.c:4232 Activating audio Secure RTP RECV
2020-10-19 21:59:18.952624 [DEBUG] switch_core_sqldb.c:2836 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:18.952624 [DEBUG] mod_sofia.c:2593 Ring SDP:
v=0
o=FreeSWITCH 1603098610 1603098611 IN IP4 158.101.139.40
s=FreeSWITCH
c=IN IP4 158.101.139.40
t=0 0
m=audio 17348 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:8l2OEp6n1ir+4ioI7i1TglMAU1eP7T8PPxPyxVbW
2020-10-19 21:59:18.952624 [NOTICE] mod_sofia.c:2596 Pre-Answer sofia/internal/3168@demo.talk.cloudplay.cloud!
2020-10-19 21:59:18.952624 [DEBUG] switch_channel.c:3565 (sofia/internal/3168@demo.talk.cloudplay.cloud) Callstate Change RINGING -> EARLY
2020-10-19 21:59:18.952624 [DEBUG] switch_ivr_originate.c:1333 Raw Codec Activation Success L16@16000hz 1 channel 20ms
2020-10-19 21:59:18.952624 [DEBUG] switch_core_codec.c:223 sofia/internal/3168@demo.talk.cloudplay.cloud Push codec L16:100
2020-10-19 21:59:18.952624 [DEBUG] switch_ivr_originate.c:1407 Play Ringback Tone [%(400,200,400,450);%(400,2000,400,450)]
2020-10-19 21:59:18.972628 [DEBUG] sofia.c:7326 Channel sofia/internal/3168@demo.talk.cloudplay.cloud entering state [early][183]
2020-10-19 21:59:19.572623 [INFO] switch_rtp.c:7719 Auto Changing audio port from 192.168.178.117:10284 to 115.66.245.196:60666
2020-10-19 21:59:24.612626 [DEBUG] sofia.c:7326 Channel sofia/internal/3115@172.16.110.6:63282 entering state [completing][200]
2020-10-19 21:59:24.612626 [DEBUG] sofia.c:7336 Remote SDP:
v=0
o=- 3812133558 3812133560 IN IP4 172.16.110.6
s=pjmedia
b=AS:352
t=0 0
a=X-nat:0
m=audio 4008 RTP/SAVP 9 101
c=IN IP4 172.16.110.6
b=TIAS:64000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4009 IN IP4 172.16.110.6
a=ssrc:541071868 cname:301d107569e55ddc
a=crypto:7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0
m=video 0 RTP/SAVP 102
c=IN IP4 172.16.110.6
2020-10-19 21:59:24.612626 [DEBUG] sofia.c:7326 Channel sofia/internal/3115@172.16.110.6:63282 entering state [ready][200]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_256_GCM_8]alias=[] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_256_GCM]alias=[] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_128_GCM_8]alias=[] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_128_GCM]alias=[] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_256_CM_HMAC_SHA1_80]alias=[AES_CM_256_HMAC_SHA1_80] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_192_CM_HMAC_SHA1_80]alias=[AES_CM_192_HMAC_SHA1_80] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_CM_128_HMAC_SHA1_80]alias=[] in [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1824 Found suite AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:1894 Set Remote Key [7 AES_CM_128_HMAC_SHA1_80 inline:6CZXExoWtcg9RlMnTD5Us40+BJLGcSI4GmkdMTV0]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:3839 Set Codec sofia/internal/3115@172.16.110.6:63282 G722/8000 20 ms 160 samples 64000 bits 1 channels
2020-10-19 21:59:24.612626 [DEBUG] switch_core_codec.c:111 sofia/internal/3115@172.16.110.6:63282 Original read codec set to G722:9
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:5911 sofia/internal/3115@172.16.110.6:63282 Set 2833 dtmf send payload to 101 recv payload to 101
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/internal/3115@172.16.110.6:63282] 10.20.0.14 port 26922 -> 172.16.110.6 port 4008 codec: 9 ms: 20
2020-10-19 21:59:24.612626 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:8885 Activating RTCP PORT 4009
2020-10-19 21:59:24.612626 [DEBUG] switch_rtp.c:4848 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4009
2020-10-19 21:59:24.612626 [DEBUG] switch_rtp.c:2636 Setting RTCP remote addr to 172.16.110.6:4009 2
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:8977 sofia/internal/3115@172.16.110.6:63282 Set 2833 dtmf send payload to 101
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:8984 sofia/internal/3115@172.16.110.6:63282 Set 2833 dtmf receive payload to 101
2020-10-19 21:59:24.612626 [DEBUG] switch_core_media.c:9007 sofia/internal/3115@172.16.110.6:63282 Set rtp dtmf delay to 40
2020-10-19 21:59:24.612626 [INFO] switch_rtp.c:4254 Activating audio Secure RTP SEND
2020-10-19 21:59:24.612626 [INFO] switch_rtp.c:4232 Activating audio Secure RTP RECV
2020-10-19 21:59:24.612626 [DEBUG] switch_core_sqldb.c:2836 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:24.612626 [DEBUG] switch_core_sqldb.c:2836 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:24.612626 [NOTICE] sofia.c:8504 Channel [sofia/internal/3115@172.16.110.6:63282] has been answered
2020-10-19 21:59:24.612626 [DEBUG] switch_channel.c:3865 (sofia/internal/3115@172.16.110.6:63282) Callstate Change RINGING -> ACTIVE
2020-10-19 21:59:24.632620 [DEBUG] switch_core_codec.c:248 sofia/internal/3168@demo.talk.cloudplay.cloud Restore previous codec G722:9.
2020-10-19 21:59:24.632620 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/internal/3168@demo.talk.cloudplay.cloud.
2020-10-19 21:59:24.632620 [DEBUG] mod_sofia.c:898 Local SDP sofia/internal/3168@demo.talk.cloudplay.cloud:
v=0
o=FreeSWITCH 1603098610 1603098612 IN IP4 158.101.139.40
s=FreeSWITCH
c=IN IP4 158.101.139.40
t=0 0
m=audio 17348 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:8l2OEp6n1ir+4ioI7i1TglMAU1eP7T8PPxPyxVbW
2020-10-19 21:59:24.632620 [NOTICE] switch_ivr_originate.c:3794 Channel [sofia/internal/3168@demo.talk.cloudplay.cloud] has been answered
2020-10-19 21:59:24.632620 [DEBUG] switch_channel.c:3865 (sofia/internal/3168@demo.talk.cloudplay.cloud) Callstate Change EARLY -> ACTIVE
2020-10-19 21:59:24.632620 [DEBUG] sofia.c:7326 Channel sofia/internal/3168@demo.talk.cloudplay.cloud entering state [completed][200]
2020-10-19 21:59:24.632620 [DEBUG] switch_ivr_originate.c:3852 Originate Resulted in Success: [sofia/internal/3115@172.16.110.6:63282]
2020-10-19 21:59:24.632620 [DEBUG] switch_ivr_originate.c:3111 sofia/internal/3115@172.16.110.6:63282 Setting leg timeout to 30
2020-10-19 21:59:24.632620 [DEBUG] switch_ivr_originate.c:3852 Originate Resulted in Success: [sofia/internal/3115@172.16.110.6:63282]
2020-10-19 21:59:24.632620 [DEBUG] switch_ivr_bridge.c:1793 (sofia/internal/3115@172.16.110.6:63282) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2020-10-19 21:59:24.632620 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/3115@172.16.110.6:63282) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 238)
2020-10-19 21:59:24.632620 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/3115@172.16.110.6:63282) State EXCHANGE_MEDIA
2020-10-19 21:59:24.632620 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
2020-10-19 21:59:24.652622 [DEBUG] switch_rtp.c:1921 rtcp_stats_init: audio ssrc[541071868] base_seq[11669]
2020-10-19 21:59:24.692623 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
2020-10-19 21:59:24.852621 [INFO] switch_rtp.c:7719 Auto Changing audio port from 172.16.110.6:4008 to 101.127.231.146:38603
2020-10-19 21:59:24.892632 [DEBUG] sofia.c:7326 Channel sofia/internal/3168@demo.talk.cloudplay.cloud entering state [ready][200]
2020-10-19 21:59:25.132623 [INFO] switch_rtp.c:7136 Auto Changing audio RTCP port from 172.16.110.6:4009 to 101.127.231.146:24867
2020-10-19 21:59:25.132623 [DEBUG] switch_rtp.c:2636 Setting RTCP remote addr to 101.127.231.146:24867 2
2020-10-19 21:59:34.992620 [DEBUG] sofia.c:7326 Channel sofia/internal/3168@demo.talk.cloudplay.cloud entering state [received][100]
2020-10-19 21:59:34.992620 [DEBUG] sofia.c:7336 Remote SDP:
v=0
o=sdp_admin 5528236524 3817450785 IN IP4 192.168.178.117
s=A conversation
c=IN IP4 192.168.178.117
t=0 0
m=audio 10284 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp
m=video 10286 RTP/SAVP 117
a=rtpmap:117 H264/90000
a=fmtp:117 profile-level-id=42801f; max-br=2000
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_256_GCM_8]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_256_GCM]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_128_GCM_8]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_128_GCM]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_256_CM_HMAC_SHA1_80]alias=[AES_CM_256_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_192_CM_HMAC_SHA1_80]alias=[AES_CM_192_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_CM_128_HMAC_SHA1_80]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:57A2GRUGbmLFrzZ3dz6nJnLzCW8tPyIPtCxtdVUp]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1824 Found suite AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1835 Existing key is still valid.
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:5911 sofia/internal/3168@demo.talk.cloudplay.cloud Set 2833 dtmf send payload to 101 recv payload to 101
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_256_GCM_8]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_256_GCM]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_128_GCM_8]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AEAD_AES_128_GCM]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_256_CM_HMAC_SHA1_80]alias=[AES_CM_256_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_192_CM_HMAC_SHA1_80]alias=[AES_CM_192_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1815 looking for crypto suite [AES_CM_128_HMAC_SHA1_80]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1824 Found suite AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1894 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:i3PGQOWz33y4ouBicyT9Wfq5TV99Uhda6mKkAG2t]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:1217 Set Local video crypto Key [1 AES_CM_128_HMAC_SHA1_80 inline:FxB6TeRVWg+5GdqWiZier5MOOeLTHpbXqtTQtmbD]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:6196 Video Codec Compare [H264:117]/[H264:97]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:6228 Video Codec Compare [H264:117] +++ is saved as a match
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:3649 Set VIDEO Codec sofia/internal/3168@demo.talk.cloudplay.cloud H264/90000 0 ms
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/internal/3168@demo.talk.cloudplay.cloud.
2020-10-19 21:59:34.992620 [DEBUG] switch_rtp.c:4465 Starting video timer.
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:9495 VIDEO RTP [sofia/internal/3168@demo.talk.cloudplay.cloud] 10.20.0.14:24874->192.168.178.117:10286 codec: 117 ms: 0 [SUCCESS]
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:7630 sofia/internal/3168@demo.talk.cloudplay.cloud Starting Video thread
2020-10-19 21:59:34.992620 [DEBUG] switch_core_media.c:7496 sofia/internal/3168@demo.talk.cloudplay.cloud Video thread started. Echo is off
2020-10-19 21:59:34.992620 [INFO] switch_rtp.c:4254 Activating video Secure RTP SEND
2020-10-19 21:59:34.992620 [INFO] switch_rtp.c:4232 Activating video Secure RTP RECV
2020-10-19 21:59:34.992620 [DEBUG] switch_core_sqldb.c:2836 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:34.992620 [DEBUG] sofia.c:8275 Processing updated SDP
2020-10-19 21:59:34.992620 [DEBUG] switch_core_sqldb.c:2836 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
2020-10-19 21:59:35.012627 [DEBUG] sofia.c:7326 Channel sofia/internal/3168@demo.talk.cloudplay.cloud entering state [completed][200]
2020-10-19 21:59:35.252622 [DEBUG] sofia.c:7326 Channel sofia/internal/3168@demo.talk.cloudplay.cloud entering state [ready][200]
2020-10-19 21:59:38.252623 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 10 errors
2020-10-19 21:59:38.273219 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 20 errors
2020-10-19 21:59:38.273219 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 30 errors
2020-10-19 21:59:38.273219 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 40 errors
2020-10-19 21:59:38.273219 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 50 errors
2020-10-19 21:59:38.292625 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1199 bytes 60 errors
2020-10-19 21:59:38.312624 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 70 errors
2020-10-19 21:59:38.312624 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 80 errors
2020-10-19 21:59:38.372622 [WARNING] switch_rtp.c:6298 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 90 errors
2020-10-19 21:59:38.372622 [WARNING] switch_rtp.c:6291 SRTP video unprotect failed with code 7 (auth check failed) 1452 bytes 100 errors
2020-10-19 21:59:38.372622 [WARNING] switch_rtp.c:6294 Ending call due to SRTP error
2020-10-19 21:59:38.372622 [NOTICE] switch_rtp.c:6296 Hangup sofia/internal/3168@demo.talk.cloudplay.cloud [CS_EXECUTE] [SRTP_READ_ERROR]
2020-10-19 21:59:38.372622 [DEBUG] mod_hash.c:296 Usage for demo.talk.cloudplay.cloud_3115 is now 0
2020-10-19 21:59:38.372622 [DEBUG] switch_core_media.c:7597 sofia/internal/3168@demo.talk.cloudplay.cloud Video thread ended
2020-10-19 21:59:38.372622 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/internal/3115@172.16.110.6:63282]
2020-10-19 21:59:38.372622 [DEBUG] switch_core_session.c:2652 sofia/internal/3168@demo.talk.cloudplay.cloud skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)