FreeSWITCH Pastebin

opuspcmareinvitre

From ft, 3 Years ago, written in Plain Text.
- view diff
URL https://pastebin.freeswitch.org/view/d2d5d980
Embed
Download Paste or View Raw
  1. freeswitch@test> sofia global siptrace on
  2. +OK Global siptrace on
  3. recv 751 bytes from udp/[192.168.1.166]:52290 at 17:03:19.386127:
  4. ------------------------------------------------------------------------
  5. INVITE sip:1001@192.168.1.166;transport=UDP SIP/2.0
  6. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---8600afbc9bef3bae;rport
  7. Max-Forwards: 70
  8. Contact: <sip:1000@192.168.1.166:52290;transport=UDP>
  9. To: <sip:1001@192.168.1.166>
  10. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  11. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  12. CSeq: 1 INVITE
  13. Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
  14. Content-Type: application/sdp
  15. User-Agent: Z 5.4.12 v2.10.13.2-mod
  16. Allow-Events: presence, kpml, talk
  17. Content-Length: 188
  18.  
  19. v=0
  20. o=Z 1639587799318 1 IN IP4 192.168.1.166
  21. s=Z
  22. c=IN IP4 192.168.1.166
  23. t=0 0
  24. m=audio 8000 RTP/AVP 106
  25. a=rtpmap:106 opus/48000/2
  26. a=fmtp:106 minptime=20; useinbandfec=1
  27. a=sendrecv
  28. 2021-12-15 17:03:19.380771 96.50% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/1000@192.168.1.166 [4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b]
  29. 2021-12-15 17:03:19.380771 96.50% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000@192.168.1.166) Running State Change CS_NEW (Cur 1 Tot 3)
  30. 2021-12-15 17:03:19.380771 96.50% [INFO] sofia.c:10462 sofia/internal/1000@192.168.1.166 receiving invite from 192.168.1.166:52290 version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit call-id: jYevjHAm1_ygYqwyPAyFbQ..
  31. 2021-12-15 17:03:19.380771 96.50% [DEBUG] sofia.c:10556 verifying acl "domains" for ip/port 192.168.1.166:0.
  32. 2021-12-15 17:03:19.380771 96.50% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/1000@192.168.1.166) State NEW
  33. send 861 bytes to udp/[192.168.1.166]:52290 at 17:03:19.386962:
  34. ------------------------------------------------------------------------
  35. SIP/2.0 407 Proxy Authentication Required
  36. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---8600afbc9bef3bae;rport=52290
  37. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  38. To: <sip:1001@192.168.1.166>;tag=j6r09BX2XXH8H
  39. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  40. CSeq: 1 INVITE
  41. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  42. Accept: application/sdp
  43. Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  44. Supported: timer, path, replaces
  45. Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  46. Proxy-Authenticate: Digest realm="192.168.1.166", nonce="8f8b8c68-6c09-49fb-a04a-bbf41670c893", algorithm=MD5, qop="auth"
  47. Content-Length: 0
  48.  
  49. 2021-12-15 17:03:19.380771 96.50% [DEBUG] sofia.c:2419 detaching session 4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b
  50. recv 331 bytes from udp/[192.168.1.166]:52290 at 17:03:19.387264:
  51. ------------------------------------------------------------------------
  52. ACK sip:1001@192.168.1.166;transport=UDP SIP/2.0
  53. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---8600afbc9bef3bae;rport
  54. Max-Forwards: 70
  55. To: <sip:1001@192.168.1.166>;tag=j6r09BX2XXH8H
  56. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  57. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  58. CSeq: 1 ACK
  59. Content-Length: 0
  60.  
  61. recv 1027 bytes from udp/[192.168.1.166]:52290 at 17:03:19.387366:
  62. ------------------------------------------------------------------------
  63. INVITE sip:1001@192.168.1.166;transport=UDP SIP/2.0
  64. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---7fd5c555ce774478;rport
  65. Max-Forwards: 70
  66. Contact: <sip:1000@192.168.1.166:52290;transport=UDP>
  67. To: <sip:1001@192.168.1.166>
  68. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  69. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  70. CSeq: 2 INVITE
  71. Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
  72. Content-Type: application/sdp
  73. Proxy-Authorization: Digest username="1000",realm="192.168.1.166",nonce="8f8b8c68-6c09-49fb-a04a-bbf41670c893",uri="sip:1001@192.168.1.166;transport=UDP",response="613a4ec442386ecfccf8a34411da8f73",cnonce="20d2c9c110b3b5de3a43ed3c3727e74d",nc=00000001,qop=auth,algorithm=MD5
  74. User-Agent: Z 5.4.12 v2.10.13.2-mod
  75. Allow-Events: presence, kpml, talk
  76. Content-Length: 188
  77.  
  78. v=0
  79. o=Z 1639587799318 1 IN IP4 192.168.1.166
  80. s=Z
  81. c=IN IP4 192.168.1.166
  82. t=0 0
  83. m=audio 8000 RTP/AVP 106
  84. a=rtpmap:106 opus/48000/2
  85. a=fmtp:106 minptime=20; useinbandfec=1
  86. a=sendrecv
  87. 2021-12-15 17:03:19.380771 96.50% [DEBUG] sofia.c:2532 Re-attaching to session 4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b
  88. 2021-12-15 17:03:19.400733 96.50% [INFO] sofia.c:10462 sofia/internal/1000@192.168.1.166 receiving invite from 192.168.1.166:52290 version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit call-id: jYevjHAm1_ygYqwyPAyFbQ..
  89. 2021-12-15 17:03:19.400733 96.50% [DEBUG] sofia.c:10556 verifying acl "domains" for ip/port 192.168.1.166:0.
  90. 2021-12-15 17:03:19.400733 96.50% [DEBUG] sofia.c:7499 Channel sofia/internal/1000@192.168.1.166 entering state [received][100]
  91. 2021-12-15 17:03:19.400733 96.50% [DEBUG] sofia.c:7509 Remote SDP:
  92. v=0
  93. o=Z 1639587799318 1 IN IP4 192.168.1.166
  94. s=Z
  95. c=IN IP4 192.168.1.166
  96. t=0 0
  97. m=audio 8000 RTP/AVP 106
  98. a=rtpmap:106 opus/48000/2
  99. a=fmtp:106 minptime=20; useinbandfec=1
  100.  
  101. 2021-12-15 17:03:19.400733 96.50% [DEBUG] sofia.c:7912 (sofia/internal/1000@192.168.1.166) State Change CS_NEW -> CS_INIT
  102. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000@192.168.1.166) Running State Change CS_INIT (Cur 1 Tot 3)
  103. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1000@192.168.1.166) State INIT
  104. 2021-12-15 17:03:19.400733 96.50% [DEBUG] mod_sofia.c:97 sofia/internal/1000@192.168.1.166 SOFIA INIT
  105. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.166 Standard INIT
  106. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.166) State Change CS_INIT -> CS_ROUTING
  107. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1000@192.168.1.166) State INIT going to sleep
  108. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000@192.168.1.166) Running State Change CS_ROUTING (Cur 1 Tot 3)
  109. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_channel.c:2380 (sofia/internal/1000@192.168.1.166) Callstate Change DOWN -> RINGING
  110. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000@192.168.1.166) State ROUTING
  111. 2021-12-15 17:03:19.400733 96.50% [DEBUG] mod_sofia.c:158 sofia/internal/1000@192.168.1.166 SOFIA ROUTING
  112. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:230 sofia/internal/1000@192.168.1.166 Standard ROUTING
  113. 2021-12-15 17:03:19.400733 96.50% [INFO] mod_dialplan_xml.c:639 Processing 1000 <1000>->1001 in context default
  114. send 357 bytes to udp/[192.168.1.166]:52290 at 17:03:19.409407:
  115. ------------------------------------------------------------------------
  116. SIP/2.0 100 Trying
  117. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---7fd5c555ce774478;rport=52290
  118. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  119. To: <sip:1001@192.168.1.166>
  120. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  121. CSeq: 2 INVITE
  122. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  123. Content-Length: 0
  124.  
  125. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->unloop] continue=false
  126. Dialplan: sofia/internal/1000@192.168.1.166 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  127. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  128. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->tod_example] continue=true
  129. Dialplan: sofia/internal/1000@192.168.1.166 Date/Time Match (PASS) [tod_example] break=on-false
  130. Dialplan: sofia/internal/1000@192.168.1.166 Action set(open=true)
  131. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->holiday_example] continue=true
  132. Dialplan: sofia/internal/1000@192.168.1.166 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  133. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->global-intercept] continue=false
  134. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
  135. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->group-intercept] continue=false
  136. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
  137. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->intercept-ext] continue=false
  138. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
  139. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->redial] continue=false
  140. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false
  141. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->global] continue=true
  142. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  143. Dialplan: sofia/internal/1000@192.168.1.166 Regex (PASS) [global] ${default_password}(1234) =~ /^1234$/ break=never
  144. Dialplan: sofia/internal/1000@192.168.1.166 Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING )
  145. Dialplan: sofia/internal/1000@192.168.1.166 Action log(CRIT Open /usr/local/freeswitch/conf/vars.xml and change the default_password.)
  146. Dialplan: sofia/internal/1000@192.168.1.166 Action log(CRIT Once changed type 'reloadxml' at the console.)
  147. Dialplan: sofia/internal/1000@192.168.1.166 Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING )
  148. Dialplan: sofia/internal/1000@192.168.1.166 Action sleep(10000)
  149. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  150. Dialplan: sofia/internal/1000@192.168.1.166 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  151. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  152. o=Z 1639587799318 1 IN IP4 192.168.1.166
  153. s=Z
  154. c=IN IP4 192.168.1.166
  155. t=0 0
  156. m=audio 8000 RTP/AVP 106
  157. a=rtpmap:106 opus/48000/2
  158. a=fmtp:106 minptime=20; useinbandfec=1
  159. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  160. Dialplan: sofia/internal/1000@192.168.1.166 Absolute Condition [global]
  161. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  162. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  163. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  164. Dialplan: sofia/internal/1000@192.168.1.166 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  165. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->snom-demo-2] continue=false
  166. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false
  167. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->snom-demo-1] continue=false
  168. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false
  169. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->eavesdrop] continue=false
  170. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  171. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->eavesdrop] continue=false
  172. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false
  173. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->call_return] continue=false
  174. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
  175. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->del-group] continue=false
  176. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false
  177. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->add-group] continue=false
  178. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false
  179. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->call-group-simo] continue=false
  180. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
  181. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->call-group-order] continue=false
  182. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
  183. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->extension-intercom] continue=false
  184. Dialplan: sofia/internal/1000@192.168.1.166 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
  185. Dialplan: sofia/internal/1000@192.168.1.166 parsing [default->Local_Extension] continue=false
  186. Dialplan: sofia/internal/1000@192.168.1.166 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
  187. Dialplan: sofia/internal/1000@192.168.1.166 Action export(dialed_extension=1001)
  188. Dialplan: sofia/internal/1000@192.168.1.166 Action bind_meta_app(1 b s execute_extension::dx XML features)
  189. Dialplan: sofia/internal/1000@192.168.1.166 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  190. Dialplan: sofia/internal/1000@192.168.1.166 Action bind_meta_app(3 b s execute_extension::cf XML features)
  191. Dialplan: sofia/internal/1000@192.168.1.166 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  192. Dialplan: sofia/internal/1000@192.168.1.166 Action set(ringback=${us-ring})
  193. Dialplan: sofia/internal/1000@192.168.1.166 Action set(transfer_ringback=local_stream://moh)
  194. Dialplan: sofia/internal/1000@192.168.1.166 Action set(call_timeout=30)
  195. Dialplan: sofia/internal/1000@192.168.1.166 Action set(hangup_after_bridge=true)
  196. Dialplan: sofia/internal/1000@192.168.1.166 Action set(continue_on_fail=true)
  197. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  198. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  199. Dialplan: sofia/internal/1000@192.168.1.166 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  200. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  201. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  202. Dialplan: sofia/internal/1000@192.168.1.166 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  203. Dialplan: sofia/internal/1000@192.168.1.166 Action bridge({absolute_codec_string=PCMA}user/${dialed_extension}@${domain_name})
  204. Dialplan: sofia/internal/1000@192.168.1.166 Action answer()
  205. Dialplan: sofia/internal/1000@192.168.1.166 Action sleep(1000)
  206. Dialplan: sofia/internal/1000@192.168.1.166 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  207. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/1000@192.168.1.166) State Change CS_ROUTING -> CS_EXECUTE
  208. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000@192.168.1.166) State ROUTING going to sleep
  209. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000@192.168.1.166) Running State Change CS_EXECUTE (Cur 1 Tot 3)
  210. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1000@192.168.1.166) State EXECUTE
  211. 2021-12-15 17:03:19.400733 96.50% [DEBUG] mod_sofia.c:213 sofia/internal/1000@192.168.1.166 SOFIA EXECUTE
  212. 2021-12-15 17:03:19.400733 96.50% [DEBUG] switch_core_state_machine.c:323 sofia/internal/1000@192.168.1.166 Standard EXECUTE
  213. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(open=true)
  214. 2021-12-15 17:03:19.400733 96.50% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [open]=[true]
  215. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING )
  216. 2021-12-15 17:03:19.400733 96.50% [CRIT] mod_dptools.c:1879 WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING
  217. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 log(CRIT Open /usr/local/freeswitch/conf/vars.xml and change the default_password.)
  218. 2021-12-15 17:03:19.400733 96.50% [CRIT] mod_dptools.c:1879 Open /usr/local/freeswitch/conf/vars.xml and change the default_password.
  219. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 log(CRIT Once changed type 'reloadxml' at the console.)
  220. 2021-12-15 17:03:19.400733 96.50% [CRIT] mod_dptools.c:1879 Once changed type 'reloadxml' at the console.
  221. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING )
  222. 2021-12-15 17:03:19.400733 96.50% [CRIT] mod_dptools.c:1879 WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING
  223. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 sleep(10000)
  224. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-spymap/1000/4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b)
  225. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-last_dial/1000/1001)
  226. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-last_dial/global/4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b)
  227. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 export(RFC2822_DATE=Wed, 15 Dec 2021 17:03:29 +0000)
  228. 2021-12-15 17:03:29.460819 95.73% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 15 Dec 2021 17:03:29 +0000]
  229. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 export(dialed_extension=1001)
  230. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [dialed_extension]=[1001]
  231. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 bind_meta_app(1 b s execute_extension::dx XML features)
  232. 2021-12-15 17:03:29.480752 95.73% [INFO] switch_ivr_async.c:4774 Bound B-Leg: *1 execute_extension::dx XML features
  233. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1000.2021-12-15-17-03-29.wav)
  234. 2021-12-15 17:03:29.480752 95.73% [INFO] switch_ivr_async.c:4774 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1000.2021-12-15-17-03-29.wav
  235. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 bind_meta_app(3 b s execute_extension::cf XML features)
  236. 2021-12-15 17:03:29.480752 95.73% [INFO] switch_ivr_async.c:4774 Bound B-Leg: *3 execute_extension::cf XML features
  237. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  238. 2021-12-15 17:03:29.480752 95.73% [INFO] switch_ivr_async.c:4774 Bound B-Leg: *4 execute_extension::att_xfer XML features
  239. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(ringback=%(2000,4000,440,480))
  240. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [ringback]=[%(2000,4000,440,480)]
  241. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(transfer_ringback=local_stream://moh)
  242. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [transfer_ringback]=[local_stream://moh]
  243. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(call_timeout=30)
  244. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [call_timeout]=[30]
  245. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(hangup_after_bridge=true)
  246. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [hangup_after_bridge]=[true]
  247. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(continue_on_fail=true)
  248. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [continue_on_fail]=[true]
  249. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-call_return/1001/1000)
  250. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-last_dial_ext/1001/4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b)
  251. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 set(called_party_callgroup=techsupport)
  252. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_dptools.c:1685 SET sofia/internal/1000@192.168.1.166 [called_party_callgroup]=[techsupport]
  253. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-last_dial_ext/techsupport/4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b)
  254. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-last_dial_ext/global/4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b)
  255. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 hash(insert/192.168.1.166-last_dial/techsupport/4c46c0fd-19c3-4c49-ba6f-c8f7f286f93b)
  256. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 bridge({absolute_codec_string=PCMA}user/1001@192.168.1.166)
  257. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_channel.c:1269 sofia/internal/1000@192.168.1.166 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 15 Dec 2021 17:03:29 +0000] to event
  258. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_channel.c:1269 sofia/internal/1000@192.168.1.166 EXPORTING[export_vars] [dialed_extension]=[1001] to event
  259. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  260. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_channel.c:1269 sofia/internal/1000@192.168.1.166 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 15 Dec 2021 17:03:29 +0000] to event
  261. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_channel.c:1269 sofia/internal/1000@192.168.1.166 EXPORTING[export_vars] [dialed_extension]=[1001] to event
  262. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  263. 2021-12-15 17:03:29.480752 95.73% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/1001@192.168.1.166:5090 [a867ec4e-35fc-4103-8b68-232a3626577c]
  264. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_sofia.c:5121 (sofia/internal/1001@192.168.1.166:5090) State Change CS_NEW -> CS_INIT
  265. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@192.168.1.166:5090) Running State Change CS_INIT (Cur 2 Tot 4)
  266. 2021-12-15 17:03:29.480752 95.73% [NOTICE] switch_ivr_originate.c:3039 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  267. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1001@192.168.1.166:5090) State INIT
  268. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_sofia.c:97 sofia/internal/1001@192.168.1.166:5090 SOFIA INIT
  269. 2021-12-15 17:03:29.480752 95.73% [INFO] sofia_glue.c:1651 sofia/internal/1001@192.168.1.166:5090 sending invite call-id: (null)
  270. 2021-12-15 17:03:29.480752 95.73% [DEBUG] sofia_glue.c:1654 sofia/internal/1001@192.168.1.166:5090 sending invite version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit
  271. Local SDP:
  272. v=0
  273. o=FreeSWITCH 1639570095 1639570096 IN IP4 192.168.1.166
  274. s=FreeSWITCH
  275. c=IN IP4 192.168.1.166
  276. t=0 0
  277. m=audio 17714 RTP/AVP 8 101
  278. a=rtpmap:8 PCMA/8000
  279. a=rtpmap:101 telephone-event/8000
  280. a=fmtp:101 0-15
  281. a=ptime:20
  282. a=sendrecv
  283.  
  284. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.1.166:5090 Standard INIT
  285. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.1.166:5090) State Change CS_INIT -> CS_ROUTING
  286. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1001@192.168.1.166:5090) State INIT going to sleep
  287. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@192.168.1.166:5090) Running State Change CS_ROUTING (Cur 2 Tot 4)
  288. send 1214 bytes to udp/[192.168.1.166]:5090 at 17:03:29.496729:
  289. ------------------------------------------------------------------------
  290. INVITE sip:1001@192.168.1.166:5090;transport=udp SIP/2.0
  291. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKgmj5BZ57HD72p
  292. Max-Forwards: 69
  293. From: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  294. To: <sip:1001@192.168.1.166:5090;transport=udp>
  295. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  296. CSeq: 45240112 INVITE
  297. Contact: <sip:mod_sofia@192.168.1.166:5060>
  298. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  299. Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  300. Supported: timer, path, replaces
  301. Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  302. Content-Type: application/sdp
  303. Content-Disposition: session
  304. Content-Length: 222
  305. X-FS-Support: update_display,send_info
  306. Remote-Party-ID: "Extension 1000" <sip:1000@192.168.1.166>;party=calling;screen=yes;privacy=off
  307.  
  308. v=0
  309. o=FreeSWITCH 1639570095 1639570096 IN IP4 192.168.1.166
  310. s=FreeSWITCH
  311. c=IN IP4 192.168.1.166
  312. t=0 0
  313. m=audio 17714 RTP/AVP 8 101
  314. a=rtpmap:8 PCMA/8000
  315. a=rtpmap:101 telephone-event/8000
  316. a=fmtp:101 0-15
  317. a=ptime:20
  318. 2021-12-15 17:03:29.480752 95.73% [DEBUG] sofia.c:7499 Channel sofia/internal/1001@192.168.1.166:5090 entering state [calling][0]
  319. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@192.168.1.166:5090) State ROUTING
  320. 2021-12-15 17:03:29.480752 95.73% [DEBUG] mod_sofia.c:158 sofia/internal/1001@192.168.1.166:5090 SOFIA ROUTING
  321. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@192.168.1.166:5090) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  322. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@192.168.1.166:5090) State ROUTING going to sleep
  323. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@192.168.1.166:5090) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 4)
  324. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:659 (sofia/internal/1001@192.168.1.166:5090) State CONSUME_MEDIA
  325. 2021-12-15 17:03:29.480752 95.73% [DEBUG] switch_core_state_machine.c:659 (sofia/internal/1001@192.168.1.166:5090) State CONSUME_MEDIA going to sleep
  326. recv 274 bytes from udp/[192.168.1.166]:5090 at 17:03:29.510806:
  327. ------------------------------------------------------------------------
  328. SIP/2.0 100 Trying
  329. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKgmj5BZ57HD72p
  330. From: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  331. To: <sip:1001@192.168.1.166:5090;transport=udp>
  332. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  333. CSeq: 45240112 INVITE
  334.  
  335. recv 365 bytes from udp/[192.168.1.166]:5090 at 17:03:29.733151:
  336. ------------------------------------------------------------------------
  337. SIP/2.0 180 Ringing
  338. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKgmj5BZ57HD72p
  339. From: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  340. To: <sip:1001@192.168.1.166:5090;transport=udp>;tag=UHPPvfh
  341. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  342. CSeq: 45240112 INVITE
  343. User-Agent: Linphone/3.12.0 (belle-sip/1.6.3)
  344. Supported: replaces, outbound
  345.  
  346. 2021-12-15 17:03:29.720738 95.73% [DEBUG] sofia.c:7499 Channel sofia/internal/1001@192.168.1.166:5090 entering state [proceeding][180]
  347. 2021-12-15 17:03:29.720738 95.73% [NOTICE] sofia.c:7610 Ring-Ready sofia/internal/1001@192.168.1.166:5090!
  348. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_channel.c:3494 (sofia/internal/1001@192.168.1.166:5090) Callstate Change DOWN -> RINGING
  349. 2021-12-15 17:03:29.720738 95.73% [INFO] switch_ivr_originate.c:1295 Sending early media
  350. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:1]
  351. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  352. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[G722:9:8000:20:64000:1]
  353. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  354. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  355. 2021-12-15 17:03:29.720738 95.73% [DEBUG] mod_opus.c:619 Opus encoder: set bitrate to local settings [72000bps]
  356. 2021-12-15 17:03:29.720738 95.73% [DEBUG] mod_opus.c:619 Opus encoder: set bitrate to local settings [72000bps]
  357. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:3872 Set Codec sofia/internal/1000@192.168.1.166 opus/48000 20 ms 960 samples 0 bits 1 channels
  358. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.1.166 Original read codec set to opus:116
  359. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5946 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  360. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:5975 sofia/internal/1000@192.168.1.166 Set 2833 dtmf send payload to 101 recv payload to 101
  361. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:8779 AUDIO RTP [sofia/internal/1000@192.168.1.166] 192.168.1.166 port 31558 -> 192.168.1.166 port 8000 codec: 106 ms: 20
  362. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 960 bytes per 20ms
  363. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:9091 sofia/internal/1000@192.168.1.166 Set 2833 dtmf send payload to 101
  364. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:9098 sofia/internal/1000@192.168.1.166 Set 2833 dtmf receive payload to 101
  365. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_core_media.c:9121 sofia/internal/1000@192.168.1.166 Set rtp dtmf delay to 40
  366. 2021-12-15 17:03:29.720738 95.73% [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@192.168.1.166!
  367. 2021-12-15 17:03:29.720738 95.73% [DEBUG] switch_channel.c:3622 (sofia/internal/1000@192.168.1.166) Callstate Change RINGING -> EARLY
  368. 2021-12-15 17:03:29.740740 95.73% [DEBUG] switch_core_media.c:8761 Audio params are unchanged for sofia/internal/1000@192.168.1.166.
  369. 2021-12-15 17:03:29.740740 95.73% [DEBUG] mod_sofia.c:2610 Ring SDP:
  370. v=0
  371. o=FreeSWITCH 1639556251 1639556252 IN IP4 192.168.1.166
  372. s=FreeSWITCH
  373. c=IN IP4 192.168.1.166
  374. t=0 0
  375. m=audio 31558 RTP/AVP 106 101
  376. a=rtpmap:106 opus/48000/2
  377. a=fmtp:106 useinbandfec=1; minptime=20
  378. a=rtpmap:101 telephone-event/8000
  379. a=fmtp:101 0-15
  380. a=ptime:20
  381. a=sendrecv
  382.  
  383. 2021-12-15 17:03:29.740740 95.73% [DEBUG] switch_ivr_originate.c:1353 Raw Codec Activation Success L16@48000hz 1 channel 20ms
  384. 2021-12-15 17:03:29.740740 95.73% [DEBUG] switch_core_codec.c:223 sofia/internal/1000@192.168.1.166 Push codec L16:100
  385. 2021-12-15 17:03:29.740740 95.73% [DEBUG] switch_ivr_originate.c:1427 Play Ringback Tone [%(2000,4000,440,480)]
  386. send 1197 bytes to udp/[192.168.1.166]:52290 at 17:03:29.740968:
  387. ------------------------------------------------------------------------
  388. SIP/2.0 183 Session Progress
  389. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---7fd5c555ce774478;rport=52290
  390. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  391. To: <sip:1001@192.168.1.166>;tag=KFjSB7D6t67tD
  392. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  393. CSeq: 2 INVITE
  394. Contact: <sip:1001@192.168.1.166:5060;transport=udp>
  395. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  396. Accept: application/sdp
  397. Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  398. Supported: timer, path, replaces
  399. Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  400. Content-Type: application/sdp
  401. Content-Disposition: session
  402. Content-Length: 269
  403. Remote-Party-ID: "1001" <sip:1001@192.168.1.166>;party=calling;privacy=off;screen=no
  404.  
  405. v=0
  406. o=FreeSWITCH 1639556251 1639556252 IN IP4 192.168.1.166
  407. s=FreeSWITCH
  408. c=IN IP4 192.168.1.166
  409. t=0 0
  410. m=audio 31558 RTP/AVP 106 101
  411. a=rtpmap:106 opus/48000/2
  412. a=fmtp:106 useinbandfec=1; minptime=20
  413. a=rtpmap:101 telephone-event/8000
  414. a=fmtp:101 0-15
  415. a=ptime:20
  416. 2021-12-15 17:03:29.760732 95.73% [DEBUG] sofia.c:7499 Channel sofia/internal/1000@192.168.1.166 entering state [early][183]
  417. 2021-12-15 17:03:30.000733 95.67% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  418. recv 772 bytes from udp/[192.168.1.166]:5090 at 17:03:31.052910:
  419. ------------------------------------------------------------------------
  420. SIP/2.0 200 Ok
  421. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKgmj5BZ57HD72p
  422. From: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  423. To: <sip:1001@192.168.1.166:5090;transport=udp>;tag=UHPPvfh
  424. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  425. CSeq: 45240112 INVITE
  426. User-Agent: Linphone/3.12.0 (belle-sip/1.6.3)
  427. Supported: replaces, outbound
  428. Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
  429. Contact: "Li" <sip:9999@192.168.1.166:5090;transport=udp>;+sip.instance="<urn:uuid:b8fee09a-4790-44f6-88d1-69c76cc5c84a>"
  430. Content-Type: application/sdp
  431. Content-Length: 146
  432.  
  433. v=0
  434. o=9999 3273 1710 IN IP4 192.168.1.166
  435. s=Talk
  436. c=IN IP4 192.168.1.166
  437. t=0 0
  438. m=audio 7078 RTP/AVP 8 101
  439. a=rtpmap:101 telephone-event/8000
  440. 2021-12-15 17:03:31.040777 95.33% [DEBUG] sofia.c:7499 Channel sofia/internal/1001@192.168.1.166:5090 entering state [completing][200]
  441. 2021-12-15 17:03:31.040777 95.33% [DEBUG] sofia.c:7509 Remote SDP:
  442. v=0
  443. o=9999 3273 1710 IN IP4 192.168.1.166
  444. s=Talk
  445. c=IN IP4 192.168.1.166
  446. t=0 0
  447. m=audio 7078 RTP/AVP 8 101
  448. a=rtpmap:101 telephone-event/8000
  449.  
  450. send 400 bytes to udp/[192.168.1.166]:5090 at 17:03:31.054907:
  451. ------------------------------------------------------------------------
  452. ACK sip:9999@192.168.1.166:5090;transport=udp SIP/2.0
  453. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKHXByDtpBFpXNj
  454. Max-Forwards: 70
  455. From: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  456. To: <sip:1001@192.168.1.166:5090;transport=udp>;tag=UHPPvfh
  457. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  458. CSeq: 45240112 ACK
  459. Contact: <sip:mod_sofia@192.168.1.166:5060>
  460. Content-Length: 0
  461.  
  462. 2021-12-15 17:03:31.040777 95.33% [DEBUG] sofia.c:7499 Channel sofia/internal/1001@192.168.1.166:5090 entering state [ready][200]
  463. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  464. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  465. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:5568 Set telephone-event payload to 101@8000
  466. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:3872 Set Codec sofia/internal/1001@192.168.1.166:5090 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  467. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.1.166:5090 Original read codec set to PCMA:8
  468. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:5917 Set telephone-event payload to 101@8000
  469. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:5975 sofia/internal/1001@192.168.1.166:5090 Set 2833 dtmf send payload to 101 recv payload to 101
  470. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:8779 AUDIO RTP [sofia/internal/1001@192.168.1.166:5090] 192.168.1.166 port 17714 -> 192.168.1.166 port 7078 codec: 8 ms: 20
  471. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
  472. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:9091 sofia/internal/1001@192.168.1.166:5090 Set 2833 dtmf send payload to 101
  473. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:9098 sofia/internal/1001@192.168.1.166:5090 Set 2833 dtmf receive payload to 101
  474. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_media.c:9121 sofia/internal/1001@192.168.1.166:5090 Set rtp dtmf delay to 40
  475. 2021-12-15 17:03:31.040777 95.33% [NOTICE] sofia.c:8683 Channel [sofia/internal/1001@192.168.1.166:5090] has been answered
  476. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_channel.c:3950 (sofia/internal/1001@192.168.1.166:5090) Callstate Change RINGING -> ACTIVE
  477. 2021-12-15 17:03:31.040777 95.33% [DEBUG] switch_core_codec.c:248 sofia/internal/1000@192.168.1.166 Restore previous codec opus:116.
  478. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_core_media.c:8761 Audio params are unchanged for sofia/internal/1000@192.168.1.166.
  479. 2021-12-15 17:03:31.060758 95.33% [DEBUG] mod_sofia.c:913 Local SDP sofia/internal/1000@192.168.1.166:
  480. v=0
  481. o=FreeSWITCH 1639556251 1639556253 IN IP4 192.168.1.166
  482. s=FreeSWITCH
  483. c=IN IP4 192.168.1.166
  484. t=0 0
  485. m=audio 31558 RTP/AVP 106 101
  486. a=rtpmap:106 opus/48000/2
  487. a=fmtp:106 useinbandfec=1; minptime=20
  488. a=rtpmap:101 telephone-event/8000
  489. a=fmtp:101 0-15
  490. a=ptime:20
  491. a=sendrecv
  492.  
  493. 2021-12-15 17:03:31.060758 95.33% [NOTICE] switch_ivr_originate.c:3834 Channel [sofia/internal/1000@192.168.1.166] has been answered
  494. send 1167 bytes to udp/[192.168.1.166]:52290 at 17:03:31.061297:
  495. ------------------------------------------------------------------------
  496. SIP/2.0 200 OK
  497. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---7fd5c555ce774478;rport=52290
  498. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  499. To: <sip:1001@192.168.1.166>;tag=KFjSB7D6t67tD
  500. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  501. CSeq: 2 INVITE
  502. Contact: <sip:1001@192.168.1.166:5060;transport=udp>
  503. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  504. Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  505. Supported: timer, path, replaces
  506. Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  507. Content-Type: application/sdp
  508. Content-Disposition: session
  509. Content-Length: 269
  510. Remote-Party-ID: "Outbound Call" <sip:1001@192.168.1.166>;party=calling;privacy=off;screen=no
  511.  
  512. v=0
  513. o=FreeSWITCH 1639556251 1639556252 IN IP4 192.168.1.166
  514. s=FreeSWITCH
  515. c=IN IP4 192.168.1.166
  516. t=0 0
  517. m=audio 31558 RTP/AVP 106 101
  518. a=rtpmap:106 opus/48000/2
  519. a=fmtp:106 useinbandfec=1; minptime=20
  520. a=rtpmap:101 telephone-event/8000
  521. a=fmtp:101 0-15
  522. a=ptime:20
  523. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_channel.c:3950 (sofia/internal/1000@192.168.1.166) Callstate Change EARLY -> ACTIVE
  524. 2021-12-15 17:03:31.060758 95.33% [DEBUG] sofia.c:7499 Channel sofia/internal/1000@192.168.1.166 entering state [completed][200]
  525. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/internal/1001@192.168.1.166:5090] Peer UUID: a867ec4e-35fc-4103-8b68-232a3626577c
  526. recv 428 bytes from udp/[192.168.1.166]:52290 at 17:03:31.061723:
  527. ------------------------------------------------------------------------
  528. ACK sip:1001@192.168.1.166:5060;transport=udp SIP/2.0
  529. Via: SIP/2.0/UDP 192.168.1.166:52290;branch=z9hG4bK-524287-1---08d023c7b637dc0e;rport
  530. Max-Forwards: 70
  531. Contact: <sip:1000@192.168.1.166:52290;transport=UDP>
  532. To: <sip:1001@192.168.1.166>;tag=KFjSB7D6t67tD
  533. From: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  534. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  535. CSeq: 2 ACK
  536. User-Agent: Z 5.4.12 v2.10.13.2-mod
  537. Content-Length: 0
  538.  
  539. 2021-12-15 17:03:31.060758 95.33% [DEBUG] sofia.c:7499 Channel sofia/internal/1000@192.168.1.166 entering state [ready][200]
  540. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/internal/1001@192.168.1.166:5090] Peer UUID: a867ec4e-35fc-4103-8b68-232a3626577c
  541. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_ivr_bridge.c:1793 (sofia/internal/1001@192.168.1.166:5090) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  542. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@192.168.1.166:5090) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 4)
  543. 2021-12-15 17:03:31.060758 95.33% [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.1.166:5090) State EXCHANGE_MEDIA
  544. 2021-12-15 17:03:31.060758 95.33% [DEBUG] mod_sofia.c:671 SOFIA EXCHANGE_MEDIA
  545. 2021-12-15 17:03:31.100843 95.33% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  546. 2021-12-15 17:03:31.100843 95.33% [NOTICE] switch_core_media.c:16153 Activating write resampler
  547. 2021-12-15 17:03:31.100843 95.33% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  548. 2021-12-15 17:03:31.100843 95.33% [NOTICE] switch_core_media.c:16153 Activating write resampler
  549. recv 928 bytes from udp/[192.168.1.166]:5090 at 17:03:36.911648:
  550. ------------------------------------------------------------------------
  551. INVITE sip:mod_sofia@192.168.1.166:5060 SIP/2.0
  552. Via: SIP/2.0/UDP 192.168.1.166:5090;branch=z9hG4bK.SfSowul~m;rport
  553. From: <sip:1001@192.168.1.166>;tag=UHPPvfh
  554. To: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  555. CSeq: 111 INVITE
  556. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  557. Max-Forwards: 70
  558. Subject: Call on hold
  559. Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
  560. Content-Type: application/sdp
  561. Content-Length: 281
  562. Contact: "Li" <sip:9999@192.168.1.166:5090;transport=udp>;+sip.instance="<urn:uuid:b8fee09a-4790-44f6-88d1-69c76cc5c84a>"
  563. User-Agent: Linphone/3.12.0 (belle-sip/1.6.3)
  564.  
  565. v=0
  566. o=9999 3273 1711 IN IP4 192.168.1.166
  567. s=Talk
  568. c=IN IP4 192.168.1.166
  569. t=0 0
  570. a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
  571. m=audio 7078 RTP/AVP 8 101
  572. a=rtpmap:101 telephone-event/8000
  573. a=sendonly
  574. a=rtcp-fb:* trr-int 5000
  575. a=rtcp-fb:* ccm tmmbr
  576. send 371 bytes to udp/[192.168.1.166]:5090 at 17:03:36.918184:
  577. ------------------------------------------------------------------------
  578. SIP/2.0 100 Trying
  579. Via: SIP/2.0/UDP 192.168.1.166:5090;branch=z9hG4bK.SfSowul~m;rport=5090
  580. From: <sip:1001@192.168.1.166>;tag=UHPPvfh
  581. To: "Extension 1000" <sip:1000@192.168.1.166>;tag=mrBjD2y9QFyDS
  582. Call-ID: c4810aa7-d86b-123a-3585-dc1ba1ed361d
  583. CSeq: 111 INVITE
  584. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  585. Content-Length: 0
  586.  
  587. 2021-12-15 17:03:36.900851 93.23% [DEBUG] sofia.c:7499 Channel sofia/internal/1001@192.168.1.166:5090 entering state [received][100]
  588. 2021-12-15 17:03:36.900851 93.23% [DEBUG] sofia.c:7509 Remote SDP:
  589. v=0
  590. o=9999 3273 1711 IN IP4 192.168.1.166
  591. s=Talk
  592. c=IN IP4 192.168.1.166
  593. t=0 0
  594. a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
  595. m=audio 7078 RTP/AVP 8 101
  596. a=rtpmap:101 telephone-event/8000
  597. a=sendonly
  598. a=rtcp-fb:* trr-int 5000
  599. a=rtcp-fb:* ccm tmmbr
  600.  
  601. 2021-12-15 17:03:36.900851 93.23% [DEBUG] switch_channel.c:1975 (sofia/internal/1001@192.168.1.166:5090) Callstate Change ACTIVE -> HELD
  602. 2021-12-15 17:03:37.060765 93.23% [DEBUG] switch_ivr.c:632 sofia/internal/1000@192.168.1.166 Command Execute [depth=0] playback(local_stream://moh)
  603. EXECUTE [depth=0] sofia/internal/1000@192.168.1.166 playback(local_stream://moh)
  604. 2021-12-15 17:03:37.060765 93.23% [WARNING] mod_local_stream.c:874 Unknown source moh, trying 'default'
  605. 2021-12-15 17:03:37.060765 93.23% [ERR] mod_local_stream.c:882 Unknown source default
  606. 2021-12-15 17:03:37.160800 93.23% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  607. 2021-12-15 17:03:37.160800 93.23% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  608. 2021-12-15 17:03:37.160800 93.23% [DEBUG] switch_core_media.c:5568 Set telephone-event payload to 101@8000
  609. 2021-12-15 17:03:37.160800 93.23% [DEBUG] switch_core_media.c:5917 Set telephone-event payload to 101@8000
  610. 2021-12-15 17:03:37.160800 93.23% [DEBUG] switch_core_media.c:5975 sofia/internal/1001@192.168.1.166:5090 Set 2833 dtmf send payload to 101 recv payload to 101
  611. 2021-12-15 17:03:37.160800 93.23% [DEBUG] switch_core_media.c:8761 Audio params are unchanged for sofia/internal/1001@192.168.1.166:5090.
  612. 2021-12-15 17:03:37.160800 93.23% [DEBUG] sofia.c:8454 Processing updated SDP
  613. 2021-12-15 17:03:37.160800 93.23% [INFO] sofia_glue.c:1651 sofia/internal/1000@192.168.1.166 sending invite call-id: (null)
  614. 2021-12-15 17:03:37.160800 93.23% [DEBUG] sofia_glue.c:1654 sofia/internal/1000@192.168.1.166 sending invite version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit
  615. Local SDP:
  616. v=0
  617. o=FreeSWITCH 1639556251 1639556255 IN IP4 192.168.1.166
  618. s=FreeSWITCH
  619. c=IN IP4 192.168.1.166
  620. t=0 0
  621. m=audio 31558 RTP/AVP 8 101
  622. a=rtpmap:8 PCMA/8000
  623. a=rtpmap:101 telephone-event/8000
  624. a=fmtp:101 0-15
  625. a=ptime:20
  626. a=sendonly
  627.  
  628. send 917 bytes to udp/[192.168.1.166]:52290 at 17:03:37.179829:
  629. ------------------------------------------------------------------------
  630. INVITE sip:1000@192.168.1.166:52290;transport=UDP SIP/2.0
  631. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKj64pFN7ecZK8D
  632. Max-Forwards: 70
  633. From: <sip:1001@192.168.1.166>;tag=KFjSB7D6t67tD
  634. To: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  635. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  636. CSeq: 45240116 INVITE
  637. Contact: <sip:1001@192.168.1.166:5060;transport=udp>
  638. User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20211117T192328Z~e428be3f1a~64bit
  639. Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  640. Supported: timer, path, replaces
  641. Content-Type: application/sdp
  642. Content-Length: 234
  643. X-FS-Support: update_display,send_info
  644.  
  645. v=0
  646. o=FreeSWITCH 1639556251 1639556255 IN IP4 192.168.1.166
  647. s=FreeSWITCH
  648. c=IN IP4 192.168.1.166
  649. t=0 0
  650. m=audio 31558 RTP/AVP 8 101
  651. a=rtpmap:8 PCMA/8000
  652. a=rtpmap:101 telephone-event/8000
  653. a=fmtp:101 0-15
  654. a=ptime:20
  655. a=sendonly
  656. recv 330 bytes from udp/[192.168.1.166]:52290 at 17:03:37.181142:
  657. ------------------------------------------------------------------------
  658. SIP/2.0 415 Unsupported Media Type
  659. Via: SIP/2.0/UDP 192.168.1.166;rport=5060;branch=z9hG4bKj64pFN7ecZK8D
  660. To: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  661. From: <sip:1001@192.168.1.166>;tag=KFjSB7D6t67tD
  662. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  663. CSeq: 45240116 INVITE
  664. User-Agent: Z 5.4.12 v2.10.13.2-mod
  665. Content-Length: 0
  666.  
  667. send 323 bytes to udp/[192.168.1.166]:52290 at 17:03:37.181313:
  668. ------------------------------------------------------------------------
  669. ACK sip:1000@192.168.1.166:52290;transport=UDP SIP/2.0
  670. Via: SIP/2.0/UDP 192.168.1.166;rport;branch=z9hG4bKj64pFN7ecZK8D
  671. Max-Forwards: 70
  672. From: <sip:1001@192.168.1.166>;tag=KFjSB7D6t67tD
  673. To: <sip:1000@192.168.1.166;transport=UDP>;tag=6544b655
  674. Call-ID: jYevjHAm1_ygYqwyPAyFbQ..
  675. CSeq: 45240116 ACK
  676. Content-Length: 0
  677.  
  678. 2021-12-15 17:03:37.180812 93.23% [DEBUG] sofia.c:7499 Channel sofia/internal/1000@192.168.1.166 entering state [calling][0]
  679. 2021-12-15 17:03:37.180812 93.23% [DEBUG] sofia.c:7492 Channel sofia/internal/1000@192.168.1.166 skipping state [ready][415]
  680.  

Reply to "opuspcmareinvitre"