1. note: outbound route is through a Cisco PBX (CUCM) but same errors appear in verto-to-verto call (https://pastebin.freeswitch.org/view/e54c7f90)
2.  
3. 2020-02-10 19:56:34.418742 [NOTICE] switch_channel.c:1118 New Channel sofia/Localnet/917072057979 [52bba2c4-d387-4770-8e86-4588443efaf3]
4. 2020-02-10 19:56:34.418742 [DEBUG] mod_sofia.c:5096 (sofia/Localnet/917072057979) State Change CS_NEW -> CS_INIT
5. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:585 (sofia/Localnet/917072057979) Running State Change CS_INIT (Cur 2 Tot 12)
6. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:628 (sofia/Localnet/917072057979) State INIT
7. 2020-02-10 19:56:34.418742 [DEBUG] mod_sofia.c:93 sofia/Localnet/917072057979 SOFIA INIT
8. 2020-02-10 19:56:34.418742 [DEBUG] sofia_glue.c:1618 sofia/Localnet/917072057979 sending invite version: 1.10.1 -release-12-f9990221e6 64bit
9. Local SDP:
10. v=0
11. o=FreeSWITCH 1581347046 1581347047 IN IP4 172.20.253.46
12. s=FreeSWITCH
13. c=IN IP4 172.20.253.46
14. t=0 0
15. m=audio 17548 RTP/AVP 0 101 13
16. a=rtpmap:0 PCMU/8000
17. a=rtpmap:101 telephone-event/8000
18. a=fmtp:101 0-16
19. a=rtpmap:13 CN/8000
20. a=ptime:20
21. a=sendrecv
22.  
23. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:40 sofia/Localnet/917072057979 Standard INIT
24. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:48 (sofia/Localnet/917072057979) State Change CS_INIT -> CS_ROUTING
25. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:628 (sofia/Localnet/917072057979) State INIT going to sleep
26. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:585 (sofia/Localnet/917072057979) Running State Change CS_ROUTING (Cur 2 Tot 12)
27. 2020-02-10 19:56:34.418742 [DEBUG] sofia.c:7290 Channel sofia/Localnet/917072057979 entering state [calling][0]
28. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:644 (sofia/Localnet/917072057979) State ROUTING
29. 2020-02-10 19:56:34.418742 [DEBUG] mod_sofia.c:154 sofia/Localnet/917072057979 SOFIA ROUTING
30. 2020-02-10 19:56:34.418742 [DEBUG] switch_ivr_originate.c:67 (sofia/Localnet/917072057979) State Change CS_ROUTING -> CS_CONSUME_MEDIA
31. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:644 (sofia/Localnet/917072057979) State ROUTING going to sleep
32. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:585 (sofia/Localnet/917072057979) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 12)
33. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:663 (sofia/Localnet/917072057979) State CONSUME_MEDIA
34. 2020-02-10 19:56:34.418742 [DEBUG] switch_core_state_machine.c:663 (sofia/Localnet/917072057979) State CONSUME_MEDIA going to sleep
35. 2020-02-10 19:56:34.478740 [INFO] sofia.c:1364 sofia/Localnet/917072057979 Update Callee ID to "7072057979" <17072057979>
36. 2020-02-10 19:56:34.478740 [DEBUG] sofia.c:7290 Channel sofia/Localnet/917072057979 entering state [proceeding][183]
37. 2020-02-10 19:56:34.478740 [DEBUG] sofia.c:7300 Remote SDP:
38. v=0
39. o=CiscoSystemsCCM-SIP 12412155 1 IN IP4 10.0.20.27
40. s=SIP Call
41. c=IN IP4 10.0.20.27
42. b=TIAS:64000
43. b=CT:64
44. b=AS:64
45. t=0 0
46. m=audio 30076 RTP/AVP 0 101
47. a=rtpmap:0 PCMU/8000
48. a=rtpmap:101 telephone-event/8000
49. a=fmtp:101 0-15
50. a=ptime:20
51.  
52. 2020-02-10 19:56:34.478740 [NOTICE] sofia.c:7303 Pre-Answer sofia/Localnet/917072057979!
53. 2020-02-10 19:56:34.478740 [DEBUG] switch_channel.c:3565 (sofia/Localnet/917072057979) Callstate Change DOWN -> EARLY
54. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
55. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
56. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:5506 Set telephone-event payload to 101@8000
57. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:3834 Set Codec sofia/Localnet/917072057979 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
58. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_codec.c:111 sofia/Localnet/917072057979 Original read codec set to PCMU:0
59. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:5849 Set telephone-event payload to 101@8000
60. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:5907 sofia/Localnet/917072057979 Set 2833 dtmf send payload to 101 recv payload to 101
61. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:8658 AUDIO RTP [sofia/Localnet/917072057979] 172.20.253.46 port 17548 -> 10.0.20.27 port 30076 codec: 0 ms: 20
62. 2020-02-10 19:56:34.478740 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
63. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:8972 sofia/Localnet/917072057979 Set 2833 dtmf send payload to 101
64. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:8979 sofia/Localnet/917072057979 Set 2833 dtmf receive payload to 101
65. 2020-02-10 19:56:34.478740 [DEBUG] switch_core_media.c:9002 sofia/Localnet/917072057979 Set rtp dtmf delay to 40
66. 2020-02-10 19:56:34.498742 [DEBUG] switch_ivr_originate.c:436 Setting codec string on verto.rtc/7072057979 to PCMU@8000h@20i
67. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:111:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
68. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
69. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
70. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
71. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
72. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
73. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
74. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [CN:106:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
75. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [CN:105:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
76. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [CN:13:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
77. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5506 Set telephone-event payload to 110@48000
78. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:3834 Set Codec verto.rtc/7072057979 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
79. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_codec.c:111 verto.rtc/7072057979 Original read codec set to PCMU:0
80. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.203.1:52162
81. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.11.4:52163
82. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: srflx addr: 47.208.143.73:52163
83. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4324 Searching for rtp candidate.
84. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4333 Choose rtp candidate, index 2, 47.208.143.73:52163
85. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4099 verto.rtc/7072057979 choosing family v4
86. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4344 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 47.208.143.73:52163
87. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4396 setting remote audio ice addr to index 2 47.208.143.73:52163 based on candidate
88. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:4431 Setting remote rtcp audio addr to 47.208.143.73:52163 based on candidate
89. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5849 Set telephone-event payload to 126@8000
90. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:5907 verto.rtc/7072057979 Set 2833 dtmf send payload to 126 recv payload to 126
91.  
92.  
93.  
94. 2020-02-10 19:56:34.498742 [CRIT] switch_channel.c:1484 Invalid data (${advertised_media_ip} contains a variable)
95. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:8658 AUDIO RTP [verto.rtc/7072057979] 172.20.253.46 port 31858 -> 47.208.143.73 port 52163 codec: 0 ms: 20
96. 2020-02-10 19:56:34.498742 [CRIT] switch_channel.c:1484 Invalid data (${advertised_media_ip} contains a variable)
97.  
98.  
99. 2020-02-10 19:56:34.498742 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
100. 2020-02-10 19:56:34.498742 [INFO] switch_core_media.c:8840 Activating Audio ICE
101. 2020-02-10 19:56:34.498742 [NOTICE] switch_rtp.c:4910 Activating RTP audio ICE: MEso:E49jHpieyRDYDTvy 47.208.143.73:52163
102. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:8880 Activating RTCP PORT 52163
103. 2020-02-10 19:56:34.498742 [DEBUG] switch_rtp.c:4806 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 52163
104. 2020-02-10 19:56:34.498742 [INFO] switch_core_media.c:8891 Skipping RTCP ICE (Same as RTP)
105. 2020-02-10 19:56:34.498742 [INFO] switch_rtp.c:3736 Activate RTP/RTCP audio DTLS client
106. 2020-02-10 19:56:34.498742 [INFO] switch_rtp.c:3903 Changing audio DTLS state from OFF to HANDSHAKE
107. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:2549 Setting Jitterbuffer to 20ms (1 frames) (50 max frames)
108. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:8972 verto.rtc/7072057979 Set 2833 dtmf send payload to 126
109. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:8979 verto.rtc/7072057979 Set 2833 dtmf receive payload to 126
110.  
111. 2020-02-10 19:56:34.498742 [CRIT] switch_channel.c:1484 Invalid data (${rtp_local_sdp_str} contains a variable)
112.  
113.  
114. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:8640 Audio params are unchanged for verto.rtc/7072057979.
115. 2020-02-10 19:56:34.498742 [DEBUG] mod_verto.c:2519 Local SDP verto.rtc/7072057979:
116. v=0
117. o=FreeSWITCH 1581332736 1581332737 IN IP4 ${external_rtp_ip}
118. s=FreeSWITCH
119. c=IN IP4 ${external_rtp_ip}
120. t=0 0
121. a=msid-semantic: WMS ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqH
122. m=audio 31858 UDP/TLS/RTP/SAVPF 0 126
123. a=rtpmap:0 PCMU/8000
124. a=rtpmap:126 telephone-event/8000
125. a=silenceSupp:off - - - -
126. a=ptime:20
127. a=sendrecv
128. a=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3
129. a=setup:active
130. a=rtcp-mux
131. a=rtcp:31858 IN IP4 ${external_rtp_ip}
132. a=ice-ufrag:E49jHpieyRDYDTvy
133. a=ice-pwd:seWjQmYFvVt02UlxPlHnAPrZ
134. a=candidate:9727255544 1 udp 659136 ${external_rtp_ip} 31858 typ host generation 0
135. a=end-of-candidates
136. a=ssrc:3447296298 cname:5JSy0MzPYj6YEhAu
137. a=ssrc:3447296298 msid:ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqH a0
138. a=ssrc:3447296298 mslabel:ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqH
139. a=ssrc:3447296298 label:ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqHa0
140.  
141. 2020-02-10 19:56:34.498742 [NOTICE] switch_ivr_originate.c:3755 Pre-Answer verto.rtc/7072057979!
142. 2020-02-10 19:56:34.498742 [DEBUG] switch_channel.c:3565 (verto.rtc/7072057979) Callstate Change RINGING -> EARLY
143. 2020-02-10 19:56:34.498742 [DEBUG] switch_ivr_originate.c:3806 Originate Resulted in Success: [sofia/Localnet/917072057979]
144. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_media.c:12806 verto.rtc/7072057979 PAUSE Jitterbuffer
145. 2020-02-10 19:56:34.498742 [DEBUG] switch_ivr_bridge.c:1794 (sofia/Localnet/917072057979) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
146. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_state_machine.c:585 (sofia/Localnet/917072057979) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 12)
147. 2020-02-10 19:56:34.498742 [DEBUG] switch_core_state_machine.c:654 (sofia/Localnet/917072057979) State EXCHANGE_MEDIA
148. 2020-02-10 19:56:34.498742 [DEBUG] mod_sofia.c:663 SOFIA EXCHANGE_MEDIA
149. 2020-02-10 19:56:34.538739 [DEBUG] mod_verto.c:607 WRITE 47.208.143.73:53106 [{
150.         "jsonrpc":      "2.0",
151.         "id":   12,
152.         "method":       "verto.media",
153.         "params":       {
154.                 "callID":       "7088e146-6b2f-2f4b-e970-f12e7a80d7bb",
155.                 "sdp":  "v=0\r\no=FreeSWITCH 1581332736 1581332737 IN IP4 ${external_rtp_ip}\r\ns=FreeSWITCH\r\nc=IN IP4 ${external_rtp_ip}\r\nt=0 0\r\na=msid-semantic: WMS ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqH\r\nm=audio 31858 UDP/TLS/RTP/SAVPF 0 126\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:126 telephone-event/8000\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\na=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3\r\na=setup:active\r\na=rtcp-mux\r\na=rtcp:31858 IN IP4 ${external_rtp_ip}\r\na=ice-ufrag:E49jHpieyRDYDTvy\r\na=ice-pwd:seWjQmYFvVt02UlxPlHnAPrZ\r\na=candidate:9727255544 1 udp 659136 ${external_rtp_ip} 31858 typ host generation 0\r\na=end-of-candidates\r\na=ssrc:3447296298 cname:5JSy0MzPYj6YEhAu\r\na=ssrc:3447296298 msid:ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqH a0\r\na=ssrc:3447296298 mslabel:ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqH\r\na=ssrc:3447296298 label:ijtlDq4aZmUq9vlM0wEOONp9GjJyzVqHa0\r\n"
156.         }
157. }]
158. 2020-02-10 19:56:34.538739 [DEBUG] switch_rtp.c:7720 Correct audio ip/port confirmed.
159. 2020-02-10 19:56:34.618739 [DEBUG] mod_verto.c:1415 READ 47.208.143.73:53106 [{
160.         "jsonrpc":      "2.0",
161.         "id":   12,
162.         "result":       {
163.                 "method":       "verto.media"
164.         }
165. }]
166. 2020-02-10 19:56:38.438738 [DEBUG] sofia.c:7290 Channel sofia/Localnet/917072057979 entering state [completing][200]
167. 2020-02-10 19:56:38.438738 [DEBUG] sofia.c:7297 Duplicate SDP
168. v=0
169. o=CiscoSystemsCCM-SIP 12412155 1 IN IP4 10.0.20.27
170. s=SIP Call
171. c=IN IP4 10.0.20.27
172. b=TIAS:64000
173. b=CT:64
174. b=AS:64
175. t=0 0
176. m=audio 30076 RTP/AVP 0 101
177. a=rtpmap:0 PCMU/8000
178. a=rtpmap:101 telephone-event/8000
179. a=fmtp:101 0-15
180. a=ptime:20
181.  
182. 2020-02-10 19:56:38.458740 [DEBUG] sofia.c:7290 Channel sofia/Localnet/917072057979 entering state [ready][200]
183. 2020-02-10 19:56:38.458740 [NOTICE] sofia.c:8409 Channel [sofia/Localnet/917072057979] has been answered